Transformer: Creating the leaf version in igmp-snooping throws error "Entry Vlan10 already exists"

[mbalachandar]

Hi Mari / Kwan

As discussed, facing this issue, creating it in the git-hub for the tracking purpose. Please let me know if you need more details.

While trying to create the leaf "version" using POST (create) method, we get error saying "Entry Vlan10 already exists". Please see the logs below:

rest-server trace

I1030 17:40:29.755898   71235 handler.go:47] [REST-6] POST /restconf/data/openconfig-interfaces:interfaces/interface=Vlan10/config/openconfig-interfaces-deviation:igmp-snooping; content-len=15
I1030 17:40:29.755957   71235 handler.go:134] [REST-6] Content-type=application/yang-data+json; data={ "version": 2}
I1030 17:40:29.755978   71235 handler.go:55] [REST-6] Translated path = /openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping
I1030 17:40:29.755991   71235 translib.go:149] Create request received with path =/openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping
I1030 17:40:29.755999   71235 translib.go:150] Create request received with payload ={ "version": 2}
I1030 17:40:29.756009   71235 app_interface.go:130] getAppModule called for path =/openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping
I1030 17:40:29.756019   71235 app_interface.go:143] No app module registered for path /openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping hence fa
llback to default/common app
I1030 17:40:29.756033   71235 app_interface.go:165] cast to appInterface worked&{<nil> <nil> <nil> map[] []}
I1030 17:40:29.756637   71235 common_app.go:64] initialize:path =/openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping
I1030 17:40:29.756666   71235 db.go:297] NewDB: Begin: opt: { DBNo: 4, InitIndicator: , TableNameSeparator: |, KeySeparator: | , DisableCVLCheck: false }
I1030 17:40:29.756717   71235 db.go:333] NewDB: Init indication not requested
I1030 17:40:29.756725   71235 db.go:347] NewDB: End: d: { client: Redis<localhost:6379 db:4>, Opts: { DBNo: 4, InitIndicator: , TableNameSeparator: |, KeySeparator: | , DisableCVLCheck: false }, txState:
txStateNone, tsCmds: [] } e: <nil>
I1030 17:40:29.756752   71235 common_app.go:73] translateCreate:path =/openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping
I1030 17:40:29.756760   71235 common_app.go:252] translateCRUDCommon:path =/openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping
I1030 17:40:29.773261   71235 xlate.go:265] CREATE case
I1030 17:40:29.773294   71235 xlate_to_db.go:486] key(""), xpathPrefix("").
I1030 17:40:29.773305   71235 xlate_to_db.go:527] slice/map data: key(""), xpathPrefix("").
I1030 17:40:29.773313   71235 xlate_to_db.go:540] slice/map data: curKey(""), xpath("/openconfig-interfaces:interfaces"), curUri("/openconfig-interfaces:interfaces").
I1030 17:40:29.773323   71235 xlate_to_db.go:486] key(""), xpathPrefix("/openconfig-interfaces:interfaces").
I1030 17:40:29.773331   71235 xlate_to_db.go:527] slice/map data: key(""), xpathPrefix("/openconfig-interfaces:interfaces").
I1030 17:40:29.773339   71235 xlate_to_db.go:540] slice/map data: curKey(""), xpath("/openconfig-interfaces:interfaces/interface"), curUri("/openconfig-interfaces:interfaces/interface").
I1030 17:40:29.773346   71235 xlate_to_db.go:486] key(""), xpathPrefix("/openconfig-interfaces:interfaces/interface").
I1030 17:40:29.773352   71235 xlate_to_db.go:490] slice data: key(""), xpathPrefix("/openconfig-interfaces:interfaces/interface").
I1030 17:40:29.773363   71235 xlate_to_db.go:486] key("Vlan10"), xpathPrefix("/openconfig-interfaces:interfaces/interface").
I1030 17:40:29.773372   71235 xlate_to_db.go:527] slice/map data: key("Vlan10"), xpathPrefix("/openconfig-interfaces:interfaces/interface").
I1030 17:40:29.773385   71235 xlate_to_db.go:540] slice/map data: curKey("Vlan10"), xpath("/openconfig-interfaces:interfaces/interface/config"), curUri("/openconfig-interfaces:interfaces/interface[name=Vl
an10]/config").
I1030 17:40:29.773394   71235 xlate_to_db.go:486] key("Vlan10"), xpathPrefix("/openconfig-interfaces:interfaces/interface/config").
I1030 17:40:29.773402   71235 xlate_to_db.go:527] slice/map data: key("Vlan10"), xpathPrefix("/openconfig-interfaces:interfaces/interface/config").
I1030 17:40:29.773409   71235 xlate_to_db.go:540] slice/map data: curKey("Vlan10"), xpath("/openconfig-interfaces:interfaces/interface/config/igmp-snooping"), curUri("/openconfig-interfaces:interfaces/int
erface[name=Vlan10]/config/igmp-snooping").
I1030 17:40:29.773418   71235 xlate_to_db.go:486] key("Vlan10"), xpathPrefix("/openconfig-interfaces:interfaces/interface/config/igmp-snooping").
I1030 17:40:29.773425   71235 xlate_to_db.go:527] slice/map data: key("Vlan10"), xpathPrefix("/openconfig-interfaces:interfaces/interface/config/igmp-snooping").
I1030 17:40:29.773433   71235 xlate_to_db.go:540] slice/map data: curKey("Vlan10"), xpath("/openconfig-interfaces:interfaces/interface/config/igmp-snooping/version"), curUri("/openconfig-interfaces:interf
aces/interface[name=Vlan10]/config/igmp-snooping/version").
I1030 17:40:29.773445   71235 xlate_to_db.go:584] data field: key("version"), value("2").
I1030 17:40:29.773506   71235 xlate_to_db.go:86] name: "version", xpathPrefix("/openconfig-interfaces:interfaces/interface/config/igmp-snooping").
I1030 17:40:29.773523   71235 xlate_to_db.go:191] TblName: "CFG_L2MC_TABLE", key: "Vlan10", field: "version", valueStr: "2".
I1030 17:40:29.773532   71235 xlate_to_db.go:527] slice/map data: key("Vlan10"), xpathPrefix("/openconfig-interfaces:interfaces/interface").
I1030 17:40:29.773539   71235 xlate_to_db.go:540] slice/map data: curKey("Vlan10"), xpath("/openconfig-interfaces:interfaces/interface/name"), curUri("/openconfig-interfaces:interfaces/interface[name=Vlan
10]/name").
I1030 17:40:29.773550   71235 xlate_to_db.go:584] data field: key("name"), value("Vlan10").
I1030 17:40:29.773556   71235 xlate_to_db.go:86] name: "name", xpathPrefix("/openconfig-interfaces:interfaces/interface").
I1030 17:40:29.773562   71235 xlate_to_db.go:440] Fill default value for /openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping, oper(2)
I1030 17:40:29.773575   71235 xlate_to_db.go:396] Update("/openconfig-interfaces:interfaces/interface/config/igmp-snooping/last-member-query-interval") default: tbl["CFG_L2MC_TABLE"]key["Vlan10"]fld["last-member-query-interval"] = val("1000").
I1030 17:40:29.773583   71235 xlate_to_db.go:86] name: "last-member-query-interval", xpathPrefix("/openconfig-interfaces:interfaces/interface/config/igmp-snooping").
I1030 17:40:29.773591   71235 xlate_to_db.go:191] TblName: "CFG_L2MC_TABLE", key: "Vlan10", field: "last-member-query-interval", valueStr: "1000".
I1030 17:40:29.773604   71235 xlate_to_db.go:396] Update("/openconfig-interfaces:interfaces/interface/config/igmp-snooping/query-max-response-time") default: tbl["CFG_L2MC_TABLE"]key["Vlan10"]fld["query-max-response-time"] = val("10").
I1030 17:40:29.773611   71235 xlate_to_db.go:86] name: "query-max-response-time", xpathPrefix("/openconfig-interfaces:interfaces/interface/config/igmp-snooping").
I1030 17:40:29.773618   71235 xlate_to_db.go:191] TblName: "CFG_L2MC_TABLE", key: "Vlan10", field: "query-max-response-time", valueStr: "10".
I1030 17:40:29.773626   71235 xlate_to_db.go:444] Module name for path /openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping is /openconfig-interfaces:interfaces
map[CFG_L2MC_TABLE:map[Vlan10:"version": "2"
"last-member-query-interval": "1000"
"query-max-response-time": "10"
]]
I1030 17:40:29.773810   71235 common_app.go:257] transformer.XlateToDb() returnedmap[CFG_L2MC_TABLE:map[Vlan10:"last-member-query-interval": "1000"
"query-max-response-time": "10"
"version": "2"
]]
I1030 17:40:29.773826   71235 xlate.go:387] received uri /openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping to extract module name from
I1030 17:40:29.773837   71235 xlate_utils.go:297] module name = openconfig-interfaces
I1030 17:40:29.773844   71235 common_app.go:280] Result Tables List[CFG_L2MC_TABLE]
I1030 17:40:29.773871   71235 xlate.go:446] Found sonic module(sonic-igmp-snooping) whose ordered table list contains table CFG_L2MC_TABLE
I1030 17:40:29.773882   71235 common_app.go:292] Tables to watch[0xc003e48a60 0xc003e48a80]
I1030 17:40:29.773899   71235 common_app.go:307] cvlSortDepTblList = [CFG_L2MC_TABLE]
I1030 17:40:29.773909   71235 db.go:1107] StartTx: Begin: w: [] tss: [0xc003e48a60 0xc003e48a80]
I1030 17:40:29.775650   71235 db.go:1131] StartTx: End: e: <nil>
I1030 17:40:29.775672   71235 common_app.go:130] processCreate:path =/openconfig-interfaces:interfaces/interface[name=Vlan10]/config/openconfig-interfaces-deviation:igmp-snooping
I1030 17:40:29.775680   71235 common_app.go:132] processCreate: Target object is a <ptr> of Type: OpenconfigInterfaces_Interfaces_Interface_Config_IgmpSnooping
I1030 17:40:29.775687   71235 common_app.go:320] Processing DB operation for map[CFG_L2MC_TABLE:map[Vlan10:"version": "2"
"last-member-query-interval": "1000"
"query-max-response-time": "10"
]]
I1030 17:40:29.775709   71235 common_app.go:323] CREATE case
I1030 17:40:29.775714   71235 common_app.go:350] In Yang to DB map returned from transformer looking for table = CFG_L2MC_TABLE
I1030 17:40:29.775720   71235 common_app.go:353] Found table entry in yang to DB map
I1030 17:40:29.775725   71235 common_app.go:355] Processing Table key and row Vlan10"version": "2"
"last-member-query-interval": "1000"
"query-max-response-time": "10"
I1030 17:40:29.775736   71235 db.go:413] GetEntry: Begin: ts: &{CFG_L2MC_TABLE 0} key: { Comp: [Vlan10] }
I1030 17:40:29.775829   71235 db.go:439] GetEntry: End: value: "last-member-query-interval": "1000"
"query-max-response-time": "10"
 e: <nil>
