From: Timo Sirainen <timo.sirainen@open-xchange.com>
Date: Tue, 26 May 2020 22:36:41 +0000 (+0300)
Subject: auth: db-oauth2 - Fix debug logging
X-Git-Tag: 2.3.14.rc1~257
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=cb327481b17f60cf7e20ca219b12dee4b3cb283b;p=thirdparty%2Fdovecot%2Fcore.git

auth: db-oauth2 - Fix debug logging

Don't log a debug message when the callback is going to be logging
exactly the same message as info/error.
---

diff --git a/src/auth/db-oauth2.c b/src/auth/db-oauth2.c
index 99d2b5902a..8ea953e840 100644
--- a/src/auth/db-oauth2.c
+++ b/src/auth/db-oauth2.c
@@ -505,10 +505,8 @@ static void db_oauth2_callback(struct db_oauth2_request *req,
 
 	i_assert(result == PASSDB_RESULT_OK || error != NULL);
 
-	e_debug(authdb_event(req->auth_request),
-		"callback(result: %s, error: %s)",
-		passdb_result_to_string(result), error);
-
+	/* Successful lookups were logged by the caller. Failed lookups will be
+	   logged either with e_error() or e_info() by the callback. */
 	if (callback != NULL) {
 		DLLIST_REMOVE(&req->db->head, req);
 		callback(req, result, error, req->context);
@@ -630,15 +628,13 @@ db_oauth2_introspect_continue(struct oauth2_request_result *result,
 
 	req->req = NULL;
 
-	e_debug(authdb_event(req->auth_request),
-		"Introspection result: %s",
-		result->error == NULL ? "success" : "failed");
-
 	if (result->error != NULL) {
 		/* fail here */
 		passdb_result = PASSDB_RESULT_INTERNAL_FAILURE;
 		error = result->error;
 	} else {
+		e_debug(authdb_event(req->auth_request),
+			"Introspection succeeded");
 		db_oauth2_fields_merge(req, result->fields);
 		db_oauth2_process_fields(req, &passdb_result, &error);
 	}
@@ -683,6 +679,10 @@ static void db_oauth2_local_validation(struct db_oauth2_request *req,
 		db_oauth2_fields_merge(req, &fields);
 		db_oauth2_process_fields(req, &passdb_result, &error);
 	}
+	if (passdb_result == PASSDB_RESULT_OK) {
+		e_debug(authdb_event(req->auth_request),
+			"Local validation succeeded");
+	}
 	db_oauth2_callback(req, passdb_result, error);
 }
 
@@ -698,6 +698,8 @@ db_oauth2_lookup_continue_valid(struct db_oauth2_request *req,
 	    !req->db->set.force_introspection) {
 		/* pass */
 	} else if (req->db->oauth2_set.introspection_mode == INTROSPECTION_MODE_LOCAL) {
+		e_debug(authdb_event(req->auth_request),
+			"Attempting to locally validate token");
 		db_oauth2_local_validation(req, req->token);
 		return;
 	} else if (!db_oauth2_user_is_enabled(req, &passdb_result, &error)) {
@@ -725,6 +727,8 @@ db_oauth2_lookup_continue(struct oauth2_request_result *result,
 		db_oauth2_callback(req, PASSDB_RESULT_PASSWORD_MISMATCH,
 				   "Invalid token");
 	} else {
+		e_debug(authdb_event(req->auth_request),
+			"Token validation succeeded");
 		db_oauth2_lookup_continue_valid(req, result->fields);
 	}
 }
@@ -740,6 +744,8 @@ db_oauth2_lookup_passwd_grant(struct oauth2_request_result *result,
 	req->req = NULL;
 
 	if (result->valid) {
+		e_debug(authdb_event(req->auth_request),
+			"Password grant succeeded");
 		token = db_oauth2_field_find(result->fields, "access_token");
 		if (token == NULL) {
 			db_oauth2_callback(req, PASSDB_RESULT_INTERNAL_FAILURE,