lib, lib-master: Send updated event to stats if fields/categories change

Based on code by Jeff Sipek

diff --git a/src/lib-master/stats-client.c b/src/lib-master/stats-client.c
index 489b0e1c59a7099387220f955372b4bf7022e822..9bba3b4a723e0e6ff08f852de257ae1cc814dcbe 100644 (file)
--- a/src/lib-master/stats-client.c
+++ b/src/lib-master/stats-client.c
@@ -114,7 +114,7 @@ static void stats_client_destroy(struct connection *conn)
 
        /* after reconnection the IDs need to be re-sent */
        for (event = events_get_head(); event != NULL; event = event->next)
-               event->id_sent_to_stats = FALSE;
+               event->sent_to_stats_id = 0;
 
        client->handshaked = FALSE;
        connection_disconnect(conn);
@@ -169,12 +169,17 @@ stats_event_write(struct event *event, const struct failure_context *ctx,
        parent_event = merged_event->parent;
 
        if (parent_event != NULL) {
-               if (!parent_event->id_sent_to_stats)
+               if (parent_event->sent_to_stats_id !=
+                   parent_event->change_id)
                        stats_event_write(parent_event, ctx, str, TRUE);
+               i_assert(parent_event->sent_to_stats_id != 0);
        }
        if (begin) {
-               str_printfa(str, "BEGIN\t%"PRIu64"\t", event->id);
-               event->id_sent_to_stats = TRUE;
+               i_assert(event == merged_event);
+               const char *cmd = event->sent_to_stats_id == 0 ?
+                       "BEGIN" : "UPDATE";
+               str_printfa(str, "%s\t%"PRIu64"\t", cmd, event->id);
+               event->sent_to_stats_id = event->change_id;
        } else {
                str_append(str, "EVENT\t");
        }
@@ -207,7 +212,7 @@ stats_client_send_event(struct stats_client *client, struct event *event,
 static void
 stats_client_free_event(struct stats_client *client, struct event *event)
 {
-       if (!event->id_sent_to_stats)
+       if (event->sent_to_stats_id == 0)
                return;
        o_stream_nsend_str(client->conn.output,
                           t_strdup_printf("END\t%"PRIu64"\n", event->id));

diff --git a/src/lib-master/test-event-stats.c b/src/lib-master/test-event-stats.c
index 7d878596ce5a36c06a74e8e6e4fed79fc209555b..35425762db1d7feb4b12075cdec9b7bd8307c5d3 100644 (file)
--- a/src/lib-master/test-event-stats.c
+++ b/src/lib-master/test-event-stats.c
@@ -334,7 +334,7 @@ static void test_no_merging2(void)
        TST_BEGIN("no merging parent sent to stats");
        struct event *parent_ev = event_create(NULL);
        event_add_category(parent_ev, &test_cats[0]);
-       parent_ev->id_sent_to_stats = TRUE;
+       parent_ev->sent_to_stats_id = parent_ev->change_id;
        id = parent_ev->id;
        struct event *child_ev = event_create(parent_ev);
        event_add_category(child_ev, &test_cats[1]);
@@ -361,7 +361,7 @@ static void test_no_merging3(void)
        lp = __LINE__ - 1;
        idp = parent_ev->id;
        event_add_category(parent_ev, &test_cats[0]);
-       parent_ev->id_sent_to_stats = FALSE;
+       parent_ev->sent_to_stats_id = 0;
        ioloop_timeval.tv_sec++;
        struct event *child_ev = event_create(parent_ev);
        event_add_category(child_ev, &test_cats[1]);
@@ -416,7 +416,7 @@ static void test_merge_events2(void)
        TST_BEGIN("merge events parent sent to stats");
        struct event *parent_ev = event_create(NULL);
        event_add_category(parent_ev, &test_cats[3]);
-       parent_ev->id_sent_to_stats = TRUE;
+       parent_ev->sent_to_stats_id = parent_ev->change_id;
        struct event *merge_ev1 = event_create(parent_ev);
        event_add_category(merge_ev1, &test_cats[0]);
        event_add_category(merge_ev1, &test_cats[1]);
@@ -520,6 +520,98 @@ static void test_merge_events_skip_parents(void)
        test_end();
 }
 
+static struct event *make_event(struct event *parent,
+                               struct event_category *cat,
+                               int *line_r, uint64_t *id_r)
+{
+       struct event *event;
+       int line;
+
+       event = event_create(parent);
+       line = __LINE__ -1;
+
+       if (line_r != NULL)
+               *line_r = line;
+       if (id_r != NULL)
+               *id_r = event->id;
+
+       /* something in the test infrastructure assumes that at least one
+          category is always present - make it happy */
+       event_add_category(event, cat);
+
+       /* advance the clock to avoid event sending optimizations */
+       ioloop_timeval.tv_sec++;
+
+       return event;
+}
+
+static void test_parent_update_post_send(void)
+{
+       struct event *a, *b, *c;
+       uint64_t id;
+       int line, line_log1, line_log2;
+
+       TST_BEGIN("parent updated after send");
+
+       a = make_event(NULL, &test_cats[0], &line, &id);
+       b = make_event(a, &test_cats[1], NULL, NULL);
+       c = make_event(b, &test_cats[2], NULL, NULL);
+
+       /* set initial field values */
+       event_add_int(a, "a", 1);
+       event_add_int(b, "b", 2);
+       event_add_int(c, "c", 3);
+
+       /* force 'a' event to be sent */
+       e_info(b, "field 'a' should be 1");
+       line_log1 = __LINE__ - 1;
+
+       event_add_int(a, "a", 1000); /* update parent */
+
+       /* log child, which should re-sent parent */
+       e_info(c, "field 'a' should be 1000");
+       line_log2 = __LINE__ - 1;
+
+       event_unref(&a);
+       event_unref(&b);
+       event_unref(&c);
+
+       /* EVENT <parent> <type> ... */
+       /* BEGIN <id> <parent> <type> ... */
+       /* END <id> */
+       test_assert(
+               compare_test_stats_to(
+                       /* first e_info() */
+                       "BEGIN  %"PRIu64"       0       1       0       0"
+                       "       stest-event-stats.c     %d      ctest1"
+                       "       Ia      1\n"
+                       "EVENT  %"PRIu64"       1       1       0"
+                       "       stest-event-stats.c     %d"
+                       "       l1      0       ctest2" "       Ib      2\n"
+                       /* second e_info() */
+                       "UPDATE %"PRIu64"       0       1       0       0"
+                       "       stest-event-stats.c     %d      ctest1"
+                       "       Ia      1000\n"
+                       "BEGIN  %"PRIu64"       %"PRIu64"       1       0       0"
+                       "       stest-event-stats.c     %d"
+                       "       l0      0       ctest2  Ib      2\n"
+                       "EVENT  %"PRIu64"       1       1       0"
+                       "       stest-event-stats.c     %d"
+                       "       l1      0       ctest3"
+                       "       Ic      3\n"
+                       "END\t%"PRIu64"\n"
+                       "END\t%"PRIu64"\n",
+                       id, line, /* BEGIN */
+                       id, line_log1, /* EVENT */
+                       id, line, /* UPDATE */
+                       id + 1, id, line, /* BEGIN */
+                       id + 1, line_log2, /* EVENT */
+                       id + 1 /* END */,
+                       id /* END */));
+
+       test_end();
+}
+
 static int run_tests(void)
 {
        int ret;
@@ -531,6 +623,7 @@ static int run_tests(void)
                test_merge_events2,
                test_skip_parents,
                test_merge_events_skip_parents,
+               test_parent_update_post_send,
                NULL
        };
        struct ioloop *ioloop = io_loop_create();

diff --git a/src/lib/lib-event-private.h b/src/lib/lib-event-private.h
index 691ac74181b96e25f6a6e1325ac87c75506a19f1..5acb9b6ee1381a77ca7d7328ff8d82b4553d2168 100644 (file)
--- a/src/lib/lib-event-private.h
+++ b/src/lib/lib-event-private.h
@@ -16,6 +16,15 @@ struct event {
        struct event *parent;
        uint64_t id;
 
+       /* Avoid sending the event to stats over and over.  The 'change_id'
+          increments every time something about this event changes.  If
+          'sent_to_stats_id' matches 'change_id', we skip sending this
+          event out.  If it doesn't match, we send it and set
+          'sent_to_stats_id' to 'change_id'. sent_to_stats_id=0 is reserved
+          for "event hasn't been sent". 'change_id' can never be 0. */
+       uint32_t change_id;
+       uint32_t sent_to_stats_id;
+
        char *log_prefix;
        unsigned int log_prefixes_dropped;
        event_log_prefix_callback_t *log_prefix_callback;
@@ -30,7 +39,6 @@ struct event {
        bool forced_debug:1;
        bool always_log_source:1;
        bool sending_debug_log:1;
-       bool id_sent_to_stats:1;
        bool debug_level_checked:1;
 
 /* Fields that are exported & imported: */

diff --git a/src/lib/lib-event.c b/src/lib/lib-event.c
index a89cfcdb9ad8ad71016801a28c296907be40290a..a821c8acf47c20ba1a1ce7dc8904dec3c37834c3 100644 (file)
--- a/src/lib/lib-event.c
+++ b/src/lib/lib-event.c
@@ -93,6 +93,16 @@ event_find_category(struct event *event, const struct event_category *category);
 static struct event_field *
 event_find_field_int(struct event *event, const char *key);
 
+static void event_set_changed(struct event *event)
+{
+       event->change_id++;
+       /* It's unlikely that change_id will ever wrap, but lets be safe
+          anyway. */
+       if (event->change_id == 0 ||
+           event->change_id == event->sent_to_stats_id)
+               event->change_id++;
+}
+
 static bool
 event_call_callbacks(struct event *event, enum event_callback_type type,
                     struct failure_context *ctx, const char *fmt, va_list args)
@@ -312,7 +322,7 @@ struct event *event_minimize(struct event *event)
        /* find the bound for field/category flattening */
        flatten_bound = NULL;
        for (cur = event->parent; cur != NULL; cur = cur->parent) {
-               if (!cur->id_sent_to_stats &&
+               if (cur->sent_to_stats_id == 0 &&
                    timeval_cmp(&cur->tv_created_ioloop,
                                &event->tv_created_ioloop) == 0)
                        continue;
@@ -324,7 +334,7 @@ struct event *event_minimize(struct event *event)
        /* continue to find the bound for empty event skipping */
        skip_bound = NULL;
        for (; cur != NULL; cur = cur->parent) {
-               if (!cur->id_sent_to_stats &&
+               if (cur->sent_to_stats_id == 0 &&
                    (!array_is_created(&cur->fields) || array_is_empty(&cur->fields)) &&
                    (!array_is_created(&cur->categories) || array_is_empty(&cur->categories)))
                        continue;
@@ -367,6 +377,7 @@ event_create_internal(struct event *parent, const char *source_filename,
        i_gettimeofday(&event->tv_created);
        event->source_filename = p_strdup(pool, source_filename);
        event->source_linenum = source_linenum;
+       event->change_id = 1;
        if (parent != NULL) {
                event->parent = parent;
                event_ref(event->parent);
@@ -757,6 +768,7 @@ event_add_categories(struct event *event,
                if (!event_find_category(event, categories[i]))
                        array_push_back(&event->categories, &representative);
        }
+       event_set_changed(event);
        event->debug_level_checked = FALSE;
        return event;
 }
@@ -826,6 +838,7 @@ event_get_field(struct event *event, const char *key)
                field = array_append_space(&event->fields);
                field->key = p_strdup(event->pool, key);
        }
+       event_set_changed(event);
        return field;
 }
 
@@ -868,6 +881,7 @@ event_inc_int(struct event *event, const char *key, intmax_t num)
                return event_add_int(event, key, num);
 
        field->value.intmax += num;
+       event_set_changed(event);
        return event;
 }