OptimisticLockFailedException: infrautils.jobcoordinator-impl... ItmTepRemoveWorker... ConflictingModificationAppliedException: Node was replaced by other transaction

Activity

Show:

Victor Pickard December 20, 2017 at 6:41 PM

I was able to reproduce this with genius debug logs in csit (Thanks Jamo for the pointers!).

 

I see 2 threads deleting the dpn at the (almost) same time. I haven't been able to get to the bottom of this yet, will likely be after the Holiday break before I am able to look at this again.

 

Meanwhile, if anyone wants to take a look, debug logs can be found here (not sure for how long they will be available):

https://logs.opendaylight.org/sandbox/vex-yul-odl-jenkins-2/netvirt-csit-1node-openstack-ocata-vic-upstream-stateful-carbon/1/odl_1/odl1_karaf.log.gz

 

 

 

2017-12-19 19:58:16,955 | DEBUG | nPool-1-worker-7 | ItmTepRemoveWorker | 327 - org.opendaylight.genius.itm-impl - 0.2.3.SNAPSHOT | Invoking Internal Tunnel delete method with DpnList to be deleted [DPNTEPsInfo [_dPNID=242939118659093, _key=DPNTEPsInfoKey [_dPNID=242939118659093], _tunnelEndPoints=[TunnelEndPoints [_gwIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=0.0.0.0]], _interfaceName=242939118659093:tunnel_port:0, _ipAddress=IpAddress [_ipv4Address=Ipv4Address [_value=10.30.170.59]], _key=TunnelEndPointsKey [_portname=tunnel_port, _vLANID=0, _ipAddress=IpAddress [_ipv4Address=Ipv4Address [_value=10.30.170.59]], _tunnelType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.rev160406.TunnelTypeVxlan], _optionTunnelTos=0, _portname=tunnel_port, _subnetMask=IpPrefix [_ipv4Prefix=Ipv4Prefix [_value=0.0.0.0/0]], _tunnelType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.rev160406.TunnelTypeVxlan, _tzMembership=[TzMembership [_key=TzMembershipKey [_zoneName=854f98a8-febd-40bd-9c0d-79f692c9e5d1], _zoneName=854f98a8-febd-40bd-9c0d-79f692c9e5d1, augmentation=[]]], _vLANID=0, _optionOfTunnel=false, augmentation=[]]], augmentation=[]]] ; Meshed DpnList [DPNTEPsInfo{getDPNID=242939118659093, getTunnelEndPoints=[TunnelEndPoints{getGwIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=0.0.0.0]], getInterfaceName=242939118659093:tunnel_port:0, getIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=10.30.170.59]], getOptionTunnelTos=0, getPortname=tunnel_port, getSubnetMask=IpPrefix [_ipv4Prefix=Ipv4Prefix [_value=0.0.0.0/0]], getTunnelType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.rev160406.TunnelTypeVxlan, getTzMembership=[TzMembership{getZoneName=48ca5c45-8aac-4dc5-abc3-5244f1222141, augmentations={}}, TzMembership{getZoneName=826636be-414b-45a9-9fd3-a79bff0e8cf3, augmentations={}}, TzMembership{getZoneName=a23a3eca-81b6-4c3b-b351-d7d2dc7a609a, augmentations={}}, TzMembership{getZoneName=98dfda45-76b3-4e53-800c-4fa345117b16, augmentations={}}, TzMembership{getZoneName=c680e4c7-c3d2-46c8-a70c-a0f91113559c, augmentations={}}, TzMembership{getZoneName=ae856023-23f2-4cb5-adec-c838c0f96cf5, augmentations={}}, TzMembership{getZoneName=5b900177-b992-4650-9ef6-1270410a4f2d, augmentations={}}, TzMembership{getZoneName=854f98a8-febd-40bd-9c0d-79f692c9e5d1, augmentations={}}, TzMembership{getZoneName=6b2c78d3-5e72-4dbe-8470-b4f8cb77445f, augmentations={}}, TzMembership{getZoneName=5288709e-b111-42d0-afdf-5b5280c27431, augmentations={}}, TzMembership{getZoneName=5a7d6cca-e942-4a3a-922a-a96012c837cc, augmentations={}}, TzMembership{getZoneName=729d4f04-9b7c-48ac-8577-53d5093c5a8b, augmentations={}}, TzMembership{getZoneName=37b5741d-443c-479b-b280-ae9aca1fd1f0, augmentations={}}, TzMembership{getZoneName=558b2444-271a-4657-9ff2-752aed518a01, augmentations={}}, TzMembership{getZoneName=495f0211-e4e1-4bd9-a8b7-fcd7d979ea52, augmentations={}}, TzMembership{getZoneName=22ace521-3748-438e-903a-b9223ed47317, augmentations={}}, TzMembership{getZoneName=8b6cde1a-d0b2-412b-8b72-871f8d70f371, augmentations={}}, TzMembership{getZoneName=48c8caae-874a-4ecf-8a6e-fcade26d142c, augmentations={}}, TzMembership{getZoneName=7124f2df-e8a5-4a97-bf2e-532304170f4c, augmentations={}}, TzMembership{getZoneName=8cbb80e9-8c52-43a7-af39-6e036aca8f3f, augmentations={}}, TzMembership{getZoneName=d86a97ea-36d3-4596-98e9-83a4eaa7cd86, augmentations={}}, TzMembership{getZoneName=a6e45bed-ff72-4fed-808a-00cc82181f66, augmentations={}}], getVLANID=0, isOptionOfTunnel=false, augmentations={}}], augmentations={}}]
2017-12-19 19:58:16,955 | TRACE | nPool-1-worker-7 | DataStoreJobCoordinator | 292 - org.opendaylight.genius.mdsalutil-api - 0.2.3.SNAPSHOT | Job 854f98a8-febd-40bd-9c0d-79f692c9e5d1 took 2ms to complete
2017-12-19 19:58:16,956 | DEBUG | nPool-1-worker-1 | ItmTepRemoveWorker | 327 - org.opendaylight.genius.itm-impl - 0.2.3.SNAPSHOT | Invoking Internal Tunnel delete method with DpnList to be deleted [DPNTEPsInfo [_dPNID=242939118659093, _key=DPNTEPsInfoKey [_dPNID=242939118659093], _tunnelEndPoints=[TunnelEndPoints [_gwIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=0.0.0.0]], _interfaceName=242939118659093:tunnel_port:0, _ipAddress=IpAddress [_ipv4Address=Ipv4Address [_value=10.30.170.59]], _key=TunnelEndPointsKey [_portname=tunnel_port, _vLANID=0, _ipAddress=IpAddress [_ipv4Address=Ipv4Address [_value=10.30.170.59]], _tunnelType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.rev160406.TunnelTypeVxlan], _optionTunnelTos=0, _portname=tunnel_port, _subnetMask=IpPrefix [_ipv4Prefix=Ipv4Prefix [_value=0.0.0.0/0]], _tunnelType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.rev160406.TunnelTypeVxlan, _tzMembership=[TzMembership [_key=TzMembershipKey [_zoneName=d86a97ea-36d3-4596-98e9-83a4eaa7cd86], _zoneName=d86a97ea-36d3-4596-98e9-83a4eaa7cd86, augmentation=[]]], _vLANID=0, _optionOfTunnel=false, augmentation=[]]], augmentation=[]]] ; Meshed DpnList [DPNTEPsInfo{getDPNID=242939118659093, getTunnelEndPoints=[TunnelEndPoints{getGwIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=0.0.0.0]], getInterfaceName=242939118659093:tunnel_port:0, getIpAddress=IpAddress [_ipv4Address=Ipv4Address [_value=10.30.170.59]], getOptionTunnelTos=0, getPortname=tunnel_port, getSubnetMask=IpPrefix [_ipv4Prefix=Ipv4Prefix [_value=0.0.0.0/0]], getTunnelType=class org.opendaylight.yang.gen.v1.urn.opendaylight.genius.interfacemanager.rev160406.TunnelTypeVxlan, getTzMembership=[TzMembership{getZoneName=48ca5c45-8aac-4dc5-abc3-5244f1222141, augmentations={}}, TzMembership{getZoneName=826636be-414b-45a9-9fd3-a79bff0e8cf3, augmentations={}}, TzMembership{getZoneName=a23a3eca-81b6-4c3b-b351-d7d2dc7a609a, augmentations={}}, TzMembership{getZoneName=98dfda45-76b3-4e53-800c-4fa345117b16, augmentations={}}, TzMembership{getZoneName=c680e4c7-c3d2-46c8-a70c-a0f91113559c, augmentations={}}, TzMembership{getZoneName=ae856023-23f2-4cb5-adec-c838c0f96cf5, augmentations={}}, TzMembership{getZoneName=5b900177-b992-4650-9ef6-1270410a4f2d, augmentations={}}, TzMembership{getZoneName=854f98a8-febd-40bd-9c0d-79f692c9e5d1, augmentations={}}, TzMembership{getZoneName=6b2c78d3-5e72-4dbe-8470-b4f8cb77445f, augmentations={}}, TzMembership{getZoneName=5288709e-b111-42d0-afdf-5b5280c27431, augmentations={}}, TzMembership{getZoneName=5a7d6cca-e942-4a3a-922a-a96012c837cc, augmentations={}}, TzMembership{getZoneName=729d4f04-9b7c-48ac-8577-53d5093c5a8b, augmentations={}}, TzMembership{getZoneName=37b5741d-443c-479b-b280-ae9aca1fd1f0, augmentations={}}, TzMembership{getZoneName=558b2444-271a-4657-9ff2-752aed518a01, augmentations={}}, TzMembership{getZoneName=495f0211-e4e1-4bd9-a8b7-fcd7d979ea52, augmentations={}}, TzMembership{getZoneName=22ace521-3748-438e-903a-b9223ed47317, augmentations={}}, TzMembership{getZoneName=8b6cde1a-d0b2-412b-8b72-871f8d70f371, augmentations={}}, TzMembership{getZoneName=48c8caae-874a-4ecf-8a6e-fcade26d142c, augmentations={}}, TzMembership{getZoneName=7124f2df-e8a5-4a97-bf2e-532304170f4c, augmentations={}}, TzMembership{getZoneName=8cbb80e9-8c52-43a7-af39-6e036aca8f3f, augmentations={}}, TzMembership{getZoneName=d86a97ea-36d3-4596-98e9-83a4eaa7cd86, augmentations={}}, TzMembership{getZoneName=a6e45bed-ff72-4fed-808a-00cc82181f66, augmentations={}}], getVLANID=0, isOptionOfTunnel=false, augmentations={}}], augmentations={}}]
2017-12-19 19:58:16,956 | TRACE | nPool-1-worker-1 | DataStoreJobCoordinator | 292 - org.opendaylight.genius.mdsalutil-api - 0.2.3.SNAPSHOT | Job d86a97ea-36d3-4596-98e9-83a4eaa7cd86 took 3ms to complete
2017-12-19 19:58:16,956 | WARN | rd-dispatcher-31 | ShardDataTree | 184 - org.opendaylight.controller.sal-distributed-datastore - 1.5.3.SNAPSHOT | member-1-shard-default-config: Store Tx member-1-datastore-config-fe-0-txn-13613-0: Conflicting modification for path /(urn:opendaylight:genius:itm:op?revision=2016-04-06)dpn-endpoints/DPN-TEPs-info/DPN-TEPs-info[{(urn:opendaylight:genius:itm:op?revision=2016-04-06)DPN-ID=242939118659093}]/tunnel-end-points/tunnel-end-points[{(urn:opendaylight:genius:itm:op?revision=2016-04-06)portname=tunnel_port, (urn:opendaylight:genius:itm:op?revision=2016-04-06)VLAN-ID=0, (urn:opendaylight:genius:itm:op?revision=2016-04-06)ip-address=10.30.170.59, (urn:opendaylight:genius:itm:op?revision=2016-04-06)tunnel-type=(urn:opendaylight:genius:interfacemanager?revision=2016-04-06)tunnel-type-vxlan}].
2017-12-19 19:58:16,958 | ERROR | lt-dispatcher-33 | LocalThreePhaseCommitCohort | 184 - org.opendaylight.controller.sal-distributed-datastore - 1.5.3.SNAPSHOT | Failed to prepare transaction member-1-datastore-config-fe-0-txn-13613-0 on backend
OptimisticLockFailedException{message=Optimistic lock failed., errorList=[RpcError [message=Optimistic lock failed., severity=ERROR, errorType=APPLICATION, tag=resource-denied, applicationTag=null, info=null, cause=org.opendaylight.yangtools.yang.data.api.schema.tree.ConflictingModificationAppliedException: Node was replaced by other transaction.]]}
at org.opendaylight.controller.cluster.datastore.ShardDataTree.lambda$processNextPendingTransaction$0(ShardDataTree.java:751)[184:org.opendaylight.controller.sal-distributed-datastore:1.5.3.SNAPSHOT]

