changeset 5259:228eacfb2647 HEAD

Added more debug logging.
author Timo Sirainen <tss@iki.fi>
date Sat, 10 Mar 2007 15:24:15 +0200
parents 1fffd36401eb
children 0d72eb2ed8af
files src/auth/db-passwd-file.c src/auth/mech-gssapi.c src/auth/passdb-bsdauth.c src/auth/passdb-cache.c src/auth/passdb-checkpassword.c src/auth/passdb-pam.c src/auth/passdb-passwd.c src/auth/passdb-shadow.c src/auth/passdb-sia.c src/auth/passdb-vpopmail.c src/auth/userdb-passwd.c src/auth/userdb-prefetch.c src/auth/userdb-vpopmail.c
diffstat 13 files changed, 53 insertions(+), 20 deletions(-) [+]
line wrap: on
line diff
--- a/src/auth/db-passwd-file.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/db-passwd-file.c	Sat Mar 10 15:24:15 2007 +0200
@@ -389,6 +389,7 @@
 {
 	struct passwd_file *pw;
 	struct passwd_user *pu;
+	const char *username;
 
 	if (!db->vars)
 		pw = db->default_file;
@@ -413,13 +414,18 @@
 
 	if (!passwd_file_sync(pw)) {
 		auth_request_log_info(request, "passwd-file",
-				      "no passwd file");
+				      "no passwd file: %s", pw->path);
 		return NULL;
 	}
 
 	t_push();
-	pu = hash_lookup(pw->users, !db->domain_var ? request->user :
-			 t_strcut(request->user, '@'));
+	username = !db->domain_var ? request->user :
+		t_strcut(request->user, '@');
+
+	auth_request_log_debug(request, "passwd-file",
+			       "lookup: user=%s file=%s", username, pw->path);
+
+	pu = hash_lookup(pw->users, username);
 	if (pu == NULL)
                 auth_request_log_info(request, "passwd-file", "unknown user");
 	t_pop();
--- a/src/auth/mech-gssapi.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/mech-gssapi.c	Sat Mar 10 15:24:15 2007 +0200
@@ -391,11 +391,14 @@
 
 	major_status = gss_release_cred(&minor_status,
 					&gssapi_request->service_cred);
-	major_status = gss_release_name(&minor_status,
-					&gssapi_request->authn_name);
-	major_status = gss_release_name(&minor_status,
-					&gssapi_request->authz_name);
-
+	if (gssapi_request->authn_name != GSS_C_NO_NAME) {
+		major_status = gss_release_name(&minor_status,
+						&gssapi_request->authn_name);
+	}
+	if (gssapi_request->authz_name != GSS_C_NO_NAME) {
+		major_status = gss_release_name(&minor_status,
+						&gssapi_request->authz_name);
+	}
 	pool_unref(request->pool);
 }
 
--- a/src/auth/passdb-bsdauth.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/passdb-bsdauth.c	Sat Mar 10 15:24:15 2007 +0200
@@ -19,6 +19,8 @@
 	struct passwd *pw;
 	int result;
 
