[ovs-dev] br-int bridge dpid changes when openvswitch is restarted

Bertrand Low Bertrand.Low at hcl.com
Sat Oct 29 00:33:35 UTC 2016


Hi Cascardo,



Thank you for replying. Please excuse the disclaimer at the bottom of the email as it is automatically added by the company mail server.



Thanks for clarifying the revalidator error that I saw.



Regarding the datapath ID, I've turned on debug logging for ovsdb-server and ovs-vswitchd and found the following lines of interest in ovsdb-server.log:



2016-10-28T23:21:02.018Z|00117|jsonrpc|DBG|tcp:192.168.254.35:6640: received request, method="transact", params=["Open_vSwitch",{"where":[["name","==","br-int"]],"table":"Bridge","op":"update","row":{"fail_mode":["set",["secure"]],"external_ids":["map",[["opendaylight-iid","/network-topology:network-topology/network-topology:topology[network-topology:topology-id='ovsdb:1']/network-topology:node[network-topology:node-id='ovsdb://uuid/b429858f-b476-44be-94ac-e9ea61265a11/bridge/br-int']"]]],"other_config":["map",[["hwaddr","90:2e:72:41:fc:da"],["disable-in-band","true"]]]}},{"mutations":[["external_ids","delete",["set",["opendaylight-iid"]]],["external_ids","insert",["map",[["opendaylight-iid","/network-topology:network-topology/network-topology:topology[network-topology:topology-id='ovsdb:1']/network-topology:node[network-topology:node-id='ovsdb://uuid/b429858f-b476-44be-94ac-e9ea61265a11/bridge/br-int']"]]]]],"where":[["name","==","br-int"]],"table":"Bridge","op":"mutate"}], id="e842a544-edd0-4234-b88c-847c89ce8605"

2016-10-28T23:21:02.019Z|00118|jsonrpc|DBG|tcp:192.168.254.35:6640: send notification, method="update", params=["f8af9856-b198-4c86-83cd-541511fa62bc",{"Bridge":{"15e50dab-60d7-4544-8051-fdf2141ef433":{"new":{"name":"br-int","flood_vlans":["set",[]],"auto_attach":["set",[]],"ports":["uuid","d20ae748-927e-4c06-bf6f-0616e1127464"],"stp_enable":false,"fail_mode":"secure","rstp_enable":false,"_uuid":["uuid","15e50dab-60d7-4544-8051-fdf2141ef433"],"rstp_status":["map",[]],"flow_tables":["map",[]],"netflow":["set",[]],"datapath_type":"","controller":["set",[["uuid","0e2fe15c-fda6-446d-9950-9e3a82062120"],["uuid","7d404ba9-d2aa-4306-bdcb-e6bc088654fb"],["uuid","fc85f0a8-d97f-49a1-86e6-13a76bdf840a"]]],"other_config":["map",[["disable-in-band","true"],["hwaddr","90:2e:72:41:fc:da"]]],"status":["map",[]],"ipfix":["set",[]],"external_ids":["map",[["opendaylight-iid","/network-topology:network-topology/network-topology:topology[network-topology:topology-id='ovsdb:1']/network-topology:node[network-topology:node-id='ovsdb://uuid/b429858f-b476-44be-94ac-e9ea61265a11/bridge/br-int']"]]],"datapath_id":"0000a8ceb1b8d124","mirrors":["set",[]],"mcast_snooping_enable":false,"datapath_version":"<unknown>","sflow":["set",[]],"protocols":"OpenFlow13"},"old":{"other_config":["map",[["disable-in-band","true"],["hwaddr","a8:ce:b1:b8:d1:24"]]]}}}}]

2016-10-28T23:21:02.019Z|00119|jsonrpc|DBG|tcp:192.168.254.35:6640: send reply, result=[{"count":1},{"count":1}], id="e842a544-edd0-4234-b88c-847c89ce8605"

2016-10-28T23:21:02.019Z|00120|poll_loop|DBG|wakeup due to 0-ms timeout at ovsdb/jsonrpc-server.c:510

2016-10-28T23:21:02.019Z|00121|jsonrpc|DBG|unix: send notification, method="update", params=[null,{"Bridge":{"15e50dab-60d7-4544-8051-fdf2141ef433":{"new":{"name":"br-int","flood_vlans":["set",[]],"auto_attach":["set",[]],"ports":["uuid","d20ae748-927e-4c06-bf6f-0616e1127464"],"stp_enable":false,"fail_mode":"secure","rstp_enable":false,"rstp_status":["map",[]],"flow_tables":["map",[]],"netflow":["set",[]],"datapath_type":"","controller":["set",[["uuid","0e2fe15c-fda6-446d-9950-9e3a82062120"],["uuid","7d404ba9-d2aa-4306-bdcb-e6bc088654fb"],["uuid","fc85f0a8-d97f-49a1-86e6-13a76bdf840a"]]],"status":["map",[]],"ipfix":["set",[]],"other_config":["map",[["disable-in-band","true"],["hwaddr","90:2e:72:41:fc:da"]]],"datapath_id":"0000a8ceb1b8d124","mirrors":["set",[]],"mcast_snooping_enable":false,"datapath_version":"<unknown>","sflow":["set",[]],"protocols":"OpenFlow13"},"old":{"other_config":["map",[["disable-in-band","true"],["hwaddr","a8:ce:b1:b8:d1:24"]]]}}}}]

