[ovs-dev] [PATCH v3 7/9] test-ovsdb: Log steps in idl test.

Ilya Maximets i.maximets at ovn.org
Fri Dec 18 22:16:50 UTC 2020


On 12/18/20 6:31 AM, Ben Pfaff wrote:
> Until now, "test-ovsdb idl" has printed the steps that it goes through
> to stdout.  This commit also makes it log the same information.  This
> makes it easier to match up the steps with the rest of the log (in
> particular with the jsonrpc logging).
> 
> Signed-off-by: Ben Pfaff <blp at ovn.org>
> ---
>  tests/test-ovsdb.c | 248 +++++++++++++++++++++++----------------------
>  1 file changed, 126 insertions(+), 122 deletions(-)

Thanks!  That looks nice.

However, this patch seems incomplete.  At least 'idl_set' function
still logs to stdout only while it could be called from the 'do_idl'
that prints to stdout and to the the log.

OTOH, some functions like 'do_idl_partial_update_map_column' and
'do_idl_partial_update_set_column' are not covered too.  Was it
intentional?  I understand that 'do_idl' was a primary target here.

Some minor nits inline.

Best regards, Ilya Maximets.

> 
> diff --git a/tests/test-ovsdb.c b/tests/test-ovsdb.c
> index 31513c537fd5..42775c5e850d 100644
> --- a/tests/test-ovsdb.c
> +++ b/tests/test-ovsdb.c
> @@ -19,6 +19,7 @@
>  #include <fcntl.h>
>  #include <getopt.h>
>  #include <inttypes.h>
> +#include <stdarg.h>
>  #include <stdio.h>
>  #include <stdlib.h>
>  
> @@ -52,6 +53,8 @@
>  #include "util.h"
>  #include "openvswitch/vlog.h"
>  
> +VLOG_DEFINE_THIS_MODULE(test_ovsdb);
> +
>  struct test_ovsdb_pvt_context {
>      bool track;
>  };
> @@ -1844,194 +1847,191 @@ compare_link1(const void *a_, const void *b_)
>      return a->i < b->i ? -1 : a->i > b->i;
>  }
>  
> +static void OVS_PRINTF_FORMAT(1, 2)
> +print_and_log(const char *format, ...)
> +{
> +    va_list args;
> +    va_start(args, format);
> +    char *message = xvasprintf(format, args);
> +    va_end(args);
> +
> +    printf("%s\n", message);
> +    VLOG_INFO("%s", message);
> +
> +    free(message);
> +}
> +
>  static void
>  print_idl_row_updated_simple(const struct idltest_simple *s, int step)
>  {
> -    size_t i;
> -    bool updated = false;
> -
> -    for (i = 0; i < IDLTEST_SIMPLE_N_COLUMNS; i++) {
> +    struct ds updates = DS_EMPTY_INITIALIZER;
> +    for (size_t i = 0; i < IDLTEST_SIMPLE_N_COLUMNS; i++) {
>          if (idltest_simple_is_updated(s, i)) {
> -            if (!updated) {
> -                printf("%03d: updated columns:", step);
> -                updated = true;
> -            }
> -            printf(" %s", idltest_simple_columns[i].name);
> +            ds_put_format(&updates, " %s", idltest_simple_columns[i].name);
>          }
>      }
> -    if (updated) {
> -        printf("\n");
> +    if (updates.length) {
> +        print_and_log("%03d: updated columns:%s", step, ds_cstr(&updates));
> +        ds_destroy(&updates);
>      }
>  }
>  
>  static void
>  print_idl_row_updated_link1(const struct idltest_link1 *l1, int step)
>  {
> -    size_t i;
> -    bool updated = false;
> -
> -    for (i = 0; i < IDLTEST_LINK1_N_COLUMNS; i++) {
> +    struct ds updates = DS_EMPTY_INITIALIZER;
> +    for (size_t i = 0; i < IDLTEST_LINK1_N_COLUMNS; i++) {
>          if (idltest_link1_is_updated(l1, i)) {
> -            if (!updated) {
> -                printf("%03d: updated columns:", step);
> -                updated = true;
> -            }
> -            printf(" %s", idltest_link1_columns[i].name);
> +            ds_put_format(&updates, " %s", idltest_link1_columns[i].name);
>          }
>      }
> -    if (updated) {
> -        printf("\n");
> +    if (updates.length) {
> +        print_and_log("%03d: updated columns:%s", step, ds_cstr(&updates));
> +        ds_destroy(&updates);
>      }
>  }
>  
>  static void
>  print_idl_row_updated_link2(const struct idltest_link2 *l2, int step)
>  {
> -    size_t i;
> -    bool updated = false;
> -
> -    for (i = 0; i < IDLTEST_LINK2_N_COLUMNS; i++) {
> +    struct ds updates = DS_EMPTY_INITIALIZER;
> +    for (size_t i = 0; i < IDLTEST_LINK2_N_COLUMNS; i++) {
>          if (idltest_link2_is_updated(l2, i)) {
> -            if (!updated) {
> -                printf("%03d: updated columns:", step);
> -                updated = true;
> -            }
> -            printf(" %s", idltest_link2_columns[i].name);
> +            ds_put_format(&updates, " %s", idltest_link2_columns[i].name);
>          }
>      }
> -    if (updated) {
> -        printf("\n");
> +    if (updates.length) {
> +        print_and_log("%03d: updated columns:%s", step, ds_cstr(&updates));
> +        ds_destroy(&updates);
>      }
>  }
>  
>  static void
>  print_idl_row_updated_simple6(const struct idltest_simple6 *s6, int step)
>  {
> -    size_t i;
> -    bool updated = false;
> -
> -    for (i = 0; i < IDLTEST_SIMPLE6_N_COLUMNS; i++) {
> +    struct ds updates = DS_EMPTY_INITIALIZER;
> +    for (size_t i = 0; i < IDLTEST_SIMPLE6_N_COLUMNS; i++) {
>          if (idltest_simple6_is_updated(s6, i)) {
> -            if (!updated) {
> -                printf("%03d: updated columns:", step);
> -                updated = true;
> -            }
> -            printf(" %s", idltest_simple6_columns[i].name);
> +            ds_put_format(&updates, " %s", idltest_simple6_columns[i].name);
>          }
>      }
> -    if (updated) {
> -        printf("\n");
> +    if (updates.length) {
> +        print_and_log("%03d: updated columns:%s", step, ds_cstr(&updates));
> +        ds_destroy(&updates);
>      }
>  }
>  
>  static void
>  print_idl_row_updated_singleton(const struct idltest_singleton *sng, int step)
>  {
> -    size_t i;
> -    bool updated = false;
> -
> -    for (i = 0; i < IDLTEST_SINGLETON_N_COLUMNS; i++) {
> +    struct ds updates = DS_EMPTY_INITIALIZER;
> +    for (size_t i = 0; i < IDLTEST_SINGLETON_N_COLUMNS; i++) {
>          if (idltest_singleton_is_updated(sng, i)) {
> -            if (!updated) {
> -                printf("%03d: updated columns:", step);
> -                updated = true;
> -            }
> -            printf(" %s", idltest_singleton_columns[i].name);
> +            ds_put_format(&updates, " %s", idltest_singleton_columns[i].name);
>          }
>      }
> -    if (updated) {
> -        printf("\n");
> +    if (updates.length) {
> +        print_and_log("%03d: updated columns:%s", step, ds_cstr(&updates));
> +        ds_destroy(&updates);
>      }
>  }
>  
>  static void
>  print_idl_row_simple(const struct idltest_simple *s, int step)
>  {
> -    size_t i;
> -
> -    printf("%03d: i=%"PRId64" r=%g b=%s s=%s u="UUID_FMT" ia=[",
> -           step, s->i, s->r, s->b ? "true" : "false",
> -           s->s, UUID_ARGS(&s->u));
> -    for (i = 0; i < s->n_ia; i++) {
> -        printf("%s%"PRId64, i ? " " : "", s->ia[i]);
> +    struct ds msg = DS_EMPTY_INITIALIZER;
> +    ds_put_format(&msg, "%03d: i=%"PRId64" r=%g b=%s s=%s u="UUID_FMT" ia=[",
> +                  step, s->i, s->r, s->b ? "true" : "false",
> +                  s->s, UUID_ARGS(&s->u));
> +    for (size_t i = 0; i < s->n_ia; i++) {
> +        ds_put_format(&msg, "%s%"PRId64, i ? " " : "", s->ia[i]);
>      }
> -    printf("] ra=[");
> -    for (i = 0; i < s->n_ra; i++) {
> -        printf("%s%g", i ? " " : "", s->ra[i]);
> +    ds_put_format(&msg, "] ra=[");

Very minor, but it might be better to use ds_put_cstr() for cases without
actual format string.

> +    for (size_t i = 0; i < s->n_ra; i++) {
> +        ds_put_format(&msg, "%s%g", i ? " " : "", s->ra[i]);
>      }
> -    printf("] ba=[");
> -    for (i = 0; i < s->n_ba; i++) {
> -        printf("%s%s", i ? " " : "", s->ba[i] ? "true" : "false");
> +    ds_put_format(&msg, "] ba=[");
> +    for (size_t i = 0; i < s->n_ba; i++) {
> +        ds_put_format(&msg, "%s%s", i ? " " : "", s->ba[i] ? "true" : "false");
>      }
> -    printf("] sa=[");
> -    for (i = 0; i < s->n_sa; i++) {
> -        printf("%s%s", i ? " " : "", s->sa[i]);
> +    ds_put_format(&msg, "] sa=[");
> +    for (size_t i = 0; i < s->n_sa; i++) {
> +        ds_put_format(&msg, "%s%s", i ? " " : "", s->sa[i]);
>      }
> -    printf("] ua=[");
> -    for (i = 0; i < s->n_ua; i++) {
> -        printf("%s"UUID_FMT, i ? " " : "", UUID_ARGS(&s->ua[i]));
> +    ds_put_format(&msg, "] ua=[");
> +    for (size_t i = 0; i < s->n_ua; i++) {
> +        ds_put_format(&msg, "%s"UUID_FMT, i ? " " : "", UUID_ARGS(&s->ua[i]));
>      }
> -    printf("] uuid="UUID_FMT"\n", UUID_ARGS(&s->header_.uuid));
> +    ds_put_format(&msg, "] uuid="UUID_FMT, UUID_ARGS(&s->header_.uuid));
> +    print_and_log("%s", ds_cstr(&msg));
> +    ds_destroy(&msg);
> +
>      print_idl_row_updated_simple(s, step);
>  }
>  
>  static void
>  print_idl_row_link1(const struct idltest_link1 *l1, int step)
>  {
> -    struct idltest_link1 **links;
> -    size_t i;
> -
> -    printf("%03d: i=%"PRId64" k=", step, l1->i);
> +    struct ds msg = DS_EMPTY_INITIALIZER;
> +    ds_put_format(&msg, "%03d: i=%"PRId64" k=", step, l1->i);
>      if (l1->k) {
> -        printf("%"PRId64, l1->k->i);
> +        ds_put_format(&msg, "%"PRId64, l1->k->i);
>      }
> -    printf(" ka=[");
> -    links = xmemdup(l1->ka, l1->n_ka * sizeof *l1->ka);
> +    ds_put_format(&msg, " ka=[");
> +    struct idltest_link1 **links = xmemdup(l1->ka, l1->n_ka * sizeof *l1->ka);
>      qsort(links, l1->n_ka, sizeof *links, compare_link1);
> -    for (i = 0; i < l1->n_ka; i++) {
> -        printf("%s%"PRId64, i ? " " : "", links[i]->i);
> +    for (size_t i = 0; i < l1->n_ka; i++) {
> +        ds_put_format(&msg, "%s%"PRId64, i ? " " : "", links[i]->i);
>      }
>      free(links);
> -    printf("] l2=");
> +    ds_put_format(&msg, "] l2=");
>      if (l1->l2) {
> -        printf("%"PRId64, l1->l2->i);
> +        ds_put_format(&msg, "%"PRId64, l1->l2->i);
>      }
> -    printf(" uuid="UUID_FMT"\n", UUID_ARGS(&l1->header_.uuid));
> +    ds_put_format(&msg, " uuid="UUID_FMT, UUID_ARGS(&l1->header_.uuid));
> +    print_and_log("%s", ds_cstr(&msg));
> +    ds_destroy(&msg);
> +
>      print_idl_row_updated_link1(l1, step);
>  }
>  
>  static void
>  print_idl_row_link2(const struct idltest_link2 *l2, int step)
>  {
> -    printf("%03d: i=%"PRId64" l1=", step, l2->i);
> +    struct ds msg = DS_EMPTY_INITIALIZER;
> +    ds_put_format(&msg, "%03d: i=%"PRId64" l1=", step, l2->i);
>      if (l2->l1) {
> -        printf("%"PRId64, l2->l1->i);
> +        ds_put_format(&msg, "%"PRId64, l2->l1->i);
>      }
> -    printf(" uuid="UUID_FMT"\n", UUID_ARGS(&l2->header_.uuid));
> +    ds_put_format(&msg, " uuid="UUID_FMT, UUID_ARGS(&l2->header_.uuid));
> +    print_and_log("%s", ds_cstr(&msg));
> +    ds_destroy(&msg);
> +
>      print_idl_row_updated_link2(l2, step);
>  }
>  
>  static void
>  print_idl_row_simple6(const struct idltest_simple6 *s6, int step)
>  {
> -    int i;
> -
> -    printf("%03d: name=%s ", step, s6->name);
> -    printf("weak_ref=[");
> -    for (i = 0; i < s6->n_weak_ref; i++) {
> -        printf("%s"UUID_FMT, i ? " " : "",
> +    struct ds msg = DS_EMPTY_INITIALIZER;
> +    ds_put_format(&msg, "%03d: name=%s ", step, s6->name);
> +    ds_put_format(&msg, "weak_ref=[");
> +    for (size_t i = 0; i < s6->n_weak_ref; i++) {
> +        ds_put_format(&msg, "%s"UUID_FMT, i ? " " : "",
>                 UUID_ARGS(&s6->weak_ref[i]->header_.uuid));

Indentation is a bit off.  Should be shifted to the '('.

>      }
> +    ds_put_format(&msg, "] uuid="UUID_FMT, UUID_ARGS(&s6->header_.uuid));
> +    print_and_log("%s", ds_cstr(&msg));
> +    ds_destroy(&msg);
>  
> -    printf("] uuid="UUID_FMT"\n", UUID_ARGS(&s6->header_.uuid));
>      print_idl_row_updated_simple6(s6, step);
>  }
>  
>  static void
>  print_idl_row_singleton(const struct idltest_singleton *sng, int step)
>  {
> -    printf("%03d: name=%s", step, sng->name);
> -    printf(" uuid="UUID_FMT"\n", UUID_ARGS(&sng->header_.uuid));
> +    print_and_log("%03d: name=%s uuid="UUID_FMT, step, sng->name,
> +                  UUID_ARGS(&sng->header_.uuid));
>      print_idl_row_updated_singleton(sng, step);
>  }
>  
> @@ -2061,7 +2061,7 @@ print_idl(struct ovsdb_idl *idl, int step)
>          n++;
>      }
>      if (!n) {
> -        printf("%03d: empty\n", step);
> +        print_and_log("%03d: empty", step);
>      }
>  }
>  
> @@ -2077,36 +2077,36 @@ print_idl_track(struct ovsdb_idl *idl, int step)
>      IDLTEST_SIMPLE_FOR_EACH_TRACKED (s, idl) {
>          print_idl_row_simple(s, step);
>          if (idltest_simple_is_deleted(s)) {
> -            printf("%03d: deleted row: uuid="UUID_FMT"\n", step,
> -                   UUID_ARGS(&s->header_.uuid));
> +            print_and_log("%03d: deleted row: uuid="UUID_FMT, step,
> +                          UUID_ARGS(&s->header_.uuid));
>          } else if (idltest_simple_is_new(s)) {
> -            printf("%03d: inserted row: uuid="UUID_FMT"\n", step,
> -                   UUID_ARGS(&s->header_.uuid));
> +            print_and_log("%03d: inserted row: uuid="UUID_FMT, step,
> +                          UUID_ARGS(&s->header_.uuid));
>          }
>          n++;
>      }
>      IDLTEST_LINK1_FOR_EACH_TRACKED (l1, idl) {
>          if (idltest_link1_is_deleted(l1)) {
> -            printf("%03d: deleted row: uuid="UUID_FMT"\n", step,
> -                   UUID_ARGS(&l1->header_.uuid));
> +            print_and_log("%03d: deleted row: uuid="UUID_FMT, step,
> +                          UUID_ARGS(&l1->header_.uuid));
>          } else {
>              print_idl_row_link1(l1, step);
>              if (idltest_link1_is_new(l1)) {
> -                printf("%03d: inserted row: uuid="UUID_FMT"\n", step,
> -                       UUID_ARGS(&l1->header_.uuid));
> +                print_and_log("%03d: inserted row: uuid="UUID_FMT, step,
> +                              UUID_ARGS(&l1->header_.uuid));
>              }
>          }
>          n++;
>      }
>      IDLTEST_LINK2_FOR_EACH_TRACKED (l2, idl) {
>          if (idltest_link2_is_deleted(l2)) {
> -            printf("%03d: deleted row: uuid="UUID_FMT"\n", step,
> -                   UUID_ARGS(&l2->header_.uuid));
> +            print_and_log("%03d: deleted row: uuid="UUID_FMT, step,
> +                          UUID_ARGS(&l2->header_.uuid));
>          } else {
>              print_idl_row_link2(l2, step);
>              if (idltest_link2_is_new(l2)) {
> -                printf("%03d: inserted row: uuid="UUID_FMT"\n", step,
> -                       UUID_ARGS(&l2->header_.uuid));
> +                print_and_log("%03d: inserted row: uuid="UUID_FMT, step,
> +                              UUID_ARGS(&l2->header_.uuid));
>              }
>  
>          }
> @@ -2115,17 +2115,17 @@ print_idl_track(struct ovsdb_idl *idl, int step)
>      IDLTEST_SIMPLE6_FOR_EACH_TRACKED (s6, idl) {
>          print_idl_row_simple6(s6, step);
>          if (idltest_simple6_is_deleted(s6)) {
> -            printf("%03d: deleted row: uuid="UUID_FMT"\n", step,
> +            print_and_log("%03d: deleted row: uuid="UUID_FMT, step,
>                     UUID_ARGS(&s6->header_.uuid));
>          } else if (idltest_simple6_is_new(s6)) {
> -            printf("%03d: inserted row: uuid="UUID_FMT"\n", step,
> -                   UUID_ARGS(&s6->header_.uuid));
> +            print_and_log("%03d: inserted row: uuid="UUID_FMT, step,
> +                          UUID_ARGS(&s6->header_.uuid));
>          }
>          n++;
>      }
>  
>      if (!n) {
> -        printf("%03d: empty\n", step);
> +        print_and_log("%03d: empty", step);
>      }
>  }
>  
> @@ -2505,7 +2505,7 @@ do_idl(struct ovs_cmdl_context *ctx)
>      const char cond_s[] = "condition ";
>      if (ctx->argc > 2 && strstr(ctx->argv[2], cond_s)) {
>          update_conditions(idl, ctx->argv[2] + strlen(cond_s));
> -        printf("%03d: change conditions\n", step++);
> +        print_and_log("%03d: change conditions", step++);
>          i = 3;
>      } else {
>          i = 2;
> @@ -2543,11 +2543,11 @@ do_idl(struct ovs_cmdl_context *ctx)
>          seqno = ovsdb_idl_get_seqno(idl);
>  
>          if (!strcmp(arg, "reconnect")) {
> -            printf("%03d: reconnect\n", step++);
> +            print_and_log("%03d: reconnect", step++);
>              ovsdb_idl_force_reconnect(idl);
>          }  else if (!strncmp(arg, cond_s, strlen(cond_s))) {
>              update_conditions(idl, arg + strlen(cond_s));
> -            printf("%03d: change conditions\n", step++);
> +            print_and_log("%03d: change conditions", step++);
>          } else if (arg[0] != '[') {
>              idl_set(idl, arg, step++);
>          } else {
> @@ -2558,13 +2558,17 @@ do_idl(struct ovs_cmdl_context *ctx)
>              if (error || reply->error) {
>                  ovs_fatal(error, "jsonrpc transaction failed");
>              }
> -            printf("%03d: ", step++);
>              if (reply->result) {
>                  parse_uuids(reply->result, symtab, &n_uuids);
>              }
>              json_destroy(reply->id);
>              reply->id = NULL;
> -            print_and_free_json(jsonrpc_msg_to_json(reply));
> +
> +            struct json *msg_json = jsonrpc_msg_to_json(reply);
> +            char *msg_s = json_to_string(msg_json, JSSF_SORT);
> +            json_destroy(msg_json);
> +            print_and_log("%03d: %s", step++, msg_s);
> +            free(msg_s);
>          }
>      }
>      ovsdb_symbol_table_destroy(symtab);
> @@ -2584,7 +2588,7 @@ do_idl(struct ovs_cmdl_context *ctx)
>      print_idl(idl, step++);
>      ovsdb_idl_track_clear(idl);
>      ovsdb_idl_destroy(idl);
> -    printf("%03d: done\n", step);
> +    print_and_log("%03d: done", step);
>  }
>  
>  static void
> 



More information about the dev mailing list