I1030 17:40:29.775845   71235 common_app.go:360] Entry already exists hence return.
I1030 17:40:29.775868   71235 common_app.go:336] Returning from processCommon() - fail
E1030 17:40:29.775876   71235 common_app.go:134] Entry Vlan10 already exists
I1030 17:40:29.775900   71235 db.go:1365] AbortTx: Begin:
I1030 17:40:29.775906   71235 db.go:1377] AbortTx: No SET|DEL done, txState: txStateWatch
I1030 17:40:29.775980   71235 db.go:1413] AbortTx: End: e: <nil>
I1030 17:40:29.775989   71235 db.go:357] DeleteDB: Begin: d: { client: Redis<localhost:6379 db:4>, Opts: { DBNo: 4, InitIndicator: , TableNameSeparator: |, KeySeparator: | , DisableCVLCheck: false }, txState: txStateNone, tsCmds: [] }
E1030 17:40:29.776049   71235 handler.go:59] [REST-6] Translib error tlerr.AlreadyExistsError - Entry Vlan10 already exists
I1030 17:40:29.776087   71235 handler.go:72] [REST-6] Sending response 409, type=application/yang-data+json, data={"ietf-restconf:errors":{"error":[{"error-type":"application","error-tag":"resource-denied","error-message":"Entry Vlan10 already exists"}]}}
I1030 17:40:29.776110   71235 router.go:128] [REST-6] PostOpenconfigInterfacesDeviationInterfacesInterfaceConfigIgmpSnoopingVersion took 20.250027ms

