| Message ID | 20220111163752.12152.85752.stgit@dceara.remote.csb |
|---|---|
| State | Accepted |
| Commit | c1691cceac322d8a49a6aeb52a608362385ae037 |
| Headers | show |
| Series | Fix IDL condition processing when reconnecting. | expand |
| Context | Check | Description |
|---|---|---|
| ovsrobot/apply-robot | success | apply and check: success |
| ovsrobot/github-robot-_Build_and_Test | success | github build: passed |
On 1/11/22 17:37, Dumitru Ceara wrote: > When reconnecting, if there are condition changes already sent to the > server but not yet acked, reset the db's 'last-id', esentially clearing > the local cache after reconnect. > > This is needed because the client cannot easily differentiate between > the following cases: > a. either the server already processed the requested monitor > condition change but the FSM was restarted before the > client was notified. In this case the client should > clear its local cache because it's out of sync with the > monitor view on the server side. > b. OR the server hasn't processed the requested monitor > condition change yet. > > Conditions changing at the same time with a reconnection happening are > rare so the performance impact of this patch should be minimal. > > Also, the tests are updated to cover the fact that we cannot control > which of the two scenarios ("a" and "b" above) are hit during the test. > Fixes: ae25f8c8fff8 ("ovsdb-idl: Avoid inconsistent IDL state with OVSDB_MONITOR_V3.") > Reported-by: Maxime Coquelin <maxime.coquelin@redhat.com> > Signed-off-by: Dumitru Ceara <dceara@redhat.com> > ---
On Tue, Jan 11, 2022 at 8:38 AM Dumitru Ceara <dceara@redhat.com> wrote: > > When reconnecting, if there are condition changes already sent to the > server but not yet acked, reset the db's 'last-id', esentially clearing > the local cache after reconnect. > > This is needed because the client cannot easily differentiate between > the following cases: > a. either the server already processed the requested monitor > condition change but the FSM was restarted before the > client was notified. In this case the client should > clear its local cache because it's out of sync with the > monitor view on the server side. > b. OR the server hasn't processed the requested monitor > condition change yet. > > Conditions changing at the same time with a reconnection happening are > rare so the performance impact of this patch should be minimal. > > Also, the tests are updated to cover the fact that we cannot control > which of the two scenarios ("a" and "b" above) are hit during the test. > > Reported-by: Maxime Coquelin <maxime.coquelin@redhat.com> > Signed-off-by: Dumitru Ceara <dceara@redhat.com> Thanks Dumitru. Could you tell more details about how this problem is reproduced? Or are there test case failures because of this? I still didn't understand how the problem would occur. When a client reconnects to the server, it should trigger the jsonrpc session recreation on the server side, so the monitor data for the session should be recreated, and so there shouldn't be "out of sync" view on the server side. Did I misunderstand? Thanks, Han > --- > Note: The python IDL is fixed in the following patch in order to make > this patch easier to backport. test-ovsdb.py is updated in this patch > to avoid having the python version of the test perma-failing if the > last patch in the series is not applied. > --- > lib/ovsdb-cs.c | 17 ++++++++++ > tests/ovsdb-idl.at | 4 +- > tests/test-ovsdb.c | 89 +++++++++++++++++++++++++++++---------------------- > tests/test-ovsdb.py | 46 ++++++++++++++++++-------- > 4 files changed, 102 insertions(+), 54 deletions(-) > > diff --git a/lib/ovsdb-cs.c b/lib/ovsdb-cs.c > index fcb6fe1b34be..a4457245aa2d 100644 > --- a/lib/ovsdb-cs.c > +++ b/lib/ovsdb-cs.c > @@ -1109,6 +1109,23 @@ ovsdb_cs_db_sync_condition(struct ovsdb_cs_db *db) > } > table->req_cond = NULL; > db->cond_changed = true; > + > + /* There are two cases: > + * a. either the server already processed the requested monitor > + * condition change but the FSM was restarted before the > + * client was notified. In this case the client should > + * clear its local cache because it's out of sync with the > + * monitor view on the server side. > + * > + * b. OR the server hasn't processed the requested monitor > + * condition change yet. > + * > + * As there's no easy way to differentiate between the two, > + * and given that this condition should be rare, reset the > + * 'last_id', essentially flushing the local cached DB > + * contents. > + */ > + db->last_id = UUID_ZERO; > } > } > } > diff --git a/tests/ovsdb-idl.at b/tests/ovsdb-idl.at > index 86a75f920379..62e2b638320c 100644 > --- a/tests/ovsdb-idl.at > +++ b/tests/ovsdb-idl.at > @@ -2336,7 +2336,7 @@ OVSDB_CHECK_CLUSTER_IDL([simple idl, monitor_cond_since, cluster disconnect], > 'condition simple [["i","==",2]]' \ > 'condition simple [["i","==",1]]' \ > '+reconnect' \ > - '["idltest", > + '?["idltest", > {"op": "update", > "table": "simple", > "where": [["i", "==", 1]], > @@ -2347,7 +2347,7 @@ OVSDB_CHECK_CLUSTER_IDL([simple idl, monitor_cond_since, cluster disconnect], > 003: table simple: i=2 r=1 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] ua=[] uuid=<1> > 004: change conditions > 005: reconnect > -006: table simple: i=2 r=1 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] ua=[] uuid=<1> > +006: table simple > 007: {"error":null,"result":[{"count":1}]} > 008: table simple: i=1 r=2 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] ua=[] uuid=<2> > 009: done > diff --git a/tests/test-ovsdb.c b/tests/test-ovsdb.c > index a40318c7dba9..ca4e87b8115c 100644 > --- a/tests/test-ovsdb.c > +++ b/tests/test-ovsdb.c > @@ -1879,7 +1879,8 @@ print_and_log(const char *format, ...) > } > > static char * > -format_idl_row(const struct ovsdb_idl_row *row, int step, const char *contents) > +format_idl_row(const struct ovsdb_idl_row *row, int step, const char *contents, > + bool terse) > { > const char *change_str = > !ovsdb_idl_track_is_set(row->table) > @@ -1890,9 +1891,13 @@ format_idl_row(const struct ovsdb_idl_row *row, int step, const char *contents) > ? "deleted row: " > : ""; > > - return xasprintf("%03d: table %s: %s%s uuid=" UUID_FMT, > - step, row->table->class_->name, change_str, contents, > - UUID_ARGS(&row->uuid)); > + if (terse) { > + return xasprintf("%03d: table %s", step, row->table->class_->name); > + } else { > + return xasprintf("%03d: table %s: %s%s uuid=" UUID_FMT, > + step, row->table->class_->name, change_str, > + contents, UUID_ARGS(&row->uuid)); > + } > } > > static void > @@ -2015,7 +2020,7 @@ print_idl_row_updated_singleton(const struct idltest_singleton *sng, int step) > } > > static void > -print_idl_row_simple(const struct idltest_simple *s, int step) > +print_idl_row_simple(const struct idltest_simple *s, int step, bool terse) > { > struct ds msg = DS_EMPTY_INITIALIZER; > ds_put_format(&msg, "i=%"PRId64" r=%g b=%s s=%s u="UUID_FMT" ia=[", > @@ -2042,7 +2047,7 @@ print_idl_row_simple(const struct idltest_simple *s, int step) > } > ds_put_cstr(&msg, "]"); > > - char *row_msg = format_idl_row(&s->header_, step, ds_cstr(&msg)); > + char *row_msg = format_idl_row(&s->header_, step, ds_cstr(&msg), terse); > print_and_log("%s", row_msg); > ds_destroy(&msg); > free(row_msg); > @@ -2051,7 +2056,7 @@ print_idl_row_simple(const struct idltest_simple *s, int step) > } > > static void > -print_idl_row_link1(const struct idltest_link1 *l1, int step) > +print_idl_row_link1(const struct idltest_link1 *l1, int step, bool terse) > { > struct ds msg = DS_EMPTY_INITIALIZER; > ds_put_format(&msg, "i=%"PRId64" k=", l1->i); > @@ -2070,7 +2075,7 @@ print_idl_row_link1(const struct idltest_link1 *l1, int step) > ds_put_format(&msg, "%"PRId64, l1->l2->i); > } > > - char *row_msg = format_idl_row(&l1->header_, step, ds_cstr(&msg)); > + char *row_msg = format_idl_row(&l1->header_, step, ds_cstr(&msg), terse); > print_and_log("%s", row_msg); > ds_destroy(&msg); > free(row_msg); > @@ -2079,7 +2084,7 @@ print_idl_row_link1(const struct idltest_link1 *l1, int step) > } > > static void > -print_idl_row_link2(const struct idltest_link2 *l2, int step) > +print_idl_row_link2(const struct idltest_link2 *l2, int step, bool terse) > { > struct ds msg = DS_EMPTY_INITIALIZER; > ds_put_format(&msg, "i=%"PRId64" l1=", l2->i); > @@ -2087,7 +2092,7 @@ print_idl_row_link2(const struct idltest_link2 *l2, int step) > ds_put_format(&msg, "%"PRId64, l2->l1->i); > } > > - char *row_msg = format_idl_row(&l2->header_, step, ds_cstr(&msg)); > + char *row_msg = format_idl_row(&l2->header_, step, ds_cstr(&msg), terse); > print_and_log("%s", row_msg); > ds_destroy(&msg); > free(row_msg); > @@ -2096,7 +2101,7 @@ print_idl_row_link2(const struct idltest_link2 *l2, int step) > } > > static void > -print_idl_row_simple3(const struct idltest_simple3 *s3, int step) > +print_idl_row_simple3(const struct idltest_simple3 *s3, int step, bool terse) > { > struct ds msg = DS_EMPTY_INITIALIZER; > size_t i; > @@ -2115,7 +2120,7 @@ print_idl_row_simple3(const struct idltest_simple3 *s3, int step) > } > ds_put_cstr(&msg, "]"); > > - char *row_msg = format_idl_row(&s3->header_, step, ds_cstr(&msg)); > + char *row_msg = format_idl_row(&s3->header_, step, ds_cstr(&msg), terse); > print_and_log("%s", row_msg); > ds_destroy(&msg); > free(row_msg); > @@ -2124,12 +2129,12 @@ print_idl_row_simple3(const struct idltest_simple3 *s3, int step) > } > > static void > -print_idl_row_simple4(const struct idltest_simple4 *s4, int step) > +print_idl_row_simple4(const struct idltest_simple4 *s4, int step, bool terse) > { > struct ds msg = DS_EMPTY_INITIALIZER; > ds_put_format(&msg, "name=%s", s4->name); > > - char *row_msg = format_idl_row(&s4->header_, step, ds_cstr(&msg)); > + char *row_msg = format_idl_row(&s4->header_, step, ds_cstr(&msg), terse); > print_and_log("%s", row_msg); > ds_destroy(&msg); > free(row_msg); > @@ -2138,7 +2143,7 @@ print_idl_row_simple4(const struct idltest_simple4 *s4, int step) > } > > static void > -print_idl_row_simple6(const struct idltest_simple6 *s6, int step) > +print_idl_row_simple6(const struct idltest_simple6 *s6, int step, bool terse) > { > struct ds msg = DS_EMPTY_INITIALIZER; > ds_put_format(&msg, "name=%s ", s6->name); > @@ -2149,7 +2154,7 @@ print_idl_row_simple6(const struct idltest_simple6 *s6, int step) > } > ds_put_cstr(&msg, "]"); > > - char *row_msg = format_idl_row(&s6->header_, step, ds_cstr(&msg)); > + char *row_msg = format_idl_row(&s6->header_, step, ds_cstr(&msg), terse); > print_and_log("%s", row_msg); > ds_destroy(&msg); > free(row_msg); > @@ -2158,12 +2163,13 @@ print_idl_row_simple6(const struct idltest_simple6 *s6, int step) > } > > static void > -print_idl_row_singleton(const struct idltest_singleton *sng, int step) > +print_idl_row_singleton(const struct idltest_singleton *sng, int step, > + bool terse) > { > struct ds msg = DS_EMPTY_INITIALIZER; > ds_put_format(&msg, "name=%s", sng->name); > > - char *row_msg = format_idl_row(&sng->header_, step, ds_cstr(&msg)); > + char *row_msg = format_idl_row(&sng->header_, step, ds_cstr(&msg), terse); > print_and_log("%s", row_msg); > ds_destroy(&msg); > free(row_msg); > @@ -2172,7 +2178,7 @@ print_idl_row_singleton(const struct idltest_singleton *sng, int step) > } > > static void > -print_idl(struct ovsdb_idl *idl, int step) > +print_idl(struct ovsdb_idl *idl, int step, bool terse) > { > const struct idltest_simple3 *s3; > const struct idltest_simple4 *s4; > @@ -2184,31 +2190,31 @@ print_idl(struct ovsdb_idl *idl, int step) > int n = 0; > > IDLTEST_SIMPLE_FOR_EACH (s, idl) { > - print_idl_row_simple(s, step); > + print_idl_row_simple(s, step, terse); > n++; > } > IDLTEST_LINK1_FOR_EACH (l1, idl) { > - print_idl_row_link1(l1, step); > + print_idl_row_link1(l1, step, terse); > n++; > } > IDLTEST_LINK2_FOR_EACH (l2, idl) { > - print_idl_row_link2(l2, step); > + print_idl_row_link2(l2, step, terse); > n++; > } > IDLTEST_SIMPLE3_FOR_EACH (s3, idl) { > - print_idl_row_simple3(s3, step); > + print_idl_row_simple3(s3, step, terse); > n++; > } > IDLTEST_SIMPLE4_FOR_EACH (s4, idl) { > - print_idl_row_simple4(s4, step); > + print_idl_row_simple4(s4, step, terse); > n++; > } > IDLTEST_SIMPLE6_FOR_EACH (s6, idl) { > - print_idl_row_simple6(s6, step); > + print_idl_row_simple6(s6, step, terse); > n++; > } > IDLTEST_SINGLETON_FOR_EACH (sng, idl) { > - print_idl_row_singleton(sng, step); > + print_idl_row_singleton(sng, step, terse); > n++; > } > if (!n) { > @@ -2217,7 +2223,7 @@ print_idl(struct ovsdb_idl *idl, int step) > } > > static void > -print_idl_track(struct ovsdb_idl *idl, int step) > +print_idl_track(struct ovsdb_idl *idl, int step, bool terse) > { > const struct idltest_simple3 *s3; > const struct idltest_simple4 *s4; > @@ -2228,27 +2234,27 @@ print_idl_track(struct ovsdb_idl *idl, int step) > int n = 0; > > IDLTEST_SIMPLE_FOR_EACH_TRACKED (s, idl) { > - print_idl_row_simple(s, step); > + print_idl_row_simple(s, step, terse); > n++; > } > IDLTEST_LINK1_FOR_EACH_TRACKED (l1, idl) { > - print_idl_row_link1(l1, step); > + print_idl_row_link1(l1, step, terse); > n++; > } > IDLTEST_LINK2_FOR_EACH_TRACKED (l2, idl) { > - print_idl_row_link2(l2, step); > + print_idl_row_link2(l2, step, terse); > n++; > } > IDLTEST_SIMPLE3_FOR_EACH_TRACKED (s3, idl) { > - print_idl_row_simple3(s3, step); > + print_idl_row_simple3(s3, step, terse); > n++; > } > IDLTEST_SIMPLE4_FOR_EACH_TRACKED (s4, idl) { > - print_idl_row_simple4(s4, step); > + print_idl_row_simple4(s4, step, terse); > n++; > } > IDLTEST_SIMPLE6_FOR_EACH_TRACKED (s6, idl) { > - print_idl_row_simple6(s6, step); > + print_idl_row_simple6(s6, step, terse); > n++; > } > > @@ -2651,6 +2657,13 @@ do_idl(struct ovs_cmdl_context *ctx) > char *arg = ctx->argv[i]; > struct jsonrpc_msg *request, *reply; > > + bool terse = false; > + if (*arg == '?') { > + /* We're only interested in terse table contents. */ > + terse = true; > + arg++; > + } > + > if (*arg == '+') { > /* The previous transaction didn't change anything. */ > arg++; > @@ -2671,10 +2684,10 @@ do_idl(struct ovs_cmdl_context *ctx) > > /* Print update. */ > if (track) { > - print_idl_track(idl, step++); > + print_idl_track(idl, step++, terse); > ovsdb_idl_track_clear(idl); > } else { > - print_idl(idl, step++); > + print_idl(idl, step++, terse); > } > } > seqno = ovsdb_idl_get_seqno(idl); > @@ -2727,7 +2740,7 @@ do_idl(struct ovs_cmdl_context *ctx) > ovsdb_idl_wait(idl); > poll_block(); > } > - print_idl(idl, step++); > + print_idl(idl, step++, false); > ovsdb_idl_track_clear(idl); > ovsdb_idl_destroy(idl); > print_and_log("%03d: done", step); > @@ -2849,7 +2862,7 @@ dump_simple3(struct ovsdb_idl *idl, > int step) > { > IDLTEST_SIMPLE3_FOR_EACH(myRow, idl) { > - print_idl_row_simple3(myRow, step); > + print_idl_row_simple3(myRow, step, false); > } > } > > @@ -2991,7 +3004,7 @@ do_idl_compound_index_with_ref(struct ovs_cmdl_context *ctx) > idltest_simple3_index_set_uref(equal, &myRow2, 1); > printf("%03d: Query using index with reference\n", step++); > IDLTEST_SIMPLE3_FOR_EACH_EQUAL (myRow, equal, index) { > - print_idl_row_simple3(myRow, step++); > + print_idl_row_simple3(myRow, step++, false); > } > idltest_simple3_index_destroy_row(equal); > > diff --git a/tests/test-ovsdb.py b/tests/test-ovsdb.py > index 5bc0bf681425..853264f22bdc 100644 > --- a/tests/test-ovsdb.py > +++ b/tests/test-ovsdb.py > @@ -232,75 +232,87 @@ def get_singleton_table_printable_row(row): > return "name=%s" % row.name > > > -def print_row(table, row, step, contents): > - s = "%03d: table %s: %s " % (step, table, contents) > - s += get_simple_printable_row_string(row, ["uuid"]) > +def print_row(table, row, step, contents, terse): > + if terse: > + s = "%03d: table %s" % (step, table) > + else: > + s = "%03d: table %s: %s " % (step, table, contents) > + s += get_simple_printable_row_string(row, ["uuid"]) > print(s) > > > -def print_idl(idl, step): > +def print_idl(idl, step, terse=False): > n = 0 > if "simple" in idl.tables: > simple = idl.tables["simple"].rows > for row in simple.values(): > print_row("simple", row, step, > - get_simple_table_printable_row(row)) > + get_simple_table_printable_row(row), > + terse) > n += 1 > > if "simple2" in idl.tables: > simple2 = idl.tables["simple2"].rows > for row in simple2.values(): > print_row("simple2", row, step, > - get_simple2_table_printable_row(row)) > + get_simple2_table_printable_row(row), > + terse) > n += 1 > > if "simple3" in idl.tables: > simple3 = idl.tables["simple3"].rows > for row in simple3.values(): > print_row("simple3", row, step, > - get_simple3_table_printable_row(row)) > + get_simple3_table_printable_row(row), > + terse) > n += 1 > > if "simple4" in idl.tables: > simple4 = idl.tables["simple4"].rows > for row in simple4.values(): > print_row("simple4", row, step, > - get_simple4_table_printable_row(row)) > + get_simple4_table_printable_row(row), > + terse) > n += 1 > > if "simple5" in idl.tables: > simple5 = idl.tables["simple5"].rows > for row in simple5.values(): > print_row("simple5", row, step, > - get_simple5_table_printable_row(row)) > + get_simple5_table_printable_row(row), > + terse) > n += 1 > > if "simple6" in idl.tables: > simple6 = idl.tables["simple6"].rows > for row in simple6.values(): > print_row("simple6", row, step, > - get_simple6_table_printable_row(row)) > + get_simple6_table_printable_row(row), > + terse) > n += 1 > > if "link1" in idl.tables: > l1 = idl.tables["link1"].rows > for row in l1.values(): > print_row("link1", row, step, > - get_link1_table_printable_row(row)) > + get_link1_table_printable_row(row), > + terse) > n += 1 > > if "link2" in idl.tables: > l2 = idl.tables["link2"].rows > for row in l2.values(): > print_row("link2", row, step, > - get_link2_table_printable_row(row)) > + get_link2_table_printable_row(row), > + terse) > n += 1 > > if "singleton" in idl.tables: > sng = idl.tables["singleton"].rows > for row in sng.values(): > print_row("singleton", row, step, > - get_singleton_table_printable_row(row)) > + get_singleton_table_printable_row(row), > + terse) > n += 1 > > if not n: > @@ -701,6 +713,12 @@ def do_idl(schema_file, remote, *commands): > step += 1 > > for command in commands: > + terse = False > + if command.startswith("?"): > + # We're only interested in terse table contents. > + terse = True > + command = command[1:] > + > if command.startswith("+"): > # The previous transaction didn't change anything. > command = command[1:] > @@ -714,7 +732,7 @@ def do_idl(schema_file, remote, *commands): > rpc.wait(poller) > poller.block() > > - print_idl(idl, step) > + print_idl(idl, step, terse) > step += 1 > > seqno = idl.change_seqno > > _______________________________________________ > dev mailing list > dev@openvswitch.org > https://mail.openvswitch.org/mailman/listinfo/ovs-dev
On 1/26/22 01:22, Han Zhou wrote: > > > On Tue, Jan 11, 2022 at 8:38 AM Dumitru Ceara <dceara@redhat.com > <mailto:dceara@redhat.com>> wrote: >> >> When reconnecting, if there are condition changes already sent to the >> server but not yet acked, reset the db's 'last-id', esentially clearing >> the local cache after reconnect. >> >> This is needed because the client cannot easily differentiate between >> the following cases: >> a. either the server already processed the requested monitor >> condition change but the FSM was restarted before the >> client was notified. In this case the client should >> clear its local cache because it's out of sync with the >> monitor view on the server side. >> b. OR the server hasn't processed the requested monitor >> condition change yet. >> >> Conditions changing at the same time with a reconnection happening are >> rare so the performance impact of this patch should be minimal. >> >> Also, the tests are updated to cover the fact that we cannot control >> which of the two scenarios ("a" and "b" above) are hit during the test. >> >> Reported-by: Maxime Coquelin <maxime.coquelin@redhat.com > <mailto:maxime.coquelin@redhat.com>> >> Signed-off-by: Dumitru Ceara <dceara@redhat.com > <mailto:dceara@redhat.com>> > > Thanks Dumitru. Could you tell more details about how this problem is > reproduced? Or are there test case failures because of this? Hi Han, Thanks for looking into this. Yes, Maxime reported that the test "2241: simple idl, monitor_cond_since, cluster disconnect - C - tcp" would occasionally fail without this patch. > I still didn't understand how the problem would occur. When a client > reconnects to the server, it should trigger the jsonrpc session > recreation on the server side, so the monitor data for the session > should be recreated, and so there shouldn't be "out of sync" view on the > server side. Did I misunderstand? Going through the test logs we see (simplified and edited, skipping the less relevant parts): 0. initial contents of the "simple" table on the server side: "row": {"i": 1, "r": 1.0, "b": true} "row": {"i": 2, "r": 1.0, "b": true} 1. the client connects for the first time, gets schema, monitors _Server database. 2. the client requests a monitor_cond_since, id=3: method="monitor_cond_since", params=[ "idltest", ["monid","idltest"], {..."simple":[{"where":[false],"columns":["b","ba","i","ia","r","ra","s","sa","u","ua"]}],...}, last_id=0 // last seen transaction id ], id=3 3. the server doesn't need to send any updates, nothing matches "false" and replies, id=3: result=[ false, // requested "last_id" not found in history, will cause the // client to flush in-memory contents "13220f46-f13f-4f30-ab19-0af58699e0aa", // last known transaction ID, // the client will store this // locally in last_id {}], id=3 4. the client changes its conditions and sends a monitor_cond_change, id=5: params=[ ["monid","idltest"],["monid","idltest"], {"simple":[{"where":[["i","==",2]]}]}], id=5 --- Client side view: - simple table: empty - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" - acked-cond: "simple": false - req-cond: "simple": {"where":[["i","==",2]]} - new-cond: <none> --- 5. this new condition matches one row in table "simple" so the server sends an update which includes that row: method="update3", params=[ ["monid","idltest"], "13220f46-f13f-4f30-ab19-0af58699e0aa", {"simple":{"fd500d06-8d0c-4149-9c69-2914538e07e5":{"insert":{"b":true,"r":1,"i":2}}}} ] 6. the client inserts the row in its in-memory copy of the database, last_id becomes "13220f46-f13f-4f30-ab19-0af58699e0aa". However, the condition change is not yet acked by the server! --- Client side view: - simple table: - row: {"b":true,"r":1,"i":2} - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" - acked-cond: "simple": false - req-cond: "simple": {"where":[["i","==",2]]} - new-cond: <none> --- 7. the client changes its conditions, doesn't send a monitor_cond_change because there's already one in-flight, not yet acked. --- Client side view: - simple table: - row: {"b":true,"r":1,"i":2} - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" - acked-cond: "simple": false - req-cond: "simple": {"where":[["i","==",2]]} - new-cond: "simple": {"where":[["i","==",1]]} --- 8. the connection goes down, ovsdb_cs_db_sync_condition() is called from ovsdb_cs_restart_fsm(): --- Client side view: - simple table: - row: {"b":true,"r":1,"i":2} - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" - acked-cond: "simple": false - req-cond: <none> - new-cond: "simple": {"where":[["i","==",1]]} --- 9. the client reconnects, gets schema, monitors _Server database, a new monitor is setup on the server side. 10. the client requests a monitor_cond_since, id=9: method="monitor_cond_since", params=[ "idltest", ["monid","idltest"], {..."simple":[{"where":[false],"columns":["b","ba","i","ia","r","ra","s","sa","u","ua"]}],...}, // last acked condition! "13220f46-f13f-4f30-ab19-0af58699e0aa" // last seen transaction id ], id=9 11. the server processes the condition change, but it changed to "false" so it shouldn't send any updates to the client because in the server's view the client didn't receive any rows yet, so there's nothing to delete. However, the last_id is _known_ by the server so it replies with: result=[ true, // last_id was found so the client will NOT flush its // in-memory db contents! "13220f46-f13f-4f30-ab19-0af58699e0aa", // last_id {}], id=9 12. At this point the client side view is inconsistent, the row doesn't match the acked condition and there's no other in-flight condition change request: --- Client side view (INCONSISTENT): - simple table: - row: {"b":true,"r":1,"i":2} - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" - acked-cond: "simple": false - req-cond: <none> - new-cond: "simple": {"where":[["i","==",1]]} --- 13. the client starts a transaction to update the row with i==1 and change "r" to 2, id=11: method="transact", params=[ "idltest", {"where":[["i","==",1]],"row":{"r":2},"op":"update","table":"simple"} ], id=11 14. the server processes the transaction, the server sides contents become: "row": {"i": 1, "r": 2.0, "b": true} "row": {"i": 2, "r": 1.0, "b": true} The updated row doesn't match the client's condition (false) so the server only sends the txn result: reply, result=[{"count":1}], id=11 15. the client sends the new conditions (were stored in new-cond), sends a monitor_cond_change, id=12: method="monitor_cond_change", params=[ ["monid","idltest"],["monid","idltest"], {"simple":[{"where":[["i","==",1]]}]}], id=12 16. the server processes the new condition, now the second row matches the condition so the server sends the update3 message: method="update3", params=[ ["monid","idltest"], "ca9454d0-c013-440a-9c56-1dd2a4693bf7", {"simple":{"f97bfbe1-1911-4d6f-89a1-b211cf3bb5dc":{"insert":{"b":true,"r":2,"i":1}}}} ] 17. the server acks the condition change: reply, result={}, id=12 --- Client side view (INCONSISTENT): - simple table: - row: {"b":true,"r":1,"i":2} - row: {"b":true,"r":2,"i":1} - last_id: "ca9454d0-c013-440a-9c56-1dd2a4693bf7" - acked-cond: "simple": {"where":[["i","==",1]]} - req-cond: <none> - new-cond: <none> --- The test fails here because it (correctly) expects the client to only have the second row in its in-memory view of the database. I'm not sure of a better way to summarize this but I'm open to suggestions about how to rephrase the commit message. > > Thanks, > Han > Thanks, Dumitru >> --- >> Note: The python IDL is fixed in the following patch in order to make >> this patch easier to backport. test-ovsdb.py is updated in this patch >> to avoid having the python version of the test perma-failing if the >> last patch in the series is not applied. >> --- >> lib/ovsdb-cs.c | 17 ++++++++++ >> tests/ovsdb-idl.at <http://ovsdb-idl.at> | 4 +- >> tests/test-ovsdb.c | 89 > +++++++++++++++++++++++++++++---------------------- >> tests/test-ovsdb.py | 46 ++++++++++++++++++-------- >> 4 files changed, 102 insertions(+), 54 deletions(-) >> >> diff --git a/lib/ovsdb-cs.c b/lib/ovsdb-cs.c >> index fcb6fe1b34be..a4457245aa2d 100644 >> --- a/lib/ovsdb-cs.c >> +++ b/lib/ovsdb-cs.c >> @@ -1109,6 +1109,23 @@ ovsdb_cs_db_sync_condition(struct ovsdb_cs_db *db) >> } >> table->req_cond = NULL; >> db->cond_changed = true; >> + >> + /* There are two cases: >> + * a. either the server already processed the > requested monitor >> + * condition change but the FSM was restarted > before the >> + * client was notified. In this case the client > should >> + * clear its local cache because it's out of sync > with the >> + * monitor view on the server side. >> + * >> + * b. OR the server hasn't processed the requested > monitor >> + * condition change yet. >> + * >> + * As there's no easy way to differentiate between > the two, >> + * and given that this condition should be rare, > reset the >> + * 'last_id', essentially flushing the local cached DB >> + * contents. >> + */ >> + db->last_id = UUID_ZERO; >> } >> } >> } >> diff --git a/tests/ovsdb-idl.at <http://ovsdb-idl.at> > b/tests/ovsdb-idl.at <http://ovsdb-idl.at> >> index 86a75f920379..62e2b638320c 100644 >> --- a/tests/ovsdb-idl.at <http://ovsdb-idl.at> >> +++ b/tests/ovsdb-idl.at <http://ovsdb-idl.at> >> @@ -2336,7 +2336,7 @@ OVSDB_CHECK_CLUSTER_IDL([simple idl, > monitor_cond_since, cluster disconnect], >> 'condition simple [["i","==",2]]' \ >> 'condition simple [["i","==",1]]' \ >> '+reconnect' \ >> - '["idltest", >> + '?["idltest", >> {"op": "update", >> "table": "simple", >> "where": [["i", "==", 1]], >> @@ -2347,7 +2347,7 @@ OVSDB_CHECK_CLUSTER_IDL([simple idl, > monitor_cond_since, cluster disconnect], >> 003: table simple: i=2 r=1 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] > ua=[] uuid=<1> >> 004: change conditions >> 005: reconnect >> -006: table simple: i=2 r=1 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] > ua=[] uuid=<1> >> +006: table simple >> 007: {"error":null,"result":[{"count":1}]} >> 008: table simple: i=1 r=2 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] > ua=[] uuid=<2> >> 009: done >> diff --git a/tests/test-ovsdb.c b/tests/test-ovsdb.c >> index a40318c7dba9..ca4e87b8115c 100644 >> --- a/tests/test-ovsdb.c >> +++ b/tests/test-ovsdb.c >> @@ -1879,7 +1879,8 @@ print_and_log(const char *format, ...) >> } >> >> static char * >> -format_idl_row(const struct ovsdb_idl_row *row, int step, const char > *contents) >> +format_idl_row(const struct ovsdb_idl_row *row, int step, const char > *contents, >> + bool terse) >> { >> const char *change_str = >> !ovsdb_idl_track_is_set(row->table) >> @@ -1890,9 +1891,13 @@ format_idl_row(const struct ovsdb_idl_row *row, > int step, const char *contents) >> ? "deleted row: " >> : ""; >> >> - return xasprintf("%03d: table %s: %s%s uuid=" UUID_FMT, >> - step, row->table->class_->name, change_str, > contents, >> - UUID_ARGS(&row->uuid)); >> + if (terse) { >> + return xasprintf("%03d: table %s", step, > row->table->class_->name); >> + } else { >> + return xasprintf("%03d: table %s: %s%s uuid=" UUID_FMT, >> + step, row->table->class_->name, change_str, >> + contents, UUID_ARGS(&row->uuid)); >> + } >> } >> >> static void >> @@ -2015,7 +2020,7 @@ print_idl_row_updated_singleton(const struct > idltest_singleton *sng, int step) >> } >> >> static void >> -print_idl_row_simple(const struct idltest_simple *s, int step) >> +print_idl_row_simple(const struct idltest_simple *s, int step, bool > terse) >> { >> struct ds msg = DS_EMPTY_INITIALIZER; >> ds_put_format(&msg, "i=%"PRId64" r=%g b=%s s=%s u="UUID_FMT" ia=[", >> @@ -2042,7 +2047,7 @@ print_idl_row_simple(const struct idltest_simple > *s, int step) >> } >> ds_put_cstr(&msg, "]"); >> >> - char *row_msg = format_idl_row(&s->header_, step, ds_cstr(&msg)); >> + char *row_msg = format_idl_row(&s->header_, step, ds_cstr(&msg), > terse); >> print_and_log("%s", row_msg); >> ds_destroy(&msg); >> free(row_msg); >> @@ -2051,7 +2056,7 @@ print_idl_row_simple(const struct idltest_simple > *s, int step) >> } >> >> static void >> -print_idl_row_link1(const struct idltest_link1 *l1, int step) >> +print_idl_row_link1(const struct idltest_link1 *l1, int step, bool terse) >> { >> struct ds msg = DS_EMPTY_INITIALIZER; >> ds_put_format(&msg, "i=%"PRId64" k=", l1->i); >> @@ -2070,7 +2075,7 @@ print_idl_row_link1(const struct idltest_link1 > *l1, int step) >> ds_put_format(&msg, "%"PRId64, l1->l2->i); >> } >> >> - char *row_msg = format_idl_row(&l1->header_, step, ds_cstr(&msg)); >> + char *row_msg = format_idl_row(&l1->header_, step, ds_cstr(&msg), > terse); >> print_and_log("%s", row_msg); >> ds_destroy(&msg); >> free(row_msg); >> @@ -2079,7 +2084,7 @@ print_idl_row_link1(const struct idltest_link1 > *l1, int step) >> } >> >> static void >> -print_idl_row_link2(const struct idltest_link2 *l2, int step) >> +print_idl_row_link2(const struct idltest_link2 *l2, int step, bool terse) >> { >> struct ds msg = DS_EMPTY_INITIALIZER; >> ds_put_format(&msg, "i=%"PRId64" l1=", l2->i); >> @@ -2087,7 +2092,7 @@ print_idl_row_link2(const struct idltest_link2 > *l2, int step) >> ds_put_format(&msg, "%"PRId64, l2->l1->i); >> } >> >> - char *row_msg = format_idl_row(&l2->header_, step, ds_cstr(&msg)); >> + char *row_msg = format_idl_row(&l2->header_, step, ds_cstr(&msg), > terse); >> print_and_log("%s", row_msg); >> ds_destroy(&msg); >> free(row_msg); >> @@ -2096,7 +2101,7 @@ print_idl_row_link2(const struct idltest_link2 > *l2, int step) >> } >> >> static void >> -print_idl_row_simple3(const struct idltest_simple3 *s3, int step) >> +print_idl_row_simple3(const struct idltest_simple3 *s3, int step, > bool terse) >> { >> struct ds msg = DS_EMPTY_INITIALIZER; >> size_t i; >> @@ -2115,7 +2120,7 @@ print_idl_row_simple3(const struct > idltest_simple3 *s3, int step) >> } >> ds_put_cstr(&msg, "]"); >> >> - char *row_msg = format_idl_row(&s3->header_, step, ds_cstr(&msg)); >> + char *row_msg = format_idl_row(&s3->header_, step, ds_cstr(&msg), > terse); >> print_and_log("%s", row_msg); >> ds_destroy(&msg); >> free(row_msg); >> @@ -2124,12 +2129,12 @@ print_idl_row_simple3(const struct > idltest_simple3 *s3, int step) >> } >> >> static void >> -print_idl_row_simple4(const struct idltest_simple4 *s4, int step) >> +print_idl_row_simple4(const struct idltest_simple4 *s4, int step, > bool terse) >> { >> struct ds msg = DS_EMPTY_INITIALIZER; >> ds_put_format(&msg, "name=%s", s4->name); >> >> - char *row_msg = format_idl_row(&s4->header_, step, ds_cstr(&msg)); >> + char *row_msg = format_idl_row(&s4->header_, step, ds_cstr(&msg), > terse); >> print_and_log("%s", row_msg); >> ds_destroy(&msg); >> free(row_msg); >> @@ -2138,7 +2143,7 @@ print_idl_row_simple4(const struct > idltest_simple4 *s4, int step) >> } >> >> static void >> -print_idl_row_simple6(const struct idltest_simple6 *s6, int step) >> +print_idl_row_simple6(const struct idltest_simple6 *s6, int step, > bool terse) >> { >> struct ds msg = DS_EMPTY_INITIALIZER; >> ds_put_format(&msg, "name=%s ", s6->name); >> @@ -2149,7 +2154,7 @@ print_idl_row_simple6(const struct > idltest_simple6 *s6, int step) >> } >> ds_put_cstr(&msg, "]"); >> >> - char *row_msg = format_idl_row(&s6->header_, step, ds_cstr(&msg)); >> + char *row_msg = format_idl_row(&s6->header_, step, ds_cstr(&msg), > terse); >> print_and_log("%s", row_msg); >> ds_destroy(&msg); >> free(row_msg); >> @@ -2158,12 +2163,13 @@ print_idl_row_simple6(const struct > idltest_simple6 *s6, int step) >> } >> >> static void >> -print_idl_row_singleton(const struct idltest_singleton *sng, int step) >> +print_idl_row_singleton(const struct idltest_singleton *sng, int step, >> + bool terse) >> { >> struct ds msg = DS_EMPTY_INITIALIZER; >> ds_put_format(&msg, "name=%s", sng->name); >> >> - char *row_msg = format_idl_row(&sng->header_, step, ds_cstr(&msg)); >> + char *row_msg = format_idl_row(&sng->header_, step, > ds_cstr(&msg), terse); >> print_and_log("%s", row_msg); >> ds_destroy(&msg); >> free(row_msg); >> @@ -2172,7 +2178,7 @@ print_idl_row_singleton(const struct > idltest_singleton *sng, int step) >> } >> >> static void >> -print_idl(struct ovsdb_idl *idl, int step) >> +print_idl(struct ovsdb_idl *idl, int step, bool terse) >> { >> const struct idltest_simple3 *s3; >> const struct idltest_simple4 *s4; >> @@ -2184,31 +2190,31 @@ print_idl(struct ovsdb_idl *idl, int step) >> int n = 0; >> >> IDLTEST_SIMPLE_FOR_EACH (s, idl) { >> - print_idl_row_simple(s, step); >> + print_idl_row_simple(s, step, terse); >> n++; >> } >> IDLTEST_LINK1_FOR_EACH (l1, idl) { >> - print_idl_row_link1(l1, step); >> + print_idl_row_link1(l1, step, terse); >> n++; >> } >> IDLTEST_LINK2_FOR_EACH (l2, idl) { >> - print_idl_row_link2(l2, step); >> + print_idl_row_link2(l2, step, terse); >> n++; >> } >> IDLTEST_SIMPLE3_FOR_EACH (s3, idl) { >> - print_idl_row_simple3(s3, step); >> + print_idl_row_simple3(s3, step, terse); >> n++; >> } >> IDLTEST_SIMPLE4_FOR_EACH (s4, idl) { >> - print_idl_row_simple4(s4, step); >> + print_idl_row_simple4(s4, step, terse); >> n++; >> } >> IDLTEST_SIMPLE6_FOR_EACH (s6, idl) { >> - print_idl_row_simple6(s6, step); >> + print_idl_row_simple6(s6, step, terse); >> n++; >> } >> IDLTEST_SINGLETON_FOR_EACH (sng, idl) { >> - print_idl_row_singleton(sng, step); >> + print_idl_row_singleton(sng, step, terse); >> n++; >> } >> if (!n) { >> @@ -2217,7 +2223,7 @@ print_idl(struct ovsdb_idl *idl, int step) >> } >> >> static void >> -print_idl_track(struct ovsdb_idl *idl, int step) >> +print_idl_track(struct ovsdb_idl *idl, int step, bool terse) >> { >> const struct idltest_simple3 *s3; >> const struct idltest_simple4 *s4; >> @@ -2228,27 +2234,27 @@ print_idl_track(struct ovsdb_idl *idl, int step) >> int n = 0; >> >> IDLTEST_SIMPLE_FOR_EACH_TRACKED (s, idl) { >> - print_idl_row_simple(s, step); >> + print_idl_row_simple(s, step, terse); >> n++; >> } >> IDLTEST_LINK1_FOR_EACH_TRACKED (l1, idl) { >> - print_idl_row_link1(l1, step); >> + print_idl_row_link1(l1, step, terse); >> n++; >> } >> IDLTEST_LINK2_FOR_EACH_TRACKED (l2, idl) { >> - print_idl_row_link2(l2, step); >> + print_idl_row_link2(l2, step, terse); >> n++; >> } >> IDLTEST_SIMPLE3_FOR_EACH_TRACKED (s3, idl) { >> - print_idl_row_simple3(s3, step); >> + print_idl_row_simple3(s3, step, terse); >> n++; >> } >> IDLTEST_SIMPLE4_FOR_EACH_TRACKED (s4, idl) { >> - print_idl_row_simple4(s4, step); >> + print_idl_row_simple4(s4, step, terse); >> n++; >> } >> IDLTEST_SIMPLE6_FOR_EACH_TRACKED (s6, idl) { >> - print_idl_row_simple6(s6, step); >> + print_idl_row_simple6(s6, step, terse); >> n++; >> } >> >> @@ -2651,6 +2657,13 @@ do_idl(struct ovs_cmdl_context *ctx) >> char *arg = ctx->argv[i]; >> struct jsonrpc_msg *request, *reply; >> >> + bool terse = false; >> + if (*arg == '?') { >> + /* We're only interested in terse table contents. */ >> + terse = true; >> + arg++; >> + } >> + >> if (*arg == '+') { >> /* The previous transaction didn't change anything. */ >> arg++; >> @@ -2671,10 +2684,10 @@ do_idl(struct ovs_cmdl_context *ctx) >> >> /* Print update. */ >> if (track) { >> - print_idl_track(idl, step++); >> + print_idl_track(idl, step++, terse); >> ovsdb_idl_track_clear(idl); >> } else { >> - print_idl(idl, step++); >> + print_idl(idl, step++, terse); >> } >> } >> seqno = ovsdb_idl_get_seqno(idl); >> @@ -2727,7 +2740,7 @@ do_idl(struct ovs_cmdl_context *ctx) >> ovsdb_idl_wait(idl); >> poll_block(); >> } >> - print_idl(idl, step++); >> + print_idl(idl, step++, false); >> ovsdb_idl_track_clear(idl); >> ovsdb_idl_destroy(idl); >> print_and_log("%03d: done", step); >> @@ -2849,7 +2862,7 @@ dump_simple3(struct ovsdb_idl *idl, >> int step) >> { >> IDLTEST_SIMPLE3_FOR_EACH(myRow, idl) { >> - print_idl_row_simple3(myRow, step); >> + print_idl_row_simple3(myRow, step, false); >> } >> } >> >> @@ -2991,7 +3004,7 @@ do_idl_compound_index_with_ref(struct > ovs_cmdl_context *ctx) >> idltest_simple3_index_set_uref(equal, &myRow2, 1); >> printf("%03d: Query using index with reference\n", step++); >> IDLTEST_SIMPLE3_FOR_EACH_EQUAL (myRow, equal, index) { >> - print_idl_row_simple3(myRow, step++); >> + print_idl_row_simple3(myRow, step++, false); >> } >> idltest_simple3_index_destroy_row(equal); >> >> diff --git a/tests/test-ovsdb.py b/tests/test-ovsdb.py >> index 5bc0bf681425..853264f22bdc 100644 >> --- a/tests/test-ovsdb.py >> +++ b/tests/test-ovsdb.py >> @@ -232,75 +232,87 @@ def get_singleton_table_printable_row(row): >> return "name=%s" % row.name <http://row.name> >> >> >> -def print_row(table, row, step, contents): >> - s = "%03d: table %s: %s " % (step, table, contents) >> - s += get_simple_printable_row_string(row, ["uuid"]) >> +def print_row(table, row, step, contents, terse): >> + if terse: >> + s = "%03d: table %s" % (step, table) >> + else: >> + s = "%03d: table %s: %s " % (step, table, contents) >> + s += get_simple_printable_row_string(row, ["uuid"]) >> print(s) >> >> >> -def print_idl(idl, step): >> +def print_idl(idl, step, terse=False): >> n = 0 >> if "simple" in idl.tables: >> simple = idl.tables["simple"].rows >> for row in simple.values(): >> print_row("simple", row, step, >> - get_simple_table_printable_row(row)) >> + get_simple_table_printable_row(row), >> + terse) >> n += 1 >> >> if "simple2" in idl.tables: >> simple2 = idl.tables["simple2"].rows >> for row in simple2.values(): >> print_row("simple2", row, step, >> - get_simple2_table_printable_row(row)) >> + get_simple2_table_printable_row(row), >> + terse) >> n += 1 >> >> if "simple3" in idl.tables: >> simple3 = idl.tables["simple3"].rows >> for row in simple3.values(): >> print_row("simple3", row, step, >> - get_simple3_table_printable_row(row)) >> + get_simple3_table_printable_row(row), >> + terse) >> n += 1 >> >> if "simple4" in idl.tables: >> simple4 = idl.tables["simple4"].rows >> for row in simple4.values(): >> print_row("simple4", row, step, >> - get_simple4_table_printable_row(row)) >> + get_simple4_table_printable_row(row), >> + terse) >> n += 1 >> >> if "simple5" in idl.tables: >> simple5 = idl.tables["simple5"].rows >> for row in simple5.values(): >> print_row("simple5", row, step, >> - get_simple5_table_printable_row(row)) >> + get_simple5_table_printable_row(row), >> + terse) >> n += 1 >> >> if "simple6" in idl.tables: >> simple6 = idl.tables["simple6"].rows >> for row in simple6.values(): >> print_row("simple6", row, step, >> - get_simple6_table_printable_row(row)) >> + get_simple6_table_printable_row(row), >> + terse) >> n += 1 >> >> if "link1" in idl.tables: >> l1 = idl.tables["link1"].rows >> for row in l1.values(): >> print_row("link1", row, step, >> - get_link1_table_printable_row(row)) >> + get_link1_table_printable_row(row), >> + terse) >> n += 1 >> >> if "link2" in idl.tables: >> l2 = idl.tables["link2"].rows >> for row in l2.values(): >> print_row("link2", row, step, >> - get_link2_table_printable_row(row)) >> + get_link2_table_printable_row(row), >> + terse) >> n += 1 >> >> if "singleton" in idl.tables: >> sng = idl.tables["singleton"].rows >> for row in sng.values(): >> print_row("singleton", row, step, >> - get_singleton_table_printable_row(row)) >> + get_singleton_table_printable_row(row), >> + terse) >> n += 1 >> >> if not n: >> @@ -701,6 +713,12 @@ def do_idl(schema_file, remote, *commands): >> step += 1 >> >> for command in commands: >> + terse = False >> + if command.startswith("?"): >> + # We're only interested in terse table contents. >> + terse = True >> + command = command[1:] >> + >> if command.startswith("+"): >> # The previous transaction didn't change anything. >> command = command[1:] >> @@ -714,7 +732,7 @@ def do_idl(schema_file, remote, *commands): >> rpc.wait(poller) >> poller.block() >> >> - print_idl(idl, step) >> + print_idl(idl, step, terse) >> step += 1 >> >> seqno = idl.change_seqno >> >> _______________________________________________ >> dev mailing list >> dev@openvswitch.org <mailto:dev@openvswitch.org> >> https://mail.openvswitch.org/mailman/listinfo/ovs-dev > <https://mail.openvswitch.org/mailman/listinfo/ovs-dev>
On Thu, Jan 27, 2022 at 3:29 AM Dumitru Ceara <dceara@redhat.com> wrote: > > On 1/26/22 01:22, Han Zhou wrote: > > > > > > On Tue, Jan 11, 2022 at 8:38 AM Dumitru Ceara <dceara@redhat.com > > <mailto:dceara@redhat.com>> wrote: > >> > >> When reconnecting, if there are condition changes already sent to the > >> server but not yet acked, reset the db's 'last-id', esentially clearing > >> the local cache after reconnect. > >> > >> This is needed because the client cannot easily differentiate between > >> the following cases: > >> a. either the server already processed the requested monitor > >> condition change but the FSM was restarted before the > >> client was notified. In this case the client should > >> clear its local cache because it's out of sync with the > >> monitor view on the server side. > >> b. OR the server hasn't processed the requested monitor > >> condition change yet. > >> > >> Conditions changing at the same time with a reconnection happening are > >> rare so the performance impact of this patch should be minimal. > >> > >> Also, the tests are updated to cover the fact that we cannot control > >> which of the two scenarios ("a" and "b" above) are hit during the test. > >> > >> Reported-by: Maxime Coquelin <maxime.coquelin@redhat.com > > <mailto:maxime.coquelin@redhat.com>> > >> Signed-off-by: Dumitru Ceara <dceara@redhat.com > > <mailto:dceara@redhat.com>> > > > > Thanks Dumitru. Could you tell more details about how this problem is > > reproduced? Or are there test case failures because of this? > > Hi Han, > > Thanks for looking into this. > > Yes, Maxime reported that the test "2241: simple idl, monitor_cond_since, > cluster disconnect - C - tcp" would occasionally fail without this patch. > > > I still didn't understand how the problem would occur. When a client > > reconnects to the server, it should trigger the jsonrpc session > > recreation on the server side, so the monitor data for the session > > should be recreated, and so there shouldn't be "out of sync" view on the > > server side. Did I misunderstand? > > > Going through the test logs we see (simplified and edited, skipping the > less relevant parts): > > 0. initial contents of the "simple" table on the server side: > "row": {"i": 1, "r": 1.0, "b": true} > "row": {"i": 2, "r": 1.0, "b": true} > > 1. the client connects for the first time, gets schema, monitors _Server > database. > > 2. the client requests a monitor_cond_since, id=3: > method="monitor_cond_since", > params=[ > "idltest", > ["monid","idltest"], > {..."simple":[{"where":[false],"columns":["b","ba","i","ia","r","ra","s","sa","u","ua"]}],...}, > last_id=0 // last seen transaction id > ], id=3 > > 3. the server doesn't need to send any updates, nothing matches "false" > and replies, id=3: > result=[ > false, // requested "last_id" not found in history, will cause the > // client to flush in-memory contents > "13220f46-f13f-4f30-ab19-0af58699e0aa", // last known transaction ID, > // the client will store this > // locally in last_id > {}], id=3 > > 4. the client changes its conditions and sends a monitor_cond_change, > id=5: > params=[ > ["monid","idltest"],["monid","idltest"], > {"simple":[{"where":[["i","==",2]]}]}], id=5 > > --- > Client side view: > - simple table: empty > - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" > - acked-cond: "simple": false > - req-cond: "simple": {"where":[["i","==",2]]} > - new-cond: <none> > --- > > 5. this new condition matches one row in table "simple" so the server > sends an update which includes that row: > method="update3", > params=[ > ["monid","idltest"], > "13220f46-f13f-4f30-ab19-0af58699e0aa", > {"simple":{"fd500d06-8d0c-4149-9c69-2914538e07e5":{"insert":{"b":true,"r":1,"i":2}}}} > ] > > 6. the client inserts the row in its in-memory copy of the database, > last_id becomes "13220f46-f13f-4f30-ab19-0af58699e0aa". However, the > condition change is not yet acked by the server! > --- > Client side view: > - simple table: > - row: {"b":true,"r":1,"i":2} > - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" > - acked-cond: "simple": false > - req-cond: "simple": {"where":[["i","==",2]]} > - new-cond: <none> > --- > > 7. the client changes its conditions, doesn't send a monitor_cond_change > because there's already one in-flight, not yet acked. > --- > Client side view: > - simple table: > - row: {"b":true,"r":1,"i":2} > - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" > - acked-cond: "simple": false > - req-cond: "simple": {"where":[["i","==",2]]} > - new-cond: "simple": {"where":[["i","==",1]]} > --- > > 8. the connection goes down, ovsdb_cs_db_sync_condition() is called from > ovsdb_cs_restart_fsm(): > --- > Client side view: > - simple table: > - row: {"b":true,"r":1,"i":2} > - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" > - acked-cond: "simple": false > - req-cond: <none> > - new-cond: "simple": {"where":[["i","==",1]]} > --- > > 9. the client reconnects, gets schema, monitors _Server database, a new > monitor is setup on the server side. > > 10. the client requests a monitor_cond_since, id=9: > method="monitor_cond_since", > params=[ > "idltest", > ["monid","idltest"], > {..."simple":[{"where":[false],"columns":["b","ba","i","ia","r","ra","s","sa","u","ua"]}],...}, // last acked condition! > "13220f46-f13f-4f30-ab19-0af58699e0aa" // last seen transaction id > ], id=9 > > 11. the server processes the condition change, but it changed to "false" > so it shouldn't send any updates to the client because in the server's > view the client didn't receive any rows yet, so there's nothing to > delete. However, the last_id is _known_ by the server so it replies > with: > result=[ > true, // last_id was found so the client will NOT flush its > // in-memory db contents! > "13220f46-f13f-4f30-ab19-0af58699e0aa", // last_id > {}], id=9 > > 12. At this point the client side view is inconsistent, the row doesn't > match the acked condition and there's no other in-flight condition > change request: > --- > Client side view (INCONSISTENT): > - simple table: > - row: {"b":true,"r":1,"i":2} > - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" > - acked-cond: "simple": false > - req-cond: <none> > - new-cond: "simple": {"where":[["i","==",1]]} > --- > > 13. the client starts a transaction to update the row with i==1 and > change "r" to 2, id=11: > method="transact", > params=[ > "idltest", > {"where":[["i","==",1]],"row":{"r":2},"op":"update","table":"simple"} > ], id=11 > > 14. the server processes the transaction, the server sides contents become: > "row": {"i": 1, "r": 2.0, "b": true} > "row": {"i": 2, "r": 1.0, "b": true} > > The updated row doesn't match the client's condition (false) so the server only sends the txn result: > reply, result=[{"count":1}], id=11 > > 15. the client sends the new conditions (were stored in new-cond), sends > a monitor_cond_change, id=12: > method="monitor_cond_change", > params=[ > ["monid","idltest"],["monid","idltest"], > {"simple":[{"where":[["i","==",1]]}]}], > id=12 > > 16. the server processes the new condition, now the second row matches > the condition so the server sends the update3 message: > method="update3", > params=[ > ["monid","idltest"], > "ca9454d0-c013-440a-9c56-1dd2a4693bf7", > {"simple":{"f97bfbe1-1911-4d6f-89a1-b211cf3bb5dc":{"insert":{"b":true,"r":2,"i":1}}}} > ] > > 17. the server acks the condition change: > reply, result={}, id=12 > --- > Client side view (INCONSISTENT): > - simple table: > - row: {"b":true,"r":1,"i":2} > - row: {"b":true,"r":2,"i":1} > - last_id: "ca9454d0-c013-440a-9c56-1dd2a4693bf7" > - acked-cond: "simple": {"where":[["i","==",1]]} > - req-cond: <none> > - new-cond: <none> > --- > > The test fails here because it (correctly) expects the client to only > have the second row in its in-memory view of the database. > > I'm not sure of a better way to summarize this but I'm open to > suggestions about how to rephrase the commit message. > Thanks Dumitru for the details! Now I understand the problem. So it is indeed an inconsistency between the client's monitor-condition and its local data. The client thinks it has data of monitor condition A (the last acked condition), but the data already reflects monitor condition B (the unacked condition). Then any subsequent operations can lead to inconsistent results, and of course inconsistent with the server side view when the server creates a new session. The problem is in fact the data updates for the condition change and the ACK message of condition change are not atomic. If we could combine these two messages into one, then we wouldn't have this problem, right? That would require a protocol change, and I don't see any obvious reason to keep these as separate messages except for convenience probably. I am ok with this patch if we don't want to fix the protocol now. Acked-by: Han Zhou <hzhou@ovn.org> > > > > Thanks, > > Han > > > > Thanks, > Dumitru > > >> --- > >> Note: The python IDL is fixed in the following patch in order to make > >> this patch easier to backport. test-ovsdb.py is updated in this patch > >> to avoid having the python version of the test perma-failing if the > >> last patch in the series is not applied. > >> --- > >> lib/ovsdb-cs.c | 17 ++++++++++ > >> tests/ovsdb-idl.at <http://ovsdb-idl.at> | 4 +- > >> tests/test-ovsdb.c | 89 > > +++++++++++++++++++++++++++++---------------------- > >> tests/test-ovsdb.py | 46 ++++++++++++++++++-------- > >> 4 files changed, 102 insertions(+), 54 deletions(-) > >> > >> diff --git a/lib/ovsdb-cs.c b/lib/ovsdb-cs.c > >> index fcb6fe1b34be..a4457245aa2d 100644 > >> --- a/lib/ovsdb-cs.c > >> +++ b/lib/ovsdb-cs.c > >> @@ -1109,6 +1109,23 @@ ovsdb_cs_db_sync_condition(struct ovsdb_cs_db *db) > >> } > >> table->req_cond = NULL; > >> db->cond_changed = true; > >> + > >> + /* There are two cases: > >> + * a. either the server already processed the > > requested monitor > >> + * condition change but the FSM was restarted > > before the > >> + * client was notified. In this case the client > > should > >> + * clear its local cache because it's out of sync > > with the > >> + * monitor view on the server side. > >> + * > >> + * b. OR the server hasn't processed the requested > > monitor > >> + * condition change yet. > >> + * > >> + * As there's no easy way to differentiate between > > the two, > >> + * and given that this condition should be rare, > > reset the > >> + * 'last_id', essentially flushing the local cached DB > >> + * contents. > >> + */ > >> + db->last_id = UUID_ZERO; > >> } > >> } > >> } > >> diff --git a/tests/ovsdb-idl.at <http://ovsdb-idl.at> > > b/tests/ovsdb-idl.at <http://ovsdb-idl.at> > >> index 86a75f920379..62e2b638320c 100644 > >> --- a/tests/ovsdb-idl.at <http://ovsdb-idl.at> > >> +++ b/tests/ovsdb-idl.at <http://ovsdb-idl.at> > >> @@ -2336,7 +2336,7 @@ OVSDB_CHECK_CLUSTER_IDL([simple idl, > > monitor_cond_since, cluster disconnect], > >> 'condition simple [["i","==",2]]' \ > >> 'condition simple [["i","==",1]]' \ > >> '+reconnect' \ > >> - '["idltest", > >> + '?["idltest", > >> {"op": "update", > >> "table": "simple", > >> "where": [["i", "==", 1]], > >> @@ -2347,7 +2347,7 @@ OVSDB_CHECK_CLUSTER_IDL([simple idl, > > monitor_cond_since, cluster disconnect], > >> 003: table simple: i=2 r=1 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] > > ua=[] uuid=<1> > >> 004: change conditions > >> 005: reconnect > >> -006: table simple: i=2 r=1 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] > > ua=[] uuid=<1> > >> +006: table simple > >> 007: {"error":null,"result":[{"count":1}]} > >> 008: table simple: i=1 r=2 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] > > ua=[] uuid=<2> > >> 009: done > >> diff --git a/tests/test-ovsdb.c b/tests/test-ovsdb.c > >> index a40318c7dba9..ca4e87b8115c 100644 > >> --- a/tests/test-ovsdb.c > >> +++ b/tests/test-ovsdb.c > >> @@ -1879,7 +1879,8 @@ print_and_log(const char *format, ...) > >> } > >> > >> static char * > >> -format_idl_row(const struct ovsdb_idl_row *row, int step, const char > > *contents) > >> +format_idl_row(const struct ovsdb_idl_row *row, int step, const char > > *contents, > >> + bool terse) > >> { > >> const char *change_str = > >> !ovsdb_idl_track_is_set(row->table) > >> @@ -1890,9 +1891,13 @@ format_idl_row(const struct ovsdb_idl_row *row, > > int step, const char *contents) > >> ? "deleted row: " > >> : ""; > >> > >> - return xasprintf("%03d: table %s: %s%s uuid=" UUID_FMT, > >> - step, row->table->class_->name, change_str, > > contents, > >> - UUID_ARGS(&row->uuid)); > >> + if (terse) { > >> + return xasprintf("%03d: table %s", step, > > row->table->class_->name); > >> + } else { > >> + return xasprintf("%03d: table %s: %s%s uuid=" UUID_FMT, > >> + step, row->table->class_->name, change_str, > >> + contents, UUID_ARGS(&row->uuid)); > >> + } > >> } > >> > >> static void > >> @@ -2015,7 +2020,7 @@ print_idl_row_updated_singleton(const struct > > idltest_singleton *sng, int step) > >> } > >> > >> static void > >> -print_idl_row_simple(const struct idltest_simple *s, int step) > >> +print_idl_row_simple(const struct idltest_simple *s, int step, bool > > terse) > >> { > >> struct ds msg = DS_EMPTY_INITIALIZER; > >> ds_put_format(&msg, "i=%"PRId64" r=%g b=%s s=%s u="UUID_FMT" ia=[", > >> @@ -2042,7 +2047,7 @@ print_idl_row_simple(const struct idltest_simple > > *s, int step) > >> } > >> ds_put_cstr(&msg, "]"); > >> > >> - char *row_msg = format_idl_row(&s->header_, step, ds_cstr(&msg)); > >> + char *row_msg = format_idl_row(&s->header_, step, ds_cstr(&msg), > > terse); > >> print_and_log("%s", row_msg); > >> ds_destroy(&msg); > >> free(row_msg); > >> @@ -2051,7 +2056,7 @@ print_idl_row_simple(const struct idltest_simple > > *s, int step) > >> } > >> > >> static void > >> -print_idl_row_link1(const struct idltest_link1 *l1, int step) > >> +print_idl_row_link1(const struct idltest_link1 *l1, int step, bool terse) > >> { > >> struct ds msg = DS_EMPTY_INITIALIZER; > >> ds_put_format(&msg, "i=%"PRId64" k=", l1->i); > >> @@ -2070,7 +2075,7 @@ print_idl_row_link1(const struct idltest_link1 > > *l1, int step) > >> ds_put_format(&msg, "%"PRId64, l1->l2->i); > >> } > >> > >> - char *row_msg = format_idl_row(&l1->header_, step, ds_cstr(&msg)); > >> + char *row_msg = format_idl_row(&l1->header_, step, ds_cstr(&msg), > > terse); > >> print_and_log("%s", row_msg); > >> ds_destroy(&msg); > >> free(row_msg); > >> @@ -2079,7 +2084,7 @@ print_idl_row_link1(const struct idltest_link1 > > *l1, int step) > >> } > >> > >> static void > >> -print_idl_row_link2(const struct idltest_link2 *l2, int step) > >> +print_idl_row_link2(const struct idltest_link2 *l2, int step, bool terse) > >> { > >> struct ds msg = DS_EMPTY_INITIALIZER; > >> ds_put_format(&msg, "i=%"PRId64" l1=", l2->i); > >> @@ -2087,7 +2092,7 @@ print_idl_row_link2(const struct idltest_link2 > > *l2, int step) > >> ds_put_format(&msg, "%"PRId64, l2->l1->i); > >> } > >> > >> - char *row_msg = format_idl_row(&l2->header_, step, ds_cstr(&msg)); > >> + char *row_msg = format_idl_row(&l2->header_, step, ds_cstr(&msg), > > terse); > >> print_and_log("%s", row_msg); > >> ds_destroy(&msg); > >> free(row_msg); > >> @@ -2096,7 +2101,7 @@ print_idl_row_link2(const struct idltest_link2 > > *l2, int step) > >> } > >> > >> static void > >> -print_idl_row_simple3(const struct idltest_simple3 *s3, int step) > >> +print_idl_row_simple3(const struct idltest_simple3 *s3, int step, > > bool terse) > >> { > >> struct ds msg = DS_EMPTY_INITIALIZER; > >> size_t i; > >> @@ -2115,7 +2120,7 @@ print_idl_row_simple3(const struct > > idltest_simple3 *s3, int step) > >> } > >> ds_put_cstr(&msg, "]"); > >> > >> - char *row_msg = format_idl_row(&s3->header_, step, ds_cstr(&msg)); > >> + char *row_msg = format_idl_row(&s3->header_, step, ds_cstr(&msg), > > terse); > >> print_and_log("%s", row_msg); > >> ds_destroy(&msg); > >> free(row_msg); > >> @@ -2124,12 +2129,12 @@ print_idl_row_simple3(const struct > > idltest_simple3 *s3, int step) > >> } > >> > >> static void > >> -print_idl_row_simple4(const struct idltest_simple4 *s4, int step) > >> +print_idl_row_simple4(const struct idltest_simple4 *s4, int step, > > bool terse) > >> { > >> struct ds msg = DS_EMPTY_INITIALIZER; > >> ds_put_format(&msg, "name=%s", s4->name); > >> > >> - char *row_msg = format_idl_row(&s4->header_, step, ds_cstr(&msg)); > >> + char *row_msg = format_idl_row(&s4->header_, step, ds_cstr(&msg), > > terse); > >> print_and_log("%s", row_msg); > >> ds_destroy(&msg); > >> free(row_msg); > >> @@ -2138,7 +2143,7 @@ print_idl_row_simple4(const struct > > idltest_simple4 *s4, int step) > >> } > >> > >> static void > >> -print_idl_row_simple6(const struct idltest_simple6 *s6, int step) > >> +print_idl_row_simple6(const struct idltest_simple6 *s6, int step, > > bool terse) > >> { > >> struct ds msg = DS_EMPTY_INITIALIZER; > >> ds_put_format(&msg, "name=%s ", s6->name); > >> @@ -2149,7 +2154,7 @@ print_idl_row_simple6(const struct > > idltest_simple6 *s6, int step) > >> } > >> ds_put_cstr(&msg, "]"); > >> > >> - char *row_msg = format_idl_row(&s6->header_, step, ds_cstr(&msg)); > >> + char *row_msg = format_idl_row(&s6->header_, step, ds_cstr(&msg), > > terse); > >> print_and_log("%s", row_msg); > >> ds_destroy(&msg); > >> free(row_msg); > >> @@ -2158,12 +2163,13 @@ print_idl_row_simple6(const struct > > idltest_simple6 *s6, int step) > >> } > >> > >> static void > >> -print_idl_row_singleton(const struct idltest_singleton *sng, int step) > >> +print_idl_row_singleton(const struct idltest_singleton *sng, int step, > >> + bool terse) > >> { > >> struct ds msg = DS_EMPTY_INITIALIZER; > >> ds_put_format(&msg, "name=%s", sng->name); > >> > >> - char *row_msg = format_idl_row(&sng->header_, step, ds_cstr(&msg)); > >> + char *row_msg = format_idl_row(&sng->header_, step, > > ds_cstr(&msg), terse); > >> print_and_log("%s", row_msg); > >> ds_destroy(&msg); > >> free(row_msg); > >> @@ -2172,7 +2178,7 @@ print_idl_row_singleton(const struct > > idltest_singleton *sng, int step) > >> } > >> > >> static void > >> -print_idl(struct ovsdb_idl *idl, int step) > >> +print_idl(struct ovsdb_idl *idl, int step, bool terse) > >> { > >> const struct idltest_simple3 *s3; > >> const struct idltest_simple4 *s4; > >> @@ -2184,31 +2190,31 @@ print_idl(struct ovsdb_idl *idl, int step) > >> int n = 0; > >> > >> IDLTEST_SIMPLE_FOR_EACH (s, idl) { > >> - print_idl_row_simple(s, step); > >> + print_idl_row_simple(s, step, terse); > >> n++; > >> } > >> IDLTEST_LINK1_FOR_EACH (l1, idl) { > >> - print_idl_row_link1(l1, step); > >> + print_idl_row_link1(l1, step, terse); > >> n++; > >> } > >> IDLTEST_LINK2_FOR_EACH (l2, idl) { > >> - print_idl_row_link2(l2, step); > >> + print_idl_row_link2(l2, step, terse); > >> n++; > >> } > >> IDLTEST_SIMPLE3_FOR_EACH (s3, idl) { > >> - print_idl_row_simple3(s3, step); > >> + print_idl_row_simple3(s3, step, terse); > >> n++; > >> } > >> IDLTEST_SIMPLE4_FOR_EACH (s4, idl) { > >> - print_idl_row_simple4(s4, step); > >> + print_idl_row_simple4(s4, step, terse); > >> n++; > >> } > >> IDLTEST_SIMPLE6_FOR_EACH (s6, idl) { > >> - print_idl_row_simple6(s6, step); > >> + print_idl_row_simple6(s6, step, terse); > >> n++; > >> } > >> IDLTEST_SINGLETON_FOR_EACH (sng, idl) { > >> - print_idl_row_singleton(sng, step); > >> + print_idl_row_singleton(sng, step, terse); > >> n++; > >> } > >> if (!n) { > >> @@ -2217,7 +2223,7 @@ print_idl(struct ovsdb_idl *idl, int step) > >> } > >> > >> static void > >> -print_idl_track(struct ovsdb_idl *idl, int step) > >> +print_idl_track(struct ovsdb_idl *idl, int step, bool terse) > >> { > >> const struct idltest_simple3 *s3; > >> const struct idltest_simple4 *s4; > >> @@ -2228,27 +2234,27 @@ print_idl_track(struct ovsdb_idl *idl, int step) > >> int n = 0; > >> > >> IDLTEST_SIMPLE_FOR_EACH_TRACKED (s, idl) { > >> - print_idl_row_simple(s, step); > >> + print_idl_row_simple(s, step, terse); > >> n++; > >> } > >> IDLTEST_LINK1_FOR_EACH_TRACKED (l1, idl) { > >> - print_idl_row_link1(l1, step); > >> + print_idl_row_link1(l1, step, terse); > >> n++; > >> } > >> IDLTEST_LINK2_FOR_EACH_TRACKED (l2, idl) { > >> - print_idl_row_link2(l2, step); > >> + print_idl_row_link2(l2, step, terse); > >> n++; > >> } > >> IDLTEST_SIMPLE3_FOR_EACH_TRACKED (s3, idl) { > >> - print_idl_row_simple3(s3, step); > >> + print_idl_row_simple3(s3, step, terse); > >> n++; > >> } > >> IDLTEST_SIMPLE4_FOR_EACH_TRACKED (s4, idl) { > >> - print_idl_row_simple4(s4, step); > >> + print_idl_row_simple4(s4, step, terse); > >> n++; > >> } > >> IDLTEST_SIMPLE6_FOR_EACH_TRACKED (s6, idl) { > >> - print_idl_row_simple6(s6, step); > >> + print_idl_row_simple6(s6, step, terse); > >> n++; > >> } > >> > >> @@ -2651,6 +2657,13 @@ do_idl(struct ovs_cmdl_context *ctx) > >> char *arg = ctx->argv[i]; > >> struct jsonrpc_msg *request, *reply; > >> > >> + bool terse = false; > >> + if (*arg == '?') { > >> + /* We're only interested in terse table contents. */ > >> + terse = true; > >> + arg++; > >> + } > >> + > >> if (*arg == '+') { > >> /* The previous transaction didn't change anything. */ > >> arg++; > >> @@ -2671,10 +2684,10 @@ do_idl(struct ovs_cmdl_context *ctx) > >> > >> /* Print update. */ > >> if (track) { > >> - print_idl_track(idl, step++); > >> + print_idl_track(idl, step++, terse); > >> ovsdb_idl_track_clear(idl); > >> } else { > >> - print_idl(idl, step++); > >> + print_idl(idl, step++, terse); > >> } > >> } > >> seqno = ovsdb_idl_get_seqno(idl); > >> @@ -2727,7 +2740,7 @@ do_idl(struct ovs_cmdl_context *ctx) > >> ovsdb_idl_wait(idl); > >> poll_block(); > >> } > >> - print_idl(idl, step++); > >> + print_idl(idl, step++, false); > >> ovsdb_idl_track_clear(idl); > >> ovsdb_idl_destroy(idl); > >> print_and_log("%03d: done", step); > >> @@ -2849,7 +2862,7 @@ dump_simple3(struct ovsdb_idl *idl, > >> int step) > >> { > >> IDLTEST_SIMPLE3_FOR_EACH(myRow, idl) { > >> - print_idl_row_simple3(myRow, step); > >> + print_idl_row_simple3(myRow, step, false); > >> } > >> } > >> > >> @@ -2991,7 +3004,7 @@ do_idl_compound_index_with_ref(struct > > ovs_cmdl_context *ctx) > >> idltest_simple3_index_set_uref(equal, &myRow2, 1); > >> printf("%03d: Query using index with reference\n", step++); > >> IDLTEST_SIMPLE3_FOR_EACH_EQUAL (myRow, equal, index) { > >> - print_idl_row_simple3(myRow, step++); > >> + print_idl_row_simple3(myRow, step++, false); > >> } > >> idltest_simple3_index_destroy_row(equal); > >> > >> diff --git a/tests/test-ovsdb.py b/tests/test-ovsdb.py > >> index 5bc0bf681425..853264f22bdc 100644 > >> --- a/tests/test-ovsdb.py > >> +++ b/tests/test-ovsdb.py > >> @@ -232,75 +232,87 @@ def get_singleton_table_printable_row(row): > >> return "name=%s" % row.name <http://row.name> > >> > >> > >> -def print_row(table, row, step, contents): > >> - s = "%03d: table %s: %s " % (step, table, contents) > >> - s += get_simple_printable_row_string(row, ["uuid"]) > >> +def print_row(table, row, step, contents, terse): > >> + if terse: > >> + s = "%03d: table %s" % (step, table) > >> + else: > >> + s = "%03d: table %s: %s " % (step, table, contents) > >> + s += get_simple_printable_row_string(row, ["uuid"]) > >> print(s) > >> > >> > >> -def print_idl(idl, step): > >> +def print_idl(idl, step, terse=False): > >> n = 0 > >> if "simple" in idl.tables: > >> simple = idl.tables["simple"].rows > >> for row in simple.values(): > >> print_row("simple", row, step, > >> - get_simple_table_printable_row(row)) > >> + get_simple_table_printable_row(row), > >> + terse) > >> n += 1 > >> > >> if "simple2" in idl.tables: > >> simple2 = idl.tables["simple2"].rows > >> for row in simple2.values(): > >> print_row("simple2", row, step, > >> - get_simple2_table_printable_row(row)) > >> + get_simple2_table_printable_row(row), > >> + terse) > >> n += 1 > >> > >> if "simple3" in idl.tables: > >> simple3 = idl.tables["simple3"].rows > >> for row in simple3.values(): > >> print_row("simple3", row, step, > >> - get_simple3_table_printable_row(row)) > >> + get_simple3_table_printable_row(row), > >> + terse) > >> n += 1 > >> > >> if "simple4" in idl.tables: > >> simple4 = idl.tables["simple4"].rows > >> for row in simple4.values(): > >> print_row("simple4", row, step, > >> - get_simple4_table_printable_row(row)) > >> + get_simple4_table_printable_row(row), > >> + terse) > >> n += 1 > >> > >> if "simple5" in idl.tables: > >> simple5 = idl.tables["simple5"].rows > >> for row in simple5.values(): > >> print_row("simple5", row, step, > >> - get_simple5_table_printable_row(row)) > >> + get_simple5_table_printable_row(row), > >> + terse) > >> n += 1 > >> > >> if "simple6" in idl.tables: > >> simple6 = idl.tables["simple6"].rows > >> for row in simple6.values(): > >> print_row("simple6", row, step, > >> - get_simple6_table_printable_row(row)) > >> + get_simple6_table_printable_row(row), > >> + terse) > >> n += 1 > >> > >> if "link1" in idl.tables: > >> l1 = idl.tables["link1"].rows > >> for row in l1.values(): > >> print_row("link1", row, step, > >> - get_link1_table_printable_row(row)) > >> + get_link1_table_printable_row(row), > >> + terse) > >> n += 1 > >> > >> if "link2" in idl.tables: > >> l2 = idl.tables["link2"].rows > >> for row in l2.values(): > >> print_row("link2", row, step, > >> - get_link2_table_printable_row(row)) > >> + get_link2_table_printable_row(row), > >> + terse) > >> n += 1 > >> > >> if "singleton" in idl.tables: > >> sng = idl.tables["singleton"].rows > >> for row in sng.values(): > >> print_row("singleton", row, step, > >> - get_singleton_table_printable_row(row)) > >> + get_singleton_table_printable_row(row), > >> + terse) > >> n += 1 > >> > >> if not n: > >> @@ -701,6 +713,12 @@ def do_idl(schema_file, remote, *commands): > >> step += 1 > >> > >> for command in commands: > >> + terse = False > >> + if command.startswith("?"): > >> + # We're only interested in terse table contents. > >> + terse = True > >> + command = command[1:] > >> + > >> if command.startswith("+"): > >> # The previous transaction didn't change anything. > >> command = command[1:] > >> @@ -714,7 +732,7 @@ def do_idl(schema_file, remote, *commands): > >> rpc.wait(poller) > >> poller.block() > >> > >> - print_idl(idl, step) > >> + print_idl(idl, step, terse) > >> step += 1 > >> > >> seqno = idl.change_seqno > >> > >> _______________________________________________ > >> dev mailing list > >> dev@openvswitch.org <mailto:dev@openvswitch.org> > >> https://mail.openvswitch.org/mailman/listinfo/ovs-dev > > <https://mail.openvswitch.org/mailman/listinfo/ovs-dev> >
On 1/27/22 19:09, Han Zhou wrote: > On Thu, Jan 27, 2022 at 3:29 AM Dumitru Ceara <dceara@redhat.com> wrote: >> >> On 1/26/22 01:22, Han Zhou wrote: >>> >>> >>> On Tue, Jan 11, 2022 at 8:38 AM Dumitru Ceara <dceara@redhat.com >>> <mailto:dceara@redhat.com>> wrote: >>>> >>>> When reconnecting, if there are condition changes already sent to the >>>> server but not yet acked, reset the db's 'last-id', esentially clearing >>>> the local cache after reconnect. >>>> >>>> This is needed because the client cannot easily differentiate between >>>> the following cases: >>>> a. either the server already processed the requested monitor >>>> condition change but the FSM was restarted before the >>>> client was notified. In this case the client should >>>> clear its local cache because it's out of sync with the >>>> monitor view on the server side. >>>> b. OR the server hasn't processed the requested monitor >>>> condition change yet. >>>> >>>> Conditions changing at the same time with a reconnection happening are >>>> rare so the performance impact of this patch should be minimal. >>>> >>>> Also, the tests are updated to cover the fact that we cannot control >>>> which of the two scenarios ("a" and "b" above) are hit during the test. >>>> >>>> Reported-by: Maxime Coquelin <maxime.coquelin@redhat.com >>> <mailto:maxime.coquelin@redhat.com>> >>>> Signed-off-by: Dumitru Ceara <dceara@redhat.com >>> <mailto:dceara@redhat.com>> >>> >>> Thanks Dumitru. Could you tell more details about how this problem is >>> reproduced? Or are there test case failures because of this? >> >> Hi Han, >> >> Thanks for looking into this. >> >> Yes, Maxime reported that the test "2241: simple idl, monitor_cond_since, >> cluster disconnect - C - tcp" would occasionally fail without this patch. >> >>> I still didn't understand how the problem would occur. When a client >>> reconnects to the server, it should trigger the jsonrpc session >>> recreation on the server side, so the monitor data for the session >>> should be recreated, and so there shouldn't be "out of sync" view on the >>> server side. Did I misunderstand? >> >> >> Going through the test logs we see (simplified and edited, skipping the >> less relevant parts): >> >> 0. initial contents of the "simple" table on the server side: >> "row": {"i": 1, "r": 1.0, "b": true} >> "row": {"i": 2, "r": 1.0, "b": true} >> >> 1. the client connects for the first time, gets schema, monitors _Server >> database. >> >> 2. the client requests a monitor_cond_since, id=3: >> method="monitor_cond_since", >> params=[ >> "idltest", >> ["monid","idltest"], >> > {..."simple":[{"where":[false],"columns":["b","ba","i","ia","r","ra","s","sa","u","ua"]}],...}, >> last_id=0 // last seen transaction id >> ], id=3 >> >> 3. the server doesn't need to send any updates, nothing matches "false" >> and replies, id=3: >> result=[ >> false, // requested "last_id" not found in history, will cause the >> // client to flush in-memory contents >> "13220f46-f13f-4f30-ab19-0af58699e0aa", // last known transaction ID, >> // the client will store this >> // locally in last_id >> {}], id=3 >> >> 4. the client changes its conditions and sends a monitor_cond_change, >> id=5: >> params=[ >> ["monid","idltest"],["monid","idltest"], >> {"simple":[{"where":[["i","==",2]]}]}], id=5 >> >> --- >> Client side view: >> - simple table: empty >> - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" >> - acked-cond: "simple": false >> - req-cond: "simple": {"where":[["i","==",2]]} >> - new-cond: <none> >> --- >> >> 5. this new condition matches one row in table "simple" so the server >> sends an update which includes that row: >> method="update3", >> params=[ >> ["monid","idltest"], >> "13220f46-f13f-4f30-ab19-0af58699e0aa", >> > {"simple":{"fd500d06-8d0c-4149-9c69-2914538e07e5":{"insert":{"b":true,"r":1,"i":2}}}} >> ] >> >> 6. the client inserts the row in its in-memory copy of the database, >> last_id becomes "13220f46-f13f-4f30-ab19-0af58699e0aa". However, the >> condition change is not yet acked by the server! >> --- >> Client side view: >> - simple table: >> - row: {"b":true,"r":1,"i":2} >> - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" >> - acked-cond: "simple": false >> - req-cond: "simple": {"where":[["i","==",2]]} >> - new-cond: <none> >> --- >> >> 7. the client changes its conditions, doesn't send a monitor_cond_change >> because there's already one in-flight, not yet acked. >> --- >> Client side view: >> - simple table: >> - row: {"b":true,"r":1,"i":2} >> - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" >> - acked-cond: "simple": false >> - req-cond: "simple": {"where":[["i","==",2]]} >> - new-cond: "simple": {"where":[["i","==",1]]} >> --- >> >> 8. the connection goes down, ovsdb_cs_db_sync_condition() is called from >> ovsdb_cs_restart_fsm(): >> --- >> Client side view: >> - simple table: >> - row: {"b":true,"r":1,"i":2} >> - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" >> - acked-cond: "simple": false >> - req-cond: <none> >> - new-cond: "simple": {"where":[["i","==",1]]} >> --- >> >> 9. the client reconnects, gets schema, monitors _Server database, a new >> monitor is setup on the server side. >> >> 10. the client requests a monitor_cond_since, id=9: >> method="monitor_cond_since", >> params=[ >> "idltest", >> ["monid","idltest"], >> > {..."simple":[{"where":[false],"columns":["b","ba","i","ia","r","ra","s","sa","u","ua"]}],...}, > // last acked condition! >> "13220f46-f13f-4f30-ab19-0af58699e0aa" // last seen transaction id >> ], id=9 >> >> 11. the server processes the condition change, but it changed to "false" >> so it shouldn't send any updates to the client because in the server's >> view the client didn't receive any rows yet, so there's nothing to >> delete. However, the last_id is _known_ by the server so it replies >> with: >> result=[ >> true, // last_id was found so the client will NOT flush its >> // in-memory db contents! >> "13220f46-f13f-4f30-ab19-0af58699e0aa", // last_id >> {}], id=9 >> >> 12. At this point the client side view is inconsistent, the row doesn't >> match the acked condition and there's no other in-flight condition >> change request: >> --- >> Client side view (INCONSISTENT): >> - simple table: >> - row: {"b":true,"r":1,"i":2} >> - last_id: "13220f46-f13f-4f30-ab19-0af58699e0aa" >> - acked-cond: "simple": false >> - req-cond: <none> >> - new-cond: "simple": {"where":[["i","==",1]]} >> --- >> >> 13. the client starts a transaction to update the row with i==1 and >> change "r" to 2, id=11: >> method="transact", >> params=[ >> "idltest", >> {"where":[["i","==",1]],"row":{"r":2},"op":"update","table":"simple"} >> ], id=11 >> >> 14. the server processes the transaction, the server sides contents > become: >> "row": {"i": 1, "r": 2.0, "b": true} >> "row": {"i": 2, "r": 1.0, "b": true} >> >> The updated row doesn't match the client's condition (false) so the > server only sends the txn result: >> reply, result=[{"count":1}], id=11 >> >> 15. the client sends the new conditions (were stored in new-cond), sends >> a monitor_cond_change, id=12: >> method="monitor_cond_change", >> params=[ >> ["monid","idltest"],["monid","idltest"], >> {"simple":[{"where":[["i","==",1]]}]}], >> id=12 >> >> 16. the server processes the new condition, now the second row matches >> the condition so the server sends the update3 message: >> method="update3", >> params=[ >> ["monid","idltest"], >> "ca9454d0-c013-440a-9c56-1dd2a4693bf7", >> > {"simple":{"f97bfbe1-1911-4d6f-89a1-b211cf3bb5dc":{"insert":{"b":true,"r":2,"i":1}}}} >> ] >> >> 17. the server acks the condition change: >> reply, result={}, id=12 >> --- >> Client side view (INCONSISTENT): >> - simple table: >> - row: {"b":true,"r":1,"i":2} >> - row: {"b":true,"r":2,"i":1} >> - last_id: "ca9454d0-c013-440a-9c56-1dd2a4693bf7" >> - acked-cond: "simple": {"where":[["i","==",1]]} >> - req-cond: <none> >> - new-cond: <none> >> --- >> >> The test fails here because it (correctly) expects the client to only >> have the second row in its in-memory view of the database. >> >> I'm not sure of a better way to summarize this but I'm open to >> suggestions about how to rephrase the commit message. >> > Thanks Dumitru for the details! Now I understand the problem. > So it is indeed an inconsistency between the client's monitor-condition and > its local data. The client thinks it has data of monitor condition A (the > last acked condition), but the data already reflects monitor condition B > (the unacked condition). Then any subsequent operations can lead to > inconsistent results, and of course inconsistent with the server side view > when the server creates a new session. > > The problem is in fact the data updates for the condition change and the > ACK message of condition change are not atomic. If we could combine these > two messages into one, then we wouldn't have this problem, right? That > would require a protocol change, and I don't see any obvious reason to keep > these as separate messages except for convenience probably. Well, in normal operation mode, there is eventual consistency, which is fine. But in the corner case of reconnecting while conditions are being changed this breaks. And this breaks only if last_id is still known on the server side. I'm not sure how easy it would be to make the protocol change without breaking existing deployments. Moreover, as mentioned in the commit log, I don't think the scenario described above is a very common case and the performance impact of the fix should be minimal. > > I am ok with this patch if we don't want to fix the protocol now. > Acked-by: Han Zhou <hzhou@ovn.org> > Thanks!
diff --git a/lib/ovsdb-cs.c b/lib/ovsdb-cs.c index fcb6fe1b34be..a4457245aa2d 100644 --- a/lib/ovsdb-cs.c +++ b/lib/ovsdb-cs.c @@ -1109,6 +1109,23 @@ ovsdb_cs_db_sync_condition(struct ovsdb_cs_db *db) } table->req_cond = NULL; db->cond_changed = true; + + /* There are two cases: + * a. either the server already processed the requested monitor + * condition change but the FSM was restarted before the + * client was notified. In this case the client should + * clear its local cache because it's out of sync with the + * monitor view on the server side. + * + * b. OR the server hasn't processed the requested monitor + * condition change yet. + * + * As there's no easy way to differentiate between the two, + * and given that this condition should be rare, reset the + * 'last_id', essentially flushing the local cached DB + * contents. + */ + db->last_id = UUID_ZERO; } } } diff --git a/tests/ovsdb-idl.at b/tests/ovsdb-idl.at index 86a75f920379..62e2b638320c 100644 --- a/tests/ovsdb-idl.at +++ b/tests/ovsdb-idl.at @@ -2336,7 +2336,7 @@ OVSDB_CHECK_CLUSTER_IDL([simple idl, monitor_cond_since, cluster disconnect], 'condition simple [["i","==",2]]' \ 'condition simple [["i","==",1]]' \ '+reconnect' \ - '["idltest", + '?["idltest", {"op": "update", "table": "simple", "where": [["i", "==", 1]], @@ -2347,7 +2347,7 @@ OVSDB_CHECK_CLUSTER_IDL([simple idl, monitor_cond_since, cluster disconnect], 003: table simple: i=2 r=1 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] ua=[] uuid=<1> 004: change conditions 005: reconnect -006: table simple: i=2 r=1 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] ua=[] uuid=<1> +006: table simple 007: {"error":null,"result":[{"count":1}]} 008: table simple: i=1 r=2 b=true s= u=<0> ia=[] ra=[] ba=[] sa=[] ua=[] uuid=<2> 009: done diff --git a/tests/test-ovsdb.c b/tests/test-ovsdb.c index a40318c7dba9..ca4e87b8115c 100644 --- a/tests/test-ovsdb.c +++ b/tests/test-ovsdb.c @@ -1879,7 +1879,8 @@ print_and_log(const char *format, ...) } static char * -format_idl_row(const struct ovsdb_idl_row *row, int step, const char *contents) +format_idl_row(const struct ovsdb_idl_row *row, int step, const char *contents, + bool terse) { const char *change_str = !ovsdb_idl_track_is_set(row->table) @@ -1890,9 +1891,13 @@ format_idl_row(const struct ovsdb_idl_row *row, int step, const char *contents) ? "deleted row: " : ""; - return xasprintf("%03d: table %s: %s%s uuid=" UUID_FMT, - step, row->table->class_->name, change_str, contents, - UUID_ARGS(&row->uuid)); + if (terse) { + return xasprintf("%03d: table %s", step, row->table->class_->name); + } else { + return xasprintf("%03d: table %s: %s%s uuid=" UUID_FMT, + step, row->table->class_->name, change_str, + contents, UUID_ARGS(&row->uuid)); + } } static void @@ -2015,7 +2020,7 @@ print_idl_row_updated_singleton(const struct idltest_singleton *sng, int step) } static void -print_idl_row_simple(const struct idltest_simple *s, int step) +print_idl_row_simple(const struct idltest_simple *s, int step, bool terse) { struct ds msg = DS_EMPTY_INITIALIZER; ds_put_format(&msg, "i=%"PRId64" r=%g b=%s s=%s u="UUID_FMT" ia=[", @@ -2042,7 +2047,7 @@ print_idl_row_simple(const struct idltest_simple *s, int step) } ds_put_cstr(&msg, "]"); - char *row_msg = format_idl_row(&s->header_, step, ds_cstr(&msg)); + char *row_msg = format_idl_row(&s->header_, step, ds_cstr(&msg), terse); print_and_log("%s", row_msg); ds_destroy(&msg); free(row_msg); @@ -2051,7 +2056,7 @@ print_idl_row_simple(const struct idltest_simple *s, int step) } static void -print_idl_row_link1(const struct idltest_link1 *l1, int step) +print_idl_row_link1(const struct idltest_link1 *l1, int step, bool terse) { struct ds msg = DS_EMPTY_INITIALIZER; ds_put_format(&msg, "i=%"PRId64" k=", l1->i); @@ -2070,7 +2075,7 @@ print_idl_row_link1(const struct idltest_link1 *l1, int step) ds_put_format(&msg, "%"PRId64, l1->l2->i); } - char *row_msg = format_idl_row(&l1->header_, step, ds_cstr(&msg)); + char *row_msg = format_idl_row(&l1->header_, step, ds_cstr(&msg), terse); print_and_log("%s", row_msg); ds_destroy(&msg); free(row_msg); @@ -2079,7 +2084,7 @@ print_idl_row_link1(const struct idltest_link1 *l1, int step) } static void -print_idl_row_link2(const struct idltest_link2 *l2, int step) +print_idl_row_link2(const struct idltest_link2 *l2, int step, bool terse) { struct ds msg = DS_EMPTY_INITIALIZER; ds_put_format(&msg, "i=%"PRId64" l1=", l2->i); @@ -2087,7 +2092,7 @@ print_idl_row_link2(const struct idltest_link2 *l2, int step) ds_put_format(&msg, "%"PRId64, l2->l1->i); } - char *row_msg = format_idl_row(&l2->header_, step, ds_cstr(&msg)); + char *row_msg = format_idl_row(&l2->header_, step, ds_cstr(&msg), terse); print_and_log("%s", row_msg); ds_destroy(&msg); free(row_msg); @@ -2096,7 +2101,7 @@ print_idl_row_link2(const struct idltest_link2 *l2, int step) } static void -print_idl_row_simple3(const struct idltest_simple3 *s3, int step) +print_idl_row_simple3(const struct idltest_simple3 *s3, int step, bool terse) { struct ds msg = DS_EMPTY_INITIALIZER; size_t i; @@ -2115,7 +2120,7 @@ print_idl_row_simple3(const struct idltest_simple3 *s3, int step) } ds_put_cstr(&msg, "]"); - char *row_msg = format_idl_row(&s3->header_, step, ds_cstr(&msg)); + char *row_msg = format_idl_row(&s3->header_, step, ds_cstr(&msg), terse); print_and_log("%s", row_msg); ds_destroy(&msg); free(row_msg); @@ -2124,12 +2129,12 @@ print_idl_row_simple3(const struct idltest_simple3 *s3, int step) } static void -print_idl_row_simple4(const struct idltest_simple4 *s4, int step) +print_idl_row_simple4(const struct idltest_simple4 *s4, int step, bool terse) { struct ds msg = DS_EMPTY_INITIALIZER; ds_put_format(&msg, "name=%s", s4->name); - char *row_msg = format_idl_row(&s4->header_, step, ds_cstr(&msg)); + char *row_msg = format_idl_row(&s4->header_, step, ds_cstr(&msg), terse); print_and_log("%s", row_msg); ds_destroy(&msg); free(row_msg); @@ -2138,7 +2143,7 @@ print_idl_row_simple4(const struct idltest_simple4 *s4, int step) } static void -print_idl_row_simple6(const struct idltest_simple6 *s6, int step) +print_idl_row_simple6(const struct idltest_simple6 *s6, int step, bool terse) { struct ds msg = DS_EMPTY_INITIALIZER; ds_put_format(&msg, "name=%s ", s6->name); @@ -2149,7 +2154,7 @@ print_idl_row_simple6(const struct idltest_simple6 *s6, int step) } ds_put_cstr(&msg, "]"); - char *row_msg = format_idl_row(&s6->header_, step, ds_cstr(&msg)); + char *row_msg = format_idl_row(&s6->header_, step, ds_cstr(&msg), terse); print_and_log("%s", row_msg); ds_destroy(&msg); free(row_msg); @@ -2158,12 +2163,13 @@ print_idl_row_simple6(const struct idltest_simple6 *s6, int step) } static void -print_idl_row_singleton(const struct idltest_singleton *sng, int step) +print_idl_row_singleton(const struct idltest_singleton *sng, int step, + bool terse) { struct ds msg = DS_EMPTY_INITIALIZER; ds_put_format(&msg, "name=%s", sng->name); - char *row_msg = format_idl_row(&sng->header_, step, ds_cstr(&msg)); + char *row_msg = format_idl_row(&sng->header_, step, ds_cstr(&msg), terse); print_and_log("%s", row_msg); ds_destroy(&msg); free(row_msg); @@ -2172,7 +2178,7 @@ print_idl_row_singleton(const struct idltest_singleton *sng, int step) } static void -print_idl(struct ovsdb_idl *idl, int step) +print_idl(struct ovsdb_idl *idl, int step, bool terse) { const struct idltest_simple3 *s3; const struct idltest_simple4 *s4; @@ -2184,31 +2190,31 @@ print_idl(struct ovsdb_idl *idl, int step) int n = 0; IDLTEST_SIMPLE_FOR_EACH (s, idl) { - print_idl_row_simple(s, step); + print_idl_row_simple(s, step, terse); n++; } IDLTEST_LINK1_FOR_EACH (l1, idl) { - print_idl_row_link1(l1, step); + print_idl_row_link1(l1, step, terse); n++; } IDLTEST_LINK2_FOR_EACH (l2, idl) { - print_idl_row_link2(l2, step); + print_idl_row_link2(l2, step, terse); n++; } IDLTEST_SIMPLE3_FOR_EACH (s3, idl) { - print_idl_row_simple3(s3, step); + print_idl_row_simple3(s3, step, terse); n++; } IDLTEST_SIMPLE4_FOR_EACH (s4, idl) { - print_idl_row_simple4(s4, step); + print_idl_row_simple4(s4, step, terse); n++; } IDLTEST_SIMPLE6_FOR_EACH (s6, idl) { - print_idl_row_simple6(s6, step); + print_idl_row_simple6(s6, step, terse); n++; } IDLTEST_SINGLETON_FOR_EACH (sng, idl) { - print_idl_row_singleton(sng, step); + print_idl_row_singleton(sng, step, terse); n++; } if (!n) { @@ -2217,7 +2223,7 @@ print_idl(struct ovsdb_idl *idl, int step) } static void -print_idl_track(struct ovsdb_idl *idl, int step) +print_idl_track(struct ovsdb_idl *idl, int step, bool terse) { const struct idltest_simple3 *s3; const struct idltest_simple4 *s4; @@ -2228,27 +2234,27 @@ print_idl_track(struct ovsdb_idl *idl, int step) int n = 0; IDLTEST_SIMPLE_FOR_EACH_TRACKED (s, idl) { - print_idl_row_simple(s, step); + print_idl_row_simple(s, step, terse); n++; } IDLTEST_LINK1_FOR_EACH_TRACKED (l1, idl) { - print_idl_row_link1(l1, step); + print_idl_row_link1(l1, step, terse); n++; } IDLTEST_LINK2_FOR_EACH_TRACKED (l2, idl) { - print_idl_row_link2(l2, step); + print_idl_row_link2(l2, step, terse); n++; } IDLTEST_SIMPLE3_FOR_EACH_TRACKED (s3, idl) { - print_idl_row_simple3(s3, step); + print_idl_row_simple3(s3, step, terse); n++; } IDLTEST_SIMPLE4_FOR_EACH_TRACKED (s4, idl) { - print_idl_row_simple4(s4, step); + print_idl_row_simple4(s4, step, terse); n++; } IDLTEST_SIMPLE6_FOR_EACH_TRACKED (s6, idl) { - print_idl_row_simple6(s6, step); + print_idl_row_simple6(s6, step, terse); n++; } @@ -2651,6 +2657,13 @@ do_idl(struct ovs_cmdl_context *ctx) char *arg = ctx->argv[i]; struct jsonrpc_msg *request, *reply; + bool terse = false; + if (*arg == '?') { + /* We're only interested in terse table contents. */ + terse = true; + arg++; + } + if (*arg == '+') { /* The previous transaction didn't change anything. */ arg++; @@ -2671,10 +2684,10 @@ do_idl(struct ovs_cmdl_context *ctx) /* Print update. */ if (track) { - print_idl_track(idl, step++); + print_idl_track(idl, step++, terse); ovsdb_idl_track_clear(idl); } else { - print_idl(idl, step++); + print_idl(idl, step++, terse); } } seqno = ovsdb_idl_get_seqno(idl); @@ -2727,7 +2740,7 @@ do_idl(struct ovs_cmdl_context *ctx) ovsdb_idl_wait(idl); poll_block(); } - print_idl(idl, step++); + print_idl(idl, step++, false); ovsdb_idl_track_clear(idl); ovsdb_idl_destroy(idl); print_and_log("%03d: done", step); @@ -2849,7 +2862,7 @@ dump_simple3(struct ovsdb_idl *idl, int step) { IDLTEST_SIMPLE3_FOR_EACH(myRow, idl) { - print_idl_row_simple3(myRow, step); + print_idl_row_simple3(myRow, step, false); } } @@ -2991,7 +3004,7 @@ do_idl_compound_index_with_ref(struct ovs_cmdl_context *ctx) idltest_simple3_index_set_uref(equal, &myRow2, 1); printf("%03d: Query using index with reference\n", step++); IDLTEST_SIMPLE3_FOR_EACH_EQUAL (myRow, equal, index) { - print_idl_row_simple3(myRow, step++); + print_idl_row_simple3(myRow, step++, false); } idltest_simple3_index_destroy_row(equal); diff --git a/tests/test-ovsdb.py b/tests/test-ovsdb.py index 5bc0bf681425..853264f22bdc 100644 --- a/tests/test-ovsdb.py +++ b/tests/test-ovsdb.py @@ -232,75 +232,87 @@ def get_singleton_table_printable_row(row): return "name=%s" % row.name -def print_row(table, row, step, contents): - s = "%03d: table %s: %s " % (step, table, contents) - s += get_simple_printable_row_string(row, ["uuid"]) +def print_row(table, row, step, contents, terse): + if terse: + s = "%03d: table %s" % (step, table) + else: + s = "%03d: table %s: %s " % (step, table, contents) + s += get_simple_printable_row_string(row, ["uuid"]) print(s) -def print_idl(idl, step): +def print_idl(idl, step, terse=False): n = 0 if "simple" in idl.tables: simple = idl.tables["simple"].rows for row in simple.values(): print_row("simple", row, step, - get_simple_table_printable_row(row)) + get_simple_table_printable_row(row), + terse) n += 1 if "simple2" in idl.tables: simple2 = idl.tables["simple2"].rows for row in simple2.values(): print_row("simple2", row, step, - get_simple2_table_printable_row(row)) + get_simple2_table_printable_row(row), + terse) n += 1 if "simple3" in idl.tables: simple3 = idl.tables["simple3"].rows for row in simple3.values(): print_row("simple3", row, step, - get_simple3_table_printable_row(row)) + get_simple3_table_printable_row(row), + terse) n += 1 if "simple4" in idl.tables: simple4 = idl.tables["simple4"].rows for row in simple4.values(): print_row("simple4", row, step, - get_simple4_table_printable_row(row)) + get_simple4_table_printable_row(row), + terse) n += 1 if "simple5" in idl.tables: simple5 = idl.tables["simple5"].rows for row in simple5.values(): print_row("simple5", row, step, - get_simple5_table_printable_row(row)) + get_simple5_table_printable_row(row), + terse) n += 1 if "simple6" in idl.tables: simple6 = idl.tables["simple6"].rows for row in simple6.values(): print_row("simple6", row, step, - get_simple6_table_printable_row(row)) + get_simple6_table_printable_row(row), + terse) n += 1 if "link1" in idl.tables: l1 = idl.tables["link1"].rows for row in l1.values(): print_row("link1", row, step, - get_link1_table_printable_row(row)) + get_link1_table_printable_row(row), + terse) n += 1 if "link2" in idl.tables: l2 = idl.tables["link2"].rows for row in l2.values(): print_row("link2", row, step, - get_link2_table_printable_row(row)) + get_link2_table_printable_row(row), + terse) n += 1 if "singleton" in idl.tables: sng = idl.tables["singleton"].rows for row in sng.values(): print_row("singleton", row, step, - get_singleton_table_printable_row(row)) + get_singleton_table_printable_row(row), + terse) n += 1 if not n: @@ -701,6 +713,12 @@ def do_idl(schema_file, remote, *commands): step += 1 for command in commands: + terse = False + if command.startswith("?"): + # We're only interested in terse table contents. + terse = True + command = command[1:] + if command.startswith("+"): # The previous transaction didn't change anything. command = command[1:] @@ -714,7 +732,7 @@ def do_idl(schema_file, remote, *commands): rpc.wait(poller) poller.block() - print_idl(idl, step) + print_idl(idl, step, terse) step += 1 seqno = idl.change_seqno
When reconnecting, if there are condition changes already sent to the server but not yet acked, reset the db's 'last-id', esentially clearing the local cache after reconnect. This is needed because the client cannot easily differentiate between the following cases: a. either the server already processed the requested monitor condition change but the FSM was restarted before the client was notified. In this case the client should clear its local cache because it's out of sync with the monitor view on the server side. b. OR the server hasn't processed the requested monitor condition change yet. Conditions changing at the same time with a reconnection happening are rare so the performance impact of this patch should be minimal. Also, the tests are updated to cover the fact that we cannot control which of the two scenarios ("a" and "b" above) are hit during the test. Reported-by: Maxime Coquelin <maxime.coquelin@redhat.com> Signed-off-by: Dumitru Ceara <dceara@redhat.com> --- Note: The python IDL is fixed in the following patch in order to make this patch easier to backport. test-ovsdb.py is updated in this patch to avoid having the python version of the test perma-failing if the last patch in the series is not applied. --- lib/ovsdb-cs.c | 17 ++++++++++ tests/ovsdb-idl.at | 4 +- tests/test-ovsdb.c | 89 +++++++++++++++++++++++++++++---------------------- tests/test-ovsdb.py | 46 ++++++++++++++++++-------- 4 files changed, 102 insertions(+), 54 deletions(-)