dovecot-2.0: dict proxy client: Timeout lookups after 30 s, log ...

[dovecot at dovecot.org]

details:   http://hg.dovecot.org/dovecot-2.0/rev/ba3c809c18e5
changeset: 11164:ba3c809c18e5
user:      Timo Sirainen <tss at iki.fi>
date:      Fri Apr 16 16:44:15 2010 +0300
description:
dict proxy client: Timeout lookups after 30 s, log warning if lookup takes >5 s.

diffstat:

 src/lib-dict/dict-client.c |  45 ++++++++++++++++++++++++++++++++++++++++++---
 1 files changed, 42 insertions(+), 3 deletions(-)

diffs (83 lines):

diff -r 4b14271e04db -r ba3c809c18e5 src/lib-dict/dict-client.c
--- a/src/lib-dict/dict-client.c	Fri Apr 16 16:42:58 2010 +0300
+++ b/src/lib-dict/dict-client.c	Fri Apr 16 16:44:15 2010 +0300
@@ -19,6 +19,11 @@
    timeout increases number of idling dict processes. */
 #define DICT_CLIENT_TIMEOUT_MSECS 1000
 
+/* Abort dict lookup after this many seconds. */
+#define DICT_CLIENT_READ_TIMEOUT_SECS 30
+/* Log a warning if dict lookup takes longer than this many seconds. */
+#define DICT_CLIENT_READ_WARN_TIMEOUT_SECS 5
+
 struct client_dict {
 	struct dict dict;
 
@@ -265,15 +270,46 @@
 		io_remove(&dict->io);
 }
 
+static ssize_t client_dict_read_timeout(struct client_dict *dict)
+{
+	time_t now, timeout;
+	unsigned int diff;
+	ssize_t ret;
+
+	now = time(NULL);
+	timeout = now + DICT_CLIENT_READ_TIMEOUT_SECS;
+
+	do {
+		alarm(timeout - now);
+		ret = i_stream_read(dict->input);
+		alarm(0);
+		if (ret != 0)
+			break;
+
+		/* interrupted most likely because of timeout,
+		   but check anyway. */
+		now = time(NULL);
+	} while (now < timeout);
+
+	if (ret > 0) {
+		diff = time(NULL) - now;
+		if (diff >= DICT_CLIENT_READ_WARN_TIMEOUT_SECS) {
+			i_warning("read(%s): dict lookup took %u seconds",
+				  dict->path, diff);
+		}
+	}
+	return ret;
+}
+
 static int client_dict_read_one_line(struct client_dict *dict, char **line_r)
 {
 	unsigned int id;
 	char *line;
-	int ret;
+	ssize_t ret;
 
 	*line_r = NULL;
 	while ((line = i_stream_next_line(dict->input)) == NULL) {
-		ret = i_stream_read(dict->input);
+		ret = client_dict_read_timeout(dict);
 		switch (ret) {
 		case -1:
 			if (dict->input->stream_errno != 0)
@@ -286,6 +322,10 @@
 		case -2:
 			i_error("read(%s) returned too much data", dict->path);
 			return -1;
+		case 0:
+			i_error("read(%s) failed: Timeout after %u seconds",
+				dict->path, DICT_CLIENT_READ_TIMEOUT_SECS);
+			return -1;
 		default:
 			i_assert(ret > 0);
 			break;
@@ -373,7 +413,6 @@
 	net_set_nonblock(dict->fd, FALSE);
 
 	dict->input = i_stream_create_fd(dict->fd, (size_t)-1, FALSE);
-	dict->input->blocking = TRUE;
 	dict->output = o_stream_create_fd(dict->fd, 4096, FALSE);
 	dict->transaction_id_counter = 0;
 	dict->async_commits = 0;