From: Stephan Bosch Date: Mon, 26 Feb 2018 22:12:03 +0000 (+0100) Subject: lib-program-client: Add more detailed debug logging. X-Git-Tag: 2.3.9~2073 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=557d4e6b20bd52cb0e998e2f775dc82bc0394d28;p=thirdparty%2Fdovecot%2Fcore.git 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 46b87dc58b..0a924e40f8 100644 --- 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 d2c3df01c5..4ded4c3d32 100644 --- 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 0dc0b540c5..4922c0ebec 100644 --- 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;