[ovs-dev] [PATCH v2 3/4] Add file descriptor persistence where possible
Dumitru Ceara
dceara at redhat.com
Mon Feb 24 12:58:43 UTC 2020
On Mon, Feb 24, 2020 at 11:47 AM Anton Ivanov
<anton.ivanov at cambridgegreys.com> wrote:
>
>
> On 19/02/2020 14:20, Dumitru Ceara wrote:
> > On 2/18/20 7:12 AM, Anton Ivanov wrote:
> >>
> >> On 17/02/2020 14:48, Dumitru Ceara wrote:
> >>> On 2/14/20 6:54 PM, anton.ivanov at cambridgegreys.com wrote:
> >>>> From: Anton Ivanov <anton.ivanov at cambridgegreys.com>
> >>>>
> >>>> 1. Adds "persistent" behaviour where feasible (streams and signals).
> >>>> These are waited upon in the same thread where they are created. This
> >>>> allows them to be registered persistently with the OS (if possible)
> >>>> as well as the OS to provide hints - is the FD ready, is it closed,
> >>>> etc.
> >>>>
> >>>> 2. Removes unnecessary attempts to perform a read vs EAGAIN on a fd
> >>>> which is not ready if that fd has been registered as "private" to the
> >>>> thread which waits upon it.
> >>>>
> >>>> 3. No longer breaks other parts of OVS which create the fd in one
> >>>> thread and waits upon it in others.
> >>>>
> >>>> 3. Adds support for EPOLL on Linux and can be expanded to cover similar
> >>>> poll++ frameworks in other OSes.
> >>>>
> >>>> 4. Sets up the necessary infrastructure to make IO/SSL multi-threaded
> >>>> using a "centeral (e)poll dispatcher + IO threads" pattern
> >>>>
> >>>> Signed-off-by: Anton Ivanov <anton.ivanov at cambridgegreys.com>
> >>> Hi Anton,
> >>>
> >>> A couple of issues inline. Except for that:
> >>>
> >>> 1. The "STP - flush the fdb and mdb when topology changed" OVS test is
> >>> failing with your patches applied:
> >>>
> >>> make check TESTSUITEFLAGS='-k "flush the fdb"'
> >> I will have a look.
>
>
> I cannot reproduce that. It succeeds every time - 20 out of 20 runs. Can you send me some logs please?
>
>
Hi Anton,
After rebasing to latest upstream master I see the failure less often.
But it's still there.
I pasted the testsuite below.
Regards,
Dumitru
$ cat tests/testsuite.dir/2185/testsuite.log
# -*- compilation -*-
2185. stp.at:467: testing STP - flush the fdb and mdb when topology changed ...
./stp.at:468: ovsdb-tool create conf.db
$abs_top_srcdir/vswitchd/vswitch.ovsschema
./stp.at:468: ovsdb-server --detach --no-chdir --pidfile --log-file
--remote=punix:$OVS_RUNDIR/db.sock
stderr:
2020-02-24T12:56:14Z|00001|vlog|INFO|opened log file
/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/ovsdb-server.log
./stp.at:468: sed < stderr '
/vlog|INFO|opened log file/d
/ovsdb_server|INFO|ovsdb-server (Open vSwitch)/d'
./stp.at:468: ovs-vsctl --no-wait init
./stp.at:468: ovs-vswitchd --enable-dummy --disable-system
--disable-system-route --detach --no-chdir --pidfile --log-file
-vvconn -vofproto_dpif -vunixctl
stderr:
2020-02-24T12:56:14Z|00001|vlog|INFO|opened log file
/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/ovs-vswitchd.log
2020-02-24T12:56:14Z|00002|ovs_numa|INFO|Discovered 8 CPU cores on NUMA node 0
2020-02-24T12:56:14Z|00003|ovs_numa|INFO|Discovered 1 NUMA nodes and 8 CPU cores
2020-02-24T12:56:14Z|00004|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/db.sock:
connecting...
2020-02-24T12:56:14Z|00005|netlink_socket|INFO|netlink: could not
enable listening to all nsid (Operation not permitted)
2020-02-24T12:56:14Z|00006|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/db.sock:
connected
./stp.at:468: sed < stderr '
/ovs_numa|INFO|Discovered /d
/vlog|INFO|opened log file/d
/vswitchd|INFO|ovs-vswitchd (Open vSwitch)/d
/reconnect|INFO|/d
/dpif_netlink|INFO|Generic Netlink family .ovs_datapath. does not exist/d
/ofproto|INFO|using datapath ID/d
/netdev_linux|INFO|.*device has unknown hardware address family/d
/ofproto|INFO|datapath ID changed to fedcba9876543210/d
/dpdk|INFO|DPDK Disabled - Use other_config:dpdk-init to enable/d
/netlink_socket|INFO|netlink: could not enable listening to all nsid/d
/probe tc:/d
/tc: Using policy/d'
./stp.at:468: add_of_br 0
./stp.at:471:
ovs-vsctl -- \
set port br0 other_config:stp-enable=false -- \
set bridge br0 datapath-type=dummy -- \
set bridge br0 stp_enable=true mcast_snooping_enable=true \
other-config:hwaddr=aa:66:aa:66:00:00 -- \
add-br br1 -- \
set port br1 other_config:stp-enable=false -- \
set bridge br1 datapath-type=dummy -- \
set bridge br1 stp_enable=true mcast_snooping_enable=true \
other-config:hwaddr=aa:66:aa:66:00:01 -- \
add-br br2 -- \
set port br2 other_config:stp-enable=false -- \
set bridge br2 datapath-type=dummy -- \
set bridge br2 stp_enable=true mcast_snooping_enable=true \
other-config:hwaddr=aa:66:aa:66:00:02
./stp.at:489: ovs-appctl vlog/set ofproto_dpif:dbg
./stp.at:490: ovs-appctl vlog/set ofproto_dpif_xlate:dbg
./stp.at:492: ovs-ofctl add-flow br0 action=normal
./stp.at:493: ovs-ofctl add-flow br1 action=normal
./stp.at:494: ovs-ofctl add-flow br2 action=normal
./stp.at:496:
ovs-vsctl add-port br0 p1 -- \
set interface p1 type=dummy
options:pstream=punix:$OVS_RUNDIR/p1.sock ofport_request=1
ovs-vsctl add-port br0 p2 -- \
set interface p2 type=dummy
options:stream=unix:$OVS_RUNDIR/p6.sock ofport_request=2
ovs-vsctl add-port br1 p3 -- \
set interface p3 type=dummy
options:stream=unix:$OVS_RUNDIR/p1.sock ofport_request=3
ovs-vsctl add-port br1 p4 -- \
set interface p4 type=dummy
options:pstream=punix:$OVS_RUNDIR/p4.sock ofport_request=4
ovs-vsctl add-port br2 p5 -- \
set interface p5 type=dummy
options:stream=unix:$OVS_RUNDIR/p4.sock ofport_request=5
ovs-vsctl add-port br2 p6 -- \
set interface p6 type=dummy
options:pstream=punix:$OVS_RUNDIR/p6.sock ofport_request=6
OK
warped
./stp.at:517: cat ovs-vswitchd.log |
grep 'disabled to listening' | sed '
s/.*ofproto_dpif|.*|port .*:/port <>:/
'
warped
./stp.at:529: cat ovs-vswitchd.log |
grep 'learning to forwarding' | sed '
s/.*ofproto_dpif|.*|port .*:/port <>:/
'
--- - 2020-02-24 13:56:14.337746686 +0100
+++ /home/dceara/git-repos/ovs/tests/testsuite.dir/at-groups/2185/stdout
2020-02-24 13:56:14.000000000 +0100
@@ -3,4 +3,5 @@
port <>: STP state changed from learning to forwarding
port <>: STP state changed from learning to forwarding
port <>: STP state changed from learning to forwarding
+port <>: STP state changed from learning to forwarding
ovsdb-server.log:
> 2020-02-24T12:56:14.033Z|00001|vlog|INFO|opened log file /home/dceara/git-repos/ovs/tests/testsuite.dir/2185/ovsdb-server.log
> 2020-02-24T12:56:14.038Z|00002|ovsdb_server|INFO|ovsdb-server (Open vSwitch) 2.13.90
ovs-vswitchd.log:
> 2020-02-24T12:56:14.059Z|00001|vlog|INFO|opened log file /home/dceara/git-repos/ovs/tests/testsuite.dir/2185/ovs-vswitchd.log
> 2020-02-24T12:56:14.061Z|00002|ovs_numa|INFO|Discovered 8 CPU cores on NUMA node 0
> 2020-02-24T12:56:14.061Z|00003|ovs_numa|INFO|Discovered 1 NUMA nodes and 8 CPU cores
> 2020-02-24T12:56:14.061Z|00004|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/db.sock: connecting...
> 2020-02-24T12:56:14.061Z|00005|netlink_socket|INFO|netlink: could not enable listening to all nsid (Operation not permitted)
> 2020-02-24T12:56:14.061Z|00006|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/db.sock: connected
> 2020-02-24T12:56:14.065Z|00007|bridge|INFO|ovs-vswitchd (Open vSwitch) 2.13.90
> 2020-02-24T12:56:14.091Z|00008|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports recirculation
> 2020-02-24T12:56:14.091Z|00009|ofproto_dpif|INFO|dummy at ovs-dummy: VLAN header stack length probed as 1
> 2020-02-24T12:56:14.091Z|00010|ofproto_dpif|INFO|dummy at ovs-dummy: MPLS label stack length probed as 3
> 2020-02-24T12:56:14.091Z|00011|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports truncate action
> 2020-02-24T12:56:14.091Z|00012|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports unique flow ids
> 2020-02-24T12:56:14.091Z|00013|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports clone action
> 2020-02-24T12:56:14.091Z|00014|ofproto_dpif|INFO|dummy at ovs-dummy: Max sample nesting level probed as 10
> 2020-02-24T12:56:14.091Z|00015|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports eventmask in conntrack action
> 2020-02-24T12:56:14.091Z|00016|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports ct_clear action
> 2020-02-24T12:56:14.091Z|00017|ofproto_dpif|INFO|dummy at ovs-dummy: Max dp_hash algorithm probed to be 1
> 2020-02-24T12:56:14.091Z|00018|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports check_pkt_len action
> 2020-02-24T12:56:14.091Z|00019|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports timeout policy in conntrack action
> 2020-02-24T12:56:14.091Z|00020|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports ct_state
> 2020-02-24T12:56:14.091Z|00021|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports ct_zone
> 2020-02-24T12:56:14.091Z|00022|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports ct_mark
> 2020-02-24T12:56:14.091Z|00023|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports ct_label
> 2020-02-24T12:56:14.091Z|00024|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports ct_state_nat
> 2020-02-24T12:56:14.091Z|00025|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports ct_orig_tuple
> 2020-02-24T12:56:14.091Z|00026|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports ct_orig_tuple6
> 2020-02-24T12:56:14.091Z|00027|ofproto_dpif|INFO|dummy at ovs-dummy: Datapath supports IPv6 ND Extensions
> 2020-02-24T12:56:14.100Z|00028|bridge|INFO|bridge br0: added interface br0 on port 65534
> 2020-02-24T12:56:14.101Z|00029|bridge|INFO|bridge br0: using datapath ID fedcba9876543210
> 2020-02-24T12:56:14.101Z|00030|connmgr|INFO|br0: added service controller "punix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/br0.mgmt"
> 2020-02-24T12:56:14.113Z|00031|bridge|INFO|bridge br2: added interface br2 on port 65534
> 2020-02-24T12:56:14.113Z|00032|bridge|INFO|bridge br1: added interface br1 on port 65534
> 2020-02-24T12:56:14.113Z|00033|bridge|INFO|bridge br2: using datapath ID 0000aa66aa660002
> 2020-02-24T12:56:14.113Z|00034|connmgr|INFO|br2: added service controller "punix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/br2.mgmt"
> 2020-02-24T12:56:14.113Z|00035|bridge|INFO|bridge br1: using datapath ID 0000aa66aa660001
> 2020-02-24T12:56:14.113Z|00036|connmgr|INFO|br1: added service controller "punix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/br1.mgmt"
> 2020-02-24T12:56:14.120Z|00037|unixctl|DBG|received request vlog/set["ofproto_dpif:dbg"], id=0
> 2020-02-24T12:56:14.120Z|00038|unixctl|DBG|replying with success, id=0: ""
> 2020-02-24T12:56:14.124Z|00039|unixctl|DBG|received request vlog/set["ofproto_dpif_xlate:dbg"], id=0
> 2020-02-24T12:56:14.124Z|00040|unixctl|DBG|replying with success, id=0: ""
> 2020-02-24T12:56:14.129Z|00041|vconn|DBG|unix#2: sent (Success): OFPT_HELLO (OF1.5) (xid=0x1):
> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2020-02-24T12:56:14.129Z|00042|vconn|DBG|unix#2: received: OFPT_HELLO (xid=0x1):
> version bitmap: 0x01
> 2020-02-24T12:56:14.129Z|00043|vconn|DBG|unix#2: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2020-02-24T12:56:14.129Z|00044|vconn|DBG|unix#2: received: OFPST_TABLE request (xid=0x2):
> 2020-02-24T12:56:14.130Z|00045|vconn|DBG|unix#2: sent (Success): OFPST_TABLE reply (xid=0x2):
> table 0:
> active=0, lookup=0, matched=0
> max_entries=1000000
> matching:
> exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
>
> tables 1...253: ditto
> 2020-02-24T12:56:14.130Z|00046|vconn|DBG|unix#3: sent (Success): OFPT_HELLO (OF1.5) (xid=0x2):
> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2020-02-24T12:56:14.130Z|00047|vconn|DBG|unix#3: received: OFPT_HELLO (xid=0x3):
> version bitmap: 0x01
> 2020-02-24T12:56:14.130Z|00048|vconn|DBG|unix#3: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2020-02-24T12:56:14.130Z|00049|vconn|DBG|unix#3: received: OFPT_FEATURES_REQUEST (xid=0x4):
> 2020-02-24T12:56:14.130Z|00050|vconn|DBG|unix#3: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:fedcba9876543210
> n_tables:254, n_buffers:0
> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
> LOCAL(br0): addr:aa:66:aa:66:00:00
> config: 0
> state: 0
> speed: 0 Mbps now, 0 Mbps max
> 2020-02-24T12:56:14.131Z|00051|vconn|DBG|unix#4: sent (Success): OFPT_HELLO (OF1.5) (xid=0x3):
> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2020-02-24T12:56:14.131Z|00052|vconn|DBG|unix#4: received: OFPT_HELLO (xid=0x5):
> version bitmap: 0x01
> 2020-02-24T12:56:14.131Z|00053|vconn|DBG|unix#4: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2020-02-24T12:56:14.131Z|00054|vconn|DBG|unix#4: received: OFPT_FLOW_MOD (xid=0x6): ADD actions=NORMAL
> 2020-02-24T12:56:14.131Z|00055|vconn|DBG|unix#4: received: OFPT_BARRIER_REQUEST (xid=0x7):
> 2020-02-24T12:56:14.131Z|00056|vconn|DBG|unix#4: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
> 2020-02-24T12:56:14.131Z|00057|connmgr|INFO|br0<->unix#4: 1 flow_mods in the last 0 s (1 adds)
> 2020-02-24T12:56:14.136Z|00058|vconn|DBG|unix#5: sent (Success): OFPT_HELLO (OF1.5) (xid=0x4):
> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2020-02-24T12:56:14.136Z|00059|vconn|DBG|unix#5: received: OFPT_HELLO (xid=0x1):
> version bitmap: 0x01
> 2020-02-24T12:56:14.136Z|00060|vconn|DBG|unix#5: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2020-02-24T12:56:14.136Z|00061|vconn|DBG|unix#5: received: OFPST_TABLE request (xid=0x2):
> 2020-02-24T12:56:14.136Z|00062|vconn|DBG|unix#5: sent (Success): OFPST_TABLE reply (xid=0x2):
> table 0:
> active=1, lookup=0, matched=0
> max_entries=1000000
> matching:
> exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
>
> table 1:
> active=0, lookup=0, matched=0
> (same features)
>
> tables 2...253: ditto
> 2020-02-24T12:56:14.137Z|00063|vconn|DBG|unix#6: sent (Success): OFPT_HELLO (OF1.5) (xid=0x5):
> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2020-02-24T12:56:14.137Z|00064|vconn|DBG|unix#6: received: OFPT_HELLO (xid=0x3):
> version bitmap: 0x01
> 2020-02-24T12:56:14.137Z|00065|vconn|DBG|unix#6: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2020-02-24T12:56:14.137Z|00066|vconn|DBG|unix#6: received: OFPT_FEATURES_REQUEST (xid=0x4):
> 2020-02-24T12:56:14.137Z|00067|vconn|DBG|unix#6: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:0000aa66aa660001
> n_tables:254, n_buffers:0
> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
> LOCAL(br1): addr:aa:66:aa:66:00:01
> config: 0
> state: 0
> speed: 0 Mbps now, 0 Mbps max
> 2020-02-24T12:56:14.137Z|00068|vconn|DBG|unix#7: sent (Success): OFPT_HELLO (OF1.5) (xid=0x6):
> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2020-02-24T12:56:14.137Z|00069|vconn|DBG|unix#7: received: OFPT_HELLO (xid=0x5):
> version bitmap: 0x01
> 2020-02-24T12:56:14.137Z|00070|vconn|DBG|unix#7: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2020-02-24T12:56:14.138Z|00071|vconn|DBG|unix#7: received: OFPT_FLOW_MOD (xid=0x6): ADD actions=NORMAL
> 2020-02-24T12:56:14.138Z|00072|vconn|DBG|unix#7: received: OFPT_BARRIER_REQUEST (xid=0x7):
> 2020-02-24T12:56:14.138Z|00073|vconn|DBG|unix#7: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
> 2020-02-24T12:56:14.138Z|00074|connmgr|INFO|br1<->unix#7: 1 flow_mods in the last 0 s (1 adds)
> 2020-02-24T12:56:14.143Z|00075|vconn|DBG|unix#8: sent (Success): OFPT_HELLO (OF1.5) (xid=0x7):
> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2020-02-24T12:56:14.143Z|00076|vconn|DBG|unix#8: received: OFPT_HELLO (xid=0x1):
> version bitmap: 0x01
> 2020-02-24T12:56:14.143Z|00077|vconn|DBG|unix#8: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2020-02-24T12:56:14.143Z|00078|vconn|DBG|unix#8: received: OFPST_TABLE request (xid=0x2):
> 2020-02-24T12:56:14.143Z|00079|vconn|DBG|unix#8: sent (Success): OFPST_TABLE reply (xid=0x2):
> table 0:
> active=1, lookup=0, matched=0
> max_entries=1000000
> matching:
> exact match or wildcard: in_port eth_{src,dst,type} vlan_{vid,pcp} ip_{src,dst} nw_{proto,tos} tcp_{src,dst}
>
> table 1:
> active=0, lookup=0, matched=0
> (same features)
>
> tables 2...253: ditto
> 2020-02-24T12:56:14.144Z|00080|vconn|DBG|unix#9: sent (Success): OFPT_HELLO (OF1.5) (xid=0x8):
> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2020-02-24T12:56:14.144Z|00081|vconn|DBG|unix#9: received: OFPT_HELLO (xid=0x3):
> version bitmap: 0x01
> 2020-02-24T12:56:14.144Z|00082|vconn|DBG|unix#9: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2020-02-24T12:56:14.144Z|00083|vconn|DBG|unix#9: received: OFPT_FEATURES_REQUEST (xid=0x4):
> 2020-02-24T12:56:14.144Z|00084|vconn|DBG|unix#9: sent (Success): OFPT_FEATURES_REPLY (xid=0x4): dpid:0000aa66aa660002
> n_tables:254, n_buffers:0
> capabilities: FLOW_STATS TABLE_STATS PORT_STATS QUEUE_STATS ARP_MATCH_IP
> actions: output enqueue set_vlan_vid set_vlan_pcp strip_vlan mod_dl_src mod_dl_dst mod_nw_src mod_nw_dst mod_nw_tos mod_tp_src mod_tp_dst
> LOCAL(br2): addr:aa:66:aa:66:00:02
> config: 0
> state: 0
> speed: 0 Mbps now, 0 Mbps max
> 2020-02-24T12:56:14.144Z|00085|vconn|DBG|unix#10: sent (Success): OFPT_HELLO (OF1.5) (xid=0x9):
> version bitmap: 0x01, 0x02, 0x03, 0x04, 0x05, 0x06
> 2020-02-24T12:56:14.144Z|00086|vconn|DBG|unix#10: received: OFPT_HELLO (xid=0x5):
> version bitmap: 0x01
> 2020-02-24T12:56:14.144Z|00087|vconn|DBG|unix#10: negotiated OpenFlow version 0x01 (we support version 0x06 and earlier, peer supports version 0x01)
> 2020-02-24T12:56:14.145Z|00088|vconn|DBG|unix#10: received: OFPT_FLOW_MOD (xid=0x6): ADD actions=NORMAL
> 2020-02-24T12:56:14.145Z|00089|vconn|DBG|unix#10: received: OFPT_BARRIER_REQUEST (xid=0x7):
> 2020-02-24T12:56:14.145Z|00090|vconn|DBG|unix#10: sent (Success): OFPT_BARRIER_REPLY (xid=0x7):
> 2020-02-24T12:56:14.145Z|00091|connmgr|INFO|br2<->unix#10: 1 flow_mods in the last 0 s (1 adds)
> 2020-02-24T12:56:14.154Z|00092|bridge|INFO|bridge br0: added interface p1 on port 1
> 2020-02-24T12:56:14.154Z|00093|ofproto_dpif|DBG|port p1: STP state changed from disabled to listening
> 2020-02-24T12:56:14.164Z|00094|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connecting...
> 2020-02-24T12:56:14.164Z|00095|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connection attempt failed (No such file or directory)
> 2020-02-24T12:56:14.164Z|00096|bridge|INFO|bridge br0: added interface p2 on port 2
> 2020-02-24T12:56:14.164Z|00097|ofproto_dpif|DBG|port p2: STP state changed from disabled to listening
> 2020-02-24T12:56:14.174Z|00098|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connecting...
> 2020-02-24T12:56:14.174Z|00099|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connection attempt failed (No such file or directory)
> 2020-02-24T12:56:14.174Z|00100|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p1.sock: connecting...
> 2020-02-24T12:56:14.174Z|00101|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p1.sock: connected
> 2020-02-24T12:56:14.174Z|00102|bridge|INFO|bridge br1: added interface p3 on port 3
> 2020-02-24T12:56:14.174Z|00103|ofproto_dpif|DBG|port p3: STP state changed from disabled to listening
> 2020-02-24T12:56:14.183Z|00104|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connecting...
> 2020-02-24T12:56:14.183Z|00105|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connection attempt failed (No such file or directory)
> 2020-02-24T12:56:14.184Z|00106|bridge|INFO|bridge br1: added interface p4 on port 4
> 2020-02-24T12:56:14.184Z|00107|ofproto_dpif|DBG|port p4: STP state changed from disabled to listening
> 2020-02-24T12:56:14.193Z|00108|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connecting...
> 2020-02-24T12:56:14.193Z|00109|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connection attempt failed (No such file or directory)
> 2020-02-24T12:56:14.193Z|00110|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p4.sock: connecting...
> 2020-02-24T12:56:14.193Z|00111|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p4.sock: connected
> 2020-02-24T12:56:14.193Z|00112|bridge|INFO|bridge br2: added interface p5 on port 5
> 2020-02-24T12:56:14.193Z|00113|ofproto_dpif|DBG|port p5: STP state changed from disabled to listening
> 2020-02-24T12:56:14.203Z|00114|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connecting...
> 2020-02-24T12:56:14.203Z|00115|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connection attempt failed (No such file or directory)
> 2020-02-24T12:56:14.203Z|00116|bridge|INFO|bridge br2: added interface p6 on port 6
> 2020-02-24T12:56:14.203Z|00117|ofproto_dpif|DBG|port p6: STP state changed from disabled to listening
> 2020-02-24T12:56:14.208Z|00118|unixctl|DBG|received request netdev-dummy/set-admin-state["up"], id=0
> 2020-02-24T12:56:14.208Z|00119|unixctl|DBG|replying with success, id=0: "OK"
> 2020-02-24T12:56:14.212Z|00120|unixctl|DBG|received request time/stop[], id=0
> 2020-02-24T12:56:14.212Z|00121|unixctl|DBG|replying with success, id=0: ""
> 2020-02-24T12:56:14.215Z|00122|unixctl|DBG|received request time/warp["6000","3000"], id=0
> 2020-02-24T12:56:14.225Z|00123|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connecting...
> 2020-02-24T12:56:14.225Z|00124|reconnect|INFO|unix:/home/dceara/git-repos/ovs/tests/testsuite.dir/2185/p6.sock: connected
> 2020-02-24T12:56:14.225Z|00125|unixctl|DBG|replying with success, id=0: "warped"
> 2020-02-24T12:56:14.236Z|00126|ofproto_dpif_xlate|DBG|/proc/sys/net/core/netdev_max_backlog: using 1000 max_backlog
> 2020-02-24T12:56:14.236Z|00127|unixctl|DBG|received request time/warp["30000","3000"], id=0
> 2020-02-24T12:56:14.257Z|00128|memory|INFO|14512 kB peak resident set size after 12.2 seconds
> 2020-02-24T12:56:14.257Z|00129|memory|INFO|handlers:5 ports:9 revalidators:3 rules:17
> 2020-02-24T12:56:14.268Z|00130|ofproto_dpif|DBG|port p2: STP state changed from listening to learning
> 2020-02-24T12:56:14.268Z|00131|ofproto_dpif|DBG|port p1: STP state changed from listening to learning
> 2020-02-24T12:56:14.268Z|00132|ofproto_dpif|DBG|port p6: STP state changed from listening to learning
> 2020-02-24T12:56:14.268Z|00133|ofproto_dpif|DBG|port p5: STP state changed from listening to learning
> 2020-02-24T12:56:14.268Z|00134|ofproto_dpif|DBG|port p3: STP state changed from listening to learning
> 2020-02-24T12:56:14.268Z|00135|ofproto_dpif|DBG|port p4: STP state changed from listening to learning
> 2020-02-24T12:56:14.280Z|00001|ovs_rcu(urcu3)|WARN|blocked 3000 ms waiting for main to quiesce
> 2020-02-24T12:56:14.280Z|00002|ovs_rcu(urcu3)|WARN|blocked 3000 ms waiting for main to quiesce
> 2020-02-24T12:56:14.323Z|00136|stp|INFO|br0: detected topology change.
> 2020-02-24T12:56:14.323Z|00137|stp|INFO|br0: detected topology change.
> 2020-02-24T12:56:14.323Z|00138|ofproto_dpif|DBG|port p2: STP state changed from learning to forwarding
> 2020-02-24T12:56:14.323Z|00139|ofproto_dpif|DBG|port p1: STP state changed from learning to forwarding
> 2020-02-24T12:56:14.323Z|00140|stp|INFO|br2: detected topology change.
> 2020-02-24T12:56:14.323Z|00141|stp|INFO|br2: detected topology change.
> 2020-02-24T12:56:14.323Z|00142|ofproto_dpif|DBG|port p6: STP state changed from learning to forwarding
> 2020-02-24T12:56:14.323Z|00143|ofproto_dpif|DBG|port p5: STP state changed from learning to forwarding
> 2020-02-24T12:56:14.323Z|00144|stp|INFO|br1: detected topology change.
> 2020-02-24T12:56:14.323Z|00145|ofproto_dpif|DBG|port p3: STP state changed from learning to forwarding
> 2020-02-24T12:56:14.323Z|00146|ofproto_dpif|DBG|port p4: STP state changed from learning to forwarding
> 2020-02-24T12:56:14.334Z|00147|unixctl|DBG|replying with success, id=0: "warped"
2185. stp.at:467: 2185. STP - flush the fdb and mdb when topology
changed (stp.at:467): FAILED (stp.at:529)
More information about the dev
mailing list