2016-10-28T23:21:02.037Z|00122|poll_loop|DBG|wakeup due to [POLLIN] on fd 17 (/var/run/openvswitch/db.sock<->) at lib/stream-fd.c:155

2016-10-28T23:21:02.037Z|00123|jsonrpc|DBG|unix: received request, method="transact", params=["Open_vSwitch",{"lock":"ovs_vswitchd","op":"assert"},{"where":[["_uuid","==",["uuid","15e50dab-60d7-4544-8051-fdf2141ef433"]]],"table":"Bridge","op":"update","row":{"datapath_id":"0000902e7241fcda"}}], id=5

2016-10-28T23:21:02.038Z|00124|jsonrpc|DBG|unix: send notification, method="update", params=[null,{"Bridge":{"15e50dab-60d7-4544-8051-fdf2141ef433":{"new":{"name":"br-int","flood_vlans":["set",[]],"auto_attach":["set",[]],"ports":["uuid","d20ae748-927e-4c06-bf6f-0616e1127464"],"stp_enable":false,"fail_mode":"secure","rstp_enable":false,"rstp_status":["map",[]],"flow_tables":["map",[]],"netflow":["set",[]],"datapath_type":"","controller":["set",[["uuid","0e2fe15c-fda6-446d-9950-9e3a82062120"],["uuid","7d404ba9-d2aa-4306-bdcb-e6bc088654fb"],["uuid","fc85f0a8-d97f-49a1-86e6-13a76bdf840a"]]],"status":["map",[]],"ipfix":["set",[]],"other_config":["map",[["disable-in-band","true"],["hwaddr","90:2e:72:41:fc:da"]]],"datapath_id":"0000902e7241fcda","mirrors":["set",[]],"mcast_snooping_enable":false,"datapath_version":"<unknown>","sflow":["set",[]],"protocols":"OpenFlow13"},"old":{"datapath_id":"0000a8ceb1b8d124"}}}}]

2016-10-28T23:21:02.039Z|00125|jsonrpc|DBG|unix: send reply, result=[{},{"count":1}], id=5

2016-10-28T23:21:02.039Z|00126|jsonrpc|DBG|tcp:192.168.254.35:6640: send notification, method="update", params=["f8af9856-b198-4c86-83cd-541511fa62bc",{"Bridge":{"15e50dab-60d7-4544-8051-fdf2141ef433":{"new":{"name":"br-int","flood_vlans":["set",[]],"auto_attach":["set",[]],"ports":["uuid","d20ae748-927e-4c06-bf6f-0616e1127464"],"stp_enable":false,"fail_mode":"secure","rstp_enable":false,"_uuid":["uuid","15e50dab-60d7-4544-8051-fdf2141ef433"],"rstp_status":["map",[]],"flow_tables":["map",[]],"netflow":["set",[]],"datapath_type":"","controller":["set",[["uuid","0e2fe15c-fda6-446d-9950-9e3a82062120"],["uuid","7d404ba9-d2aa-4306-bdcb-e6bc088654fb"],["uuid","fc85f0a8-d97f-49a1-86e6-13a76bdf840a"]]],"other_config":["map",[["disable-in-band","true"],["hwaddr","90:2e:72:41:fc:da"]]],"status":["map",[]],"ipfix":["set",[]],"external_ids":["map",[["opendaylight-iid","/network-topology:network-topology/network-topology:topology[network-topology:topology-id='ovsdb:1']/network-topology:node[network-topology:node-id='ovsdb://uuid/b429858f-b476-44be-94ac-e9ea61265a11/bridge/br-int']"]]],"datapath_id":"0000902e7241fcda","mirrors":["set",[]],"mcast_snooping_enable":false,"datapath_version":"<unknown>","sflow":["set",[]],"protocols":"OpenFlow13"},"old":{"datapath_id":"0000a8ceb1b8d124"}}}}]

2016-10-28T23:21:02.040Z|00127|poll_loop|DBG|wakeup due to 0-ms timeout at unix



