dovecot-2.1: director: -D parameter now enables extensive debug ...
dovecot at dovecot.org
dovecot at dovecot.org
Mon Oct 22 15:36:06 EEST 2012
details: http://hg.dovecot.org/dovecot-2.1/rev/48af47f2eb9c
changeset: 14780:48af47f2eb9c
user: Timo Sirainen <tss at iki.fi>
date: Mon Oct 22 15:35:59 2012 +0300
description:
director: -D parameter now enables extensive debug logging.
diffstat:
src/director/director-connection.c | 50 +++++++++++++++++++++----------------
src/director/director-request.c | 17 ++++++++++++
src/director/director.c | 33 ++++++++++++++++--------
src/director/director.h | 5 +++-
src/director/main.c | 2 +-
5 files changed, 72 insertions(+), 35 deletions(-)
diffs (truncated from 305 to 300 lines):
diff -r c16a0182533f -r 48af47f2eb9c src/director/director-connection.c
--- a/src/director/director-connection.c Mon Oct 22 15:32:04 2012 +0300
+++ b/src/director/director-connection.c Mon Oct 22 15:35:59 2012 +0300
@@ -454,12 +454,15 @@
*user_r = user_directory_add(dir->users, username_hash,
host, timestamp);
(*user_r)->weak = weak;
+ dir_debug("user refresh: %u added", username_hash);
return TRUE;
}
if (user->weak) {
if (!weak) {
/* removing user's weakness */
+ dir_debug("user refresh: %u weakness removed",
+ username_hash);
unset_weak_user = TRUE;
user->weak = FALSE;
ret = TRUE;
@@ -469,6 +472,7 @@
} else if (weak &&
!user_directory_user_is_recently_updated(dir->users, user)) {
/* mark the user as weak */
+ dir_debug("user refresh: %u set weak", username_hash);
user->weak = TRUE;
ret = TRUE;
} else if (user->host != host) {
@@ -516,6 +520,8 @@
user_directory_refresh(dir->users, user);
ret = TRUE;
}
+ dir_debug("user refresh: %u refreshed timeout to %ld",
+ username_hash, (long)user->timestamp);
if (unset_weak_user) {
/* user is no longer weak. handle pending requests for
@@ -938,7 +944,7 @@
unsigned int handshake_secs = time(NULL) - conn->created;
string_t *str;
- if (handshake_secs >= DIRECTOR_HANDSHAKE_WARN_SECS || dir->debug) {
+ if (handshake_secs >= DIRECTOR_HANDSHAKE_WARN_SECS || director_debug) {
str = t_str_new(128);
str_printfa(str, "director(%s): Handshake took %u secs, "
"bytes in=%"PRIuUOFF_T" out=%"PRIuUOFF_T,
@@ -1065,10 +1071,8 @@
/* duplicate SYNC (which was sent just in case the
previous one got lost) */
} else {
- if (dir->debug) {
- i_debug("Ring is synced (%s sent seq=%u)",
- conn->name, seq);
- }
+ dir_debug("Ring is synced (%s sent seq=%u)",
+ conn->name, seq);
director_set_ring_synced(dir);
}
} else if (dir->right != NULL) {
@@ -1130,23 +1134,18 @@
director_host_cmp_to_self(host, dir->right->host,
dir->self_host) <= 0) {
/* the old connection is the correct one */
- if (dir->debug) {
- i_debug("Ignoring CONNECT request to %s "
- "(current right is %s)",
- host->name, dir->right->name);
- }
+ dir_debug("Ignoring CONNECT request to %s (current right is %s)",
+ host->name, dir->right->name);
return TRUE;
}
- if (dir->debug) {
- if (dir->right == NULL) {
- i_debug("Received CONNECT request to %s, "
- "initializing right", host->name);
- } else {
- i_debug("Received CONNECT request to %s, "
- "replacing current right %s",
- host->name, dir->right->name);
- }
+ if (dir->right == NULL) {
+ dir_debug("Received CONNECT request to %s, "
+ "initializing right", host->name);
+ } else {
+ dir_debug("Received CONNECT request to %s, "
+ "replacing current right %s",
+ host->name, dir->right->name);
}
/* connect here */
@@ -1254,6 +1253,8 @@
const char *cmd, *const *args;
bool ret;
+ dir_debug("input: %s: %s", conn->name, line);
+
args = t_strsplit_tab(line);
cmd = args[0]; args++;
if (cmd == NULL) {
@@ -1535,9 +1536,9 @@
*_conn = NULL;
- if (dir->debug && conn->host != NULL) {
- i_debug("Disconnecting from %s: %s",
- conn->host->name, remote_reason);
+ if (conn->host != NULL) {
+ dir_debug("Disconnecting from %s: %s",
+ conn->host->name, remote_reason);
}
if (*remote_reason != '\0' &&
conn->minor_version >= DIRECTOR_VERSION_QUIT) {
@@ -1629,6 +1630,11 @@
if (conn->output->closed || !conn->connected)
return;
+ if (director_debug) T_BEGIN {
+ const char *const *lines = t_strsplit(data, "\n");
+ for (; lines[1] != NULL; lines++)
+ dir_debug("output: %s: %s", conn->name, *lines);
+ } T_END;
ret = o_stream_send(conn->output, data, len);
if (ret != (off_t)len) {
if (ret < 0)
diff -r c16a0182533f -r 48af47f2eb9c src/director/director-request.c
--- a/src/director/director-request.c Mon Oct 22 15:32:04 2012 +0300
+++ b/src/director/director-request.c Mon Oct 22 15:35:59 2012 +0300
@@ -168,6 +168,8 @@
/* delay processing this user's connections until
its existing connections have been killed */
request->delay_reason = REQUEST_DELAY_KILL;
+ dir_debug("request: %u waiting for kill to finish",
+ user->username_hash);
return FALSE;
}
if (dir->right == NULL && dir->ring_synced) {
@@ -182,6 +184,8 @@
if (user->weak) {
/* wait for user to become non-weak */
request->delay_reason = REQUEST_DELAY_WEAK;
+ dir_debug("request: %u waiting for weakness",
+ request->username_hash);
return FALSE;
}
if (!user_directory_user_is_near_expiring(dir->users, user))
@@ -193,6 +197,8 @@
if (!dir->ring_synced) {
/* try again later once ring is synced */
request->delay_reason = REQUEST_DELAY_RINGNOTSYNCED;
+ dir_debug("request: %u waiting for sync for making weak",
+ request->username_hash);
return FALSE;
}
if (user->host == host) {
@@ -237,6 +243,7 @@
user->weak = TRUE;
director_update_user_weak(dir, dir->self_host, NULL, user);
request->delay_reason = REQUEST_DELAY_WEAK;
+ dir_debug("request: %u set to weak", request->username_hash);
return FALSE;
}
}
@@ -249,6 +256,8 @@
if (!dir->ring_handshaked) {
/* delay requests until ring handshaking is complete */
+ dir_debug("request: %u waiting for handshake",
+ request->username_hash);
ring_log_delayed_warning(dir);
request->delay_reason = REQUEST_DELAY_RINGNOTHANDSHAKED;
return FALSE;
@@ -259,11 +268,15 @@
if (!director_request_existing(request, user))
return FALSE;
user_directory_refresh(dir->users, user);
+ dir_debug("request: %u refreshed timeout to %u",
+ request->username_hash, user->timestamp);
} else {
if (!dir->ring_synced) {
/* delay adding new users until ring is again synced */
ring_log_delayed_warning(dir);
request->delay_reason = REQUEST_DELAY_RINGNOTSYNCED;
+ dir_debug("request: %u waiting for sync for adding",
+ request->username_hash);
return FALSE;
}
host = mail_host_get_by_hash(dir->mail_hosts,
@@ -271,10 +284,14 @@
if (host == NULL) {
/* all hosts have been removed */
request->delay_reason = REQUEST_DELAY_NOHOSTS;
+ dir_debug("request: %u waiting for hosts",
+ request->username_hash);
return FALSE;
}
user = user_directory_add(dir->users, request->username_hash,
host, ioloop_time);
+ dir_debug("request: %u added timeout to %u",
+ request->username_hash, user->timestamp);
}
i_assert(!user->weak);
diff -r c16a0182533f -r 48af47f2eb9c src/director/director.c
--- a/src/director/director.c Mon Oct 22 15:32:04 2012 +0300
+++ b/src/director/director.c Mon Oct 22 15:35:59 2012 +0300
@@ -22,6 +22,8 @@
#define DIRECTOR_QUICK_RECONNECT_TIMEOUT_MSECS 1000
#define DIRECTOR_DELAYED_DIR_REMOVE_MSECS (1000*30)
+bool director_debug;
+
static bool director_is_self_ip_set(struct director *dir)
{
struct ip_addr ip;
@@ -106,10 +108,8 @@
if (director_has_outgoing_connection(dir, host))
return 0;
- if (dir->debug) {
- i_debug("Connecting to %s:%u",
- net_ip2addr(&host->ip), host->port);
- }
+ dir_debug("Connecting to %s:%u",
+ net_ip2addr(&host->ip), host->port);
port = dir->test_port != 0 ? dir->test_port : host->port;
fd = net_connect_ip(&host->ip, port, &dir->self_ip);
if (fd == -1) {
@@ -239,8 +239,7 @@
"continuing delayed requests");
dir->ring_handshake_warning_sent = FALSE;
}
- if (dir->debug)
- i_debug("Director ring handshaked");
+ dir_debug("Director ring handshaked");
dir->ring_handshaked = TRUE;
director_set_ring_synced(dir);
@@ -383,11 +382,9 @@
return;
}
- if (dir->debug) {
- i_debug("Ring is desynced (seq=%u, sending SYNC to %s)",
- dir->sync_seq, dir->right == NULL ? "(nowhere)" :
- director_connection_get_name(dir->right));
- }
+ dir_debug("Ring is desynced (seq=%u, sending SYNC to %s)",
+ dir->sync_seq, dir->right == NULL ? "(nowhere)" :
+ director_connection_get_name(dir->right));
/* send PINGs to our connections more rapidly until we've synced again.
if the connection has actually died, we don't need to wait (and
@@ -889,3 +886,17 @@
array_free(&dir->connections);
i_free(dir);
}
+
+void dir_debug(const char *fmt, ...)
+{
+ va_list args;
+
+ if (!director_debug)
+ return;
+
+ va_start(args, fmt);
+ T_BEGIN {
+ i_debug("%s", t_strdup_vprintf(fmt, args));
+ } T_END;
+ va_end(args);
+}
diff -r c16a0182533f -r 48af47f2eb9c src/director/director.h
--- a/src/director/director.h Mon Oct 22 15:32:04 2012 +0300
+++ b/src/director/director.h Mon Oct 22 15:35:59 2012 +0300
@@ -80,9 +80,10 @@
unsigned int ring_synced:1;
unsigned int sync_frozen:1;
unsigned int sync_pending:1;
- unsigned int debug:1;
};
+extern bool director_debug;
+
/* Create a new director. If listen_ip specifies an actual IP, it's used with
listen_port for finding ourself from the director_servers setting.
listen_port is used regardless by director_host_add_from_string() for hosts
@@ -147,4 +148,6 @@
int director_connect_host(struct director *dir, struct director_host *host);
+void dir_debug(const char *fmt, ...) ATTR_FORMAT(1, 2);
+
#endif
diff -r c16a0182533f -r 48af47f2eb9c src/director/main.c
--- a/src/director/main.c Mon Oct 22 15:32:04 2012 +0300
+++ b/src/director/main.c Mon Oct 22 15:35:59 2012 +0300
@@ -215,7 +215,7 @@
main_preinit();
master_service_init_finish(master_service);
director->test_port = test_port;
More information about the dovecot-cvs
mailing list