=======

curl -v -X POST "http://10.175.125.43:4443/restconf/data/openconfig-interfaces:interfaces/interface=Vlan10/config/openconfig-interfaces-deviation:igmp-snooping" -H "accept: application/yang-data+json" -H "Content-Type: application/yang-data+json" -d "{ \"version\": 2}"
Note: Unnecessary use of -X or --request, POST is already inferred.
*   Trying 10.175.125.43...
* Connected to 10.175.125.43 (10.175.125.43) port 4443 (#0)
> POST /restconf/data/openconfig-interfaces:interfaces/interface=Vlan10/config/openconfig-interfaces-deviation:igmp-snooping HTTP/1.1
> Host: 10.175.125.43:4443
> User-Agent: curl/7.45.0
> accept: application/yang-data+json
> Content-Type: application/yang-data+json
> Content-Length: 15
>
* upload completely sent off: 15 out of 15 bytes
< HTTP/1.1 409 Conflict
< Content-Type: application/yang-data+json
< Date: Thu, 31 Oct 2019 00:40:29 GMT
< Content-Length: 141
<
* Connection #0 to host 10.175.125.43 left intact
{"ietf-restconf:errors":{"error":[{"error-type":"application","error-tag":"resource-denied","error-message":"Entry Vlan10 already exists"}]}}

[bhavini-gada]

@mbalachandar - Should this be closed as the YANG used will be different now ?

[mbalachandar]

This issue is irrespective of this model, this error should not be thrown since VLAN is not a target node of the URI

[kwangsuk]

@mbalachandar
if you issue the POST (CREATE) on the resource "../igmp-snooping" and the resource is already existent in the DB, the server will respond to the client with an error. Please refer to https://tools.ietf.org/html/rfc8040#section-4.4.1.
" If the data resource already exists, then the POST request MUST fail
and a "409 Conflict" status-line MUST be returned. The error-tag
value "resource-denied" is used in this case."

Once an initial creation is made, you should use ether PATCH or PUT.
Do you think this is an issue?

[mbalachandar]

igmp-snooping is not exist at this time of issuing the request

[kwangsuk]

@mbalachandar
Ok, so, the problem is about initial creation (POST) on the resource, igmp-snooping. Right?

[mbalachandar]

yes Kwan, keep the parent table VLAN with the entry Vlan10 in the db, and try create the target node igmp-snooping

[kwangsuk]

@mbalachandar
According to the log, the CFG_L2MC_TABLE|Vlan10 already exists.
I understand that the resource "igmp-snooping" is mapped to the CFG_L2MC_TABLE in your annotation. So, the initial creation of resource "igmp-snooping" is to create CFG_L2MC_TABLE | , where the key is derived from the parent interface, i.e. vlan10. But, since the CFG_L2MC_TABLE|Vlan10 already exists, the POST operation should fail. Right? So, you should not use the POST operation on the resource "igmp-snooping". Instead you can use the PATCH on the "igmp-snooping" as target resource.

I1030 17:40:29.775709 71235 common_app.go:323] CREATE case
I1030 17:40:29.775714 71235 common_app.go:350] In Yang to DB map returned from transformer looking for table = CFG_L2MC_TABLE
I1030 17:40:29.775720 71235 common_app.go:353] Found table entry in yang to DB map
I1030 17:40:29.775725 71235 common_app.go:355] Processing Table key and row Vlan10"version": "2"
"last-member-query-interval": "1000"
"query-max-response-time": "10"
I1030 17:40:29.775736 71235 db.go:413] GetEntry: Begin: ts: &{CFG_L2MC_TABLE 0} key: { Comp: [Vlan10] }
I1030 17:40:29.775829 71235 db.go:439] GetEntry: End: value: "last-member-query-interval": "1000"
"query-max-response-time": "10"
e:
I1030 17:40:29.775845 71235 common_app.go:360] Entry already exists hence return.
I1030 17:40:29.775868 71235 common_app.go:336] Returning from processCommon() - fail

