It's probably a long-standing bug then.

Does the problem seem correlated with a high transaction rate on the
database server, or does it happen even at a low to medium pace?  Do you
have other hints to what might trigger the issue?

On Wed, Jun 10, 2015 at 06:19:19PM -0700, Saurabh Shrivastava (सौरभ श्रीवास्तव) 
wrote:
> This happens with an older (more than 6 month) OVSDB server. It is
> difficult to reproduce this behaviour.
> 
> --
> Saurabh (सौरभ)
> 
> On Wed, Jun 10, 2015 at 6:06 PM, Ben Pfaff <b...@nicira.com> wrote:
> 
> > The database server should always report a single transaction as a
> > single update.  It can sometimes merge multiple transactions into one
> > update but it's a bug if it ever splits a single transaction into
> > multiple updates.
> >
> > Is this with bleeding-edge OVS from master, by any chance?  We've had a
> > lot of churn in that code over the last month or so, so new bugs are
> > possible.  (Before that, though, it is basically unchanged for years.)
> >
> > I'd love a reproduction case.
> >
> > On Wed, Jun 10, 2015 at 06:01:16PM -0700, Saurabh Shrivastava (सौरभ
> > श्रीवास्तव) wrote:
> > > The transaction reply appears after all the updates are received (but I
> > > dont have those traces at this time)
> > >
> > > Here is the good case where all the changes to the database come in one
> > > giant update instead of split up into 3 updates. Note that in the bad
> > case
> > > the 3 row deletes appeared as 3 different updates. I think the issue is
> > > that sometimes the server will split up the updates.
> > >
> > > good case:
> > >
> > > [001 d 05/28/15 18:17:31.295]  A:dc_rpc:OVS: ovs|654524|jsonrpc|DBG|ssl:
> > > 135.227.147.205:44978: send request, method="transact",
> > >
> > params=["hardware_vtep",{"lock":"my_controller","op":"assert"},{"table":"Mcast_Macs_Remote","where":[["_uuid","==",["uuid","1f1d55cc-6ee4-4c67-81e0-3e5246c93c01"]]],"op":"delete"},{"comment":"thdl
> > > 969","op":"comment"}], id=17043
> > > [001 d 05/28/15 18:17:31.301]  A:dc_rpc:OVS:
> > > ovs|654526|poll_loop|DBG|wakeup due to [POLLIN] on fd 154 (FIFO) at
> > > /home/saurabh/dc35/os/ovs/lib/stream-fd.c:131 (0% CPU usage)
> > > [001 d 05/28/15 18:17:31.304]  A:dc_rpc:OVS:
> > > ovs|654527|poll_loop|DBG|wakeup due to [POLLIN] on fd 9378 (
> > > 135.227.144.122:6632<->135.227.147.205:44978) at
> > > /home/saurabh/dc35/os/ovs/lib/stream-ssl.c:744 (0% CPU usage)
> > > [001 d 05/28/15 18:17:31.307]  A:dc_rpc:OVS: ovs|654528|jsonrpc|DBG|ssl:
> > > 135.227.147.205:44978: received notification, method="update",
> > >
> > params=[null,{"Physical_Locator":{"f22d3188-8495-4108-8403-bd1c89a3801c":{"old":{"dst_ip":"10.15.33.254","encapsulation_type":"vxlan_over_ipv4"}}},"Physical_Locator_Set":{"dfdba754-179d-4380-bab0-6d1968dfa5ff":{"old":{"locators":["uuid","f22d3188-8495-4108-8403-bd1c89a3801c"]}}},"Mcast_Macs_Remote":{"1f1d55cc-6ee4-4c67-81e0-3e5246c93c01":{"old":{"ipaddr":"","logical_switch":["uuid","c70577c4-e61d-4049-9987-3b9f8bce19db"],"locator_set":["uuid","dfdba754-179d-4380-bab0-6d1968dfa5ff"],"MAC":"unknown-dst"}}}
> > >
> > >
> > > bad case:
> > >
> > > [027 m 05/26/15 22:22:16.824]  A:dc_rpc:OVS: ovs|09826|jsonrpc|DBG|ssl:
> > > 135.227.147.205:43858: send request, method="transact",
> > >
> > params=["hardware_vtep",{"lock":"my_controller","op":"assert"},{"table":"Mcast_Macs_Remote","where":[["_uuid","==",["uuid","63bdbbfe-0f90-4f33-acdd-f6334852302c"]]],"op":"delete"},{"comment":"thdl
> > > 20","op":"comment"}], id=201
> > > [027 m 05/26/15 22:22:16.832]  A:dc_rpc:OVS:
> > ovs|09828|poll_loop|DBG|wakeup
> > > due to [POLLIN] on fd 154 (FIFO) at
> > > /home/saurabh/dc35/os/ovs/lib/stream-fd.c:131 (0% CPU usage)
> > > [027 m 05/26/15 22:22:16.835]  A:dc_rpc:OVS:
> > ovs|09829|poll_loop|DBG|wakeup
> > > due to [POLLIN] on fd 246 (135.227.144.122:6632<->135.227.147.205:43858)
> > at
> > > /home/saurabh/dc35/os/ovs/lib/stream-ssl.c:744 (0% CPU usage)
> > > [027 m 05/26/15 22:22:16.838]  A:dc_rpc:OVS: ovs|09830|jsonrpc|DBG|ssl:
> > > 135.227.147.205:43858: received notification, method="update",
> > >
> > params=[null,{"Physical_Locator_Set":{"ff6908de-98aa-4c30-8809-7e1395ea13c9":{"old":{"locators":["uuid","901cdefe-0292-48bb-a9df-6a4837061931"]}}}}]
> > > [027 m 05/26/15 22:22:16.846]  A:dc_rpc:OVS: ovs|09831|jsonrpc|DBG|ssl:
> > > 135.227.147.205:43858: received notification, method="update",
> > >
> > params=[null,{"Physical_Locator":{"901cdefe-0292-48bb-a9df-6a4837061931":{"old":{"dst_ip":"10.50.50.1","encapsulation_type":"vxlan_over_ipv4"}}}}]
> > >
> > > < the Mcast_Macs_Remote update came at this point but I dont have the
> > trace
> > > with me >
> > >
> > >
> > >
> > > --
> > > Saurabh (सौरभ)
> > >
> > > On Wed, Jun 10, 2015 at 12:51 PM, Ben Pfaff <b...@nicira.com> wrote:
> > >
> > > > The updates you're showing me might not be related to the transaction
> > at
> > > > all, since the update doesn't mention the Mcast_Macs_Remote table.
> > > > Where's the transaction reply?
> > > >
> > > > On Wed, Jun 10, 2015 at 09:50:47AM -0700, Saurabh Shrivastava (सौरभ
> > > > श्रीवास्तव) wrote:
> > > > > An example of where deletes are received out of order:
> > Mcast_Macs_Remote
> > > > > points to Physical_Locator_Set which points to Physical_Locator.
> > When a
> > > > > transaction deletes Mcast_Macs_Remote, delete for
> > Physical_Locator_Set is
> > > > > received first.
> > > > >
> > > > > [027 m 05/26/15 22:22:16.824]  A:dc_rpc:OVS:
> > ovs|09826|jsonrpc|DBG|ssl:
> > > > > 135.227.147.205:43858: send request, method="transact",
> > > > > params=["hardware_vtep",{"
> > > > >
> > > >
> > lock":"my_controller","op":"assert"},{"table":"Mcast_Macs_Remote","where":[["_uuid","==",["uuid","63bdbbfe-0f90-4f33-acdd-f6334852302c"]]],"op":"delete"},{"comment":"thdl
> > > > > 20","op":"comment"}], id=201
> > > > > [027 m 05/26/15 22:22:16.832]  A:dc_rpc:OVS:
> > > > ovs|09828|poll_loop|DBG|wakeup
> > > > > due to [POLLIN] on fd 154 (FIFO) at
> > > > > /home/saurabh/dc35/os/ovs/lib/stream-fd.c:131 (0% CPU usage)
> > > > > [027 m 05/26/15 22:22:16.835]  A:dc_rpc:OVS:
> > > > ovs|09829|poll_loop|DBG|wakeup
> > > > > due to [POLLIN] on fd 246 (135.227.144.122:6632<->
> > 135.227.147.205:43858)
> > > > at
> > > > > /home/saurabh/dc35/os/ovs/lib/stream-ssl.c:744 (0% CPU usage)
> > > > > [027 m 05/26/15 22:22:16.838]  A:dc_rpc:OVS:
> > ovs|09830|jsonrpc|DBG|ssl:
> > > > > 135.227.147.205:43858: received notification, method="update",
> > > > >
> > > >
> > params=[null,{"Physical_Locator_Set":{"ff6908de-98aa-4c30-8809-7e1395ea13c9":{"old":{"locators":["uuid","901cdefe-0292-48bb-a9df-6a4837061931"]}}}}]
> > > > > [027 m 05/26/15 22:22:16.846]  A:dc_rpc:OVS:
> > ovs|09831|jsonrpc|DBG|ssl:
> > > > > 135.227.147.205:43858: received notification, method="update",
> > > > >
> > > >
> > params=[null,{"Physical_Locator":{"901cdefe-0292-48bb-a9df-6a4837061931":{"old":{"dst_ip":"10.50.50.1","encapsulation_type":"vxlan_over_ipv4"}}}}]
> > > > >
> > > > >
> > > > >
> > > > > --
> > > > > Saurabh (सौरभ)
> > > > >
> > > > > On Wed, Jun 10, 2015 at 9:41 AM, Saurabh Shrivastava (सौरभ
> > श्रीवास्तव) <
> > > > > saur...@gmail.com> wrote:
> > > > >
> > > > > > Thanks Ben. I have seen that when a transaction is deleting rowA
> > which
> > > > > > points to rowB which points to rowC, and if all the references to
> > rowB
> > > > and
> > > > > > rowC are gone, the updates generated can be in any order ie rowC
> > > > delete can
> > > > > > be received before deletes for rowA or rowB. Should this be
> > expected
> > > > for
> > > > > > "deletes"?
> > > > > >
> > > > > >
> > > > > > --
> > > > > > Saurabh (सौरभ)
> > > > > >
> > > > > > On Wed, Jun 10, 2015 at 8:15 AM, Ben Pfaff <b...@nicira.com> wrote:
> > > > > >
> > > > > >> On Wed, Jun 10, 2015 at 07:55:20AM -0700, Ben Pfaff wrote:
> > > > > >> > On Tue, Jun 09, 2015 at 11:16:34PM -0700, Saurabh Shrivastava
> > (सौरभ
> > > > > >> श्रीवास्तव) wrote:
> > > > > >> > > When OVSDB server sends updates to an OVSDB client, the IDL
> > > > changes
> > > > > >> > > idl_seqno. When idl_seqno changes, the client can rebrowse
> > the IDL
> > > > > >> and look
> > > > > >> > > for changes.
> > > > > >> > >
> > > > > >> > > Does OVSDB server guarantee that the updates always maintain
> > > > > >> referential
> > > > > >> > > integrity for row creation and row updates i.e. if the client
> > > > browses
> > > > > >> the
> > > > > >> > > IDL it should never run into a situation where rowA in tableA
> > > > points
> > > > > >> to a
> > > > > >> > > non-existent rowB in tableB because the update for rowA has
> > > > arrived
> > > > > >> but
> > > > > >> > > update for rowB is still in flight.
> > > > > >> >
> > > > > >> > Yes.
> > > > > >>
> > > > > >> I sent out a patch to document this:
> > > > > >>
> > http://openvswitch.org/pipermail/dev/2015-June/056200.html
> > > > > >>
> > > > > >
> > > > > >
> > > >
> >
_______________________________________________
discuss mailing list
discuss@openvswitch.org
http://openvswitch.org/mailman/listinfo/discuss

Reply via email to