From 9f79942d2d2a8db78c61fdbc93e5d477108a67a7 Mon Sep 17 00:00:00 2001 From: Free Ekanayaka Date: Sat, 16 Mar 2024 11:17:35 +0000 Subject: [PATCH] test: Add support for matching diagnostic traces --- include/vr.h | 41 +++++++++++- src/tracing.h | 58 +++++++++++++++++ src/vr.c | 61 +++++++++++++++++- test/integration/test_normal.c | 3 +- test/integration/test_step.c | 31 ++++++++-- test/lib/cluster.c | 110 +++++++++++++++++++++++++++++++++ test/lib/cluster.h | 22 +++++++ 7 files changed, 318 insertions(+), 8 deletions(-) create mode 100644 src/tracing.h diff --git a/include/vr.h b/include/vr.h index 049ede3..f7e02f6 100644 --- a/include/vr.h +++ b/include/vr.h @@ -5,7 +5,13 @@ #define VR_API __attribute__((visibility("default"))) -enum { VR_NOMEM = 1, VR_DUPLICATEID, VR_DUPLICATEADDRESS, VR_BADROLE }; +enum { + VR_NOMEM = 1, + VR_DUPLICATEID, + VR_DUPLICATEADDRESS, + VR_BADROLE, + VR_INVALID /* Invalid parameter */ +}; /* Customizable tracer for debugging, logging and metrics purposes. */ struct vr_tracer @@ -129,7 +135,38 @@ struct vr VR_API int vr_init(struct vr *v, unsigned id); VR_API int vr_close(struct vr *v); -VR_API int vr_step(void); +enum vr_event_type { + VR_START = 1, /* Initial event starting the server. */ + VR_RECEIVE /* A message has been received from another server. */ +}; + +/* Represents an external event that drives the VR engine forward (for example + * receiving a message). */ +struct vr_event +{ + unsigned long time; + enum vr_event_type type; + unsigned char unused; + unsigned short capacity; + unsigned char reserved[4]; + union { + struct + { + unsigned long view; + } start; + }; +}; + +/* Hold information about changes that user code must perform after a call to + * vr_step() returns (e.g. new messages that must be sent, etc.). */ +struct vr_update +{ + unsigned flags; +}; + +VR_API int vr_step(struct vr *v, + const struct vr_event *event, + struct vr_update *update); /** * User-definable dynamic memory allocation functions. diff --git a/src/tracing.h b/src/tracing.h new file mode 100644 index 0000000..ffaf952 --- /dev/null +++ b/src/tracing.h @@ -0,0 +1,58 @@ +/* Tracing functions and helpers. */ + +#ifndef TRACING_H_ +#define TRACING_H_ + +#include "../include/vr.h" + +#define LIKELY(x) __builtin_expect(!!(x), 1) + +/* Use TRACER to trace an event of type TYPE with the given INFO. */ +#define Trace(TRACER, TYPE, INFO) \ + do { \ + if (LIKELY(TRACER == NULL)) { \ + break; \ + } \ + if (LIKELY(TRACER->version == 2)) { \ + TRACER->emit(TRACER, TYPE, INFO); \ + } \ + } while (0) + +/* Emit a diagnostic message with the given tracer at level 3. */ +#define Infof(TRACER, ...) Logf(TRACER, 3, __VA_ARGS__) + +/* Emit diagnostic message with the given tracer at level 5. */ +#define Tracef(TRACER, ...) Logf(TRACER, 5, __VA_ARGS__) + +/* Use the tracer to log an event at the given level. + * + * The LEVEL parameter should be one of: + * + * - 1: error + * - 2: warning + * - 3: info + * - 4: debug + * - 5: trace + */ +#define Logf(TRACER, LEVEL, ...) \ + do { \ + unsigned _type; \ + struct vr_tracer_info _info; \ + static char _msg[1024]; \ + \ + if (LIKELY(TRACER == NULL)) { \ + break; \ + } \ + \ + snprintf(_msg, sizeof _msg, __VA_ARGS__); \ + \ + _type = VR_TRACER_DIAGNOSTIC; \ + _info.version = 1; \ + _info.diagnostic.level = LEVEL; \ + _info.diagnostic.message = _msg; \ + _info.diagnostic.file = __FILE__; \ + _info.diagnostic.line = __LINE__; \ + TRACER->emit(TRACER, _type, &_info); \ + } while (0) + +#endif /* TRACING_H_ */ diff --git a/src/vr.c b/src/vr.c index 8e206a3..f2a1557 100644 --- a/src/vr.c +++ b/src/vr.c @@ -1,7 +1,14 @@ #include "../include/vr.h" +#include +#include + +#include "assert.h" #include "configuration.h" #include "heap.h" +#include "tracing.h" + +#define infof(...) Infof(v->tracer, "> " __VA_ARGS__) int vr_init(struct vr *v, unsigned id) { @@ -22,8 +29,60 @@ int vr_close(struct vr *v) return 0; } -int vr_step(void) +/* Emit a start message containing information about the current state. */ +static void stepStartEmitMessage(const struct vr *v) +{ + char msg[512] = {0}; + + if (v->view == 0) { + strcat(msg, "no state"); + goto emit; + } + + if (v->view > 0) { + char msg_term[64]; + sprintf(msg_term, "term %lu", v->view); + strcat(msg, msg_term); + } + +emit: + infof("%s", msg); +} + +/* Handle a VR_START event. */ +static int stepStart(struct vr *v, unsigned long view) +{ + v->view = view; + stepStartEmitMessage(v); + return 0; +} + +int vr_step(struct vr *v, + const struct vr_event *event, + struct vr_update *update) { + int rv; + + assert(event != NULL); + assert(update != NULL); + + switch (event->type) { + case VR_START: + rv = stepStart(v, event->start.view); + break; + default: + rv = VR_INVALID; + break; + } + + if (rv != 0) { + goto out; + } + +out: + if (rv != 0) { + return rv; + } return 0; } diff --git a/test/integration/test_normal.c b/test/integration/test_normal.c index 9dea19b..25933a4 100644 --- a/test/integration/test_normal.c +++ b/test/integration/test_normal.c @@ -25,6 +25,7 @@ SUITE(normal) TEST(normal, request, setUp, tearDown, 0, NULL) { struct fixture *f = data; - (void)f; + CLUSTER_START(1); + CLUSTER_TRACE("[ 0] 1 > no state\n"); return MUNIT_OK; } diff --git a/test/integration/test_step.c b/test/integration/test_step.c index a324cb0..e9fb647 100644 --- a/test/integration/test_step.c +++ b/test/integration/test_step.c @@ -1,13 +1,36 @@ #include "../../include/vr.h" #include "../lib/runner.h" +static void *setUp(const MunitParameter params[], MUNIT_UNUSED void *user_data) +{ + struct vr *v = munit_malloc(sizeof *v); + int rv; + + (void)params; + rv = vr_init(v, 1); + munit_assert_int(rv, ==, 0); + + return v; +} + +static void tearDown(void *data) +{ + struct vr *v = data; + vr_close(v); + free(v); +} + SUITE(step) -/* Generation of the ID of the bootstrap dqlite node. */ -TEST(step, noop, NULL, NULL, 0, NULL) +/* Passing an invalid event code results in an error. */ +TEST(step, invalid, setUp, tearDown, 0, NULL) { + struct vr *v = data; + struct vr_event event; + struct vr_update update; int rv; - rv = vr_step(); - munit_assert_int(0, ==, rv); + event.type = 666; + rv = vr_step(v, &event, &update); + munit_assert_int(rv, ==, VR_INVALID); return MUNIT_OK; } diff --git a/test/lib/cluster.c b/test/lib/cluster.c index fd2e2f8..6c0ed9e 100644 --- a/test/lib/cluster.c +++ b/test/lib/cluster.c @@ -74,6 +74,40 @@ static void serverClose(struct test_server *s) vr_close(&s->vr); } +/* Fire the given event using raft_step() and process the resulting struct + * raft_update object. */ +static int serverStep(struct test_server *s, struct vr_event *event) +{ + struct vr *v = &s->vr; + struct vr_update update; + int rv; + + munit_assert_true(s->running); + + rv = vr_step(v, event, &update); + if (rv != 0) { + return rv; + } + + return 0; +} + +/* Start the server by passing to raft_step() a RAFT_START event with the + * current disk state. */ +static void serverStart(struct test_server *s) +{ + struct vr_event event; + int rv; + + s->running = true; + + event.time = s->cluster->time; + event.type = VR_START; + + rv = serverStep(s, &event); + munit_assert_int(rv, ==, 0); +} + void test_cluster_setup(const MunitParameter params[], struct test_cluster *c) { unsigned i; @@ -88,6 +122,13 @@ void test_cluster_setup(const MunitParameter params[], struct test_cluster *c) c->in_tear_down = false; } +/* Return the server with the given @id. */ +static struct test_server *clusterGetServer(struct test_cluster *c, unsigned id) +{ + munit_assert_ulong(id, <=, TEST_CLUSTER_N_SERVERS); + return &c->servers[id - 1]; +} + void test_cluster_tear_down(struct test_cluster *c) { unsigned i; @@ -98,3 +139,72 @@ void test_cluster_tear_down(struct test_cluster *c) serverClose(&c->servers[i]); } } + +void test_cluster_start(struct test_cluster *c, unsigned id) +{ + struct test_server *server = clusterGetServer(c, id); + serverStart(server); +} + +void test_cluster_step(struct test_cluster *c) +{ + (void)c; +} + +bool test_cluster_trace(struct test_cluster *c, const char *expected) +{ + size_t n1; + size_t n2; + size_t i; + unsigned max_steps = 100; + +consume: + if (max_steps == 0) { + goto mismatch; + } + max_steps -= 1; + + n1 = strlen(c->trace); + n2 = strlen(expected); + + for (i = 0; i < n1 && i < n2; i++) { + if (c->trace[i] != expected[i]) { + break; + } + } + + /* Check if we produced more output than the expected one. */ + if (n1 > n2) { + goto mismatch; + } + + /* If there's more expected output, check that so far we're good, then + * step and repeat. */ + if (n1 < n2) { + if (i != n1) { + goto mismatch; + } + c->trace[0] = 0; + expected += i; + test_cluster_step(c); + goto consume; + } + + munit_assert_ulong(n1, ==, n2); + if (i != n1) { + goto mismatch; + } + + c->trace[0] = 0; + + return true; + +mismatch: + fprintf(stderr, "==> Expected:\n"); + fprintf(stderr, "%s\n", expected); + + fprintf(stderr, "==> Actual:\n"); + fprintf(stderr, "%s\n", c->trace); + + return false; +} diff --git a/test/lib/cluster.h b/test/lib/cluster.h index 8e1e2d1..eaeb382 100644 --- a/test/lib/cluster.h +++ b/test/lib/cluster.h @@ -15,6 +15,16 @@ #define TEAR_DOWN_CLUSTER() test_cluster_tear_down(&f->cluster) +/* Start the server with the given ID. */ +#define CLUSTER_START(ID) test_cluster_start(&f->cluster, ID) + +/* Step the cluster until the all expected output is consumed. Fail the test if + * a mismatch is found. */ +#define CLUSTER_TRACE(EXPECTED) \ + if (!test_cluster_trace(&f->cluster, EXPECTED)) { \ + munit_error("trace does not match"); \ + } + /* Wrap a @vr instance and maintain network state. */ struct test_cluster; struct test_server @@ -41,4 +51,16 @@ struct test_cluster void test_cluster_setup(const MunitParameter params[], struct test_cluster *c); void test_cluster_tear_down(struct test_cluster *c); +/* Start the server with the given @id. */ +void test_cluster_start(struct test_cluster *c, unsigned id); + +/* Advance the cluster by completing a single asynchronous operation or firing a + * timeout. */ +void test_cluster_step(struct test_cluster *c); + +/* Compare the trace of all messages emitted by all servers with the given + * expected trace. If they don't match, print the last line which differs and + * return #false. */ +bool test_cluster_trace(struct test_cluster *c, const char *expected); + #endif /* TEST_CLUSTER_H */