>From the above excerpt, I'm trying to understand if the request was initiated by Opendaylight (192.168.254.35) to update br-int but because no dpid was specified, this caused OVS to change the dpid as well. Would appreciate your insight on this.



Please find attached the full logs as well.



Thanks,

Bertrand



-----Original Message-----
From: Thadeu Lima de Souza Cascardo [mailto:cascardo at redhat.com]
Sent: October 27, 2016 5:08 PM
To: Bertrand Low <Bertrand.Low at hcl.com>
Cc: dev at openvswitch.org
Subject: Re: [ovs-dev] br-int bridge dpid changes when openvswitch is restarted



On Thu, Oct 27, 2016 at 11:51:42PM +0000, Bertrand Low wrote:

> Hi there,

>

> Has anyone noticed a "connection flapping" behaviour for the br-int bridge (used between openstack and opendaylight's netvirt module) when openvswitch is restarted? I've provided some details below.

>

> Scenario:

>

> -          Opendaylight 3-node cluster running distribution-karaf-0.5.0-Boron with the odl-ovsdb-openstack feature installed

>

> -          A standalone OVS node running OVS version 2.4.0

>

>

>

> -          Step 1) set-manager of OVS node to all 3-nodes in the cluster

>

> -          Step 2) confirm that br-int is created automatically by the Opendaylight's NetVirt module) and all pipeline flows are pushed to the OVS node

>

> -          Step 3) on the OVS node, run systemctl stop openvswitch

>

> -          Step 4) on the OVS node, run systemctl start openvswitch

>

> Here is what ovs-vswitchd.log shows at step 4):

>

> 2016-10-26T19:16:24.910Z|00004|reconnect|INFO|unix:/var/run/openvswitch/db.sock: connecting...

> 2016-10-26T19:16:24.910Z|00005|reconnect|INFO|unix:/var/run/openvswitc

> h/db.sock: connected

> 2016-10-26T19:16:24.912Z|00006|ofproto_dpif|INFO|system at ovs-system:

> Datapath supports recirculation

> 2016-10-26T19:16:24.912Z|00007|ofproto_dpif|INFO|system at ovs-system:

> MPLS label stack length probed as 0

> 2016-10-26T19:16:24.912Z|00008|ofproto_dpif|INFO|system at ovs-system: datapath does not support masked set action feature.

> 2016-10-26T19:16:24.912Z|00009|ofproto_dpif|INFO|system at ovs-system:

> Datapath does not support unique flow ids

> 2016-10-26T19:16:24.916Z|00010|bridge|INFO|bridge br-int: added

> interface br-int on port 65534

> 2016-10-26T19:16:24.916Z|00011|bridge|INFO|bridge br-int: using

> datapath ID 0000bc8838168d41

> 2016-10-26T19:16:24.916Z|00012|connmgr|INFO|br-int: added service controller "punix:/var/run/openvswitch/br-int.mgmt"

> 2016-10-26T19:16:24.916Z|00013|connmgr|INFO|br-int: added primary controller "tcp:192.168.254.35:6653"

> 2016-10-26T19:16:24.917Z|00014|rconn|INFO|br-int<->tcp:192.168.254.35:6653: connecting...

> 2016-10-26T19:16:24.917Z|00015|connmgr|INFO|br-int: added primary controller "tcp:192.168.254.33:6653"

> 2016-10-26T19:16:24.917Z|00016|rconn|INFO|br-int<->tcp:192.168.254.33:6653: connecting...

> 2016-10-26T19:16:24.917Z|00017|connmgr|INFO|br-int: added primary controller "tcp:192.168.254.34:6653"

> 2016-10-26T19:16:24.917Z|00018|rconn|INFO|br-int<->tcp:192.168.254.34:6653: connecting...

> 2016-10-26T19:16:24.924Z|00019|rconn|INFO|br-int<->tcp:192.168.254.33:

> 6653: connected

> 2016-10-26T19:16:24.924Z|00020|rconn|INFO|br-int<->tcp:192.168.254.34:

> 6653: connected

> 2016-10-26T19:16:24.925Z|00021|bridge|INFO|ovs-vswitchd (Open vSwitch)

> 2.4.0

> 2016-10-26T19:16:24.927Z|00022|rconn|INFO|br-int<->tcp:192.168.254.35:

> 6653: connected

> 2016-10-26T19:16:24.929Z|00001|ofproto_dpif_upcall(handler5)|INFO|rece

> ived packet on unassociated datapath port 0

> 2016-10-26T19:16:25.430Z|00001|dpif(revalidator4)|WARN|system at ovs-syst

> em: failed to flow_get (Invalid argument)

> ufid:b1d72bef-1acb-4755-850a-2aeb4fb75ad2 <empty>, packets:0, bytes:0,

> used:never

