From patchwork Fri Dec 18 05:31:42 2020 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Ben Pfaff X-Patchwork-Id: 1418061 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Authentication-Results: ozlabs.org; spf=pass (sender SPF authorized) smtp.mailfrom=openvswitch.org (client-ip=140.211.166.136; helo=silver.osuosl.org; envelope-from=ovs-dev-bounces@openvswitch.org; receiver=) Authentication-Results: ozlabs.org; dmarc=none (p=none dis=none) header.from=ovn.org Received: from silver.osuosl.org (smtp3.osuosl.org [140.211.166.136]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by ozlabs.org (Postfix) with ESMTPS id 4CxyF25hGTz9sVj for ; Fri, 18 Dec 2020 16:32:54 +1100 (AEDT) Received: from localhost (localhost [127.0.0.1]) by silver.osuosl.org (Postfix) with ESMTP id E18652E300; Fri, 18 Dec 2020 05:32:50 +0000 (UTC) X-Virus-Scanned: amavisd-new at osuosl.org Received: from silver.osuosl.org ([127.0.0.1]) by localhost (.osuosl.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id clRHeFctvZjc; Fri, 18 Dec 2020 05:32:24 +0000 (UTC) Received: from lists.linuxfoundation.org (lf-lists.osuosl.org [140.211.9.56]) by silver.osuosl.org (Postfix) with ESMTP id 82D3A2E2FE; Fri, 18 Dec 2020 05:32:11 +0000 (UTC) Received: from lf-lists.osuosl.org (localhost [127.0.0.1]) by lists.linuxfoundation.org (Postfix) with ESMTP id 57227C1787; Fri, 18 Dec 2020 05:32:11 +0000 (UTC) X-Original-To: dev@openvswitch.org Delivered-To: ovs-dev@lists.linuxfoundation.org Received: from fraxinus.osuosl.org (smtp4.osuosl.org [140.211.166.137]) by lists.linuxfoundation.org (Postfix) with ESMTP id CF441C0893 for ; Fri, 18 Dec 2020 05:32:10 +0000 (UTC) Received: from localhost (localhost [127.0.0.1]) by fraxinus.osuosl.org (Postfix) with ESMTP id C8E168777C for ; Fri, 18 Dec 2020 05:32:10 +0000 (UTC) X-Virus-Scanned: amavisd-new at osuosl.org Received: from fraxinus.osuosl.org ([127.0.0.1]) by localhost (.osuosl.org [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id U8yIhz87lC1d for ; Fri, 18 Dec 2020 05:32:07 +0000 (UTC) X-Greylist: domain auto-whitelisted by SQLgrey-1.7.6 Received: from relay8-d.mail.gandi.net (relay8-d.mail.gandi.net [217.70.183.201]) by fraxinus.osuosl.org (Postfix) with ESMTPS id 3E173877B7 for ; Fri, 18 Dec 2020 05:32:06 +0000 (UTC) X-Originating-IP: 75.54.222.30 Received: from sigfpe.attlocal.net (75-54-222-30.lightspeed.rdcyca.sbcglobal.net [75.54.222.30]) (Authenticated sender: blp@ovn.org) by relay8-d.mail.gandi.net (Postfix) with ESMTPSA id B4F261BF207; Fri, 18 Dec 2020 05:32:03 +0000 (UTC) From: Ben Pfaff To: dev@openvswitch.org Date: Thu, 17 Dec 2020 21:31:42 -0800 Message-Id: <20201218053144.2637583-8-blp@ovn.org> X-Mailer: git-send-email 2.28.0 In-Reply-To: <20201218053144.2637583-1-blp@ovn.org> References: <20201218053144.2637583-1-blp@ovn.org> MIME-Version: 1.0 Cc: Ben Pfaff Subject: [ovs-dev] [PATCH v3 7/9] test-ovsdb: Log steps in idl test. X-BeenThere: ovs-dev@openvswitch.org X-Mailman-Version: 2.1.15 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: ovs-dev-bounces@openvswitch.org Sender: "dev" 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 --- tests/test-ovsdb.c | 248 +++++++++++++++++++++++---------------------- 1 file changed, 126 insertions(+), 122 deletions(-) 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 #include #include +#include #include #include @@ -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=["); + 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)); } + 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