Re: [ovs-dev] [ovn] OF connection dropped when OVS port mac is changes

Vladislav Odintsov Mon, 12 Aug 2024 09:52:56 -0700

Hi Ilya, thanks for the quick response!

On 12.08.2024 23:42, Ilya Maximets wrote:

On 8/12/24 18:33, Ilya Maximets wrote:

On 8/12/24 18:24, Vladislav Odintsov wrote:

Hi,


I've faced with a behavior of OVS/OVN (I couldn't understand which part
to blame) loosing openflow connection if I change mac address of an
added to br-int logical port, which is claimed as a normal VIF port by
ovn-controller. There is a simple reproducer script:

ovn-nbctl ls-add test
ovn-nbctl lsp-add test test1
ip li add test1 type dummy
ovs-vsctl add-port br-int test1
ip li set test1 add 00:00:00:00:00:01

When the last line is executed in ovn-controller.log I see openflow is
re-connected:

2024-08-12T15:42:02.493Z|03705|rconn(ovn_pinctrl0)|INFO|unix:/run/openvswitch/br-int.mgmt:
connection closed by peer
2024-08-12T15:42:02.494Z|00222|rconn|INFO|unix:/run/openvswitch/br-int.mgmt:
connection closed by peer
2024-08-12T15:42:02.494Z|00223|rconn|INFO|unix:/run/openvswitch/br-int.mgmt:
connection closed by peer
2024-08-12T15:42:03.495Z|00224|rconn|INFO|unix:/run/openvswitch/br-int.mgmt:
connecting...
2024-08-12T15:42:03.495Z|00225|rconn|INFO|unix:/run/openvswitch/br-int.mgmt:
connecting...
2024-08-12T15:42:03.495Z|03706|rconn(ovn_pinctrl0)|INFO|unix:/run/openvswitch/br-int.mgmt:
connecting...
2024-08-12T15:42:03.495Z|00226|rconn|INFO|unix:/run/openvswitch/br-int.mgmt:
connected

In ovs-vswitchd with enabled DBG logs there is:

