[ovs-dev] ovs-vsctl add-br stuck on raspbian

Ben Pfaff blp at ovn.org
Wed Dec 28 18:47:10 UTC 2016


It looks like your database schema doesn't match the version of Open
vSwitch you're using.  I don't how that could have happened.  Since this
is a new installation, you might just stop OVS, delete the database, and
then restart it.

On Wed, Dec 28, 2016 at 06:17:01PM +0000, Piyush Agarwal wrote:
> Here are the logs:
> On issuing "add-br br1", I see ovs-vsctl is just "stuck" and I see
> ovs-vswitchd.log printing messages continuously (please note the ID in
> jsonrpc request, this is incrementing continuously and has reached all
> the way to 6k so far!).
> 
> (i) Are the missing columns a likely cause? Should I fix that? How can
> I? I just used all standard (apt-get) schema, wonder why it complains
> of missing columns.
> (ii) Do the logs give a hint as to what could be wrong?
> (iii) Anything else I need to gather?
> 
> ovs-vswitchd.log:
> ============
> 
> 2016-12-28T18:14:05.150Z|08413|poll_loop(revalidator8)|DBG|wakeup due
> to 499-ms timeout at ofproto/ofproto-dpif-upcall.c:917 (0% CPU usage)
> 2016-12-28T18:14:05.151Z|08414|dpif(revalidator8)|DBG|system at ovs-system:
> get_stats success
> 2016-12-28T18:14:05.151Z|08415|dpif(revalidator8)|DBG|system at ovs-system:
> dumped all flows
> 2016-12-28T18:14:05.151Z|03687|poll_loop(revalidator9)|DBG|wakeup due
> to [POLLIN] on fd 29 (FIFO pipe:[532099]) at lib/ovs-thread.c:306 (0%
> CPU usage)
> 2016-12-28T18:14:05.151Z|03688|dpif(revalidator9)|DBG|system at ovs-system:
> dumped all flows
> 2016-12-28T18:14:05.152Z|08416|poll_loop(revalidator8)|DBG|wakeup due
> to [POLLIN] on fd 36 (FIFO pipe:[532103]) at lib/ovs-thread.c:306 (0%
> CPU usage)
> 2016-12-28T18:14:05.152Z|08417|dpif(revalidator8)|DBG|system at ovs-system:
> flow_dump_destroy success
> 2016-12-28T18:14:05.152Z|03689|poll_loop(revalidator9)|DBG|wakeup due
> to [POLLIN] on fd 29 (FIFO pipe:[532099]) at lib/ovs-thread.c:306 (0%
> CPU usage)
> 2016-12-28T18:14:05.152Z|24166|poll_loop|DBG|wakeup due to [POLLIN] on
> fd 33 (FIFO pipe:[530270]) at ofproto/ofproto-dpif.c:1665 (2% CPU
> usage)
> 2016-12-28T18:14:05.153Z|24167|jsonrpc|DBG|unix:/usr/local/var/run/openvswitch/db.sock:
> send request, method="transact",
> params=["Open_vSwitch",{"lock":"ovs_vswitchd","op":"assert"},{"where":[["_uuid","==",["uuid","5dfa7c7c-0b21-4259-97d4-d7d20c8a89ea"]]],"row":{"mac_in_use":"0e:1f:6f:5c:4f:45","link_resets":1,"mtu":1500,"status":["map",[["driver_name","openvswitch"]]],"admin_state":"up","ifindex":9,"link_state":"up"},"op":"update","table":"Interface"},{"where":[["_uuid","==",["uuid","5c6f1f0d-ad87-454f-b71f-360684f36b3a"]]],"row":{"datapath_version":"<unknown>"},"op":"update","table":"Bridge"}],
> id=5899
> 2016-12-28T18:14:05.155Z|24168|poll_loop|DBG|wakeup due to [POLLIN] on
> fd 11 (<->/usr/local/var/run/openvswitch/db.sock) at
> lib/stream-fd.c:155 (2% CPU usage)
> 2016-12-28T18:14:05.156Z|24169|jsonrpc|DBG|unix:/usr/local/var/run/openvswitch/db.sock:
> received reply,
> result=[{},{"count":1},{"syntax":"{\"datapath_version\":\"<unknown>\"}","details":"No
> column datapath_version in table Bridge.","error":"unknown column"}],
> id=5899
> 2016-12-28T18:14:05.257Z|24170|poll_loop|DBG|wakeup due to 101-ms
> timeout at vswitchd/bridge.c:2836 (2% CPU usage)
> 2016-12-28T18:14:05.258Z|24171|jsonrpc|DBG|unix:/usr/local/var/run/openvswitch/db.sock:
> send request, method="transact",
> params=["Open_vSwitch",{"lock":"ovs_vswitchd","op":"assert"},{"where":[["_uuid","==",["uuid","5dfa7c7c-0b21-4259-97d4-d7d20c8a89ea"]]],"row":{"mac_in_use":"0e:1f:6f:5c:4f:45","link_resets":1,"mtu":1500,"status":["map",[["driver_name","openvswitch"]]],"admin_state":"up","ifindex":9,"link_state":"up"},"op":"update","table":"Interface"},{"where":[["_uuid","==",["uuid","5c6f1f0d-ad87-454f-b71f-360684f36b3a"]]],"row":{"datapath_version":"<unknown>"},"op":"update","table":"Bridge"}],
> id=5900
> 2016-12-28T18:14:05.260Z|24172|poll_loop|DBG|wakeup due to [POLLIN] on
> fd 11 (<->/usr/local/var/run/openvswitch/db.sock) at
> lib/stream-fd.c:155 (2% CPU usage)
> 2016-12-28T18:14:05.261Z|24173|jsonrpc|DBG|unix:/usr/local/var/run/openvswitch/db.sock:
> received reply,
> result=[{},{"count":1},{"syntax":"{\"datapath_version\":\"<unknown>\"}","details":"No
> column datapath_version in table Bridge.","error":"unknown column"}],
> id=5900
> 2016-12-28T18:14:05.361Z|24174|poll_loop|DBG|wakeup due to 101-ms
> timeout at vswitchd/bridge.c:2836 (2% CPU usage)
> 2016-12-28T18:14:05.362Z|24175|jsonrpc|DBG|unix:/usr/local/var/run/openvswitch/db.sock:
> send request, method="transact",
> params=["Open_vSwitch",{"lock":"ovs_vswitchd","op":"assert"},{"where":[["_uuid","==",["uuid","5dfa7c7c-0b21-4259-97d4-d7d20c8a89ea"]]],"row":{"mac_in_use":"0e:1f:6f:5c:4f:45","link_resets":1,"mtu":1500,"status":["map",[["driver_name","openvswitch"]]],"admin_state":"up","ifindex":9,"link_state":"up"},"op":"update","table":"Interface"},{"where":[["_uuid","==",["uuid","5c6f1f0d-ad87-454f-b71f-360684f36b3a"]]],"row":{"datapath_version":"<unknown>"},"op":"update","table":"Bridge"}],
> id=5901
> 2016-12-28T18:14:05.364Z|24176|poll_loop|DBG|wakeup due to [POLLIN] on
> fd 11 (<->/usr/local/var/run/openvswitch/db.sock) at
> lib/stream-fd.c:155 (2% CPU usage)
> 2016-12-28T18:14:05.365Z|24177|jsonrpc|DBG|unix:/usr/local/var/run/openvswitch/db.sock:
> received reply,
> result=[{},{"count":1},{"syntax":"{\"datapath_version\":\"<unknown>\"}","details":"No
> column datapath_version in table Bridge.","error":"unknown column"}],
> id=5901
> 2016-12-28T18:14:05.466Z|24178|poll_loop|DBG|wakeup due to 100-ms
> timeout at vswitchd/bridge.c:2836 (2% CPU usage)
> 2016-12-28T18:14:05.467Z|24179|jsonrpc|DBG|unix:/usr/local/var/run/openvswitch/db.sock:
> send request, method="transact",
> params=["Open_vSwitch",{"lock":"ovs_vswitchd","op":"assert"},{"where":[["_uuid","==",["uuid","5dfa7c7c-0b21-4259-97d4-d7d20c8a89ea"]]],"row":{"mac_in_use":"0e:1f:6f:5c:4f:45","link_resets":1,"mtu":1500,"status":["map",[["driver_name","openvswitch"]]],"admin_state":"up","ifindex":9,"link_state":"up"},"op":"update","table":"Interface"},{"where":[["_uuid","==",["uuid","5c6f1f0d-ad87-454f-b71f-360684f36b3a"]]],"row":{"datapath_version":"<unknown>"},"op":"update","table":"Bridge"}],
> id=5902
> 2016-12-28T18:14:05.470Z|24180|poll_loop|DBG|wakeup due to [POLLIN] on
> fd 11 (<->/usr/local/var/run/openvswitch/db.sock) at
> lib/stream-fd.c:155 (2% CPU usage)
> 2016-12-28T18:14:05.471Z|24181|jsonrpc|DBG|unix:/usr/local/var/run/openvswitch/db.sock:
> received reply,
> result=[{},{"count":1},{"syntax":"{\"datapath_version\":\"<unknown>\"}","details":"No
> column datapath_version in table Bridge.","error":"unknown column"}],
> id=5902
> 
> 
> ovs-vsctl logs:
> ==========
> pi at raspberrypi:/usr/share/openvswitch $ vsct
> --db=unix://usr/local/var/run/openvswitch/db.sock -v
> --log-file=/usr/local/var/log/openvswitch/ovs-vsctl.log add-br b2
> 2016-12-28T18:04:36Z|00002|vlog|INFO|opened log file
> /usr/local/var/log/openvswitch/ovs-vsctl.log
> 2016-12-28T18:04:36Z|00003|reconnect|DBG|unix://usr/local/var/run/openvswitch/db.sock:
> entering BACKOFF
> 2016-12-28T18:04:36Z|00004|hmap|DBG|../lib/shash.c:112: 6 nodes in
> bucket (16 nodes, 8 buckets)
> 2016-12-28T18:04:36Z|00005|reconnect|INFO|unix://usr/local/var/run/openvswitch/db.sock:
> connecting...
> 2016-12-28T18:04:36Z|00006|reconnect|DBG|unix://usr/local/var/run/openvswitch/db.sock:
> entering CONNECTING
> 2016-12-28T18:04:36Z|00007|poll_loop|DBG|wakeup due to [POLLOUT] on fd
> 5 (<->/usr/local/var/run/openvswitch/db.sock) at
> ../lib/stream-fd-unix.c:120
> 2016-12-28T18:04:36Z|00008|reconnect|INFO|unix://usr/local/var/run/openvswitch/db.sock:
> connected
> 2016-12-28T18:04:36Z|00009|reconnect|DBG|unix://usr/local/var/run/openvswitch/db.sock:
> entering ACTIVE
> 2016-12-28T18:04:36Z|00010|jsonrpc|DBG|unix://usr/local/var/run/openvswitch/db.sock:
> send request, method="monitor",
> params=["Open_vSwitch",null,{"Port":{"columns":["fake_bridge","interfaces","name","tag"]},"Interface":{"columns":["name","ofport"]},"Bridge":{"columns":["controller","fail_mode","name","ports"]},"Controller":{"columns":[]},"Open_vSwitch":{"columns":["bridges","cur_cfg"]}}],
> id=0
> 2016-12-28T18:04:36Z|00011|poll_loop|DBG|wakeup due to [POLLIN] on fd
> 5 (<->/usr/local/var/run/openvswitch/db.sock) at
> ../lib/stream-fd-unix.c:124
> 2016-12-28T18:04:36Z|00012|jsonrpc|DBG|unix://usr/local/var/run/openvswitch/db.sock:
> received reply,
> result={"Open_vSwitch":{"60d66f1b-944f-4be1-b9cf-a3e9902b1f9e":{"new":{"bridges":["set",[]],"cur_cfg":0}}}},
> id=0
> 2016-12-28T18:04:36Z|00013|jsonrpc|DBG|unix://usr/local/var/run/openvswitch/db.sock:
> send request, method="transact",
> params=["Open_vSwitch",{"rows":[{"bridges":["set",[]]}],"columns":["bridges"],"table":"Open_vSwitch","until":"==","where":[["_uuid","==",["uuid","60d66f1b-944f-4be1-b9cf-a3e9902b1f9e"]]],"timeout":0,"op":"wait"},{"row":{"name":"b2","ports":["named-uuid","row875cb077_3576_49a9_96da_74341e732709"]},"table":"Bridge","uuid-name":"row8e5585d0_1cce_43f0_ae77_c39c1d6d0911","op":"insert"},{"row":{"name":"b2","type":"internal"},"table":"Interface","uuid-name":"rowe9a64624_f63b_4430_a193_0d49aecf3af2","op":"insert"},{"row":{"name":"b2","interfaces":["named-uuid","rowe9a64624_f63b_4430_a193_0d49aecf3af2"]},"table":"Port","uuid-name":"row875cb077_3576_49a9_96da_74341e732709","op":"insert"},{"row":{"bridges":["named-uuid","row8e5585d0_1cce_43f0_ae77_c39c1d6d0911"]},"table":"Open_vSwitch","where":[["_uuid","==",["uuid","60d66f1b-944f-4be1-b9cf-a3e9902b1f9e"]]],"op":"update"},{"mutations":[["next_cfg","+=",1]],"table":"Open_vSwitch","where":[["_uuid","==",["uuid","60d66f1b-944f-4be1-b9cf-a3e9902b1f9e"]]],"op":"mutate"},{"columns":["next_cfg"],"table":"Open_vSwitch","where":[["_uuid","==",["uuid","60d66f1b-944f-4be1-b9cf-a3e9902b1f9e"]]],"op":"select"},{"comment":"ovs-vsctl:
> ovs-vsctl --db=unix://usr/local/var/run/openvswitch/db.sock -v
> --log-file=/usr/local/var/log/openvswitch/ovs-vsctl.log add-br
> b2","op":"comment"}], id=1
> 2016-12-28T18:04:36Z|00014|poll_loop|DBG|wakeup due to [POLLIN] on fd
> 5 (<->/usr/local/var/run/openvswitch/db.sock) at
> ../lib/stream-fd-unix.c:124
> 2016-12-28T18:04:36Z|00015|jsonrpc|DBG|unix://usr/local/var/run/openvswitch/db.sock:
> received notification, method="update",
> params=[null,{"Port":{"842f5fcd-84b3-4269-91f7-0b9ee481930b":{"new":{"name":"b2","fake_bridge":false,"interfaces":["uuid","5dfa7c7c-0b21-4259-97d4-d7d20c8a89ea"],"tag":["set",[]]}}},"Bridge":{"5c6f1f0d-ad87-454f-b71f-360684f36b3a":{"new":{"fail_mode":["set",[]],"name":"b2","ports":["uuid","842f5fcd-84b3-4269-91f7-0b9ee481930b"],"controller":["set",[]]}}},"Interface":{"5dfa7c7c-0b21-4259-97d4-d7d20c8a89ea":{"new":{"name":"b2","ofport":["set",[]]}}},"Open_vSwitch":{"60d66f1b-944f-4be1-b9cf-a3e9902b1f9e":{"old":{"bridges":["set",[]]},"new":{"bridges":["uuid","5c6f1f0d-ad87-454f-b71f-360684f36b3a"],"cur_cfg":0}}}}]
> 2016-12-28T18:04:36Z|00016|poll_loop|DBG|wakeup due to [POLLIN] on fd
> 5 (<->/usr/local/var/run/openvswitch/db.sock) at
> ../lib/stream-fd-unix.c:124
> 2016-12-28T18:04:36Z|00017|jsonrpc|DBG|unix://usr/local/var/run/openvswitch/db.sock:
> received reply,
> result=[{},{"uuid":["uuid","5c6f1f0d-ad87-454f-b71f-360684f36b3a"]},{"uuid":["uuid","5dfa7c7c-0b21-4259-97d4-d7d20c8a89ea"]},{"uuid":["uuid","842f5fcd-84b3-4269-91f7-0b9ee481930b"]},{"count":1},{"count":1},{"rows":[{"next_cfg":1}]},{}],
> id=1
> 2016-12-28T18:04:36Z|00018|poll_loop|DBG|wakeup due to 0-ms timeout at
> ../lib/ovsdb-idl.c:1354
> 
> 
> 
> Thanks much for taking a look.
> 
> On 12/28/16, Ben Pfaff <blp at ovn.org> wrote:
> > On Tue, Dec 27, 2016 at 06:22:06PM -0800, Piyush Agarwal wrote:
> >> I am trying to get ovs up and running on Raspbian (Jessie).
> >>
> >> I installed the following:
> >>
> >> apt-get install openvswitch-switch
> >> apt-get install openvswitch-common
> >>
> >> I see lsmod shows openvswitch module loaded fine.
> >>
> >> I started ovsdb-server, ovs-vsctl init and ovs-vswitchd and all of them
> >> came up fine.
> >>
> >> However, when I try to create a bridge using
> >>
> >> ++++++++++++
> >> ovs-vsctl add-br br1
> >> ++++++++++++
> >>
> >> This command just gets stuck. If I Ctrl-C here and issue a "show", I do
> >> see
> >> the bridge was created in the show output.
> >>
> >> Reading elsewhere, this points to issue with vswitchd and/or kernel
> >> module.
> >> Is this where the issue is?
> >>
> >> Can someone please suggest what more information I can gather (or
> >> where/how
> >> I can search) to get past this.
> >
> > There might be more information in the log.
> >
> 
> 
> -- 
> Piyush Agarwal


More information about the dev mailing list