dict-client: Don't timeout lookups without waiting 1sec in dict ioloop.

What could have happened was:

 - dict-client sends a request to dict-server
 - dict-client process starts doing something else
 - dict-server answers
 - dict-client process continues doing something else for over 30 seconds,
   not reading the dict-server answer
 - dict-client process gets back to dict ioloop, which runs the timeout
   before checking if there is anything available for reading.

Now we'll wait for 1 second in the last dict ioloop before assuming that
there's a timeout.

diff --git a/src/lib-dict/dict-client.c b/src/lib-dict/dict-client.c
index 847a98da7e7aceb156768ed2fde53684088b1ec5..b6ed2659dc373cececd92c0e5465ca1cfee4902c 100644 (file)
--- a/src/lib-dict/dict-client.c
+++ b/src/lib-dict/dict-client.c
@@ -25,6 +25,9 @@
 
 /* Abort dict lookup after this many seconds. */
 #define DICT_CLIENT_REQUEST_TIMEOUT_MSECS 30000
+/* When dict lookup timeout is reached, wait a bit longer if the last dict
+   ioloop wait was shorter than this. */
+#define DICT_CLIENT_REQUEST_TIMEOUT_MIN_LAST_IOLOOP_WAIT_MSECS 1000
 /* Log a warning if dict lookup takes longer than this many milliseconds. */
 #define DICT_CLIENT_DEFAULT_WARN_SLOW_MSECS 5000
 
@@ -78,6 +81,7 @@ struct client_dict {
 
        struct ioloop *ioloop, *prev_ioloop;
        struct io_wait_timer *wait_timer;
+       uint64_t last_timer_switch_usecs;
        struct timeout *to_requests;
        struct timeout *to_idle;
        unsigned int idle_msecs;
@@ -237,6 +241,7 @@ static void client_dict_input_timeout(struct client_dict *dict)
 {
        struct client_dict_cmd *cmd;
        const char *error;
+       uint64_t msecs_in_last_dict_ioloop_wait;
        int cmd_diff;
 
        /* find the first non-background command. there must be at least one. */
@@ -255,6 +260,21 @@ static void client_dict_input_timeout(struct client_dict *dict)
                return;
        }
 
+       /* If we've gotten here because all the time was spent in other ioloops
+          or locks, make sure there's a bit of time waiting for the dict
+          ioloop as well. There's a good chance that the reply can be read. */
+       msecs_in_last_dict_ioloop_wait =
+               (io_wait_timer_get_usecs(dict->wait_timer) -
+                dict->last_timer_switch_usecs + 999) / 1000;
+       if (msecs_in_last_dict_ioloop_wait < DICT_CLIENT_REQUEST_TIMEOUT_MIN_LAST_IOLOOP_WAIT_MSECS) {
+               timeout_remove(&dict->to_requests);
+               dict->to_requests =
+                       timeout_add(DICT_CLIENT_REQUEST_TIMEOUT_MIN_LAST_IOLOOP_WAIT_MSECS -
+                                   msecs_in_last_dict_ioloop_wait,
+                                   client_dict_input_timeout, dict);
+               return;
+       }
+
        (void)client_dict_reconnect(dict, t_strdup_printf(
                "Dict server timeout: %s "
                "(%u commands pending, oldest sent %u.%03u secs ago: %s, %s)",
@@ -824,6 +844,8 @@ static bool client_dict_switch_ioloop(struct dict *_dict)
 {
        struct client_dict *dict = (struct client_dict *)_dict;
 
+       dict->last_timer_switch_usecs =
+               io_wait_timer_get_usecs(dict->wait_timer);
        dict->wait_timer = io_wait_timer_move(&dict->wait_timer);
        if (dict->to_idle != NULL)
                dict->to_idle = io_loop_move_timeout(&dict->to_idle);