lib-program-client: Add more detailed debug logging.

diff --git a/src/lib-program-client/program-client-local.c b/src/lib-program-client/program-client-local.c
index 46b87dc58bef469b742e231b7acc6a390d783a08..0a924e40f8b197fdcd97545b1b652df4bf21c028 100644 (file)
--- a/src/lib-program-client/program-client-local.c
+++ b/src/lib-program-client/program-client-local.c
@@ -142,6 +142,8 @@ program_client_local_waitchild(const struct child_wait_status *status,
 
        i_assert(plclient->pid == status->pid);
 
+       e_debug(pclient->event, "Child process ended");
+
        plclient->status = status->status;
        plclient->exited = TRUE;
        plclient->pid = -1;
@@ -267,6 +269,8 @@ program_client_local_connect(struct program_client *pclient)
        }
 
        /* parent */
+       e_debug(pclient->event, "Forked child process");
+
        program_client_set_label(pclient,
                t_strdup_printf("exec:%s (%d)", plclient->bin_path,
                                plclient->pid));
@@ -386,6 +390,8 @@ program_client_local_kill_now(struct program_client_local *plclient)
        if (plclient->pid < 0)
                return;
 
+       e_debug(pclient->event, "Sending SIGKILL signal to program");
+
        /* kill it brutally now: it should die right away */
        if (kill(plclient->pid, SIGKILL) < 0) {
                e_error(pclient->event,
@@ -468,6 +474,7 @@ program_client_local_disconnect(struct program_client *pclient, bool force)
 
        /* make sure it hasn't already been reaped */
        if (waitpid(plclient->pid, &plclient->status, WNOHANG) > 0) {
+               e_debug(pclient->event, "Child process ended");
                program_client_local_exited(plclient);
                return;
        }

diff --git a/src/lib-program-client/program-client-remote.c b/src/lib-program-client/program-client-remote.c
index d2c3df01c530bb64fc2ae53d45e9e3a4e1a8715f..4ded4c3d3212112c162657dab6b2d9a8577684ba 100644 (file)
--- a/src/lib-program-client/program-client-remote.c
+++ b/src/lib-program-client/program-client-remote.c
@@ -447,6 +447,9 @@ program_client_net_connect_resolved(const struct dns_lookup_result *result,
                return;
        }
 
+       e_debug(pclient->event, "DNS lookup successful; got %d IPs",
+               result->ips_count);
+
        /* reduce timeout */
        if (pclient->set.client_connect_timeout_msecs > 0) {
                if (pclient->set.client_connect_timeout_msecs <= result->msecs) {
@@ -483,6 +486,8 @@ program_client_net_connect_init(struct program_client *pclient)
        } else {
                prclient->resolved = FALSE;
                if (pclient->set.dns_client_socket_path != NULL) {
+                       e_debug(pclient->event,
+                               "Performing asynchronous DNS lookup");
                        prclient->dns_set.dns_client_socket_path =
                                pclient->set.dns_client_socket_path;
                        prclient->dns_set.timeout_msecs =
@@ -507,6 +512,10 @@ program_client_net_connect_init(struct program_client *pclient)
                        prclient->ips_count = ips_count;
                        prclient->ips = p_memdup(pclient->pool,
                                                 ips, sizeof(*ips)*ips_count);
+
+                       e_debug(pclient->event,
+                               "DNS lookup successful; got %d IPs",
+                               ips_count);
                }
        }
 

diff --git a/src/lib-program-client/program-client.c b/src/lib-program-client/program-client.c
index 0dc0b540c5106a5775d4f7884cc9c4151977f16d..4922c0ebec3b601333268a54c76983cee6cb1915 100644 (file)
--- a/src/lib-program-client/program-client.c
+++ b/src/lib-program-client/program-client.c
@@ -4,6 +4,7 @@
 #include "ioloop.h"
 #include "array.h"
 #include "str.h"
+#include "str-sanitize.h"
 #include "safe-mkstemp.h"
 #include "istream-private.h"
 #include "ostream-dot.h"
@@ -60,6 +61,8 @@ program_client_connect_timeout(struct program_client *pclient)
 static int
 program_client_connect(struct program_client *pclient)
 {
+       e_debug(pclient->event, "Establishing connection");
+
        if (pclient->set.client_connect_timeout_msecs != 0) {
                pclient->to = timeout_add(
                        pclient->set.client_connect_timeout_msecs,
@@ -122,6 +125,8 @@ program_client_do_disconnect(struct program_client *pclient)
 
        program_client_disconnect_extra_fds(pclient);
 
+       if (!pclient->disconnected)
+               e_debug(pclient->event, "Disconnected");
        pclient->disconnected = TRUE;
 }
 
@@ -156,6 +161,8 @@ void program_client_fail(struct program_client *pclient,
        if (pclient->error != PROGRAM_CLIENT_ERROR_NONE)
                return;
 
+       e_debug(pclient->event, "Failed to run program");
+
        pclient->error = error;
        program_client_disconnect(pclient, TRUE);
 }
@@ -197,6 +204,8 @@ program_client_input_pending(struct program_client *pclient)
 static void
 program_client_output_finished(struct program_client *pclient)
 {
+       e_debug(pclient->event, "Finished input to program");
+
        /* check whether program i/o is finished */
        if (!program_client_input_pending(pclient)) {
                /* finished */
@@ -259,6 +268,8 @@ program_client_output_pump_finished(enum iostream_pump_status status,
 
        iostream_pump_destroy(&pclient->pump_out);
 
+       e_debug(pclient->event, "Finished streaming payload to program");
+
        o_stream_set_flush_callback(pclient->program_output,
                program_client_output_finish, pclient);
        o_stream_set_flush_pending(pclient->program_output, TRUE);
@@ -267,6 +278,8 @@ program_client_output_pump_finished(enum iostream_pump_status status,
 static void
 program_client_input_finished(struct program_client *pclient)
 {
+       e_debug(pclient->event, "Finished output from program");
+
        /* check whether program i/o is finished */
        if (program_client_input_pending(pclient))
                return;
@@ -347,6 +360,8 @@ program_client_input_pump_finished(enum iostream_pump_status status,
 
        iostream_pump_destroy(&pclient->pump_in);
 
+       e_debug(pclient->event, "Finished streaming payload from program");
+
        if (pclient->program_input != pclient->raw_program_input) {
                /* return to raw program input */
                i_stream_unref(&pclient->program_input);
@@ -376,6 +391,8 @@ program_client_extra_fd_input(struct program_client_extra_fd *efd)
 
 void program_client_connected(struct program_client *pclient)
 {
+       e_debug(pclient->event, "Connected to program");
+
        /* finish creating program input */
        if (pclient->raw_program_input != NULL) {
                struct istream *input = pclient->raw_program_input;
@@ -458,6 +475,8 @@ void program_client_init(struct program_client *pclient, pool_t pool,
        if ((set != NULL && set->debug))
                event_set_forced_debug(pclient->event, TRUE);
        program_client_set_label(pclient, initial_label);
+
+       e_debug(pclient->event, "Created");
 }
 
 void program_client_set_input(struct program_client *pclient,
@@ -537,6 +556,9 @@ void program_client_set_env(struct program_client *pclient, const char *name,
 
        env = p_strdup_printf(pclient->pool, "%s=%s", name, value);
        array_append(&pclient->envs, &env, 1);
+
+       e_debug(pclient->event, "Pass environment: %s",
+               str_sanitize(env, 256));
 }
 
 void program_client_init_streams(struct program_client *pclient)
@@ -585,6 +607,8 @@ void program_client_destroy(struct program_client **_pclient)
 
        *_pclient = NULL;
 
+       e_debug(pclient->event, "Destroy");
+
        pclient->destroying = TRUE;
        pclient->callback = NULL;