2024-08-12T16:01:08.694Z|3796712|poll_loop|DBG|wakeup due to [POLLIN] on
fd 18 (NETLINK_ROUTE<->NETLINK_ROUTE) at lib/netlink-socket.c:1409 (0%
CPU usage)
2024-08-12T16:01:08.695Z|3796713|poll_loop|DBG|wakeup due to [POLLIN] on
fd 16 (NETLINK_ROUTE<->NETLINK_ROUTE) at lib/netlink-socket.c:1409 (0%
CPU usage)
2024-08-12T16:01:08.695Z|3796714|netlink_socket|DBG|Dropped 505 log
messages in last 1 seconds (most recently, 0 seconds ago) due to
excessive rate
2024-08-12T16:01:08.695Z|3796715|netlink_socket|DBG|nl_sock_recv__
(Success): nl(len:1360, type=16(family-defined), flags=0, seq=0, pid=0
2024-08-12T16:01:08.695Z|3796716|dpif|DBG|Dropped 15 log messages in
last 0 seconds (most recently, 0 seconds ago) due to excessive rate
2024-08-12T16:01:08.695Z|3796717|dpif|DBG|system@ovs-system: device
internet is on port 1
2024-08-12T16:01:08.695Z|3796718|dpif|DBG|system@ovs-system: device
br-ext is on port 2
2024-08-12T16:01:08.695Z|3796719|jsonrpc|DBG|unix:/var/run/openvswitch/db.sock:
send request, method="transact",
params=["Open_vSwitch",{"where":[["_uuid","==",["uuid","acae6b73-de5f-46e4-a3d9-7874efd43cb4"]]],"row":{"mac_in_use":"00:00:00:00:00:02"},"op":"update","table":"Interface"},{"lock":"ovs_vswitchd","op":"assert"}],
id=4284801
2024-08-12T16:01:08.699Z|3796720|poll_loop|DBG|wakeup due to [POLLIN] on
fd 37 (FIFO pipe:[103980657]) at vswitchd/bridge.c:421 (0% CPU usage)
2024-08-12T16:01:08.699Z|3796721|poll_loop|DBG|wakeup due to [POLLIN] on
fd 17 (<->/var/run/openvswitch/db.sock) at lib/stream-fd.c:157 (0% CPU
usage)
2024-08-12T16:01:08.699Z|00690|poll_loop(urcu5)|DBG|wakeup due to
[POLLIN] on fd 56 (FIFO pipe:[103975681]) at lib/ovs-rcu.c:363
2024-08-12T16:01:08.699Z|3796722|jsonrpc|DBG|unix:/var/run/openvswitch/db.sock:
received notification, method="update3",
params=[["monid","Open_vSwitch"],"00000000-0000-0000-0000-000000000000",{"Interface":{"acae6b73-de5f-46e4-a3d9-7874efd43cb4":{"modify":{"mac_in_use":"00:00:00:00:00:02"}}}}]
2024-08-12T16:01:08.699Z|3796723|jsonrpc|DBG|unix:/var/run/openvswitch/db.sock:
received reply, result=[{"count":1},{}], id=4284801
2024-08-12T16:01:08.699Z|3796724|vconn|DBG|unix#121: sent (Success):
OFPT_PORT_STATUS (OF1.5) (xid=0x0): MOD: 15(test1): addr:00:00:00:00:00:02
       config:     PORT_DOWN
       state:      LINK_DOWN
       speed: 0 Mbps now, 0 Mbps max
2024-08-12T16:01:08.699Z|3796725|bridge|INFO|bridge br-int: using
datapath ID 0000000000000002
2024-08-12T16:01:08.699Z|3796726|rconn|INFO|br-int<->unix#121: disconnecting
2024-08-12T16:01:08.699Z|3796727|rconn|DBG|br-int<->unix#121: entering
DISCONNECTED
2024-08-12T16:01:08.699Z|3796728|rconn|INFO|br-int<->unix#122: disconnecting
2024-08-12T16:01:08.699Z|3796729|rconn|DBG|br-int<->unix#122: entering
DISCONNECTED
2024-08-12T16:01:08.699Z|3796730|rconn|INFO|br-int<->unix#123: disconnecting
2024-08-12T16:01:08.699Z|3796731|rconn|DBG|br-int<->unix#123: entering
DISCONNECTED
2024-08-12T16:01:08.699Z|3796732|jsonrpc|DBG|unix:/var/run/openvswitch/db.sock:
send request, method="transact",
params=["Open_vSwitch",{"where":[["_uuid","==",["uuid","5c37aa7c-9394-4068-8a4d-ab23705036d7"]]],"row":{"datapath_id":"0000000000000002"},"op":"update","table":"Bridge"},{"lock":"ovs_vswitchd","op":"assert"}],
id=4284802
2024-08-12T16:01:08.701Z|3796733|poll_loop|DBG|wakeup due to [POLLIN] on
fd 37 (FIFO pipe:[103980657]) at vswitchd/bridge.c:421 (0% CPU usage)
2024-08-12T16:01:08.701Z|3796734|poll_loop|DBG|wakeup due to [POLLIN] on
fd 17 (<->/var/run/openvswitch/db.sock) at lib/stream-fd.c:157 (0% CPU
usage)
2024-08-12T16:01:08.701Z|00691|poll_loop(urcu5)|DBG|wakeup due to
[POLLIN] on fd 56 (FIFO pipe:[103975681]) at lib/ovs-rcu.c:236
2024-08-12T16:01:08.701Z|3796735|poll_loop|DBG|wakeup due to [POLLIN] on
fd 16 (NETLINK_ROUTE<->NETLINK_ROUTE) at lib/netlink-socket.c:1409 (0%
CPU usage)
2024-08-12T16:01:08.701Z|3796736|jsonrpc|DBG|unix:/var/run/openvswitch/db.sock:
received notification, method="update3",
params=[["monid","Open_vSwitch"],"00000000-0000-0000-0000-000000000000",{"Bridge":{"5c37aa7c-9394-4068-8a4d-ab23705036d7":{"modify":{"datapath_id":"0000000000000002"}}}}]
2024-08-12T16:01:08.701Z|3796737|jsonrpc|DBG|unix:/var/run/openvswitch/db.sock:
received reply, result=[{"count":1},{}], id=4284802
2024-08-12T16:01:08.701Z|3796738|ovsdb_cs|DBG|unix:/var/run/openvswitch/db.sock:
received unexpected reply message:
{"error":null,"id":4284802,"result":[{"count":1},{}]}
2024-08-12T16:01:08.702Z|3796739|jsonrpc|DBG|unix:/var/run/openvswitch/db.sock:
send request, method="transact",
params=["Open_vSwitch",{"where":[["_uuid","==",["uuid","c0210d7f-8482-44e5-8fcb-49df616d3f97"]]],"row":{"mac_in_use":"00:00:00:00:00:02"},"op":"update","table":"Interface"},{"lock":"ovs_vswitchd","op":"assert"}],
id=4284803
2024-08-12T16:01:08.703Z|3796740|poll_loop|DBG|wakeup due to [POLLIN] on
fd 17 (<->/var/run/openvswitch/db.sock) at lib/stream-fd.c:157 (0% CPU
usage)
2024-08-12T16:01:08.703Z|3796741|jsonrpc|DBG|unix:/var/run/openvswitch/db.sock:
received notification, method="update3",
params=[["monid","Open_vSwitch"],"00000000-0000-0000-0000-000000000000",{"Interface":{"c0210d7f-8482-44e5-8fcb-49df616d3f97":{"modify":{"mac_in_use":"00:00:00:00:00:02"}}}}]
2024-08-12T16:01:08.703Z|3796742|jsonrpc|DBG|unix:/var/run/openvswitch/db.sock:
received reply, result=[{"count":1},{}], id=4284803


Then OVN re-instansiates OF connection. With OVN 22.09.1 this looks like
this:


2024-08-12T16:03:52.189Z|00709|poll_loop|DBG|wakeup due to [POLLIN] on
fd 55 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:274 (0%
CPU usage)
2024-08-12T16:03:52.189Z|00710|rconn|DBG|br-int<->unix#4: entering
CONNECTING
2024-08-12T16:03:52.189Z|00711|poll_loop|DBG|wakeup due to [POLLOUT] on
fd 63 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:153 (0%
CPU usage)
2024-08-12T16:03:52.189Z|00712|poll_loop|DBG|wakeup due to [POLLIN] on
fd 55 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:274 (0%
CPU usage)
2024-08-12T16:03:52.189Z|00713|vconn|DBG|unix#4: sent (Success):
OFPT_HELLO (OF1.5) (xid=0x4):
   version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
2024-08-12T16:03:52.189Z|00714|vconn|DBG|unix#4: received: OFPT_HELLO
(OF1.5) (xid=0x14):
   version bitmap: 0x06
2024-08-12T16:03:52.189Z|00715|vconn|DBG|unix#4: negotiated OpenFlow
version 0x06 (we support version 0x06 and earlier, peer supports version
0x06)
2024-08-12T16:03:52.189Z|00716|rconn|DBG|br-int<->unix#4: connected
2024-08-12T16:03:52.189Z|00717|rconn|DBG|br-int<->unix#4: entering ACTIVE
2024-08-12T16:03:52.189Z|00718|rconn|DBG|br-int<->unix#5: entering
CONNECTING
2024-08-12T16:03:52.189Z|00719|poll_loop|DBG|wakeup due to [POLLIN] on
fd 63 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:157 (0%
CPU usage)
2024-08-12T16:03:52.189Z|00720|poll_loop|DBG|wakeup due to [POLLIN] on
fd 55 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:274 (0%
CPU usage)
2024-08-12T16:03:52.189Z|00721|poll_loop|DBG|wakeup due to [POLLOUT] on
fd 64 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:153 (0%
CPU usage)
2024-08-12T16:03:52.189Z|00722|vconn|DBG|unix#4: received:
OFPT_GET_CONFIG_REQUEST (OF1.5) (xid=0x17):
2024-08-12T16:03:52.189Z|00723|vconn|DBG|unix#4: sent (Success):
OFPT_GET_CONFIG_REPLY (OF1.5) (xid=0x17): frags=normal miss_send_len=0
2024-08-12T16:03:52.189Z|00724|vconn|DBG|unix#4: received:
NXT_SET_PACKET_IN_FORMAT (OF1.5) (xid=0x18): format=nxt_packet_in2
2024-08-12T16:03:52.189Z|00725|vconn|DBG|unix#4: received:
OFPT_SET_CONFIG (OF1.5) (xid=0x19): frags=normal miss_send_len=65535
2024-08-12T16:03:52.189Z|00726|vconn|DBG|unix#5: sent (Success):
OFPT_HELLO (OF1.5) (xid=0x5):
   version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
2024-08-12T16:03:52.189Z|00727|vconn|DBG|unix#5: received: OFPT_HELLO
(OF1.5) (xid=0x15):
   version bitmap: 0x06
2024-08-12T16:03:52.189Z|00728|vconn|DBG|unix#5: negotiated OpenFlow
version 0x06 (we support version 0x06 and earlier, peer supports version
0x06)
2024-08-12T16:03:52.189Z|00729|rconn|DBG|br-int<->unix#5: connected
2024-08-12T16:03:52.189Z|00730|rconn|DBG|br-int<->unix#5: entering ACTIVE
2024-08-12T16:03:52.189Z|00731|rconn|DBG|br-int<->unix#6: entering
CONNECTING
2024-08-12T16:03:52.189Z|00732|poll_loop|DBG|wakeup due to [POLLOUT] on
fd 65 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:153 (0%
CPU usage)
2024-08-12T16:03:52.189Z|00733|vconn|DBG|unix#6: sent (Success):
OFPT_HELLO (OF1.5) (xid=0x6):
   version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
2024-08-12T16:03:52.189Z|00734|vconn|DBG|unix#6: received: OFPT_HELLO
(OF1.5) (xid=0x16):
   version bitmap: 0x06
2024-08-12T16:03:52.189Z|00735|vconn|DBG|unix#6: negotiated OpenFlow
version 0x06 (we support version 0x06 and earlier, peer supports version
0x06)
2024-08-12T16:03:52.189Z|00736|rconn|DBG|br-int<->unix#6: connected
2024-08-12T16:03:52.189Z|00737|rconn|DBG|br-int<->unix#6: entering ACTIVE
2024-08-12T16:03:52.190Z|00738|poll_loop|DBG|wakeup due to [POLLIN] on
fd 65 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:157 (0%
CPU usage)
2024-08-12T16:03:52.190Z|00739|poll_loop|DBG|wakeup due to [POLLIN] on
fd 64 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:157 (0%
CPU usage)
2024-08-12T16:03:52.190Z|00740|vconn|DBG|unix#5: received:
OFPST_METER_FEATURES request (OF1.5) (xid=0x1a):
2024-08-12T16:03:52.190Z|00741|vconn|DBG|unix#5: sent (Success):
OFPST_METER_FEATURES reply (OF1.5) (xid=0x1a):
max_meter:4294967295 max_bands:1 max_color:0
band_types: drop
capabilities: kbps pktps burst stats
2024-08-12T16:03:52.190Z|00742|vconn|DBG|unix#6: received:
NXT_TLV_TABLE_REQUEST (OF1.5) (xid=0x1b):
2024-08-12T16:03:52.190Z|00743|vconn|DBG|unix#6: sent (Success):
NXT_TLV_TABLE_REPLY (OF1.5) (xid=0x1b):
   max option space=256 max fields=64
   allocated option space=4

   mapping table:
    class  type  length  match field
   ------  ----  ------  --------------
    0x102  0x80       4  tun_metadata0

2024-08-12T16:03:52.209Z|00744|poll_loop|DBG|wakeup due to [POLLIN] on
fd 64 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:157 (0%
CPU usage)
2024-08-12T16:03:52.209Z|00745|vconn|DBG|unix#5: received:
OFPST_METER_FEATURES request (OF1.5) (xid=0x1c):
2024-08-12T16:03:52.209Z|00746|vconn|DBG|unix#5: sent (Success):
OFPST_METER_FEATURES reply (OF1.5) (xid=0x1c):
max_meter:4294967295 max_bands:1 max_color:0
band_types: drop
capabilities: kbps pktps burst stats


But with OVN main there is an OpenFlow error:


2024-08-12T16:08:29.607Z|01803|vconn|DBG|unix#10: sent (Success):
OFPT_HELLO (OF1.5) (xid=0xa):
   version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
2024-08-12T16:08:29.607Z|01804|vconn|DBG|unix#10: received: OFPT_HELLO
(OF1.5) (xid=0x20d4):
   version bitmap: 0x06
2024-08-12T16:08:29.607Z|01805|vconn|DBG|unix#10: negotiated OpenFlow
version 0x06 (we support version 0x06 and earlier, peer supports version
0x06)
2024-08-12T16:08:29.607Z|01806|rconn|DBG|br-int<->unix#10: connected
2024-08-12T16:08:29.607Z|01807|rconn|DBG|br-int<->unix#10: entering ACTIVE
2024-08-12T16:08:29.607Z|01808|vconn|DBG|unix#10: received:
OFPT_GET_CONFIG_REQUEST (OF1.5) (xid=0x20d7):
2024-08-12T16:08:29.607Z|01809|vconn|DBG|unix#10: sent (Success):
OFPT_GET_CONFIG_REPLY (OF1.5) (xid=0x20d7): frags=normal miss_send_len=0
2024-08-12T16:08:29.607Z|01810|vconn|DBG|unix#10: received:
NXT_SET_PACKET_IN_FORMAT (OF1.5) (xid=0x20d8): format=nxt_packet_in2
2024-08-12T16:08:29.607Z|01811|vconn|DBG|unix#10: received:
OFPT_SET_CONFIG (OF1.5) (xid=0x20d9): frags=normal miss_send_len=65535
2024-08-12T16:08:29.607Z|01812|rconn|DBG|br-int<->unix#11: entering
CONNECTING
2024-08-12T16:08:29.607Z|01813|poll_loop|DBG|wakeup due to [POLLIN] on
fd 91 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:274 (0%
CPU usage)
2024-08-12T16:08:29.607Z|01814|poll_loop|DBG|wakeup due to [POLLOUT] on
fd 104 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:153 (0%
CPU usage)
2024-08-12T16:08:29.608Z|01815|vconn|DBG|unix#11: sent (Success):
OFPT_HELLO (OF1.5) (xid=0xb):
   version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
2024-08-12T16:08:29.608Z|01816|vconn|DBG|unix#11: received: OFPT_HELLO
(OF1.5) (xid=0x20d5):
   version bitmap: 0x06
2024-08-12T16:08:29.608Z|01817|vconn|DBG|unix#11: negotiated OpenFlow
version 0x06 (we support version 0x06 and earlier, peer supports version
0x06)
2024-08-12T16:08:29.608Z|01818|rconn|DBG|br-int<->unix#11: connected
2024-08-12T16:08:29.608Z|01819|rconn|DBG|br-int<->unix#11: entering ACTIVE
2024-08-12T16:08:29.608Z|01820|rconn|DBG|br-int<->unix#12: entering
CONNECTING
2024-08-12T16:08:29.608Z|01821|poll_loop|DBG|wakeup due to [POLLOUT] on
fd 105 (//var/run/openvswitch/br-int.mgmt<->) at lib/stream-fd.c:153 (0%
CPU usage)
2024-08-12T16:08:29.608Z|01822|vconn|DBG|unix#11: received:
OFPST_METER_FEATURES request (OF1.5) (xid=0x20da):
2024-08-12T16:08:29.608Z|01823|vconn|DBG|unix#11: sent (Success):
OFPST_METER_FEATURES reply (OF1.5) (xid=0x20da):
max_meter:4294967295 max_bands:1 max_color:0
band_types: drop
capabilities: kbps pktps burst stats
2024-08-12T16:08:29.608Z|01824|vconn|DBG|unix#11: received:
OFPT_BARRIER_REQUEST (OF1.5) (xid=0x20db):
2024-08-12T16:08:29.608Z|01825|vconn|DBG|unix#11: sent (Success):
OFPT_BARRIER_REPLY (OF1.5) (xid=0x20db):
2024-08-12T16:08:29.608Z|01826|vconn|DBG|unix#11: received:
OFPST_GROUP_FEATURES request (OF1.5) (xid=0x20dc):
2024-08-12T16:08:29.608Z|01827|vconn|DBG|unix#11: sent (Success):
OFPST_GROUP_FEATURES reply (OF1.5) (xid=0x20dc):
   Group table:
      Types:  0xf
      Capabilities:  0x7
      all group:
         max_groups=0xffffff00
         actions: output group set_field strip_vlan push_vlan mod_nw_ttl
dec_ttl set_mpls_ttl dec_mpls_ttl push_mpls pop_mpls set_queue
      select group:
         max_groups=0xffffff00
         actions: output group set_field strip_vlan push_vlan mod_nw_ttl
dec_ttl set_mpls_ttl dec_mpls_ttl push_mpls pop_mpls set_queue
      indirect group:
         max_groups=0xffffff00
         actions: output group set_field strip_vlan push_vlan mod_nw_ttl
dec_ttl set_mpls_ttl dec_mpls_ttl push_mpls pop_mpls set_queue
      fast failover group:
         max_groups=0xffffff00
         actions: output group set_field strip_vlan push_vlan mod_nw_ttl
dec_ttl set_mpls_ttl dec_mpls_ttl push_mpls pop_mpls set_queue
2024-08-12T16:08:29.608Z|01828|vconn|DBG|unix#11: received:
OFPT_BARRIER_REQUEST (OF1.5) (xid=0x20dd):
2024-08-12T16:08:29.608Z|01829|vconn|DBG|unix#11: sent (Success):
OFPT_BARRIER_REPLY (OF1.5) (xid=0x20dd):
2024-08-12T16:08:29.609Z|01830|vconn|DBG|unix#11: received:
OFPT_BUNDLE_CONTROL (OF1.5) (xid=0x20de):
   bundle_id=0 type=OPEN_REQUEST flags=atomic ordered
2024-08-12T16:08:29.609Z|01831|vconn|DBG|unix#11: sent (Success):
OFPT_BUNDLE_CONTROL (OF1.5) (xid=0x20de):
   bundle_id=0 type=OPEN_REPLY flags=0
2024-08-12T16:08:29.609Z|01832|ofp_actions|WARN|Dropped 3 log messages
in last 104 seconds (most recently, 104 seconds ago) due to excessive rate
2024-08-12T16:08:29.609Z|01833|ofp_actions|WARN|unknown OpenFlow15
action for vendor 0x2320 and type 51
2024-08-12T16:08:29.609Z|01834|ofp_actions|WARN|bad action at offset 0
(OFPBAC_BAD_VENDOR_TYPE):
00000000  ff ff 00 28 00 00 23 20-00 33 ff ff 00 00 00 00
00000010  00 01 00 04 00 1f 00 00-00 01 00 04 00 1f 00 00
00000020  ff ff 00 00 00 00 00 00-
2024-08-12T16:08:29.609Z|01835|vconn|DBG|unix#11: received:
OFPT_BUNDLE_ADD_MESSAGE (OF1.5) (xid=0x20df):
   bundle_id=0 flags=atomic ordered
OFPT_FLOW_MOD (OF1.5) (xid=0x20df): ***decode error:
OFPBAC_BAD_VENDOR_TYPE***
00000000  06 0e 00 68 00 00 20 df-00 00 00 00 00 00 00 00 |...h.. .........|
00000010  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00 |................|
00000020  ff ff ff ff ff ff ff ff-ff ff ff ff 00 00 00 00 |................|
00000030  00 01 00 04 00 00 00 00-00 04 00 30 00 00 00 00 |...........0....|
00000040  ff ff 00 28 00 00 23 20-00 33 ff ff 00 00 00 00 |...(..# .3......|
00000050  00 01 00 04 00 1f 00 00-00 01 00 04 00 1f 00 00 |................|
00000060  ff ff 00 00 00 00 00 00- |........        |
2024-08-12T16:08:29.609Z|01836|connmgr|INFO|br-int<->unix#11: sending
OFPBAC_BAD_VENDOR_TYPE error reply to OFPT_BUNDLE_ADD_MESSAGE message
2024-08-12T16:08:29.609Z|01837|vconn|DBG|unix#11: sent (Success):
OFPT_ERROR (OF1.5) (xid=0x20df): OFPBAC_BAD_VENDOR_TYPE
OFPT_BUNDLE_ADD_MESSAGE (OF1.5) (xid=0x20df):
   bundle_id=0 flags=atomic ordered
OFPT_FLOW_MOD (OF1.5) (xid=0x20df): ***decode error:
OFPBAC_BAD_VENDOR_TYPE***
00000000  06 0e 00 68 00 00 20 df-00 00 00 00 00 00 00 00 |...h.. .........|
00000010  00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00 |................|
00000020  ff ff ff ff ff ff ff ff-ff ff ff ff 00 00 00 00 |................|
00000030  00 01 00 04 00 00 00 00-00 04 00 30 00 00 00 00 |...........0....|
00000040  ff ff 00 28 00 00 23 20-00 33 ff ff 00 00 00 00 |...(..# .3......|
00000050  00 01 00 04 00 1f 00 00-00 01 00 04 00 1f 00 00 |................|
00000060  ff ff 00 00 00 00 00 00- |........        |
2024-08-12T16:08:29.609Z|01838|vconn|DBG|unix#11: received:
OFPT_BUNDLE_CONTROL (OF1.5) (xid=0x20e0):
   bundle_id=0 type=DISCARD_REQUEST flags=atomic ordered
2024-08-12T16:08:29.609Z|01839|vconn|DBG|unix#11: sent (Success):
OFPT_BUNDLE_CONTROL (OF1.5) (xid=0x20e0):
   bundle_id=0 type=DISCARD_REPLY flags=0
2024-08-12T16:08:29.609Z|01840|vconn|DBG|unix#11: received:
OFPT_BARRIER_REQUEST (OF1.5) (xid=0x20e1):
2024-08-12T16:08:29.609Z|01841|vconn|DBG|unix#11: sent (Success):
OFPT_BARRIER_REPLY (OF1.5) (xid=0x20e1):


The behavior was tested against OVS 3.1.1 and 3.3.1. Results are the same.

My questions are:

1. How to understand the reason for OF disconnect? I don't see any
specific error in OVS log.> 2. I see that OF Error in handling 
OFPT_BUNDLE_ADD_MESSAGE is triggered
on each OF connection instantiation within ovn-controller. Is this a
real error (despite of this is a DBG loglevel)?

I'd guess it's a feature discovery for the new SAMPLE4 action, i.e.
sample action with registers as observation point/ids.  This is only
supported in upcoming OVS 3.4.  So, you'll see these debug errors on
earlier releases and that is expected.

Do you see the same issue with OVS' branch-3.4 ?


Huh, I didn't test it with 3.4 :)


However, OVN should not disconnect on these errors.  Might be a bug in
the feature checking code in ovn-controller.  I'd guess that controller
disconnects after receiving any OF error.  But it should not do that
during feature support checks.

Or maybe I misunderstood.  The disconnection happens before the feature
re-negotiation.  Either way the OF errors in the log are likely expected
when using older OVS.

I don't think disconnect is somehow related to feature probing, becausethe disconnect also present on old OVN version, which doesn't triggerany OF errors. Also feature probing is not present in case, whereinterface's mac is changed. For that time all features are already probed.

Ales, could you take a look?

Best regards, Ilya Maximets.

_______________________________________________
dev mailing list
[email protected]
https://mail.openvswitch.org/mailman/listinfo/ovs-dev

_______________________________________________
dev mailing list
[email protected]
https://mail.openvswitch.org/mailman/listinfo/ovs-dev

Re: [ovs-dev] [ovn] OF connection dropped when OVS port mac is changes

Reply via email to