[OVSDB-413] vlan tag info remains in operational store even after manually removing from ovs Created: 23/May/17  Updated: 25/Nov/20

Status: In Progress
Project: ovsdb
Component/s: Southbound.Open_vSwitch
Affects Version/s: unspecified
Fix Version/s: None

Type: Bug
Reporter: Jamo Luhrsen Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All

External issue ID: 8529

 Description   
  1. Create port using ovs-vsctl add-port br0 port1. Use rest api to query operational datastore sees the port is created.
  2. Configure port vlan tag using: ovs-vsctl set port port1 tag=100. See the tag entry is created in the operational datastore: "ovsdb:vlan-tag": 100
  3. Deleting vlan tag using: ovs-vsctl clear port port1 tag. Checking ovsdb table, tag is deleted. But checking odl operational datastore ovsdb:vlan-tag is still there.

 Comments   
Comment by Jamo Luhrsen [ 23/May/17 ]

email thread here:
https://lists.opendaylight.org/pipermail/ovsdb-dev/2017-May/004271.html

Comment by Vishal Thapar [ 24/May/17 ]

WiP patch in master: https://git.opendaylight.org/gerrit/#/c/57760/

Comment by Jamo Luhrsen [ 16/Aug/17 ]

re-opening this, because CSIT is still failing for the 2nd case here
where trunks hang around in operational.

the case where tags hang around is fixed.

example CSIT failure:

https://logs.opendaylight.org/releng/jenkins092/ovsdb-csit-1node-upstream-southbound-all-carbon/164/log.html.gz#s1-s1-t17

Comment by Anil Vishnoi [ 01/May/19 ]

jluhrsen Any clue if this issue is fixed or not ?

Comment by Anil Vishnoi [ 02/May/19 ]

Looks like it's not.

Comment by Robert Varga [ 04/Dec/19 ]

I think the problem lies here (https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/ovsdb-csit-1node-gate-southbound-all-magnesium/10/odl_1/odl1_karaf.log.gz):

2019-12-04T11:56:51,054 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-21 | ContextChainHolderImpl           | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Try to remove device openflow:2 from operational DS
2019-12-04T11:56:51,056 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-21 | ContextChainHolderImpl           | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Removing device from operational DS 2 was successful
2019-12-04T11:56:51,227 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Get Config Topology to verify the entry added to the config datastore" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Get Operational Topology to verify the bridge has been deleted manually
2019-12-04T11:56:51,418 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Get Config Topology to verify the entry added to the config datastore" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Config Topology Still Contains Bridge
2019-12-04T11:56:51,604 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Get Config Topology to verify the entry added to the config datastore" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Delete the Bridge through rest call
2019-12-04T11:56:51,636 | INFO  | opendaylight-cluster-data-notification-dispatcher-64 | ControllerUpdateCommand          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Register ODL controllers : {}  bridges detail : {}


