changeset 22968:304c434e382f

lib-master: Improve error logging for master_auth_connection failures
author Timo Sirainen <timo.sirainen@dovecot.fi>
date Fri, 04 May 2018 13:56:45 +0300
parents 9b388281d133
children 3e71d3877872
files src/lib-master/master-auth.c
diffstat 1 files changed, 33 insertions(+), 14 deletions(-) [+]
line wrap: on
line diff
--- a/src/lib-master/master-auth.c	Fri May 04 13:42:23 2018 +0300
+++ b/src/lib-master/master-auth.c	Fri May 04 13:56:45 2018 +0300
@@ -20,6 +20,10 @@
 	struct master_auth *auth;
 	unsigned int tag;
 
+	unsigned int client_pid, auth_id;
+	struct ip_addr remote_ip;
+	struct timeval create_time;
+
 	char *path;
 	int fd;
 	struct io *io;
@@ -85,6 +89,20 @@
 	i_free(conn);
 }
 
+static void ATTR_FORMAT(2, 3)
+conn_error(struct master_auth_connection *conn, const char *fmt, ...)
+{
+	va_list args;
+
+	va_start(args, fmt);
+	i_error("master(%s): %s (client-pid=%u, client-id=%u, rip=%s, created %u msecs ago, received %u/%zu bytes)",
+		conn->path, t_strdup_vprintf(fmt, args),
+		conn->client_pid, conn->auth_id, net_ip2addr(&conn->remote_ip),
+		timeval_diff_msecs(&ioloop_timeval, &conn->create_time),
+		conn->buf_pos, sizeof(conn->buf_pos));
+	va_end(args);
+}
+
 void master_auth_deinit(struct master_auth **_auth)
 {
 	struct master_auth *auth = *_auth;
@@ -113,13 +131,12 @@
 		   sizeof(conn->buf) - conn->buf_pos);
 	if (ret <= 0) {
 		if (ret == 0 || errno == ECONNRESET) {
-			i_error("read(%s) failed: Remote closed connection "
-				"(destination service { process_limit } reached?)",
-				conn->path);
+			conn_error(conn, "read() failed: Remote closed connection "
+				"(destination service { process_limit } reached?)");
 		} else {
 			if (errno == EAGAIN)
 				return;
-			i_error("read(%s) failed: %m", conn->path);
+			conn_error(conn, "read() failed: %m");
 		}
 		master_auth_connection_deinit(&conn);
 		return;
@@ -134,8 +151,7 @@
 	conn->buf_pos = 0;
 
 	if (conn->tag != reply->tag)
-		i_error("master(%s): Received reply with unknown tag %u",
-			conn->path, reply->tag);
+		conn_error(conn, "Received reply with unknown tag %u", reply->tag);
 	else if (conn->callback == NULL) {
 		/* request aborted */
 	} else {
@@ -147,9 +163,7 @@
 
 static void master_auth_connection_timeout(struct master_auth_connection *conn)
 {
-	i_error("master(%s): Auth request timed out (received %u/%u bytes)",
-		conn->path, conn->buf_pos,
-		(unsigned int)sizeof(conn->buf));
+	conn_error(conn, "Auth request timed out");
 	master_auth_connection_deinit(&conn);
 }
 
@@ -169,6 +183,7 @@
 
 	conn = i_new(struct master_auth_connection, 1);
 	conn->auth = auth;
+	conn->create_time = ioloop_timeval;
 	conn->callback = callback;
 	conn->context = context;
 	conn->path = params->socket_path != NULL ?
@@ -179,6 +194,10 @@
 	if (req.tag == 0)
 		req.tag = ++auth->tag_counter;
 
+	conn->client_pid = req.client_pid;
+	conn->auth_id = req.auth_id;
+	conn->remote_ip = req.remote_ip;
+
 	if (fstat(params->client_fd, &st) < 0)
 		i_fatal("fstat(auth dest fd) failed: %m");
 	req.ino = st.st_ino;
@@ -211,7 +230,7 @@
 		}
 	}
 	if (conn->fd == -1) {
-		i_error("net_connect_unix(%s) failed: %m%s",
+		conn_error(conn, "net_connect_unix(%s) failed: %m%s",
 			conn->path, errno != EAGAIN ? "" :
 			" - http://wiki2.dovecot.org/SocketUnavailable");
 		master_auth_connection_deinit(&conn);
@@ -220,11 +239,11 @@
 
 	ret = fd_send(conn->fd, params->client_fd, buf->data, buf->used);
 	if (ret < 0) {
-		i_error("fd_send(%s, %d) failed: %m", conn->path,
-			params->client_fd);
+		conn_error(conn, "fd_send(fd=%d) failed: %m",
+			   params->client_fd);
 	} else if ((size_t)ret != buf->used) {
-		i_error("fd_send(%s) sent only %d of %d bytes",
-			conn->path, (int)ret, (int)buf->used);
+		conn_error(conn, "fd_send() sent only %d of %d bytes",
+			   (int)ret, (int)buf->used);
 		ret = -1;
 	}
 	if (ret < 0) {