| Message ID | 1599002805-103574-3-git-send-email-hzhou@ovn.org |
|---|---|
| State | Accepted |
| Headers | show |
| Series | [ovs-dev,1/4] ovn-nbctl.8.xml: Fix section OVN_NBCTL_OPTIONS. | expand |
Bleep bloop. Greetings Han Zhou, I am a robot and I have tried out your patch. Thanks for your contribution. I encountered some error that I wasn't expecting. See the details below. checkpatch: WARNING: Line lacks whitespace around operator #124 FILE: utilities/ovn-nbctl.c:788: --print-wait-time print time spent on waiting\n\ Lines checked: 179, Warnings: 1, Errors: 0 Please check this out. If you feel there has been an error, please email aconole@redhat.com Thanks, 0-day Robot
On Wed, Sep 2, 2020 at 4:57 AM Han Zhou <hzhou@ovn.org> wrote: > This patch adds option --print-wait-time, which can be used together > with --wait=sb/hv to print the time spent on respective processing. > > For example: > $ ovn-nbctl --print-wait-time --wait=hv sync > Time spent on processing nb_cfg 392: > ovn-northd delay before processing: 1ms > ovn-northd completion: 32ms > ovn-controller(s) completion: 39ms > > Without this, we had to use "time" command to measure the total time > spent by the ovn-nbctl command. However, it doesn't refect the actual > control plane latency, because the nb_cfg updates from all hypervisors > to SB DB contributes a significant part to the time spent on waiting > by the ovn-nbctl command. This doesn't reflect the real production > scenario. With this option (and the timestamp support from the previous > commit), we can measure the exact time when hypervisors completed > SB DB change handling and enforcing to OVS. > > Signed-off-by: Han Zhou <hzhou@ovn.org> > Acked-by: Numan Siddique <numans@ovn.org> Thanks Numan > --- > tests/ovn.at | 3 +++ > utilities/ovn-nbctl.8.xml | 17 +++++++++++++++++ > utilities/ovn-nbctl.c | 38 +++++++++++++++++++++++++++++++++----- > 3 files changed, 53 insertions(+), 5 deletions(-) > > diff --git a/tests/ovn.at b/tests/ovn.at > index 55257c3..f238b66 100644 > --- a/tests/ovn.at > +++ b/tests/ovn.at > @@ -21451,6 +21451,9 @@ hv3_ts=$(ovn-sbctl --bare > --columns=nb_cfg_timestamp find chassis_private name=h > hv_cfg_ts=$(ovn-nbctl get nb_global . hv_cfg_timestamp) > AT_CHECK([test x$hv3_ts == x$hv_cfg_ts]) > > +AT_CHECK([test x$(ovn-nbctl --print-wait-time --wait=sb sync | grep ms | > wc -l) == x2]) > +AT_CHECK([test x$(ovn-nbctl --print-wait-time --wait=hv sync | grep ms | > wc -l) == x3]) > + > for i in $(seq 2 $n); do > OVN_CLEANUP_SBOX([hv$i]) > done > diff --git a/utilities/ovn-nbctl.8.xml b/utilities/ovn-nbctl.8.xml > index 07447d2..fcc4312 100644 > --- a/utilities/ovn-nbctl.8.xml > +++ b/utilities/ovn-nbctl.8.xml > @@ -1322,6 +1322,23 @@ > </p> > </dd> > > + <dt><code>--print-wait-time</code></dt> > + <dd> > + When <code>--wait</code> is specified, the option > + <code>--print-wait-time</code> can be used to print the time spent > on > + waiting, depending on the value specified in <code> --wait</code> > option. > + If <code>--wait=sb</code> is specified, it prints "ovn-northd delay > + before processing", which is the time between the Northbound DB > update by > + the command and the moment when <code> ovn-northd</code> starts > + processing the update, and "ovn-northd completion", which is the > time > + between the Northbound DB update and the moment when > + <code>ovn-northd</code> completes the Southbound DB updating > + successfully. If <code>--wait=hv</code> is specified, in addition > to the > + above information, it also prints "ovn-controller(s) completion", > which > + is the time between the Northbound DB update and the moment when the > + slowest hypervisor finishes processing the update. > + </dd> > + > <dt><code>--db</code> <var>database</var></dt> > <dd> > The OVSDB database remote to contact. If the <env>OVN_NB_DB</env> > diff --git a/utilities/ovn-nbctl.c b/utilities/ovn-nbctl.c > index d7bb4b4..57dfaa1 100644 > --- a/utilities/ovn-nbctl.c > +++ b/utilities/ovn-nbctl.c > @@ -63,6 +63,8 @@ enum nbctl_wait_type { > }; > static enum nbctl_wait_type wait_type = NBCTL_WAIT_NONE; > > +static bool print_wait_time = false; > + > /* Should we wait (if specified by 'wait_type') even if the commands don't > * change the database at all? */ > static bool force_wait = false; > @@ -302,14 +304,16 @@ main_loop(const char *args, struct ctl_command > *commands, size_t n_commands, > #define MAIN_LOOP_OPTION_ENUMS \ > OPT_NO_WAIT, \ > OPT_WAIT, \ > + OPT_PRINT_WAIT_TIME, \ > OPT_DRY_RUN, \ > OPT_ONELINE > > -#define MAIN_LOOP_LONG_OPTIONS \ > - {"no-wait", no_argument, NULL, OPT_NO_WAIT}, \ > - {"wait", required_argument, NULL, OPT_WAIT}, \ > - {"dry-run", no_argument, NULL, OPT_DRY_RUN}, \ > - {"oneline", no_argument, NULL, OPT_ONELINE}, \ > +#define MAIN_LOOP_LONG_OPTIONS \ > + {"no-wait", no_argument, NULL, OPT_NO_WAIT}, \ > + {"wait", required_argument, NULL, OPT_WAIT}, \ > + {"print-wait-time", no_argument, NULL, OPT_PRINT_WAIT_TIME}, \ > + {"dry-run", no_argument, NULL, OPT_DRY_RUN}, \ > + {"oneline", no_argument, NULL, OPT_ONELINE}, \ > {"timeout", required_argument, NULL, 't'} > > enum { > @@ -358,6 +362,10 @@ handle_main_loop_option(int opt, const char *arg, > bool *handled) > } > break; > > + case OPT_PRINT_WAIT_TIME: > + print_wait_time = true; > + break; > + > case OPT_DRY_RUN: > dry_run = true; > break; > @@ -777,6 +785,7 @@ Options:\n\ > --no-shuffle-remotes do not shuffle the order of remotes\n\ > --wait=sb wait for southbound database update\n\ > --wait=hv wait for all chassis to catch up\n\ > + --print-wait-time print time spent on waiting\n\ > -t, --timeout=SECS wait at most SECS seconds\n\ > --dry-run do not commit changes to database\n\ > --oneline print exactly one line of output per > command\n", > @@ -5992,8 +6001,10 @@ run_prerequisites(struct ctl_command *commands, > size_t n_commands, > ovsdb_idl_add_table(idl, &nbrec_table_nb_global); > if (wait_type == NBCTL_WAIT_SB) { > ovsdb_idl_add_column(idl, &nbrec_nb_global_col_sb_cfg); > + ovsdb_idl_add_column(idl, &nbrec_nb_global_col_sb_cfg_timestamp); > } else if (wait_type == NBCTL_WAIT_HV) { > ovsdb_idl_add_column(idl, &nbrec_nb_global_col_hv_cfg); > + ovsdb_idl_add_column(idl, &nbrec_nb_global_col_hv_cfg_timestamp); > } > > for (struct ctl_command *c = commands; c < &commands[n_commands]; > c++) { > @@ -6065,6 +6076,7 @@ do_nbctl(const char *args, struct ctl_command > *commands, size_t n_commands, > struct shash_node *node; > int64_t next_cfg = 0; > char *error = NULL; > + int64_t start_time = 0; > > ovs_assert(retry); > > @@ -6132,6 +6144,7 @@ do_nbctl(const char *args, struct ctl_command > *commands, size_t n_commands, > } > } > > + start_time = time_wall_msec(); > status = ovsdb_idl_txn_commit_block(txn); > if (wait_type != NBCTL_WAIT_NONE && status == TXN_SUCCESS) { > next_cfg = ovsdb_idl_txn_get_increment_new_value(txn); > @@ -6203,6 +6216,21 @@ do_nbctl(const char *args, struct ctl_command > *commands, size_t n_commands, > ? nb->sb_cfg > : nb->hv_cfg); > if (cur_cfg >= next_cfg) { > + if (print_wait_time) { > + printf("Time spent on processing nb_cfg > %"PRId64":\n", > + next_cfg); > + printf("\tovn-northd delay before processing:" > + "\t%"PRId64"ms\n", > + nb->nb_cfg_timestamp - start_time); > + printf("\tovn-northd completion:" > + "\t\t\t%"PRId64"ms\n", > + nb->sb_cfg_timestamp - start_time); > + if (wait_type == NBCTL_WAIT_HV) { > + printf("\tovn-controller(s) completion:" > + "\t\t%"PRId64"ms\n", > + nb->hv_cfg_timestamp - start_time); > + } > + } > goto done; > } > } > -- > 2.1.0 > > _______________________________________________ > dev mailing list > dev@openvswitch.org > https://mail.openvswitch.org/mailman/listinfo/ovs-dev > >
On Mon, Sep 7, 2020 at 10:57 AM Numan Siddique <numans@ovn.org> wrote: > > > On Wed, Sep 2, 2020 at 4:57 AM Han Zhou <hzhou@ovn.org> wrote: > >> This patch adds option --print-wait-time, which can be used together >> with --wait=sb/hv to print the time spent on respective processing. >> >> For example: >> $ ovn-nbctl --print-wait-time --wait=hv sync >> Time spent on processing nb_cfg 392: >> ovn-northd delay before processing: 1ms >> ovn-northd completion: 32ms >> ovn-controller(s) completion: 39ms >> >> Without this, we had to use "time" command to measure the total time >> spent by the ovn-nbctl command. However, it doesn't refect the actual >> control plane latency, because the nb_cfg updates from all hypervisors >> to SB DB contributes a significant part to the time spent on waiting >> by the ovn-nbctl command. This doesn't reflect the real production >> scenario. With this option (and the timestamp support from the previous >> commit), we can measure the exact time when hypervisors completed >> SB DB change handling and enforcing to OVS. >> >> Signed-off-by: Han Zhou <hzhou@ovn.org> >> > > Acked-by: Numan Siddique <numans@ovn.org> > > Thanks Numan. I applied this to master. > Thanks > Numan > > >> --- >> tests/ovn.at | 3 +++ >> utilities/ovn-nbctl.8.xml | 17 +++++++++++++++++ >> utilities/ovn-nbctl.c | 38 +++++++++++++++++++++++++++++++++----- >> 3 files changed, 53 insertions(+), 5 deletions(-) >> >> diff --git a/tests/ovn.at b/tests/ovn.at >> index 55257c3..f238b66 100644 >> --- a/tests/ovn.at >> +++ b/tests/ovn.at >> @@ -21451,6 +21451,9 @@ hv3_ts=$(ovn-sbctl --bare >> --columns=nb_cfg_timestamp find chassis_private name=h >> hv_cfg_ts=$(ovn-nbctl get nb_global . hv_cfg_timestamp) >> AT_CHECK([test x$hv3_ts == x$hv_cfg_ts]) >> >> +AT_CHECK([test x$(ovn-nbctl --print-wait-time --wait=sb sync | grep ms | >> wc -l) == x2]) >> +AT_CHECK([test x$(ovn-nbctl --print-wait-time --wait=hv sync | grep ms | >> wc -l) == x3]) >> + >> for i in $(seq 2 $n); do >> OVN_CLEANUP_SBOX([hv$i]) >> done >> diff --git a/utilities/ovn-nbctl.8.xml b/utilities/ovn-nbctl.8.xml >> index 07447d2..fcc4312 100644 >> --- a/utilities/ovn-nbctl.8.xml >> +++ b/utilities/ovn-nbctl.8.xml >> @@ -1322,6 +1322,23 @@ >> </p> >> </dd> >> >> + <dt><code>--print-wait-time</code></dt> >> + <dd> >> + When <code>--wait</code> is specified, the option >> + <code>--print-wait-time</code> can be used to print the time spent >> on >> + waiting, depending on the value specified in <code> --wait</code> >> option. >> + If <code>--wait=sb</code> is specified, it prints "ovn-northd delay >> + before processing", which is the time between the Northbound DB >> update by >> + the command and the moment when <code> ovn-northd</code> starts >> + processing the update, and "ovn-northd completion", which is the >> time >> + between the Northbound DB update and the moment when >> + <code>ovn-northd</code> completes the Southbound DB updating >> + successfully. If <code>--wait=hv</code> is specified, in addition >> to the >> + above information, it also prints "ovn-controller(s) completion", >> which >> + is the time between the Northbound DB update and the moment when >> the >> + slowest hypervisor finishes processing the update. >> + </dd> >> + >> <dt><code>--db</code> <var>database</var></dt> >> <dd> >> The OVSDB database remote to contact. If the <env>OVN_NB_DB</env> >> diff --git a/utilities/ovn-nbctl.c b/utilities/ovn-nbctl.c >> index d7bb4b4..57dfaa1 100644 >> --- a/utilities/ovn-nbctl.c >> +++ b/utilities/ovn-nbctl.c >> @@ -63,6 +63,8 @@ enum nbctl_wait_type { >> }; >> static enum nbctl_wait_type wait_type = NBCTL_WAIT_NONE; >> >> +static bool print_wait_time = false; >> + >> /* Should we wait (if specified by 'wait_type') even if the commands >> don't >> * change the database at all? */ >> static bool force_wait = false; >> @@ -302,14 +304,16 @@ main_loop(const char *args, struct ctl_command >> *commands, size_t n_commands, >> #define MAIN_LOOP_OPTION_ENUMS \ >> OPT_NO_WAIT, \ >> OPT_WAIT, \ >> + OPT_PRINT_WAIT_TIME, \ >> OPT_DRY_RUN, \ >> OPT_ONELINE >> >> -#define MAIN_LOOP_LONG_OPTIONS \ >> - {"no-wait", no_argument, NULL, OPT_NO_WAIT}, \ >> - {"wait", required_argument, NULL, OPT_WAIT}, \ >> - {"dry-run", no_argument, NULL, OPT_DRY_RUN}, \ >> - {"oneline", no_argument, NULL, OPT_ONELINE}, \ >> +#define MAIN_LOOP_LONG_OPTIONS \ >> + {"no-wait", no_argument, NULL, OPT_NO_WAIT}, \ >> + {"wait", required_argument, NULL, OPT_WAIT}, \ >> + {"print-wait-time", no_argument, NULL, OPT_PRINT_WAIT_TIME}, \ >> + {"dry-run", no_argument, NULL, OPT_DRY_RUN}, \ >> + {"oneline", no_argument, NULL, OPT_ONELINE}, \ >> {"timeout", required_argument, NULL, 't'} >> >> enum { >> @@ -358,6 +362,10 @@ handle_main_loop_option(int opt, const char *arg, >> bool *handled) >> } >> break; >> >> + case OPT_PRINT_WAIT_TIME: >> + print_wait_time = true; >> + break; >> + >> case OPT_DRY_RUN: >> dry_run = true; >> break; >> @@ -777,6 +785,7 @@ Options:\n\ >> --no-shuffle-remotes do not shuffle the order of remotes\n\ >> --wait=sb wait for southbound database update\n\ >> --wait=hv wait for all chassis to catch up\n\ >> + --print-wait-time print time spent on waiting\n\ >> -t, --timeout=SECS wait at most SECS seconds\n\ >> --dry-run do not commit changes to database\n\ >> --oneline print exactly one line of output per >> command\n", >> @@ -5992,8 +6001,10 @@ run_prerequisites(struct ctl_command *commands, >> size_t n_commands, >> ovsdb_idl_add_table(idl, &nbrec_table_nb_global); >> if (wait_type == NBCTL_WAIT_SB) { >> ovsdb_idl_add_column(idl, &nbrec_nb_global_col_sb_cfg); >> + ovsdb_idl_add_column(idl, &nbrec_nb_global_col_sb_cfg_timestamp); >> } else if (wait_type == NBCTL_WAIT_HV) { >> ovsdb_idl_add_column(idl, &nbrec_nb_global_col_hv_cfg); >> + ovsdb_idl_add_column(idl, &nbrec_nb_global_col_hv_cfg_timestamp); >> } >> >> for (struct ctl_command *c = commands; c < &commands[n_commands]; >> c++) { >> @@ -6065,6 +6076,7 @@ do_nbctl(const char *args, struct ctl_command >> *commands, size_t n_commands, >> struct shash_node *node; >> int64_t next_cfg = 0; >> char *error = NULL; >> + int64_t start_time = 0; >> >> ovs_assert(retry); >> >> @@ -6132,6 +6144,7 @@ do_nbctl(const char *args, struct ctl_command >> *commands, size_t n_commands, >> } >> } >> >> + start_time = time_wall_msec(); >> status = ovsdb_idl_txn_commit_block(txn); >> if (wait_type != NBCTL_WAIT_NONE && status == TXN_SUCCESS) { >> next_cfg = ovsdb_idl_txn_get_increment_new_value(txn); >> @@ -6203,6 +6216,21 @@ do_nbctl(const char *args, struct ctl_command >> *commands, size_t n_commands, >> ? nb->sb_cfg >> : nb->hv_cfg); >> if (cur_cfg >= next_cfg) { >> + if (print_wait_time) { >> + printf("Time spent on processing nb_cfg >> %"PRId64":\n", >> + next_cfg); >> + printf("\tovn-northd delay before processing:" >> + "\t%"PRId64"ms\n", >> + nb->nb_cfg_timestamp - start_time); >> + printf("\tovn-northd completion:" >> + "\t\t\t%"PRId64"ms\n", >> + nb->sb_cfg_timestamp - start_time); >> + if (wait_type == NBCTL_WAIT_HV) { >> + printf("\tovn-controller(s) completion:" >> + "\t\t%"PRId64"ms\n", >> + nb->hv_cfg_timestamp - start_time); >> + } >> + } >> goto done; >> } >> } >> -- >> 2.1.0 >> >> _______________________________________________ >> dev mailing list >> dev@openvswitch.org >> https://mail.openvswitch.org/mailman/listinfo/ovs-dev >> >>
diff --git a/tests/ovn.at b/tests/ovn.at index 55257c3..f238b66 100644 --- a/tests/ovn.at +++ b/tests/ovn.at @@ -21451,6 +21451,9 @@ hv3_ts=$(ovn-sbctl --bare --columns=nb_cfg_timestamp find chassis_private name=h hv_cfg_ts=$(ovn-nbctl get nb_global . hv_cfg_timestamp) AT_CHECK([test x$hv3_ts == x$hv_cfg_ts]) +AT_CHECK([test x$(ovn-nbctl --print-wait-time --wait=sb sync | grep ms | wc -l) == x2]) +AT_CHECK([test x$(ovn-nbctl --print-wait-time --wait=hv sync | grep ms | wc -l) == x3]) + for i in $(seq 2 $n); do OVN_CLEANUP_SBOX([hv$i]) done diff --git a/utilities/ovn-nbctl.8.xml b/utilities/ovn-nbctl.8.xml index 07447d2..fcc4312 100644 --- a/utilities/ovn-nbctl.8.xml +++ b/utilities/ovn-nbctl.8.xml @@ -1322,6 +1322,23 @@ </p> </dd> + <dt><code>--print-wait-time</code></dt> + <dd> + When <code>--wait</code> is specified, the option + <code>--print-wait-time</code> can be used to print the time spent on + waiting, depending on the value specified in <code> --wait</code> option. + If <code>--wait=sb</code> is specified, it prints "ovn-northd delay + before processing", which is the time between the Northbound DB update by + the command and the moment when <code> ovn-northd</code> starts + processing the update, and "ovn-northd completion", which is the time + between the Northbound DB update and the moment when + <code>ovn-northd</code> completes the Southbound DB updating + successfully. If <code>--wait=hv</code> is specified, in addition to the + above information, it also prints "ovn-controller(s) completion", which + is the time between the Northbound DB update and the moment when the + slowest hypervisor finishes processing the update. + </dd> + <dt><code>--db</code> <var>database</var></dt> <dd> The OVSDB database remote to contact. If the <env>OVN_NB_DB</env> diff --git a/utilities/ovn-nbctl.c b/utilities/ovn-nbctl.c index d7bb4b4..57dfaa1 100644 --- a/utilities/ovn-nbctl.c +++ b/utilities/ovn-nbctl.c @@ -63,6 +63,8 @@ enum nbctl_wait_type { }; static enum nbctl_wait_type wait_type = NBCTL_WAIT_NONE; +static bool print_wait_time = false; + /* Should we wait (if specified by 'wait_type') even if the commands don't * change the database at all? */ static bool force_wait = false; @@ -302,14 +304,16 @@ main_loop(const char *args, struct ctl_command *commands, size_t n_commands, #define MAIN_LOOP_OPTION_ENUMS \ OPT_NO_WAIT, \ OPT_WAIT, \ + OPT_PRINT_WAIT_TIME, \ OPT_DRY_RUN, \ OPT_ONELINE -#define MAIN_LOOP_LONG_OPTIONS \ - {"no-wait", no_argument, NULL, OPT_NO_WAIT}, \ - {"wait", required_argument, NULL, OPT_WAIT}, \ - {"dry-run", no_argument, NULL, OPT_DRY_RUN}, \ - {"oneline", no_argument, NULL, OPT_ONELINE}, \ +#define MAIN_LOOP_LONG_OPTIONS \ + {"no-wait", no_argument, NULL, OPT_NO_WAIT}, \ + {"wait", required_argument, NULL, OPT_WAIT}, \ + {"print-wait-time", no_argument, NULL, OPT_PRINT_WAIT_TIME}, \ + {"dry-run", no_argument, NULL, OPT_DRY_RUN}, \ + {"oneline", no_argument, NULL, OPT_ONELINE}, \ {"timeout", required_argument, NULL, 't'} enum { @@ -358,6 +362,10 @@ handle_main_loop_option(int opt, const char *arg, bool *handled) } break; + case OPT_PRINT_WAIT_TIME: + print_wait_time = true; + break; + case OPT_DRY_RUN: dry_run = true; break; @@ -777,6 +785,7 @@ Options:\n\ --no-shuffle-remotes do not shuffle the order of remotes\n\ --wait=sb wait for southbound database update\n\ --wait=hv wait for all chassis to catch up\n\ + --print-wait-time print time spent on waiting\n\ -t, --timeout=SECS wait at most SECS seconds\n\ --dry-run do not commit changes to database\n\ --oneline print exactly one line of output per command\n", @@ -5992,8 +6001,10 @@ run_prerequisites(struct ctl_command *commands, size_t n_commands, ovsdb_idl_add_table(idl, &nbrec_table_nb_global); if (wait_type == NBCTL_WAIT_SB) { ovsdb_idl_add_column(idl, &nbrec_nb_global_col_sb_cfg); + ovsdb_idl_add_column(idl, &nbrec_nb_global_col_sb_cfg_timestamp); } else if (wait_type == NBCTL_WAIT_HV) { ovsdb_idl_add_column(idl, &nbrec_nb_global_col_hv_cfg); + ovsdb_idl_add_column(idl, &nbrec_nb_global_col_hv_cfg_timestamp); } for (struct ctl_command *c = commands; c < &commands[n_commands]; c++) { @@ -6065,6 +6076,7 @@ do_nbctl(const char *args, struct ctl_command *commands, size_t n_commands, struct shash_node *node; int64_t next_cfg = 0; char *error = NULL; + int64_t start_time = 0; ovs_assert(retry); @@ -6132,6 +6144,7 @@ do_nbctl(const char *args, struct ctl_command *commands, size_t n_commands, } } + start_time = time_wall_msec(); status = ovsdb_idl_txn_commit_block(txn); if (wait_type != NBCTL_WAIT_NONE && status == TXN_SUCCESS) { next_cfg = ovsdb_idl_txn_get_increment_new_value(txn); @@ -6203,6 +6216,21 @@ do_nbctl(const char *args, struct ctl_command *commands, size_t n_commands, ? nb->sb_cfg : nb->hv_cfg); if (cur_cfg >= next_cfg) { + if (print_wait_time) { + printf("Time spent on processing nb_cfg %"PRId64":\n", + next_cfg); + printf("\tovn-northd delay before processing:" + "\t%"PRId64"ms\n", + nb->nb_cfg_timestamp - start_time); + printf("\tovn-northd completion:" + "\t\t\t%"PRId64"ms\n", + nb->sb_cfg_timestamp - start_time); + if (wait_type == NBCTL_WAIT_HV) { + printf("\tovn-controller(s) completion:" + "\t\t%"PRId64"ms\n", + nb->hv_cfg_timestamp - start_time); + } + } goto done; } }
This patch adds option --print-wait-time, which can be used together with --wait=sb/hv to print the time spent on respective processing. For example: $ ovn-nbctl --print-wait-time --wait=hv sync Time spent on processing nb_cfg 392: ovn-northd delay before processing: 1ms ovn-northd completion: 32ms ovn-controller(s) completion: 39ms Without this, we had to use "time" command to measure the total time spent by the ovn-nbctl command. However, it doesn't refect the actual control plane latency, because the nb_cfg updates from all hypervisors to SB DB contributes a significant part to the time spent on waiting by the ovn-nbctl command. This doesn't reflect the real production scenario. With this option (and the timestamp support from the previous commit), we can measure the exact time when hypervisors completed SB DB change handling and enforcing to OVS. Signed-off-by: Han Zhou <hzhou@ovn.org> --- tests/ovn.at | 3 +++ utilities/ovn-nbctl.8.xml | 17 +++++++++++++++++ utilities/ovn-nbctl.c | 38 +++++++++++++++++++++++++++++++++----- 3 files changed, 53 insertions(+), 5 deletions(-)