From 0177479cc58ec6a744a6aa17f739dc833dde40f6 Mon Sep 17 00:00:00 2001
From: Jessie Murray <jessie.murray@protonmail.com>
Date: Mon, 1 Mar 2021 18:24:48 -0800
Subject: [PATCH] Log Redis auth response

We were ignoring the response sent by Redis for AUTH commands. This
commit adds a callback which logs the response; I've tested it with
valid and invalid credentials and the log message is correct in both
cases. There's a lock on the server object to only log this once; I
tried adding it on the pool object but there's one pool per thread so
we still ended up with multiple messages.
---
 src/pool.c   | 41 +++++++++++++++++++++++++++++++++++++++--
 src/server.c |  2 ++
 src/server.h |  4 ++++
 3 files changed, 45 insertions(+), 2 deletions(-)

diff --git a/src/pool.c b/src/pool.c
index a3c77e7..262f9ba 100644
--- a/src/pool.c
+++ b/src/pool.c
@@ -116,6 +116,43 @@ pool_on_disconnect(const redisAsyncContext *ac, int status) {
 	pool_schedule_reconnect(p);
 }
 
+static void
+pool_log_auth(struct server *s, log_level level, const char *format, size_t format_len, const char *str) {
+	/* -2 for `%s`, 6 for "(null)", +1 for \0 */
+	size_t msg_size = format_len - 2 + (str ? strlen(str) : 6) + 1;
+	char *msg = calloc(1, msg_size);
+	if(msg) {
+		snprintf(msg, msg_size, format, str ? str : "(null)");
+		slog(s, level, msg, msg_size - 1);
+		free(msg);
+	}
+}
+
+static void
+pool_on_auth_complete(redisAsyncContext *c, void *r, void *data) {
+	redisReply *reply = r;
+	struct pool *p = data;
+	const char err_format[] = "Authentication failed: %s";
+	const char ok_format[] = "Authentication succeeded: %s";
+	struct server *s = p->w->s;
+	(void)c;
+	if(!reply) {
+		return;
+	}
+	pthread_mutex_lock(&s->auth_log_mutex);
+	if(s->auth_logged) {
+		pthread_mutex_unlock(&s->auth_log_mutex);
+		return;
+	}
+	if(reply->type == REDIS_REPLY_ERROR) {
+		pool_log_auth(s, WEBDIS_ERROR, err_format, sizeof(err_format) - 1, reply->str);
+	} else if(reply->type == REDIS_REPLY_STATUS) {
+		pool_log_auth(s, WEBDIS_INFO, ok_format, sizeof(ok_format) - 1, reply->str);
+	}
+	s->auth_logged++;
+	pthread_mutex_unlock(&s->auth_log_mutex);
+}
+
 /**
  * Create new connection.
  */
@@ -155,10 +192,10 @@ pool_connect(struct pool *p, int db_num, int attach) {
 
 	if(p->cfg->redis_auth) { /* authenticate. */
 		if(p->cfg->redis_auth->use_legacy_auth) {
-			redisAsyncCommand(ac, NULL, NULL, "AUTH %s",
+			redisAsyncCommand(ac, pool_on_auth_complete, p, "AUTH %s",
 				p->cfg->redis_auth->password);
 		} else {
-			redisAsyncCommand(ac, NULL, NULL, "AUTH %s %s",
+			redisAsyncCommand(ac, pool_on_auth_complete, p, "AUTH %s %s",
 				p->cfg->redis_auth->username,
 				p->cfg->redis_auth->password);
 		}
diff --git a/src/server.c b/src/server.c
index 34d6d8e..dd53415 100644
--- a/src/server.c
+++ b/src/server.c
@@ -104,6 +104,8 @@ server_new(const char *cfg_file) {
 	for(i = 0; i < s->cfg->http_threads; ++i) {
 		s->w[i] = worker_new(s);
 	}
+
+	pthread_mutex_init(&s->auth_log_mutex, NULL);
 	return s;
 }
 
diff --git a/src/server.h b/src/server.h
index 42438b3..5679530 100644
--- a/src/server.h
+++ b/src/server.h
@@ -25,6 +25,10 @@ struct server {
 		pid_t self;
 		int fd;
 	} log;
+
+	/* used to log auth message only once */
+	pthread_mutex_t auth_log_mutex;
+	int auth_logged;
 };
 
 struct server *