From: Timo Sirainen <tss@iki.fi>
Date: Tue, 10 Jan 2012 19:37:54 +0000 (+0200)
Subject: director: If request is timed out, log an error.
X-Git-Tag: 2.1.rc4~68
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=152db3f90f298b7fb2dbbd4276f0fc30a9bc30f6;p=thirdparty%2Fdovecot%2Fcore.git

director: If request is timed out, log an error.
---

diff --git a/src/director/director-connection.c b/src/director/director-connection.c
index be90c2bddc..857f9c057e 100644
--- a/src/director/director-connection.c
+++ b/src/director/director-connection.c
@@ -570,7 +570,7 @@ static void director_handshake_cmd_done(struct director_connection *conn)
 		/* we're connected to both directors. see if the ring is
 		   finished by sending a SYNC. if we get it back, it's done. */
 		dir->sync_seq++;
-		dir->ring_synced = FALSE;
+		director_set_ring_unsynced(dir);
 		director_connection_send(dir->right,
 			t_strdup_printf("SYNC\t%s\t%u\t%u\n",
 					net_ip2addr(&dir->self_ip),
@@ -1130,7 +1130,7 @@ void director_connection_deinit(struct director_connection **_conn)
 	if (dir->left == NULL || dir->right == NULL) {
 		/* we aren't synced until we're again connected to a ring */
 		dir->sync_seq++;
-		dir->ring_synced = FALSE;
+		director_set_ring_unsynced(dir);
 	}
 }
 
diff --git a/src/director/director-request.c b/src/director/director-request.c
index a54d476810..195fcc10c3 100644
--- a/src/director/director-request.c
+++ b/src/director/director-request.c
@@ -3,6 +3,7 @@
 #include "lib.h"
 #include "ioloop.h"
 #include "array.h"
+#include "str.h"
 #include "mail-host.h"
 #include "user-directory.h"
 #include "director.h"
@@ -21,9 +22,32 @@ struct director_request {
 	void *context;
 };
 
+static const char *
+director_request_get_timeout_error(struct director_request *request)
+{
+	string_t *str = t_str_new(128);
+	unsigned int secs;
+
+	str_printfa(str, "Timeout - queued for %u secs (",
+		    (unsigned int)(ioloop_time - request->create_time));
+
+	if (request->dir->ring_last_sync_time == 0)
+		str_append(str, "Ring has never been synced");
+	else {
+		secs =ioloop_time - request->dir->ring_last_sync_time;
+		if (request->dir->ring_synced)
+			str_printfa(str, "Ring synced for %u secs", secs);
+		else
+			str_printfa(str, "Ring not synced for %u secs", secs);
+	}
+	str_append_c(str, ')');
+	return str_c(str);
+}
+
 static void director_request_timeout(struct director *dir)
 {
 	struct director_request **requestp, *request;
+	const char *errormsg;
 
 	while (array_count(&dir->pending_requests) > 0) {
 		requestp = array_idx_modifiable(&dir->pending_requests, 0);
@@ -34,7 +58,10 @@ static void director_request_timeout(struct director *dir)
 			break;
 
 		array_delete(&dir->pending_requests, 0, 1);
-		request->callback(NULL, request->context);
+		errormsg = director_request_get_timeout_error(request);
+		T_BEGIN {
+			request->callback(NULL, errormsg, request->context);
+		} T_END;
 		i_free(request);
 	}
 
@@ -126,7 +153,9 @@ bool director_request_continue(struct director_request *request)
 	}
 
 	director_update_user(dir, dir->self_host, user);
-	request->callback(&user->host->ip, request->context);
+	T_BEGIN {
+		request->callback(&user->host->ip, NULL, request->context);
+	} T_END;
 	i_free(request);
 	return TRUE;
 }
diff --git a/src/director/director-request.h b/src/director/director-request.h
index 6de5cae71b..0773d5ef88 100644
--- a/src/director/director-request.h
+++ b/src/director/director-request.h
@@ -5,7 +5,8 @@ struct director;
 struct director_request;
 
 typedef void
-director_request_callback(const struct ip_addr *ip, void *context);
+director_request_callback(const struct ip_addr *ip, const char *errormsg,
+			  void *context);
 
 void director_request(struct director *dir, const char *username,
 		      director_request_callback *callback, void *context);