Victor Pickard December 2, 2017 at 2:47 AM

Job completed, verified that this exception is not in the exception log file, so patch should be good to go.

 

https://logs.opendaylight.org/sandbox/jenkins091/netvirt-csit-1node-openstack-ocata-upstream-stateful-oxygen/3/odl_1/odl1_exception.log.gz

Victor Pickard December 1, 2017 at 6:02 PM

Pushed patch https://git.opendaylight.org/gerrit/#/c/66160/, which removed deletion of vtep. Local testing with just deleting the transport zone also removes the tep, as Dimple said above. Note: I did not see any exceptions in my local testing with original patch that deleted vtep.

I just started a CSIT run with patch 66160 to verify that this exception has been resolved. 

https://jenkins.opendaylight.org/sandbox/job/netvirt-csit-1node-openstack-ocata-upstream-stateful-oxygen/1/console

Dimple J November 30, 2017 at 11:55 AM

Yes Sam, the exception is because of the gerrit https://git.opendaylight.org/gerrit/#/c/65726/3.
TransportZoneNotificationUtil is performing tep removal and transportzone deletion using SingleTransactionDataBroker.
Since both threads are modifying the same piece of data, ConflictingModificationAppliedException is thrown.
Moreover, just transportzone deletion is sufficient to perform the needed operation as that will take care of tep removal too.

Cannot Reproduce

Details

Assignee

Reporter

Labels

Components

Affects versions

Priority

Created November 22, 2017 at 12:59 PM
Updated April 6, 2018 at 12:43 PM
Resolved April 6, 2018 at 12:43 PM