[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