doveadm: Deliver remote logs over doveadm socket

src/doveadm/client-connection.c

@@ -2,6 +2,7 @@
 
 #include "lib.h"
 #include "lib-signals.h"
+#include "str.h"
 #include "base64.h"
 #include "ioloop.h"
 #include "istream.h"
@@ -10,6 +11,7 @@
 #include "process-title.h"
 #include "settings-parser.h"
 #include "iostream-ssl.h"
+#include "ostream-multiplex.h"
 #include "master-service.h"
 #include "master-service-ssl.h"
 #include "master-service-settings.h"
@@ -27,6 +29,86 @@
 
 static void client_connection_input(struct client_connection *conn);
 
+static failure_callback_t *orig_error_callback, *orig_fatal_callback;
+static failure_callback_t *orig_info_callback, *orig_debug_callback = NULL;
+
+static bool log_recursing = FALSE;
+
+
+static void ATTR_FORMAT(2, 0)
+doveadm_server_log_handler(const struct failure_context *ctx,
+			   const char *format, va_list args)
+{
+	if (!log_recursing && doveadm_client != NULL &&
+	    doveadm_client->log_out != NULL) T_BEGIN {
+		/* prevent re-entering this code if
+		   any of the following code causes logging */
+		log_recursing = TRUE;
+		char c = doveadm_log_type_to_char(ctx->type);
+		const char *ptr,*start;
+		bool corked = o_stream_is_corked(doveadm_client->log_out);
+		va_list va;
+		va_copy(va, args);
+		string_t *str = t_str_new(128);
+		str_vprintfa(str, format, va);
+		va_end(va);
+		start = str_c(str);
+		if (!corked)
+			o_stream_cork(doveadm_client->log_out);
+		while((ptr = strchr(start, '\n'))!=NULL) {
+			o_stream_nsend(doveadm_client->log_out, &c, 1);
+			o_stream_nsend(doveadm_client->log_out, start, ptr-start+1);
+			str_delete(str, 0, ptr-start+1);
+		}
+		if (str->used > 0) {
+			o_stream_nsend(doveadm_client->log_out, &c, 1);
+			o_stream_nsend(doveadm_client->log_out, str->data, str->used);
+			o_stream_nsend(doveadm_client->log_out, "\n", 1);
+		}
+		o_stream_uncork(doveadm_client->log_out);
+		if (corked)
+			o_stream_cork(doveadm_client->log_out);
+		log_recursing = FALSE;
+	} T_END;
+
+	switch(ctx->type) {
+	case LOG_TYPE_DEBUG:
+		orig_debug_callback(ctx, format, args);
+		break;
+	case LOG_TYPE_INFO:
+		orig_info_callback(ctx, format, args);
+		break;
+	case LOG_TYPE_WARNING:
+	case LOG_TYPE_ERROR:
+		orig_error_callback(ctx, format, args);
+		break;
+	default:
+		i_unreached();
+	}
+}
+
+static void doveadm_server_capture_logs(void)
+{
+	i_assert(orig_debug_callback == NULL);
+	i_get_failure_handlers(&orig_fatal_callback, &orig_error_callback,
+			       &orig_info_callback, &orig_debug_callback);
+	i_set_error_handler(doveadm_server_log_handler);
+	i_set_info_handler(doveadm_server_log_handler);
+	i_set_debug_handler(doveadm_server_log_handler);
+}
+
+static void doveadm_server_restore_logs(void)
+{
+	i_assert(orig_debug_callback != NULL);
+	i_set_error_handler(orig_error_callback);
+	i_set_info_handler(orig_info_callback);
+	i_set_debug_handler(orig_debug_callback);
+	orig_fatal_callback = NULL;
+	orig_error_callback = NULL;
+	orig_info_callback = NULL;
+	orig_debug_callback = NULL;
+}
+
 static void
 doveadm_cmd_server_post(struct client_connection *conn, const char *cmd_name)
 {
@@ -249,6 +331,8 @@ static int doveadm_cmd_handle(struct client_connection *conn,
 	io_loop_set_current(prev_ioloop);
 	lib_signals_reset_ioloop();
 	o_stream_switch_ioloop(conn->output);
+	if (conn->log_out != NULL)
+		o_stream_switch_ioloop(conn->log_out);
 	io_loop_set_current(ioloop);
 	io_loop_destroy(&ioloop);
 
@@ -427,11 +511,25 @@ static void client_connection_input(struct client_connection *conn)
 		}
 		o_stream_nsend(conn->output, "+\n", 2);
 		conn->authenticated = TRUE;
-		doveadm_print_ostream = conn->output;
 	}
 
 	if (!conn->io_setup) {
 		conn->io_setup = TRUE;
+                if (conn->use_multiplex) {
+                        o_stream_flush(conn->output);
+                        struct ostream *os = conn->output;
+                        conn->output = o_stream_create_multiplex(os, (size_t)-1);
+                        o_stream_set_name(conn->output, o_stream_get_name(os));
+                        o_stream_set_no_error_handling(conn->output, TRUE);
+                        o_stream_unref(&os);
+                        conn->log_out =
+                                o_stream_multiplex_add_channel(conn->output,
+                                                               DOVEADM_LOG_CHANNEL_ID);
+                        o_stream_set_no_error_handling(conn->log_out, TRUE);
+                        o_stream_set_name(conn->log_out, t_strdup_printf("%s (log)",
+                                          o_stream_get_name(conn->output)));
+                        doveadm_server_capture_logs();
+                }
 		doveadm_print_ostream = conn->output;
 	}
 
