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 ?
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.
Ales, could you take a look?
Best regards, Ilya Maximets.
_______________________________________________
dev mailing list
[email protected]
https://mail.openvswitch.org/mailman/listinfo/ovs-dev
