https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/netvirt-csit-1node-openstack-ocata-upstream-stateful-nitrogen/771/log_01_l2.html.gz
 
See two issues with patch ports between br-int and br-physnet1:
 
1. They are never created
2. They take over 90s to be created
 [1] is a job where the patch ports fail to add on compute_2. What I also notice is from the time br-physnet1 is created until patch ports are created on control_1 is 30s, then for compute_1 it is 100s. And then compute_2 never tries to create the patch ports.
 
Recall the flow in csit:
0. Start stacking
1. Nodes connect to ODL
2. netvirt adds br-int and adds br-physnet1 port to br-int
3. Stacking completes
4. Delete br-physnet1 from br-int
5. Add br-physnet1 bridge
6. netvirt adds patch ports
 
That all seems to work for the control and compute_1 but fails on the patch ports for compute_2. And as noted above, it took 37s to add them on the control node and 100s to add them on the control_1. Below for each node is the log when the br-physnet1 is seen and the next log is adding the patch ports.
 
Can anyone see anything strange in the logs that would explain the issue? This happens randomly on either node or sometimes both nodes.
 
I see in [2] which is the ovsdb log, that during this time when the ports should be updated that something is trying to create br-int, which you can see in the "record 24" and "record 25" logs below. It says invoked by user/python so that leads me to believe it is openstack code and not ODL. That seems to trigger the ovsdbnode update in ODL for compute 1, but doesn't help on compute 2. on compute 2 it happened just as tap ports were being added so maybe that casues problems.
 
So it seems the patch to make sure the patch ports are created is missing something since it is not triggering the creation.
 
 

 control_1:    2018-01-14 23:27:10,854 | INFO  | eChangeHandler-0 | OvsdbNodeListener                | 242 - org.opendaylight.genius.itm-impl - 0.3.2.SNAPSHOT | OvsdbBridgeAugmentation ADD: DPID for bridge br-physnet1 is NULL. 2018-01-14 23:27:57,483 | INFO  | eChangeHandler-0 | ElanBridgeManager                | 314 - org.opendaylight.netvirt.elanmanager-impl - 0.5.2.SNAPSHOT | addPatchPort: node: ovsdb://uuid/72adceaf-e656-432f-8d49-6eab88d40d06/bridge/br-int, bridge: br-int, portname: br-physnet1-pa peer: br-physnet1-int-patch status: success    compute_1:
 2018-01-14 23:27:12,127 | INFO  | eChangeHandler-0 | OvsdbNodeListener                | 242 - org.opendaylight.genius.itm-impl - 0.3.2.SNAPSHOT | OvsdbBridgeAugmentation ADD: DPID for bridge br-physnet1 is NULL.
  record 24: 2018-01-14 23:28:56.501 "ovs-vsctl (invoked by /bin/python): ovs-vsctl -- --may-exist add-br br-int -- set Bridge br-int datapath_type=system"    2018-01-14 23:28:56,524 | INFO  | eChangeHandler-0 | ElanBridgeManager                | 314 - org.opendaylight.netvirt.elanmanager-impl - 0.5.2.SNAPSHOT | addPatchPort: node: ovsdb://uuid/c2e6d059-7ae8-4c4c-92fb-c40b656f5bdb/bridge/br-int, bridge: br-int, portname: br-physnet1-pa peer: br-physnet1-int-patch status: success
   compute_2: 2018-01-14 23:27:13,326 | INFO  | eChangeHandler-0 | OvsdbNodeListener                | 242 - org.opendaylight.genius.itm-impl - 0.3.2.SNAPSHOT | OvsdbBridgeAugmentation ADD: DPID for bridge br-physnet1 is NULL.
  record 25: 2018-01-14 23:29:05.581 "ovs-vsctl (invoked by /bin/python): ovs-vsctl -- --may-exist add-br br-int -- set Bridge br-int datapath_type=system"    

 
[1] https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/netvirt-csit-1node-openstack-ocata-upstream-stateful-nitrogen/771/log_01_l2.html.gz
 
[2] https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/netvirt-csit-1node-openstack-ocata-upstream-stateful-nitrogen/771/compute_2/extra_debug.log.gz