2019-12-04T11:56:51,637 | WARN  | opendaylight-cluster-data-notification-dispatcher-64 | BridgeRemovedCommand             | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Unable to delete bridge InstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.ovsdb.rev150105.OvsdbBridgeAugmentation, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey{_topologyId=Uri{_value=ovsdb:1}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=ovsdb://uuid/a89375a4-ca72-4221-b9ec-869d3c916cb8/bridge/ovscon_br2}}], org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.ovsdb.rev150105.OvsdbBridgeAugmentation]} because it was not found in the operational store, and thus we cannot retrieve its UUID


2019-12-04T11:56:51,774 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Get Config Topology to verify the entry added to the config datastore" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Get Operational Topology after Deletion of Bridge
2019-12-04T11:56:51,971 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Get Config Topology to verify the entry added to the config datastore" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-gate-southbound.txt.Connection Manager.Trunk And Vlan Tag Is Removed From Operational
2019-12-04T11:56:53,612 | INFO  | opendaylight-cluster-data-notification-dispatcher-63 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2019-12-04T11:56:53,740 | WARN  | transaction-invoker-impl-0 | OvsdbPortRemoveCommand           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Bridge not found for port Port : Row [columns={bond_updelay=[bond_updelay=0], interfaces=[interfaces=[6a5cf514-e313-49df-9b82-c78b516aa99f]], other_config=[other_config={}], bond_fake_iface=[bond_fake_iface=false], bond_downdelay=[bond_downdelay=0], _uuid=[_uuid=f57c9767-87f7-4607-9aea-7a218de4ba2a], bond_mode=[bond_mode=[]], rstp_statistics=[rstp_statistics={}], rstp_status=[rstp_status={}], external_ids=[external_ids={}], mac=[mac=[]], trunks=[trunks=[]], lacp=[lacp=[]], qos=[qos=[]], fake_bridge=[fake_bridge=false], vlan_mode=[vlan_mode=[]], bond_active_slave=[bond_active_slave=[]], name=[name=ovscon_br1], tag=[tag=[]], status=[status={}]}]
Comment by Robert Varga [ 04/Dec/19 ]

I think this may be related to BridgeOperationalState, which captures operational datastore state when it's instantiated.

There is little explanation as to what the workflow is supposed to be here, as the code relied on the oper datastore before the cache was introduced: https://git.opendaylight.org/gerrit/c/ovsdb/+/17967

 

Comment by Robert Varga [ 04/Dec/19 ]

https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/ovsdb-csit-1node-gate-southbound-all-magnesium/10/robot-plugin/log.html.gz#s1-s1-t17 shows:

Keyword 'Utils.Check For Elements Not At URI' failed after retrying for 8 seconds. The last error was: '

{ "topology": [
  { "topology-id":"ovsdb:1",
    "node":[
      { "node-id":"ovsdb://uuid/726098fe-e7ab-4415-a1e0-3882a283d6a6/bridge/vlan-tag-br",
        "ovsdb:datapath-type":"ovsdb:datapath-type-system",
        "ovsdb:bridge-name":"vlan-tag-br",
        "ovsdb:datapath-id":"00:00:76:20:aa:29:2c:42",
        "ovsdb:bridge-uuid":"29aa2076-fd17-422c-8edf-2a19374fe3eb",
        "ovsdb:stp_enable":false,
        "ovsdb:managed-by":"/network-topology:network-topology/network-topology:topology[network-topology:topology-id='ovsdb:1']/network-topology:node[network-topology:node-id='ovsdb://uuid/726098fe-e7ab-4415-a1e0-3882a283d6a6']",
        "termination-point":[
          { "tp-id":"vlan-tag-br",
            "ovsdb:ingress-policing-rate":0,
            "ovsdb:interface-type":"ovsdb:interface-type-internal",
            "ovsdb:interface-uuid":"c8511a9a-3a90-440a-9caa-440738c8907a",
            "ovsdb:name":"vlan-tag-br",
            "ovsdb:ingress-policing-burst":0,
            "ovsdb:port-uuid":"885f33a0-5f58-4675-abd0-adea55cf0646",
            "ovsdb:ifindex":6,
            "ovsdb:mac-in-use":"76:20:aa:29:2c:42",
            "ovsdb:ofport":65534
          },
          { "tp-id":"vlan-tag-port",
            "ovsdb:ingress-policing-rate":0,
            "ovsdb:ingress-policing-burst":0,
            "ovsdb:interface-uuid":"aa33ed67-a699-4716-ad6a-e3baa84ee55c",
            "ovsdb:port-uuid":"6b74aeba-378e-4af4-8518-6e7b335cd2c9",
            "ovsdb:name":"vlan-tag-port",
            "ovsdb:vlan-tag":81,
            "ovsdb:trunks":[{"trunk":182}]
          }]
      },
      { "node-id":"ovsdb://uuid/726098fe-e7ab-4415-a1e0-3882a283d6a6",
        "ovsdb:datapath-type-entry":[
          { "datapath-type":"ovsdb:datapath-type-netdev" },
          { "datapath-type":"ovsdb:datapath-type-system"}],
        "ovsdb:ovs-version":"2.5.5",
        "ovsdb:connection-info":{
          "local-ip":"10.30.170.15",
          "remote-port":37896,
          "remote-ip":"10.30.170.90",
          "local-port":6640
        },
        "ovsdb:openvswitch-external-ids":[{"external-id-key":"system-id","external-id-value":""}],
        "ovsdb:db-version":"7.12.1",
        "ovsdb:interface-type-entry":[
          {"interface-type":"ovsdb:interface-type-lisp"},
          {"interface-type":"ovsdb:interface-type-geneve"},
          {"interface-type":"ovsdb:interface-type-gre"},
          {"interface-type":"ovsdb:interface-type-system"},
          {"interface-type":"ovsdb:interface-type-vxlan"},
          {"interface-type":"ovsdb:interface-type-ipsec-gre"},
          {"interface-type":"ovsdb:interface-type-internal"},
          {"interface-type":"ovsdb:interface-type-stt"},
          {"interface-type":"ovsdb:interface-type-tap"},
          {"interface-type":"ovsdb:interface-type-patch"}],
        "ovsdb:manager-entry":[{"target":"tcp:10.30.170.15:6640","connected":true,"number_of_connections":1}],
        "ovsdb:managed-node-entry":[{"bridge-ref":"/network-topology:network-topology/network-topology:topology[network-topology:topology-id='ovsdb:1']/network-topology:node[network-topology:node-id='ovsdb://uuid/726098fe-e7ab-4415-a1e0-3882a283d6a6/bridge/vlan-tag-br']"}]
      }]
    }]
}

' contains '"ovsdb:vlan-tag":81'

 

 

Comment by Robert Varga [ 04/Dec/19 ] 
[04/12/2019 14:35:49] <rovarga> one trouble is that I do not know if the invocation path is from device updates (final DataChangeEvent events) or from DTCL, but I suspect it is the latter
[04/12/2019 14:36:25] <rovarga> at any rate, it seems weird that we extract https://github.com/opendaylight/ovsdb/blob/master/southbound/southbound-impl/src/main/java/org/opendaylight/ovsdb/southbound/ovsdb/transact/BridgeRemovedCommand.java#L54 'original', whatever that is
[04/12/2019 14:36:40] <rovarga> and then check the state here: https://github.com/opendaylight/ovsdb/blob/master/southbound/southbound-impl/src/main/java/org/opendaylight/ovsdb/southbound/ovsdb/transact/BridgeRemovedCommand.java#L56
[04/12/2019 14:37:01] <rovarga> and if the captured state does not find it, well, tough luck (as is now)
[04/12/2019 14:38:41] <rovarga> now for DTCL, the entire indirection through those pesky maps is just BS -- if we were processing this as a DTCL, we could see the before-image without going to the DS
[04/12/2019 14:38:55] <rovarga> if 'originals' is really the before image, we should be able to use it here
Comment by Stephen Kitt [ 04/Dec/19 ]

Yes, IIRC this comes from DTCL. originals contains the result of getDataBefore(), it’s not retrieved separately from the DS AFAICS.

Comment by Robert Varga [ 04/Dec/19 ]

Hmm, okay, so this dates back to when we did not have DataTreeChangeListeners, only DataChangeListeners. I suspect with DTCL we can just not decompose the changes into old/new/etc., but rather retain DataTreeModification<Node> and operate on that.

Adding some debug here results in:

2019-12-04T15:11:24,616 | WARN  | opendaylight-cluster-data-notification-dispatcher-65 | BridgeRemovedCommand             | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Unable to delete bridge InstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.ovsdb.rev150105.OvsdbBridgeAugmentation, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey{_topologyId=Uri{_value=ovsdb:1}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=ovsdb://uuid/a89375a4-ca72-4221-b9ec-869d3c916cb8/bridge/ovscon_br2}}], org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.ovsdb.rev150105.OvsdbBridgeAugmentation]} because it was not found in the operational store, and thus we cannot retrieve its UUID
2019-12-04T15:11:24,616 | INFO  | opendaylight-cluster-data-notification-dispatcher-65 | BridgeRemovedCommand             | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Original points to OvsdbBridgeAugmentation{getBridgeName=OvsdbBridgeName{_value=ovscon_br2}, getBridgeOtherConfigs=[BridgeOtherConfigs{getBridgeOtherConfigKey=datapath-id, getBridgeOtherConfigValue=0000000000000002, augmentation=[]}], getControllerEntry=[ControllerEntry{getTarget=Uri{_value=tcp:10.30.170.22:6633}, augmentation=[]}], getManagedBy=OvsdbNodeRef{_value=KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey{_topologyId=Uri{_value=ovsdb:1}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=ovsdb://uuid/a89375a4-ca72-4221-b9ec-869d3c916cb8}}]]}}, getProtocolEntry=[ProtocolEntry{getProtocol=interface org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.ovsdb.rev150105.OvsdbBridgeProtocolOpenflow13, augmentation=[]}]}

i.e. 'original' does not seem to contain enough data.

Comment by Jamo Luhrsen [ 04/Dec/19 ]

Good to see activity on this really old bug. Let me know if we need any help from the CSIT side to get more
logs, or extra debugs, etc. I'd love to see this single consistent failure go away

Comment by Robert Varga [ 05/Dec/19 ]

Yeah, it nagged me, so I decided to do something about it. The logs produced by gating CSIT are fine, too.

 

Comment by Robert Varga [ 05/Dec/19 ]

The call stack is:

	at org.opendaylight.ovsdb.southbound.ovsdb.transact.BridgeRemovedCommand.execute(BridgeRemovedCommand.java:72) ~[453:org.opendaylight.ovsdb.southbound-impl:1.10.0.SNAPSHOT]
	at org.opendaylight.ovsdb.southbound.ovsdb.transact.BridgeRemovedCommand.execute(BridgeRemovedCommand.java:44) ~[453:org.opendaylight.ovsdb.southbound-impl:1.10.0.SNAPSHOT]
	at org.opendaylight.ovsdb.southbound.ovsdb.transact.TransactCommandAggregator.execute(TransactCommandAggregator.java:59) ~[453:org.opendaylight.ovsdb.southbound-impl:1.10.0.SNAPSHOT]
	at org.opendaylight.ovsdb.southbound.ovsdb.transact.TransactInvokerImpl.invoke(TransactInvokerImpl.java:48) ~[453:org.opendaylight.ovsdb.southbound-impl:1.10.0.SNAPSHOT]
	at org.opendaylight.ovsdb.southbound.OvsdbConnectionInstance.transact(OvsdbConnectionInstance.java:117) ~[453:org.opendaylight.ovsdb.southbound-impl:1.10.0.SNAPSHOT]
	at org.opendaylight.ovsdb.southbound.OvsdbDataTreeChangeListener.updateData(OvsdbDataTreeChangeListener.java:230) ~[453:org.opendaylight.ovsdb.southbound-impl:1.10.0.SNAPSHOT]
	at org.opendaylight.ovsdb.southbound.OvsdbDataTreeChangeListener.onDataTreeChanged(OvsdbDataTreeChangeListener.java:100) ~[453:org.opendaylight.ovsdb.southbound-impl:1.10.0.SNAPSHOT]
	at org.opendaylight.controller.md.sal.binding.impl.BindingDOMDataTreeChangeListenerAdapter.onDataTreeChanged(BindingDOMDataTreeChangeListenerAdapter.java:43) ~[295:org.opendaylight.controller.sal-binding-broker-impl:1.11.0.SNAPSHOT]
	at org.opendaylight.controller.sal.core.compat.AbstractLegacyDOMDataBrokerAdapter$ProxyListener.onDataTreeChanged(AbstractLegacyDOMDataBrokerAdapter.java:360) ~[305:org.opendaylight.controller.sal-core-compat:1.11.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.DataTreeChangeListenerActor.dataChanged(DataTreeChangeListenerActor.java:82) ~[307:org.opendaylight.controller.sal-distributed-datastore:1.11.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.DataTreeChangeListenerActor.handleReceive(DataTreeChangeListenerActor.java:43) ~[307:org.opendaylight.controller.sal-distributed-datastore:1.11.0.SNAPSHOT]

Which is indicative that the CONFIG datastore changed, which explains why 'original' does not have the oper state data.

Comment by Robert Varga [ 05/Dec/19 ]

Argh, this actually is not the problem

Comment by Robert Varga [ 05/Dec/19 ]

So correlating https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/ovsdb-csit-1node-gate-southbound-all-magnesium/15/robot-plugin/log.html.gz#s1-s1-t17-k16 and https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/ovsdb-csit-1node-gate-southbound-all-magnesium/15/odl_1/odl1_karaf.log.gz it seems there is a delay in events being processed. The time delta between the system is about 0.8 seconds (RF 14:31:27.902-14:31:28.053 corresponds with Karaf 2019-12-05T13:31:28,431-682)

RF deletes the bridges at 14:31:40.506, karaf logs warnings about them:

2019-12-05T13:31:51,727 | WARN  | transaction-invoker-impl-0 | OvsdbPortRemoveCommand           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Bridge not found for port Port : Row [columns={bond_updelay=[bond_updelay=0], interfaces=[interfaces=[22cbdd22-32c6-4707-8375-289ca712e773]], other_config=[other_config={}], bond_fake_iface=[bond_fake_iface=false], bond_downdelay=[bond_downdelay=0], _uuid=[_uuid=261c1580-0554-46ff-962f-f952395f9963], bond_mode=[bond_mode=[]], cvlans=[cvlans=[]], rstp_statistics=[rstp_statistics={}], rstp_status=[rstp_status={}], external_ids=[external_ids={}], mac=[mac=[]], trunks=[trunks=[182]], lacp=[lacp=[]], protected=[protected=false], qos=[qos=[]], fake_bridge=[fake_bridge=false], vlan_mode=[vlan_mode=[]], bond_active_slave=[bond_active_slave=[]], name=[name=vlan-tag-port], tag=[tag=[]], status=[status={}]}]
2019-12-05T13:31:51,727 | WARN  | transaction-invoker-impl-0 | OvsdbPortRemoveCommand           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Bridge not found for port Port : Row [columns={bond_updelay=[bond_updelay=0], interfaces=[interfaces=[0caff817-3103-41fd-b098-d101362f3735]], other_config=[other_config={}], bond_fake_iface=[bond_fake_iface=false], bond_downdelay=[bond_downdelay=0], _uuid=[_uuid=cf7d9330-cead-4cd2-8e53-a459064f80f1], bond_mode=[bond_mode=[]], cvlans=[cvlans=[]], rstp_statistics=[rstp_statistics={}], rstp_status=[rstp_status={}], external_ids=[external_ids={}], mac=[mac=[]], trunks=[trunks=[]], lacp=[lacp=[]], protected=[protected=false], qos=[qos=[]], fake_bridge=[fake_bridge=false], vlan_mode=[vlan_mode=[]], bond_active_slave=[bond_active_slave=[]], name=[name=vlan-tag-br], tag=[tag=[]], status=[status={}]}]

at 2019-12-05T13:31:51,727 – i.e. full 11 seconds. At this point the CSIT has proceeded to shutdown mininet – is this a timing issue or a reaction to mininet being shutdown?

Comment by Jamo Luhrsen [ 05/Dec/19 ]

even with 2 minutes of polling instead of the 8 seconds, and using the distribution from
https://git.opendaylight.org/gerrit/c/ovsdb/+/86188, the failure is still happening. I will
post logs.

Comment by Jamo Luhrsen [ 05/Dec/19 ]

link to all the logs from the robot job

karaf logs for the duration of the failing test case:

2019-12-05T20:24:04,183 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Connection Manager.Trunk And Vlan Tag Is Removed From Operational" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Connection Manager.Trunk And Vlan Tag Is Removed From Operational
2019-12-05T20:24:06,158 | INFO  | epollEventLoopGroup-18-2 | SystemNotificationsListenerImpl  | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | ConnectionEvent: Connection closed by device, Device:/10.30.170.28:36952, NodeId:openflow:1
2019-12-05T20:24:06,159 | INFO  | epollEventLoopGroup-18-2 | ContextChainHolderImpl           | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Device openflow:1 disconnected.
2019-12-05T20:24:06,159 | INFO  | epollEventLoopGroup-18-2 | ReconciliationManagerImpl        | 427 - org.opendaylight.openflowplugin.applications.reconciliation-framework - 0.10.0.SNAPSHOT | Stopping reconciliation for node Uri{_value=openflow:1}
2019-12-05T20:24:06,163 | INFO  | epollEventLoopGroup-18-2 | DeviceManagerImpl                | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Publishing node removed notification for Uri{_value=openflow:1}
2019-12-05T20:24:06,164 | INFO  | epollEventLoopGroup-18-2 | ReconciliationManagerImpl        | 427 - org.opendaylight.openflowplugin.applications.reconciliation-framework - 0.10.0.SNAPSHOT | Stopping reconciliation for node Uri{_value=openflow:1}
2019-12-05T20:24:06,164 | INFO  | epollEventLoopGroup-18-2 | ContextChainHolderImpl           | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Role SLAVE was granted to device openflow:1
2019-12-05T20:24:06,164 | INFO  | epollEventLoopGroup-18-2 | GuardedContextImpl               | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Stopping RoleContextImpl[RUNNING] service for node openflow:1
2019-12-05T20:24:06,165 | INFO  | epollEventLoopGroup-18-2 | GuardedContextImpl               | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Stopping StatisticsContextImpl[RUNNING] service for node openflow:1
2019-12-05T20:24:06,165 | INFO  | epollEventLoopGroup-18-2 | StatisticsContextImpl            | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Stopping running statistics gathering for node openflow:1
2019-12-05T20:24:06,165 | INFO  | epollEventLoopGroup-18-2 | GuardedContextImpl               | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Stopping RpcContextImpl[RUNNING] service for node openflow:1
2019-12-05T20:24:06,168 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | DeviceOwnershipServiceImpl       | 423 - org.opendaylight.openflowplugin.applications.device-ownership-service - 0.10.0.SNAPSHOT | Entity ownership change received for node : openflow:1 : EntityOwnershipChange [entity=Entity [type=org.opendaylight.mdsal.ServiceEntityType, id=KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.mdsal.core.general.entity.rev150930.Entity, path=[org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.mdsal.core.general.entity.rev150930.Entity[key=EntityKey{_name=openflow:1}]]}], state=LOCAL_OWNERSHIP_LOST_NO_OWNER [wasOwner=true, isOwner=false, hasOwner=false], inJeopardy=false]
2019-12-05T20:24:06,175 | INFO  | epollEventLoopGroup-18-2 | GuardedContextImpl               | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Stopping DeviceContextImpl[RUNNING] service for node openflow:1
2019-12-05T20:24:06,176 | INFO  | epollEventLoopGroup-18-2 | ContextChainImpl                 | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Closed clustering services registration for node openflow:1
2019-12-05T20:24:06,176 | INFO  | epollEventLoopGroup-18-2 | GuardedContextImpl               | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Terminating DeviceContextImpl[TERMINATED] service for node openflow:1
2019-12-05T20:24:06,176 | INFO  | epollEventLoopGroup-18-2 | GuardedContextImpl               | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Terminating RpcContextImpl[TERMINATED] service for node openflow:1
2019-12-05T20:24:06,176 | INFO  | epollEventLoopGroup-18-2 | GuardedContextImpl               | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Terminating StatisticsContextImpl[TERMINATED] service for node openflow:1
2019-12-05T20:24:06,176 | INFO  | epollEventLoopGroup-18-2 | StatisticsContextImpl            | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Stopping running statistics gathering for node openflow:1
2019-12-05T20:24:06,176 | INFO  | ofppool-2        | ContextChainImpl                 | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Closed clustering services for node openflow:1
2019-12-05T20:24:06,177 | INFO  | epollEventLoopGroup-18-2 | GuardedContextImpl               | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Terminating RoleContextImpl[TERMINATED] service for node openflow:1
2019-12-05T20:24:06,179 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | ContextChainHolderImpl           | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Try to remove device openflow:1 from operational DS
2019-12-05T20:24:06,183 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | ContextChainHolderImpl           | 435 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Removing device from operational DS 1 was successful
2019-12-05T20:24:07,559 | INFO  | nioEventLoopGroup-8-1 | OvsdbConnectionService           | 449 - org.opendaylight.ovsdb.library - 1.10.0.SNAPSHOT | Connection closed ConnectionInfo [Remote-address=10.30.170.28, Remote-port=46558, Local-address10.30.170.61, Local-port=6640, type=PASSIVE]
2019-12-05T20:24:07,559 | INFO  | nioEventLoopGroup-8-1 | HwvtepConnectionManager          | 448 - org.opendaylight.ovsdb.hwvtepsouthbound-impl - 1.10.0.SNAPSHOT | Library disconnected PASSIVE from /10.30.170.28:46558 to /10.30.170.61:6640. Cleaning up the operational data store
2019-12-05T20:24:07,563 | WARN  | nioEventLoopGroup-8-1 | HwvtepConnectionManager          | 448 - org.opendaylight.ovsdb.hwvtepsouthbound-impl - 1.10.0.SNAPSHOT | HWVTEP disconnected event did not find connection instance for ConnectionInfo{_localIp=IpAddress{_ipv4Address=Ipv4Address{_value=10.30.170.61}}, _localPort=PortNumber{_value=6640}, _remoteIp=IpAddress{_ipv4Address=Ipv4Address{_value=10.30.170.28}}, _remotePort=PortNumber{_value=46558}, augmentation=[]}
2019-12-05T20:24:07,563 | INFO  | nioEventLoopGroup-8-1 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Library disconnected PASSIVE from /10.30.170.28:46558 to /10.30.170.61:6640. Cleaning up the operational data store
2019-12-05T20:24:07,563 | INFO  | nioEventLoopGroup-8-1 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Library disconnected ConnectionInfo{_localIp=IpAddress{_ipv4Address=Ipv4Address{_value=10.30.170.61}}, _localPort=PortNumber{_value=6640}, _remoteIp=IpAddress{_ipv4Address=Ipv4Address{_value=10.30.170.28}}, _remotePort=PortNumber{_value=46558}, augmentation=[]} this controller instance has ownership
2019-12-05T20:24:07,568 | INFO  | nioEventLoopGroup-8-1 | StalePassiveConnectionService    | 449 - org.opendaylight.ovsdb.library - 1.10.0.SNAPSHOT | Client disconnected ConnectionInfo [Remote-address=10.30.170.28, Remote-port=46558, Local-address10.30.170.61, Local-port=6640, type=PASSIVE]
2019-12-05T20:24:07,569 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-43 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Entity [type=ovsdb, id=KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey{_topologyId=Uri{_value=ovsdb:1}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=ovsdb://uuid/9492573c-8688-4ff4-9245-a03e74e197c3}}]]}] has no owner, cleaning up the operational data store
2019-12-05T20:24:11,075 | INFO  | nioEventLoopGroup-7-1 | LoggingHandler                   | 64 - io.netty.common - 4.1.42.Final | [id: 0x2184501d, L:/0:0:0:0:0:0:0:0:6640] READ: [id: 0x8381f22c, L:/10.30.170.61:6640 - R:/10.30.170.28:46564]
2019-12-05T20:24:11,076 | INFO  | nioEventLoopGroup-7-1 | LoggingHandler                   | 64 - io.netty.common - 4.1.42.Final | [id: 0x2184501d, L:/0:0:0:0:0:0:0:0:6640] READ COMPLETE
2019-12-05T20:24:11,090 | INFO  | OVSDBConnNotifSer-1 | HwvtepConnectionManager          | 448 - org.opendaylight.ovsdb.hwvtepsouthbound-impl - 1.10.0.SNAPSHOT | Library connected PASSIVE from /10.30.170.28:46564 to /10.30.170.61:6640
2019-12-05T20:24:11,091 | INFO  | OVSDBConnNotifSer-0 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Library connected PASSIVE from /10.30.170.28:46564 to /10.30.170.61:6640
2019-12-05T20:24:11,093 | INFO  | OVSDBConnNotifSer-0 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | OVSDB Connection from /10.30.170.28:46564
2019-12-05T20:24:11,106 | INFO  | OVSDBConnNotifSer-0 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | InstanceIdentifier KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey{_topologyId=Uri{_value=ovsdb:1}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=ovsdb://uuid/302f4bef-5079-4ed8-a691-425374e37a6a}}]]} generated for device connection ConnectionInfo [Remote-address=10.30.170.28, Remote-port=46564, Local-address10.30.170.61, Local-port=6640, type=PASSIVE]
2019-12-05T20:24:11,107 | INFO  | OVSDBConnNotifSer-0 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | OVSDB entity Entity [type=ovsdb, id=KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey{_topologyId=Uri{_value=ovsdb:1}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=ovsdb://uuid/302f4bef-5079-4ed8-a691-425374e37a6a}}]]}] is registered for ownership.
2019-12-05T20:24:11,111 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | handleOwnershipChanged: *this* southbound plugin instance is an OWNER of the device ConnectionInfo [Remote-address=10.30.170.28, Remote-port=46564, Local-address10.30.170.61, Local-port=6640, type=PASSIVE]
2019-12-05T20:24:11,111 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Monitoring database: Open_vSwitch
2019-12-05T20:24:11,111 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Open_vSwitch
2019-12-05T20:24:11,111 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [statistics, _version] in table Open_vSwitch
2019-12-05T20:24:11,111 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Port
2019-12-05T20:24:11,111 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [statistics, _version] in table Port
2019-12-05T20:24:11,111 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Controller
2019-12-05T20:24:11,112 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [status, _version] in table Controller
2019-12-05T20:24:11,112 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Manager
2019-12-05T20:24:11,112 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table Manager
2019-12-05T20:24:11,112 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table SSL
2019-12-05T20:24:11,112 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table SSL
2019-12-05T20:24:11,112 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table QoS
2019-12-05T20:24:11,112 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table QoS
2019-12-05T20:24:11,112 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table AutoAttach
2019-12-05T20:24:11,113 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Queue
2019-12-05T20:24:11,113 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table Queue
2019-12-05T20:24:11,113 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Bridge
2019-12-05T20:24:11,113 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table Bridge
2019-12-05T20:24:11,113 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Interface
2019-12-05T20:24:11,113 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [statistics, _version] in table Interface
2019-12-05T20:24:11,722 | INFO  | opendaylight-cluster-data-notification-dispatcher-50 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2019-12-05T20:24:11,726 | INFO  | opendaylight-cluster-data-notification-dispatcher-53 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2019-12-05T20:24:12,329 | INFO  | opendaylight-cluster-data-notification-dispatcher-50 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2019-12-05T20:24:12,332 | INFO  | opendaylight-cluster-data-notification-dispatcher-53 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2019-12-05T20:24:13,247 | INFO  | opendaylight-cluster-data-notification-dispatcher-53 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2019-12-05T20:24:14,247 | INFO  | opendaylight-cluster-data-notification-dispatcher-53 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2019-12-05T20:24:17,594 | INFO  | opendaylight-cluster-data-notification-dispatcher-53 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2019-12-05T20:24:18,336 | INFO  | opendaylight-cluster-data-notification-dispatcher-50 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2019-12-05T20:26:24,519 | INFO  | nioEventLoopGroup-8-2 | OvsdbConnectionService           | 449 - org.opendaylight.ovsdb.library - 1.10.0.SNAPSHOT | Connection closed ConnectionInfo [Remote-address=10.30.170.28, Remote-port=46564, Local-address10.30.170.61, Local-port=6640, type=PASSIVE]
2019-12-05T20:26:24,519 | INFO  | nioEventLoopGroup-8-2 | HwvtepConnectionManager          | 448 - org.opendaylight.ovsdb.hwvtepsouthbound-impl - 1.10.0.SNAPSHOT | Library disconnected PASSIVE from /10.30.170.28:46564 to /10.30.170.61:6640. Cleaning up the operational data store
2019-12-05T20:26:24,520 | WARN  | nioEventLoopGroup-8-2 | HwvtepConnectionManager          | 448 - org.opendaylight.ovsdb.hwvtepsouthbound-impl - 1.10.0.SNAPSHOT | HWVTEP disconnected event did not find connection instance for ConnectionInfo{_localIp=IpAddress{_ipv4Address=Ipv4Address{_value=10.30.170.61}}, _localPort=PortNumber{_value=6640}, _remoteIp=IpAddress{_ipv4Address=Ipv4Address{_value=10.30.170.28}}, _remotePort=PortNumber{_value=46564}, augmentation=[]}
2019-12-05T20:26:24,520 | INFO  | nioEventLoopGroup-8-2 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Library disconnected PASSIVE from /10.30.170.28:46564 to /10.30.170.61:6640. Cleaning up the operational data store
2019-12-05T20:26:24,520 | INFO  | nioEventLoopGroup-8-2 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Library disconnected ConnectionInfo{_localIp=IpAddress{_ipv4Address=Ipv4Address{_value=10.30.170.61}}, _localPort=PortNumber{_value=6640}, _remoteIp=IpAddress{_ipv4Address=Ipv4Address{_value=10.30.170.28}}, _remotePort=PortNumber{_value=46564}, augmentation=[]} this controller instance has ownership
2019-12-05T20:26:24,521 | INFO  | nioEventLoopGroup-8-2 | StalePassiveConnectionService    | 449 - org.opendaylight.ovsdb.library - 1.10.0.SNAPSHOT | Client disconnected ConnectionInfo [Remote-address=10.30.170.28, Remote-port=46564, Local-address10.30.170.61, Local-port=6640, type=PASSIVE]
2019-12-05T20:26:24,524 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-3 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Entity [type=ovsdb, id=KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey{_topologyId=Uri{_value=ovsdb:1}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=ovsdb://uuid/302f4bef-5079-4ed8-a691-425374e37a6a}}]]}] has no owner, cleaning up the operational data store
2019-12-05T20:26:27,385 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Connection Manager.Check For Bug 4756" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Connection Manager.Check For Bug 4756
2019-12-05T20:26:28,179 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Connection Manager.Check For Bug 4756" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Connection Manager.Check For Bug 4794
2019-12-05T20:26:36,014 | INFO  | sshd-SshServer[5161a645]-nio2-thread-1 | ServerUserAuthService            | 146 - org.apache.sshd.core - 1.7.0 | Session karaf@/10.30.170.54:41282 authenticated
2019-12-05T20:26:36,372 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting suite /w/workspace/ovsdb-csit-1node-upstream-southbound-all-magnesium/test/csit/suites/ovsdb/Southbound_Domain/030__configure_exit_ovsdb_node.robot" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting suite /w/workspace/ovsdb-csit-1node-upstream-southbound-all-magnesium/test/csit/suites/ovsdb/Southbound_Domain/030__configure_exit_ovsdb_node.robot
2019-12-05T20:26:36,466 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting suite /w/workspace/ovsdb-csit-1node-upstream-southbound-all-magnesium/test/csit/suites/ovsdb/Southbound_Domain/030__configure_exit_ovsdb_node.robot" | LogoutAction                     | 136 - org.apache.karaf.shell.commands - 4.2.2 | Disconnecting from current session...
2019-12-05T20:26:36,469 | WARN  | sshd-SshServer[5161a645]-nio2-thread-2 | ServerSessionImpl                | 146 - org.apache.sshd.core - 1.7.0 | exceptionCaught(ServerSessionImpl[karaf@/10.30.170.54:41282])[state=Opened] IOException: Connection reset by peer
2019-12-05T20:26:36,548 | INFO  | sshd-SshServer[5161a645]-nio2-thread-2 | ServerUserAuthService            | 146 - org.apache.sshd.core - 1.7.0 | Session karaf@/10.30.170.54:41284 authenticated
2019-12-05T20:26:36,883 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Configure Exit Ovsdb Node.Create a Topology in OVSDB node" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Configure Exit Ovsdb Node.Create a Topology in OVSDB node
2019-12-05T20:26:39,984 | INFO  | pipe-log:log "ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Configure Exit Ovsdb Node.Create a Topology in OVSDB node" | core                             | 129 - org.apache.karaf.log.core - 4.2.2 | ROBOT MESSAGE: Starting test ovsdb-upstream-southbound.txt.Configure Exit Ovsdb Node.Connect to OVSDB Node
2019-12-05T20:26:40,039 | INFO  | opendaylight-cluster-data-notification-dispatcher-49 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Connecting to 10.30.170.28:6634
2019-12-05T20:26:40,056 | INFO  | opendaylight-cluster-data-notification-dispatcher-49 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | OVSDB Connection from /10.30.170.28:6634
2019-12-05T20:26:40,085 | INFO  | opendaylight-cluster-data-notification-dispatcher-49 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | OVSDB entity Entity [type=ovsdb, id=KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey{_topologyId=Uri{_value=ovsdb:1}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=ovsdb://10.30.170.28:6634}}]]}] is registered for ownership.
2019-12-05T20:26:40,086 | INFO  | opendaylight-cluster-data-notification-dispatcher-49 | OvsdbDataTreeChangeListener      | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | OVSDB node has been connected: OvsdbNodeAugmentation{getConnectionInfo=ConnectionInfo{getRemoteIp=IpAddress{_ipv4Address=Ipv4Address{_value=10.30.170.28}}, getRemotePort=PortNumber{_value=6634}, augmentation=[]}}
2019-12-05T20:26:40,091 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionManager           | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | handleOwnershipChanged: *this* southbound plugin instance is an OWNER of the device ConnectionInfo [Remote-address=10.30.170.28, Remote-port=6634, Local-address10.30.170.61, Local-port=48180, type=ACTIVE]
2019-12-05T20:26:40,096 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Monitoring database: Open_vSwitch
2019-12-05T20:26:40,096 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Open_vSwitch
2019-12-05T20:26:40,096 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [statistics, _version] in table Open_vSwitch
2019-12-05T20:26:40,096 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Port
2019-12-05T20:26:40,096 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [statistics, _version] in table Port
2019-12-05T20:26:40,096 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Controller
2019-12-05T20:26:40,097 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [status, _version] in table Controller
2019-12-05T20:26:40,097 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Manager
2019-12-05T20:26:40,097 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table Manager
2019-12-05T20:26:40,097 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table SSL
2019-12-05T20:26:40,097 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table SSL
2019-12-05T20:26:40,097 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table QoS
2019-12-05T20:26:40,097 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table QoS
2019-12-05T20:26:40,097 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table AutoAttach
2019-12-05T20:26:40,098 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Queue
2019-12-05T20:26:40,098 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table Queue
2019-12-05T20:26:40,098 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Bridge
2019-12-05T20:26:40,098 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [_version] in table Bridge
2019-12-05T20:26:40,098 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound monitoring OVSDB schema table Interface
2019-12-05T20:26:40,098 | INFO  | opendaylight-cluster-data-akka.actor.default-dispatcher-41 | OvsdbConnectionInstance          | 453 - org.opendaylight.ovsdb.southbound-impl - 1.10.0.SNAPSHOT | Southbound NOT monitoring columns [statistics, _version] in table Interface
2019-12-05T20:26:40,115 | INFO  | opendaylight-cluster-data-notification-dispatcher-47 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SfcOvsNodeDataListener::add() bridge name [OvsdbBridgeName{_value=ovsconf_exit_br}] DPID [DatapathId{_value=00:00:ae:55:61:54:e1:4e}]
2019-12-05T20:26:40,116 | INFO  | opendaylight-cluster-data-notification-dispatcher-47 | SfcOvsNodeDataListener           | 467 - org.opendaylight.sfc.ovs - 0.11.0.SNAPSHOT | SFFs empty in runSffOvsBridgeAugOpenflowNodeId.
2
Comment by Jamo Luhrsen [ 08/Jan/20 ]

just fyi that the recent patch "Lookup up bridge in old bridges when the port is removed" did not resolve this failure. let me know if there is something I can do on the CSIT side to help keep driving on this one

Comment by Luis Gomez [ 25/Nov/20 ]

This test is skipped here: https://git.opendaylight.org/gerrit/c/integration/test/+/93923

I do not think anybody will fix it at this point.

Generated at Wed Feb 07 20:36:19 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.