From: Aki Tuomi <aki.tuomi@dovecot.fi>
Date: Tue, 20 Nov 2018 12:09:43 +0000 (+0200)
Subject: auth: auth-worker - Add event
X-Git-Tag: 2.3.9~771
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=825242011cd4fdbbd34a7eef9331d4d77c6706c0;p=thirdparty%2Fdovecot%2Fcore.git

auth: auth-worker - Add event
---

diff --git a/src/auth/auth-worker-client.c b/src/auth/auth-worker-client.c
index f3ca0383f7..970e9cbdb0 100644
--- a/src/auth/auth-worker-client.c
+++ b/src/auth/auth-worker-client.c
@@ -29,6 +29,7 @@ struct auth_worker_client {
 	int refcount;
 
         struct auth *auth;
+	struct event *event;
 	time_t cmd_start;
 
 	bool error_sent:1;
@@ -50,6 +51,19 @@ static int auth_worker_output(struct auth_worker_client *client);
 static void auth_worker_client_destroy(struct connection *conn);
 static void auth_worker_client_unref(struct auth_worker_client **_client);
 
+static void auth_worker_log_finished(struct auth_worker_client *client,
+				     const char *error)
+{
+	struct event_passthrough *e = event_create_passthrough(client->event)->
+		set_name("auth_worker_request_finished");
+	if (error != NULL) {
+		e->add_str("error", error);
+		e_error(e->event(), "Finished: %s", error);
+	} else {
+		e_debug(e->event(), "Finished");
+	}
+}
+
 void auth_worker_refresh_proctitle(const char *state)
 {
 	if (!global_auth_settings->verbose_proctitle || !worker)
@@ -126,7 +140,7 @@ static void auth_worker_send_reply(struct auth_worker_client *client,
 		p = i_strchr_to_next(str_c(str), '\t');
 		p = p == NULL ? "BUG" : t_strcut(p, '\t');
 
-		i_warning("Auth master disconnected us while handling "
+		e_warning(client->event, "Auth master disconnected us while handling "
 			  "request for %s for %ld secs (result=%s)",
 			  request->user, (long)cmd_duration, p);
 	}
@@ -183,6 +197,7 @@ static void verify_plain_callback(enum passdb_result result,
 	str_append_c(str, '\n');
 	auth_worker_send_reply(client, request, str);
 
+	auth_worker_log_finished(client, NULL);
 	auth_request_unref(&request);
 	auth_worker_client_check_throttle(client);
 	auth_worker_client_unref(&client);
@@ -283,6 +298,7 @@ auth_worker_handle_passw(struct auth_worker_client *client,
 	str_append_c(str, '\n');
 	auth_worker_send_reply(client, request, str);
 
+	auth_worker_log_finished(client, NULL);
 	auth_request_unref(&request);
 	auth_worker_client_check_throttle(client);
 	auth_worker_client_unref(&client);
@@ -325,6 +341,7 @@ lookup_credentials_callback(enum passdb_result result,
 	auth_worker_send_reply(client, request, str);
 
 	auth_request_unref(&request);
+	auth_worker_log_finished(client, NULL);
 	auth_worker_client_check_throttle(client);
 	auth_worker_client_unref(&client);
 }
@@ -384,6 +401,7 @@ set_credentials_callback(bool success, struct auth_request *request)
 	str_printfa(str, "%u\t%s\n", request->id, success ? "OK" : "FAIL");
 	auth_worker_send_reply(client, request, str);
 
+	auth_worker_log_finished(client, NULL);
 	auth_request_unref(&request);
 	auth_worker_client_check_throttle(client);
 	auth_worker_client_unref(&client);
@@ -457,6 +475,7 @@ lookup_user_callback(enum userdb_result result,
 
 	auth_worker_send_reply(client, auth_request, str);
 
+	auth_worker_log_finished(client, NULL);
 	auth_request_unref(&auth_request);
 	auth_worker_client_check_throttle(client);
 	auth_worker_client_unref(&client);
@@ -534,6 +553,7 @@ static void list_iter_deinit(struct auth_worker_list_context *ctx)
 	connection_input_resume(&client->conn);
 	o_stream_set_flush_callback(client->conn.output, auth_worker_output,
 				    client);
+	auth_worker_log_finished(client, NULL);
 	auth_request_unref(&ctx->auth_request);
 	auth_worker_client_unref(&client);
 	i_free(ctx);
@@ -701,8 +721,14 @@ auth_worker_client_input_args(struct connection *conn, const char *const *args)
 	}
 
 	io_loop_time_refresh();
+	if (client->event == NULL)
+		client->event = event_create(client->conn.event);
+	event_add_str(client->event, "command", args[1]);
+	event_add_int(client->event, "id", id);
+	event_set_append_log_prefix(client->event, t_strdup_printf("auth-worker<%u>: ", id));
 	client->cmd_start = ioloop_time;
 	client->refcount++;
+	e_debug(client->event, "Handling %s request", args[1]);
 
 	auth_worker_refresh_proctitle(args[1]);
 	if (strcmp(args[1], "PASSV") == 0)
@@ -724,11 +750,11 @@ auth_worker_client_input_args(struct connection *conn, const char *const *args)
 
 	i_assert(ret || error != NULL);
 
-	if (!ret)
-		i_error("%s", error);
-
-	if (client->conn.io != NULL)
+	if (!ret) {
+		auth_worker_log_finished(client, error);
+	} else if (client->conn.io == NULL) {
 		auth_worker_refresh_proctitle(CLIENT_STATE_IDLE);
+	}
 	auth_worker_client_unref(&client);
 	return ret ? 1 : -1;
 }