lib-master: Improve error logging for post-login script failures

diff --git a/src/lib-master/master-login.c b/src/lib-master/master-login.c
index 42d4a1677cfe4a7cc623cc5e4075ccf3bfca0d17..cbf00c9f3da88f22d534386fc38888c767553638 100644 (file)
--- a/src/lib-master/master-login.c
+++ b/src/lib-master/master-login.c
@@ -39,6 +39,7 @@ struct master_login_postlogin {
        struct master_login_client *client;
 
        int fd;
+       struct timeval create_time;
        struct io *io;
        struct timeout *to;
        string_t *input;
@@ -129,6 +130,14 @@ conn_error(struct master_login_connection *conn, const char *fmt, ...)
                            (long)client->auth_req.auth_pid,
                            client->auth_req.client_pid,
                            client->auth_req.auth_id);
+               if (client->postlogin_client != NULL) {
+                       struct master_login_postlogin *pl =
+                               client->postlogin_client;
+                       str_printfa(str, ", post-login script %s started %d msecs ago",
+                                   pl->socket_path,
+                                   timeval_diff_msecs(&ioloop_timeval,
+                                                      &pl->create_time));
+               }
        }
        i_error("%s (%s)", t_strdup_vprintf(fmt, args), str_c(str));
        va_end(args);
@@ -261,6 +270,10 @@ static void master_login_auth_finish(struct master_login_client *client,
 
 static void master_login_postlogin_free(struct master_login_postlogin *pl)
 {
+       if (pl->client != NULL) {
+               i_assert(pl->client->postlogin_client == pl);
+               master_login_client_free(&pl->client);
+       }
        timeout_remove(&pl->to);
        io_remove(&pl->io);
        if (close(pl->fd) < 0)
@@ -273,6 +286,7 @@ static void master_login_postlogin_free(struct master_login_postlogin *pl)
 
 static void master_login_postlogin_input(struct master_login_postlogin *pl)
 {
+       struct master_login_connection *conn = pl->client->conn;
        char buf[1024];
        const char **auth_args, **p;
        size_t len;
@@ -283,7 +297,7 @@ static void master_login_postlogin_input(struct master_login_postlogin *pl)
                if (fd != -1) {
                        /* post-login script replaced fd */
                        if (close(pl->client->fd) < 0)
-                               i_error("close(client) failed: %m");
+                               conn_error(conn, "close(client) failed: %m");
                        pl->client->fd = fd;
                }
                str_append_n(pl->input, buf, ret);
@@ -298,15 +312,14 @@ static void master_login_postlogin_input(struct master_login_postlogin *pl)
                        if (errno == EAGAIN)
                                return;
 
-                       i_error("fd_read(%s) failed: %m", pl->socket_path);
+                       conn_error(conn, "fd_read(%s) failed: %m", pl->socket_path);
                } else if (str_len(pl->input) > 0) {
-                       i_error("fd_read(%s) failed: disconnected",
-                               pl->socket_path);
+                       conn_error(conn, "fd_read(%s) failed: disconnected",
+                                  pl->socket_path);
                } else {
-                       i_info("Post-login script denied access to user %s",
-                              pl->username);
+                       conn_error(conn, "Post-login script denied access to user %s",
+                                  pl->username);
                }
-               master_login_client_free(&pl->client);
                master_login_postlogin_free(pl);
                return;
        }
@@ -315,16 +328,18 @@ static void master_login_postlogin_input(struct master_login_postlogin *pl)
        for (p = auth_args; *p != NULL; p++)
                *p = str_tabunescape(t_strdup_noconst(*p));
 
+       pl->client->postlogin_client = NULL;
        master_login_auth_finish(pl->client, auth_args);
+
+       pl->client = NULL;
        master_login_postlogin_free(pl);
 }
 
 static void master_login_postlogin_timeout(struct master_login_postlogin *pl)
 {
-       i_error("%s: Timeout waiting for post-login script to finish, aborting",
-               pl->socket_path);
+       conn_error(pl->client->conn,
+                  "Timeout waiting for post-login script to finish, aborting");
 
-       master_login_client_free(&pl->client);
        master_login_postlogin_free(pl);
 }
 
@@ -341,9 +356,9 @@ static int master_login_postlogin(struct master_login_client *client,
 
        fd = net_connect_unix_with_retries(socket_path, 1000);
        if (fd == -1) {
-               i_error("net_connect_unix(%s) failed: %m%s",
-                       socket_path, errno != EAGAIN ? "" :
-                       " - http://wiki2.dovecot.org/SocketUnavailable");
+               conn_error(client->conn, "net_connect_unix(%s) failed: %m%s",
+                          socket_path, errno != EAGAIN ? "" :
+                          " - http://wiki2.dovecot.org/SocketUnavailable");
                return -1;
        }
 
@@ -359,24 +374,29 @@ static int master_login_postlogin(struct master_login_client *client,
        ret = fd_send(fd, client->fd, str_data(str), str_len(str));
        if (ret != (ssize_t)str_len(str)) {
                if (ret < 0) {
-                       i_error("write(%s) failed: %m", socket_path);
+                       conn_error(client->conn, "write(%s) failed: %m", socket_path);
                } else {
-                       i_error("write(%s) failed: partial write", socket_path);
+                       conn_error(client->conn, "write(%s) failed: partial write", socket_path);
                }
                i_close_fd(&fd);
                return -1;
        }
        net_set_nonblock(fd, TRUE);
+       io_loop_time_refresh();
 
        pl = i_new(struct master_login_postlogin, 1);
        pl->client = client;
        pl->username = i_strdup(auth_args[0]);
        pl->socket_path = i_strdup(socket_path);
+       pl->create_time = ioloop_timeval;
        pl->fd = fd;
        pl->io = io_add(fd, IO_READ, master_login_postlogin_input, pl);
        pl->to = timeout_add(login->postlogin_timeout_secs * 1000,
                             master_login_postlogin_timeout, pl);
        pl->input = str_new(default_pool, 512);
+
+       i_assert(client->postlogin_client == NULL);
+       client->postlogin_client = pl;
        return 0;
 }
 

diff --git a/src/lib-master/master-login.h b/src/lib-master/master-login.h
index 00c086f42cb2b8807c0e1294f304984e2fef54fa..97e3e6594666de2d4177f4c35713211479a7c36b 100644 (file)
--- a/src/lib-master/master-login.h
+++ b/src/lib-master/master-login.h
@@ -10,6 +10,8 @@ struct master_login_client {
        struct master_login_connection *conn;
        /* linked list of all clients within the connection */
        struct master_login_client *prev, *next;
+       /* non-NULL while running postlogin script */
+       struct master_login_postlogin *postlogin_client;
 
        int fd;
        struct timeval create_time;