diff --git a/src/director/director.c b/src/director/director.c
index 1a8177cce1..6d39ce03e1 100644
--- a/src/director/director.c
+++ b/src/director/director.c
@@ -226,9 +226,18 @@ void director_set_ring_synced(struct director *dir)
 	}
 
 	dir->ring_synced = TRUE;
+	dir->ring_last_sync_time = ioloop_time;
 	director_set_state_changed(dir);
 }
 
+void director_set_ring_unsynced(struct director *dir)
+{
+	if (dir->ring_synced) {
+		dir->ring_synced = FALSE;
+		dir->ring_last_sync_time = ioloop_time;
+	}
+}
+
 static void director_sync(struct director *dir)
 {
 	if (dir->sync_frozen) {
@@ -243,7 +252,7 @@ static void director_sync(struct director *dir)
 
 	/* we're synced again when we receive this SYNC back */
 	dir->sync_seq++;
-	dir->ring_synced = FALSE;
+	director_set_ring_unsynced(dir);
 
 	if (dir->debug) {
 		i_debug("Ring is desynced (seq=%u, sending SYNC to %s)",
diff --git a/src/director/director.h b/src/director/director.h
index 889662bec9..f737f725b0 100644
--- a/src/director/director.h
+++ b/src/director/director.h
@@ -45,6 +45,7 @@ struct director {
 
 	struct ipc_client *ipc_proxy;
 	unsigned int sync_seq;
+	time_t ring_last_sync_time;
 
 	/* director ring handshaking is complete.
 	   director can start serving clients. */
@@ -71,6 +72,7 @@ void director_connect(struct director *dir);
 
 void director_set_ring_handshaked(struct director *dir);
 void director_set_ring_synced(struct director *dir);
+void director_set_ring_unsynced(struct director *dir);
 void director_set_state_changed(struct director *dir);
 
 void director_update_host(struct director *dir, struct director_host *src,
diff --git a/src/director/login-connection.c b/src/director/login-connection.c
index ac2efbab48..0500a0266c 100644
--- a/src/director/login-connection.c
+++ b/src/director/login-connection.c
@@ -30,7 +30,7 @@ struct login_connection {
 
 struct login_host_request {
 	struct login_connection *conn;
-	char *line;
+	char *line, *username;
 };
 
 static struct login_connection *login_connections;
@@ -70,29 +70,31 @@ login_connection_send_line(struct login_connection *conn, const char *line)
 	(void)o_stream_sendv(conn->output, iov, N_ELEMENTS(iov));
 }
 
-static void login_host_callback(const struct ip_addr *ip, void *context)
+static void
+login_host_callback(const struct ip_addr *ip, const char *errormsg,
+		    void *context)
 {
 	struct login_host_request *request = context;
 	struct director *dir = request->conn->dir;
 	const char *line;
 	unsigned int secs;
 
-	T_BEGIN {
-		if (ip != NULL) {
-			secs = dir->set->director_user_expire / 2;
-			line = t_strdup_printf("%s\thost=%s\tproxy_refresh=%u",
-					       request->line, net_ip2addr(ip),
-					       secs);
-		} else {
-			i_assert(strncmp(request->line, "OK\t", 3) == 0);
-			line = t_strconcat("FAIL\t",
-					   t_strcut(request->line + 3, '\t'),
-					   "\ttemp", NULL);
-		}
-		login_connection_send_line(request->conn, line);
-	} T_END;
+	if (ip != NULL) {
+		secs = dir->set->director_user_expire / 2;
+		line = t_strdup_printf("%s\thost=%s\tproxy_refresh=%u",
+				       request->line, net_ip2addr(ip), secs);
+	} else {
+		i_assert(strncmp(request->line, "OK\t", 3) == 0);
+
+		i_error("director: User %s host lookup failed: %s",
+			request->username, errormsg);
+		line = t_strconcat("FAIL\t", t_strcut(request->line + 3, '\t'),
+				   "\ttemp", NULL);
+	}
+	login_connection_send_line(request->conn, line);
 
 	login_connection_unref(&request->conn);
+	i_free(request->username);
 	i_free(request->line);
 	i_free(request);
 }
@@ -155,6 +157,7 @@ static void auth_input_line(const char *line, void *context)
 	request = i_new(struct login_host_request, 1);
 	request->conn = conn;
 	request->line = i_strdup(line);
+	request->username = i_strdup(username);
 
 	conn->refcount++;
 	director_request(conn->dir, username, login_host_callback, request);