> 2016-10-26T19:16:25.430Z|00002|ofproto_dpif_upcall(revalidator4)|WARN|

> Failed to acquire udpif_key corresponding to unexpected flow (Invalid

> argument): ufid:b1d72bef-1acb-4755-850a-2aeb4fb75ad2

> 2016-10-26T19:16:26.312Z|00023|bridge|INFO|bridge br-int: using

> datapath ID 0000b88fc560944b

> 2016-10-26T19:16:26.313Z|00024|rconn|INFO|br-int<->tcp:192.168.254.35:

> 6653: disconnecting

> 2016-10-26T19:16:26.313Z|00025|rconn|INFO|br-int<->tcp:192.168.254.33:

> 6653: disconnecting

> 2016-10-26T19:16:26.313Z|00026|rconn|INFO|br-int<->tcp:192.168.254.34:

> 6653: disconnecting

> 2016-10-26T19:16:26.952Z|00028|rconn|INFO|br-int<->tcp:192.168.254.35:6653: connecting...

> 2016-10-26T19:16:26.952Z|00029|rconn|INFO|br-int<->tcp:192.168.254.33:6653: connecting...

> 2016-10-26T19:16:26.952Z|00030|rconn|INFO|br-int<->tcp:192.168.254.34:6653: connecting...

> 2016-10-26T19:16:26.958Z|00031|rconn|INFO|br-int<->tcp:192.168.254.35:

> 6653: connected

> 2016-10-26T19:16:26.958Z|00032|rconn|INFO|br-int<->tcp:192.168.254.33:

> 6653: connected

> 2016-10-26T19:16:26.958Z|00033|rconn|INFO|br-int<->tcp:192.168.254.34:

> 6653: connected

> 2016-10-26T19:16:34.926Z|00034|memory|INFO|35400 kB peak resident set

> size after 10.0 seconds

>

> It seems like the bridge has an initial dpid 0000bc8838168d41 that connects to opendaylight and then it changes to dpid 0000b88fc560944b and disconnects and reconnects to opendaylight.

>

> Can anyone provide insight on the errors:

> 2016-10-26T19:16:24.929Z|00001|ofproto_dpif_upcall(handler5)|INFO|rece

> ived packet on unassociated datapath port 0

> 2016-10-26T19:16:25.430Z|00001|dpif(revalidator4)|WARN|system at ovs-syst

> em: failed to flow_get (Invalid argument)

> ufid:b1d72bef-1acb-4755-850a-2aeb4fb75ad2 <empty>, packets:0, bytes:0,

> used:never

> 2016-10-26T19:16:25.430Z|00002|ofproto_dpif_upcall(revalidator4)|WARN|

> Failed to acquire udpif_key corresponding to unexpected flow (Invalid

> argument): ufid:b1d72bef-1acb-4755-850a-2aeb4fb75ad2

>

> Do the errors above cause the bridge to get a new dpid, which then causes the disconnect and reconnect to opendaylight?

>

> Thanks,

> Bertrand

>

>

> ::DISCLAIMER::

> ----------------------------------------------------------------------

> ----------------------------------------------------------------------

> --------

>

> The contents of this e-mail and any attachment(s) are confidential and intended for the named recipient(s) only.

> E-mail transmission is not guaranteed to be secure or error-free as

> information could be intercepted, corrupted, lost, destroyed, arrive

> late or incomplete, or may contain viruses in transmission. The e mail and its contents (with or without referred errors) shall therefore not attach any liability on the originator or HCL or its affiliates.

> Views or opinions, if any, presented in this email are solely those of

> the author and may not necessarily reflect the views or opinions of

> HCL or its affiliates. Any form of reproduction, dissemination,

> copying, disclosure, modification, distribution and / or publication of this message without the prior written consent of authorized representative of HCL is strictly prohibited. If you have received this email in error please delete it and notify the sender immediately.

> Before opening any email and/or attachments, please check them for viruses and other defects.

>



Please, refrain yourself from including such disclaimers on public mailing lists. They don't make sense here.



The error you see is just an indication that the revalidator has found flows that this current instance has not put there. It was the old instance.



As for the datapath ID, whenever the bridge reconfigures (ports are added or

removed) and pick a different MAC address and has not a datapath ID configured, it will change its datapath ID. You have two options to make them stable. Set the datapath ID or set the MAC address for the bridge local port.



It should be something like:



ovs-vsctl set bridge br-int other-config:datapath-id=1234



Regards.

Cascardo.



> ----------------------------------------------------------------------

> ----------------------------------------------------------------------

> -------- _______________________________________________

> dev mailing list

> dev at openvswitch.org<mailto:dev at openvswitch.org>

> http://openvswitch.org/mailman/listinfo/dev



More information about the dev mailing list