@@ -589,6 +687,10 @@ void client_connection_destroy(struct client_connection **_conn)
 	if (conn->input != NULL) {
 		i_stream_destroy(&conn->input);
 	}
+	if (conn->log_out != NULL) {
+		doveadm_server_restore_logs();
+		o_stream_unref(&conn->log_out);
+	}
 
 	if (conn->fd > 0 && close(conn->fd) < 0)
 		i_error("close(client) failed: %m");

src/doveadm/client-connection.h

@@ -3,6 +3,8 @@
 
 #include "net.h"
 
+#define DOVEADM_LOG_CHANNEL_ID 'L'
+
 struct client_connection {
 	pool_t pool;
 
@@ -11,6 +13,7 @@ struct client_connection {
 	struct io *io;
 	struct istream *input;
 	struct ostream *output;
+	struct ostream *log_out;
 	struct ssl_iostream *ssl_iostream;
 	struct ip_addr local_ip, remote_ip;
 	in_port_t local_port, remote_port;
@@ -19,6 +22,7 @@ struct client_connection {
 	unsigned int handshaked:1;
 	unsigned int authenticated:1;
 	unsigned int io_setup:1;
+	unsigned int use_multiplex:1;
 };
 
 struct client_connection *

src/doveadm/doveadm-util.c

@@ -172,3 +172,50 @@ int i_strccdascmp(const char *a, const char *b)
 	return *a-*b;
 }
 
+char doveadm_log_type_to_char(enum log_type type)
+{
+	switch(type) {
+	case LOG_TYPE_DEBUG:
+		return '\x01';
+	case LOG_TYPE_INFO:
+		return '\x02';
+	case LOG_TYPE_WARNING:
+		return '\x03';
+	case LOG_TYPE_ERROR:
+		return '\x04';
+	case LOG_TYPE_FATAL:
+		return '\x05';
+	case LOG_TYPE_PANIC:
+		return '\x06';
+	default:
+		i_unreached();
+	}
+}
+
+bool doveadm_log_type_from_char(char c, enum log_type *type_r)
+{
+	switch(c) {
+	case '\x01':
+		*type_r = LOG_TYPE_DEBUG;
+		break;
+	case '\x02':
+		*type_r = LOG_TYPE_INFO;
+		break;
+	case '\x03':
+		*type_r = LOG_TYPE_WARNING;
+		break;
+	case '\x04':
+		*type_r = LOG_TYPE_ERROR;
+		break;
+	case '\x05':
+		*type_r = LOG_TYPE_FATAL;
+		break;
+	case '\x06':
+		*type_r = LOG_TYPE_PANIC;
+		break;
+	default:
+		*type_r = LOG_TYPE_WARNING;
+		return FALSE;
+	}
+	return TRUE;
+}

src/doveadm/doveadm-util.h

@@ -4,9 +4,9 @@
 #include "net.h"
 
 #define DOVEADM_SERVER_PROTOCOL_VERSION_MAJOR 1
-#define DOVEADM_SERVER_PROTOCOL_VERSION_MINOR 0
-#define DOVEADM_SERVER_PROTOCOL_VERSION_LINE "VERSION\tdoveadm-server\t1\t0"
-#define DOVEADM_CLIENT_PROTOCOL_VERSION_LINE "VERSION\tdoveadm-client\t1\t0"
+#define DOVEADM_SERVER_PROTOCOL_VERSION_MINOR 1
+#define DOVEADM_SERVER_PROTOCOL_VERSION_LINE "VERSION\tdoveadm-server\t1\t1"
+#define DOVEADM_CLIENT_PROTOCOL_VERSION_LINE "VERSION\tdoveadm-client\t1\t1"
 
 extern bool doveadm_verbose, doveadm_debug, doveadm_server;
 
@@ -21,6 +21,9 @@ void doveadm_load_modules(void);
 void doveadm_unload_modules(void);
 bool doveadm_has_unloaded_plugin(const char *name);
 
+char doveadm_log_type_to_char(enum log_type type) ATTR_PURE;
+bool doveadm_log_type_from_char(char c, enum log_type *type_r);
+
 /* Similar to strcmp(), except "camel case" == "camel-case" == "camelCase".
    Otherwise the comparison is case-sensitive. */
 int i_strccdascmp(const char *a, const char *b) ATTR_PURE;

src/doveadm/server-connection.c

@@ -6,6 +6,7 @@
 #include "ioloop.h"
 #include "net.h"
 #include "istream.h"
+#include "istream-multiplex.h"
 #include "ostream.h"
 #include "ostream-dot.h"
 #include "str.h"
@@ -24,6 +25,8 @@
 #include <sysexits.h>
 #include <unistd.h>
 
+#define DOVEADM_LOG_CHANNEL_ID 'L'
+
 #define MAX_INBUF_SIZE (1024*32)
 
 enum server_reply_state {
@@ -42,7 +45,9 @@ struct server_connection {
 	unsigned int minor;
 
 	struct io *io;
+	struct io *io_log;
 	struct istream *input;
+	struct istream *log_input;
 	struct ostream *output;
 	struct ssl_iostream *ssl_iostream;
 	struct timeout *to_input;
@@ -291,6 +296,36 @@ static void server_log_disconnect_error(struct server_connection *conn)
 	i_error("doveadm server disconnected before handshake: %s", error);
 }
 
+static void server_connection_print_log(struct server_connection *conn)
+{
+	const char *line;
+	struct failure_context ctx;
+	i_zero(&ctx);
+
+	while((line = i_stream_read_next_line(conn->log_input))!=NULL) {
+		/* skip empty lines */
+		if (*line == '\0') continue;
+
+		if (!doveadm_log_type_from_char(line[0], &ctx.type))
+			i_warning("Doveadm server sent invalid log type 0x%02x",
+				  line[0]);
+		line++;
+		i_log_type(&ctx, "%s", line);
+	}
+}
+
+static void server_connection_start_multiplex(struct server_connection *conn)
+{
+	struct istream *is = conn->input;
+	conn->input = i_stream_create_multiplex(is, MAX_INBUF_SIZE);
+	i_stream_unref(&is);
+	io_remove(&conn->io);
+	conn->io = io_add_istream(conn->input, server_connection_input, conn);
+	conn->log_input = i_stream_multiplex_add_channel(conn->input, DOVEADM_LOG_CHANNEL_ID);
+	conn->io_log = io_add_istream(conn->log_input, server_connection_print_log, conn);
+	i_stream_set_return_partial_line(conn->log_input, TRUE);
+}
+
 static void server_connection_input(struct server_connection *conn)
 {
 	const char *line;
@@ -311,6 +346,8 @@ static void server_connection_input(struct server_connection *conn)
 				continue;
 			}
 			if (strcmp(line, "+") == 0) {
+				if (conn->minor > 0)
+					server_connection_start_multiplex(conn);
 				server_connection_authenticated(conn);
 				break;
 			} else if (strcmp(line, "-") == 0) {
@@ -363,6 +400,9 @@ static bool server_connection_input_one(struct server_connection *conn)
 	if (size == 0)
 		return FALSE;
 
+	/* check logs */
+	(void)server_connection_print_log(conn);
+
 	switch (conn->state) {
 	case SERVER_REPLY_STATE_DONE:
 		i_error("doveadm server sent unexpected input");
@@ -561,12 +601,20 @@ void server_connection_destroy(struct server_connection **_conn)
 		o_stream_destroy(&conn->cmd_output);
 	if (conn->ssl_iostream != NULL)
 		ssl_iostream_unref(&conn->ssl_iostream);
+        if (conn->io_log != NULL)
+                io_remove(&conn->io_log);
+        /* make sure all logs got consumed */
+        if (conn->log_input != NULL) {
+                server_connection_print_log(conn);
+                i_stream_unref(&conn->log_input);
+	}
 	if (conn->io != NULL)
 		io_remove(&conn->io);
 	if (conn->fd != -1) {
 		if (close(conn->fd) < 0)
 			i_error("close(server) failed: %m");
 	}
+
 	pool_unref(&conn->pool);
 }