+	auth_request_log_debug(request, "bsdauth", "lookup");
+
 	pw = getpwnam(request->user);
 	if (pw == NULL) {
 		auth_request_log_info(request, "bsdauth", "unknown user");
--- a/src/auth/passdb-cache.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/passdb-cache.c	Sat Mar 10 15:24:15 2007 +0200
@@ -23,8 +23,12 @@
 
 	/* value = password \t ... */
 	value = auth_cache_lookup(passdb_cache, request, key, &node, &expired);
-	if (value == NULL || (expired && !use_expired))
+	if (value == NULL || (expired && !use_expired)) {
+		auth_request_log_debug(request, "cache",
+				       value == NULL ? "miss" : "expired");
 		return FALSE;
+	}
+	auth_request_log_debug(request, "cache", "hit");
 
 	if (*value == '\0') {
 		/* negative cache entry */
@@ -79,8 +83,12 @@
 		return FALSE;
 
 	value = auth_cache_lookup(passdb_cache, request, key, &node, &expired);
-	if (value == NULL || (expired && !use_expired))
+	if (value == NULL || (expired && !use_expired)) {
+		auth_request_log_debug(request, "cache",
+				       value == NULL ? "miss" : "expired");
 		return FALSE;
+	}
+	auth_request_log_debug(request, "cache", "hit");
 
 	if (*value == '\0') {
 		/* negative cache entry */
--- a/src/auth/passdb-checkpassword.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/passdb-checkpassword.c	Sat Mar 10 15:24:15 2007 +0200
@@ -221,15 +221,9 @@
 		auth_request_log_error(request, "checkpassword",
 				       "dup2() failed: %m");
 	} else {
-		/* very simple argument splitting. */
-		cmd = t_strconcat(module->checkpassword_path, " ",
-				  module->checkpassword_reply_path, NULL);
-		args = t_strsplit(cmd, " ");
-
 		/* Besides passing the standard username and password in a
 		   pipe, also pass some other possibly interesting information
 		   via environment. Use UCSPI names for local/remote IPs. */
-		/*  */
 		env_put("PROTO=TCP"); /* UCSPI */
 		env_put(t_strconcat("SERVICE=", request->service, NULL));
 		if (request->local_ip.family != 0) {
@@ -264,9 +258,13 @@
 			env_put_extra_fields(fields);
 		}
 
+		/* very simple argument splitting. */
+		cmd = t_strconcat(module->checkpassword_path, " ",
+				  module->checkpassword_reply_path, NULL);
 		auth_request_log_debug(request, "checkpassword",
-				       "Executed: %s", cmd);
+				       "execute: %s", cmd);
 
+		args = t_strsplit(cmd, " ");
 		execv(args[0], (char **)args);
 		auth_request_log_error(request, "checkpassword",
 				       "execv(%s) failed: %m", args[0]);
--- a/src/auth/passdb-pam.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/passdb-pam.c	Sat Mar 10 15:24:15 2007 +0200
@@ -430,6 +430,7 @@
 
 	service = module->service_name != NULL ?
 		module->service_name : request->service;
+	auth_request_log_debug(request, "pam", "lookup service=%s", service);
 
 	if (worker) {
 		/* blocking=yes code path in auth worker */
--- a/src/auth/passdb-passwd.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/passdb-passwd.c	Sat Mar 10 15:24:15 2007 +0200
@@ -20,6 +20,8 @@
 	struct passwd *pw;
 	bool result;
 
+	auth_request_log_debug(request, "passwd", "lookup");
+
 	pw = getpwnam(request->user);
 	if (pw == NULL) {
 		auth_request_log_info(request, "passwd", "unknown user");
--- a/src/auth/passdb-shadow.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/passdb-shadow.c	Sat Mar 10 15:24:15 2007 +0200
@@ -20,6 +20,8 @@
 	struct spwd *spw;
 	bool result;
 
+	auth_request_log_debug(request, "shadow", "lookup");
+
 	spw = getspnam(request->user);
 	if (spw == NULL) {
 		auth_request_log_info(request, "shadow", "unknown user");
--- a/src/auth/passdb-sia.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/passdb-sia.c	Sat Mar 10 15:24:15 2007 +0200
@@ -35,6 +35,8 @@
 {
 	char *argutility = "dovecot";
 
+	auth_request_log_debug(request, "sia", "lookup");
+
 	/* check if the password is valid */
 	if (sia_validate_user(checkpw_collect, 1, &argutility, NULL,
 			      (char *)request->user, NULL, NULL, NULL,
--- a/src/auth/passdb-vpopmail.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/passdb-vpopmail.c	Sat Mar 10 15:24:15 2007 +0200
@@ -24,6 +24,10 @@
 	struct vqpasswd *vpw;
 	char *password;
 
+	auth_request_log_debug(auth_request, "vpopmail",
+			       "lookup user=%s domain=%s",
+			       vpop_user, vpop_domain);
+
 	vpw = vpopmail_lookup_vqp(auth_request, vpop_user, vpop_domain);
 	if (vpw == NULL) {
 		*result_r = PASSDB_RESULT_USER_UNKNOWN;
@@ -86,9 +90,6 @@
 		return;
 	}
 
-	auth_request_log_debug(request, "vpopmail",
-			       "crypted password=%s", password);
-
 	tmp_pass = crypted_pass;
 	scheme = password_get_scheme(&tmp_pass);
 	if (scheme == NULL)
--- a/src/auth/userdb-passwd.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/userdb-passwd.c	Sat Mar 10 15:24:15 2007 +0200
@@ -16,6 +16,8 @@
 	struct passwd *pw;
 	struct auth_stream_reply *reply;
 
+	auth_request_log_debug(auth_request, "passwd", "lookup");
+
 	pw = getpwnam(auth_request->user);
 	if (pw == NULL) {
 		auth_request_log_info(auth_request, "passwd", "unknown user");
--- a/src/auth/userdb-prefetch.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/userdb-prefetch.c	Sat Mar 10 15:24:15 2007 +0200
@@ -88,6 +88,8 @@
 	else {
 		struct auth_stream_reply *reply;
 
+		auth_request_log_debug(auth_request, "prefetch", "success");
+
 		/* import the string into request. since the values were
 		   exported they are already in escaped form in the string. */
 		reply = auth_stream_reply_init(auth_request);
--- a/src/auth/userdb-vpopmail.c	Sat Mar 10 14:54:20 2007 +0200
+++ b/src/auth/userdb-vpopmail.c	Sat Mar 10 15:24:15 2007 +0200
@@ -27,6 +27,10 @@
 		return NULL;
 	}
 
+	auth_request_log_debug(auth_request, "vpopmail",
+			       "lookup user=%s domain=%s",
+			       vpop_user, vpop_domain);
+
 	vpw = vauth_getpw(vpop_user, vpop_domain);
 	if (vpw == NULL) {
 		auth_request_log_info(request, "vpopmail", "unknown user");