[bhavini-gada]

@kwangsuk - IGMP snooping will be augmented using network-instance YANG. @mbalachandar - Please create a new issue if you are still running into issues with that YANG.

[anand-kumar-subramanian]

I understand Bala will have a different yang path. But this is a generic transformer issue and this was discussed in length when we visited DELL. Following is the understanding on this.

Kwan,Mari,

I discussed with Bala on the default value handling. He clarified that the create at leaf level (URI containing the leaf) is not allowed by the REST server itself.
We verified this behavior with our REST server as well and it is not allowing that operation.
Only update and replace operations are allowed with the leaf URI by the REST server.

So I am updating the behavior.

Create Operation:
First container level create: Yang leaves with default value should be added to incoming json payload.
Uri : "/openconfig-interfaces:interfaces/interface[name=Vlan100]/config/openconfig-interfaces-deviation:igmp-snooping”
Payload : { "enabled" : true }
RedisDB data :
HGETALL "CFG_L2MC_TABLE|Vlan100"

1. "enabled"
2. "true"
3. "fast-leave"
4. "false"
5. "querier"
6. "false"
7. "query-max-response-time"
8. "10"
9. "last-member-query-interval"
10. "1000"
    Subsequent leaf level create
    Uri : "/openconfig-interfaces:interfaces/interface[name=Vlan100]/config/openconfig-interfaces-deviation:igmp-snooping/version”
    Payload : { "version" : 2 }
    Output : ERROR BY REST SERVER
    Subsequent container level create: (Even though URI is at the container level, the payload contains the leaf and hence this should be considered a leaf level create (as per RESTconf standard))
    Uri : "/openconfig-interfaces:interfaces/interface[name=Vlan100]/config/openconfig-interfaces-deviation:igmp-snooping”
    Payload : { "version" : 2 }
    RedisDB data :
    HGETALL "CFG_L2MC_TABLE|Vlan100"
11. "enabled"
12. "true"
13. "fast-leave"
14. "false"
15. "querier"
16. "false"
17. "query-max-response-time"
18. "10"
19. "last-member-query-interval"
20. "1000"
21. “version”
22. “2”
    Subsequent leaf level create:
    Uri : "/openconfig-interfaces:interfaces/interface[name=Vlan100]/config/openconfig-interfaces-deviation:igmp-snooping/version”
    Payload : { "version" : 3 }
    ERROR(Since version already exists)
    Subsequent leaf level update/replace:
    Uri : "/openconfig-interfaces:interfaces/interface[name=Vlan100]/config/openconfig-interfaces-deviation:igmp-snooping/version”
    Payload : { "version" : 3 }
    RedisDB data :
    HGETALL "CFG_L2MC_TABLE|Vlan100"
23. "enabled"
24. "true"
25. "fast-leave"
26. "false"
27. "querier"
28. "false"
29. "query-max-response-time"
30. "10"
31. "last-member-query-interval"
32. "1000"
33. “version”
34. “3”