aggregator: Add debug logging

diff --git a/src/replication/aggregator/aggregator-settings.h b/src/replication/aggregator/aggregator-settings.h
index 06c8ac3c53ca5424e6d1b75d287f340b23fd9f8f..1ada71de062e220d9518624d9bae2193f1dd7aa9 100644 (file)
--- a/src/replication/aggregator/aggregator-settings.h
+++ b/src/replication/aggregator/aggregator-settings.h
@@ -8,5 +8,6 @@ struct aggregator_settings {
 
 extern const struct setting_parser_info aggregator_setting_parser_info;
 extern const struct aggregator_settings *aggregator_settings;
+extern struct event *aggregator_event;
 
 #endif

diff --git a/src/replication/aggregator/aggregator.c b/src/replication/aggregator/aggregator.c
index 1677f9f76d52adbfd1b1215c72211905fb5266a6..7a02d8f58d110f686ba1696a7c202f832849e599 100644 (file)
--- a/src/replication/aggregator/aggregator.c
+++ b/src/replication/aggregator/aggregator.c
@@ -9,6 +9,11 @@
 #include "replicator-connection.h"
 
 struct replicator_connection *replicator;
+struct event *aggregator_event;
+
+static struct event_category event_category_replication = {
+       .name = "replication"
+};
 
 static void client_connected(struct master_service_connection *conn)
 {
@@ -27,6 +32,9 @@ static void main_preinit(void)
        sets = master_service_settings_get_others(master_service);
        set = sets[0];
 
+       aggregator_event = event_create(NULL);
+       event_add_category(aggregator_event, &event_category_replication);
+
        if (set->replicator_port != 0) {
                ret = net_gethostbyname(set->replicator_host, &ips, &ips_count);
                if (ret != 0) {
@@ -69,6 +77,7 @@ int main(int argc, char *argv[])
 
        notify_connections_destroy_all();
        replicator_connection_destroy(&replicator);
+       event_unref(&aggregator_event);
        master_service_deinit(&master_service);
         return 0;
 }

diff --git a/src/replication/aggregator/notify-connection.c b/src/replication/aggregator/notify-connection.c
index 80dc05b590fc8b12c57ede64a25ec5873dd2cb1e..68dcfc9f87130bc5e562745b511a30230cdc6482 100644 (file)
--- a/src/replication/aggregator/notify-connection.c
+++ b/src/replication/aggregator/notify-connection.c
@@ -11,6 +11,7 @@
 #include "replication-common.h"
 #include "replicator-connection.h"
 #include "notify-connection.h"
+#include "aggregator-settings.h"
 
 #define MAX_INBUF_SIZE 8192
 
@@ -45,6 +46,8 @@ void notify_connection_sync_callback(bool success, void *context)
 {
        struct notify_connection *conn = context;
 
+       e_debug(conn->event, "Sending %s result",
+               success ? "success" : "failure");
        o_stream_nsend_str(conn->output, success ? "+\n" : "-\n");
        notify_connection_unref(conn);
 }
@@ -67,6 +70,10 @@ notify_input_line(struct notify_connection *conn, const char *line,
                        "Client sent invalid priority: %s", args[1]);
                return -1;
        }
+
+       e_debug(conn->event, "Received priority %s request for %s",
+               args[1], args[0]);
+
        if (priority != REPLICATION_PRIORITY_SYNC)
                replicator_connection_notify(replicator, args[0], priority);
        else {
@@ -117,6 +124,7 @@ void notify_connection_create(int fd, bool fifo)
        conn->io = io_add(fd, IO_READ, notify_input, conn);
        conn->input = i_stream_create_fd(fd, MAX_INBUF_SIZE);
        conn->event = event_create(NULL);
+       event_set_append_log_prefix(conn->event, "notify: ");
        if (!fifo) {
                conn->output = o_stream_create_fd(fd, SIZE_MAX);
                o_stream_set_no_error_handling(conn->output, TRUE);
@@ -141,6 +149,8 @@ static void notify_connection_destroy(struct notify_connection *conn)
 {
        i_assert(conn->fd != -1);
 
+       e_debug(conn->event, "Disconnected");
+
        if (!CONNECTION_IS_FIFO(conn))
                master_service_client_connection_destroyed(master_service);
 

diff --git a/src/replication/aggregator/replicator-connection.c b/src/replication/aggregator/replicator-connection.c
index b5900db94b322ebe50be69d661d65b58a4382b9a..b5bfed18608efbc5d6ff1c352d62da5decf86ae9 100644 (file)
--- a/src/replication/aggregator/replicator-connection.c
+++ b/src/replication/aggregator/replicator-connection.c
@@ -10,6 +10,7 @@
 #include "llist.h"
 #include "strescape.h"
 #include "replicator-connection.h"
+#include "aggregator-settings.h"
 
 #define MAX_INBUF_SIZE 1024
 #define REPLICATOR_RECONNECT_MSECS 5000
@@ -56,6 +57,9 @@ replicator_input_line(struct replicator_connection *conn, const char *line)
                e_error(conn->event, "Replicator sent invalid ID: %u", id);
                return -1;
        }
+
+       e_debug(conn->event, "Request id %u has %s",
+               id, line[0] == '+' ? "succeeded" : "failed");
        hash_table_remove(conn->requests, POINTER_CAST(id));
        conn->callback(line[0] == '+', context);
        return 0;
@@ -143,6 +147,9 @@ static void replicator_connection_connect(struct replicator_connection *conn)
                return;
 
        if (conn->port == 0) {
+               event_set_append_log_prefix(conn->event,
+                                           t_strdup_printf("(unix:%s): ", conn->path));
+               e_debug(conn->event, "Connecting to replicator");
                fd = net_connect_unix(conn->path);
                if (fd == -1)
                        e_error(conn->event, "net_connect_unix(%s) failed: %m",
@@ -152,6 +159,9 @@ static void replicator_connection_connect(struct replicator_connection *conn)
                        unsigned int idx = conn->ip_idx;
 
                        conn->ip_idx = (conn->ip_idx + 1) % conn->ips_count;
+                       event_set_append_log_prefix(conn->event, t_strdup_printf(
+                               "(%s): ", net_ipport2str(&conn->ips[idx], conn->port)));
+                       e_debug(conn->event, "Connecting to replicator");
                        fd = net_connect_ip(&conn->ips[idx], conn->port, NULL);
                        if (fd != -1)
                                break;
@@ -161,7 +171,9 @@ static void replicator_connection_connect(struct replicator_connection *conn)
        }
 
        if (fd == -1) {
+               event_set_append_log_prefix(conn->event, "");
                if (conn->to == NULL) {
+                       e_debug(conn->event, "Reconnecting in %u msecs", REPLICATOR_RECONNECT_MSECS);
                        conn->to = timeout_add(REPLICATOR_RECONNECT_MSECS,
                                               replicator_connection_connect,
                                               conn);
@@ -174,6 +186,7 @@ static void replicator_connection_connect(struct replicator_connection *conn)
        conn->io = io_add(fd, IO_READ, replicator_input, conn);
        conn->input = i_stream_create_fd(fd, MAX_INBUF_SIZE);
        conn->output = o_stream_create_fd(fd, SIZE_MAX);
+       e_debug(conn->event, "Sending handshake");
        o_stream_set_no_error_handling(conn->output, TRUE);
        o_stream_nsend_str(conn->output, REPLICATOR_HANDSHAKE);
        o_stream_set_flush_callback(conn->output, replicator_output, conn);
@@ -184,6 +197,7 @@ static void replicator_abort_all_requests(struct replicator_connection *conn)
        struct hash_iterate_context *iter;
        void *key, *value;
 
+       e_debug(conn->event, "Aborting all requests");
        iter = hash_table_iterate_init(conn->requests);
        while (hash_table_iterate(iter, conn->requests, &key, &value))
                conn->callback(FALSE, value);
@@ -196,11 +210,13 @@ static void replicator_connection_disconnect(struct replicator_connection *conn)
        if (conn->fd == -1)
                return;
 
+       e_debug(conn->event, "Disconnecting");
        replicator_abort_all_requests(conn);
        io_remove(&conn->io);
        i_stream_destroy(&conn->input);
        o_stream_destroy(&conn->output);
        net_disconnect(conn->fd);
+       event_set_append_log_prefix(conn->event, "");
        conn->fd = -1;
 }
 
@@ -307,6 +323,8 @@ void replicator_connection_notify(struct replicator_connection *conn,
        }
 
        T_BEGIN {
+               e_debug(conn->event, "Requesting replication of %s priority for user %s",
+                       priority_str, username);
                replicator_send(conn, priority, t_strdup_printf(
                        "U\t%s\t%s\n", str_tabescape(username), priority_str));
        } T_END;
@@ -324,6 +342,8 @@ void replicator_connection_notify_sync(struct replicator_connection *conn,
        hash_table_insert(conn->requests, POINTER_CAST(id), context);
 
        T_BEGIN {
+               e_debug(conn->event, "Requesting synchronization with id %u for user %s",
+                       id, username);
                replicator_send(conn, REPLICATION_PRIORITY_SYNC, t_strdup_printf(
                        "U\t%s\tsync\t%u\n", str_tabescape(username), id));
        } T_END;