Mercurial > dovecot > original-hg > dovecot-1.2
changeset 3069:131151e25e4b HEAD
Added auth_request_log_*().
line wrap: on
line diff
--- a/src/auth/auth-client-connection.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/auth-client-connection.c Sat Jan 08 18:56:04 2005 +0200 @@ -278,11 +278,8 @@ if (request->auth->ssl_require_client_cert && !valid_client_cert) { /* we fail without valid certificate */ - if (verbose) { - i_info("ssl-cert-check(%s): " - "Client didn't present valid SSL certificate", - get_log_prefix(request)); - } + auth_request_log_info(request, "ssl-cert-check", + "Client didn't present valid SSL certificate"); auth_request_destroy(request); auth_client_send(conn, "FAIL\t%u", id); return TRUE; @@ -296,11 +293,8 @@ buf = buffer_create_dynamic(pool_datastack_create(), MAX_BASE64_DECODED_SIZE(len)); if (base64_decode(initial_resp, len, NULL, buf) < 0) { - if (verbose) { - i_info("%s(%s): Invalid base64 data in " - "initial response", mech->mech_name, - get_log_prefix(request)); - } + auth_request_log_info(request, mech->mech_name, + "Invalid base64 data in initial response"); auth_request_destroy(request); auth_client_send(conn, "FAIL\t%u\t" "reason=Invalid base64 data in initial " @@ -355,11 +349,8 @@ buf = buffer_create_dynamic(pool_datastack_create(), MAX_BASE64_DECODED_SIZE(data_len)); if (base64_decode(data, data_len, NULL, buf) < 0) { - if (verbose) { - i_info("%s(%s): Invalid base64 data in " - "continued response", request->mech->mech_name, - get_log_prefix(request)); - } + auth_request_log_info(request, request->mech->mech_name, + "Invalid base64 data in continued response"); auth_client_send(conn, "FAIL\t%u\treason=Invalid base64 data " "in continued response", id); auth_request_destroy(request);
--- a/src/auth/auth-master-connection.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/auth-master-connection.c Sat Jan 08 18:56:04 2005 +0200 @@ -84,12 +84,12 @@ struct master_userdb_request *master_request = context; string_t *str; - if (verbose_debug && user != NULL) { - i_info("userdb(%s): uid=%s gid=%s home=%s mail=%s", - get_log_prefix(master_request->auth_request), - dec2str(user->uid), dec2str(user->gid), - user->home != NULL ? user->home : "", - user->mail != NULL ? user->mail : ""); + if (user != NULL) { + auth_request_log_debug(master_request->auth_request, "userdb", + "uid=%s gid=%s home=%s mail=%s", + dec2str(user->uid), dec2str(user->gid), + user->home != NULL ? user->home : "", + user->mail != NULL ? user->mail : ""); } if (auth_master_connection_unref(master_request->conn)) { @@ -133,10 +133,8 @@ POINTER_CAST(client_id)); if (request == NULL) { - if (verbose) { - i_info("Master request %u.%u not found", - client_pid, client_id); - } + i_error("Master request %u.%u not found", + client_pid, client_id); master_send(conn, "NOTFOUND\t%u", id); } else if (!request->successful) { i_error("Master requested unfinished authentication request "
--- a/src/auth/auth-request.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/auth-request.c Sat Jan 08 18:56:04 2005 +0200 @@ -325,13 +325,17 @@ return tab; } -const char *get_log_prefix(const struct auth_request *auth_request) +static const char * +get_log_str(struct auth_request *auth_request, const char *subsystem, + const char *format, va_list va) { #define MAX_LOG_USERNAME_LEN 64 const char *ip; string_t *str; - str = t_str_new(64); + str = t_str_new(128); + str_append(str, subsystem); + str_append_c(str, '('); if (auth_request->user == NULL) str_append(str, "?"); @@ -345,9 +349,56 @@ str_append_c(str, ','); str_append(str, ip); } + str_append(str, "): "); + str_vprintfa(str, format, va); return str_c(str); } +void auth_request_log_debug(struct auth_request *auth_request, + const char *subsystem, + const char *format, ...) +{ + va_list va; + + if (!auth_request->auth->verbose_debug) + return; + + va_start(va, format); + t_push(); + i_info("%s", get_log_str(auth_request, subsystem, format, va)); + t_pop(); + va_end(va); +} + +void auth_request_log_info(struct auth_request *auth_request, + const char *subsystem, + const char *format, ...) +{ + va_list va; + + if (!auth_request->auth->verbose) + return; + + va_start(va, format); + t_push(); + i_info("%s", get_log_str(auth_request, subsystem, format, va)); + t_pop(); + va_end(va); +} + +void auth_request_log_error(struct auth_request *auth_request, + const char *subsystem, + const char *format, ...) +{ + va_list va; + + va_start(va, format); + t_push(); + i_info("%s", get_log_str(auth_request, subsystem, format, va)); + t_pop(); + va_end(va); +} + void auth_failure_buf_flush(void) { struct auth_request **auth_request;
--- a/src/auth/auth-request.h Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/auth-request.h Sat Jan 08 18:56:04 2005 +0200 @@ -77,7 +77,15 @@ auth_request_get_var_expand_table(const struct auth_request *auth_request, const char *(*escape_func)(const char *)); -const char *get_log_prefix(const struct auth_request *auth_request); +void auth_request_log_debug(struct auth_request *auth_request, + const char *subsystem, + const char *format, ...) __attr_format__(3, 4); +void auth_request_log_info(struct auth_request *auth_request, + const char *subsystem, + const char *format, ...) __attr_format__(3, 4); +void auth_request_log_error(struct auth_request *auth_request, + const char *subsystem, + const char *format, ...) __attr_format__(3, 4); void auth_failure_buf_flush(void);
--- a/src/auth/auth.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/auth.c Sat Jan 08 18:56:04 2005 +0200 @@ -16,6 +16,9 @@ auth = i_new(struct auth, 1); + auth->verbose = getenv("VERBOSE") != NULL; + auth->verbose_debug = getenv("VERBOSE_DEBUG") != NULL; + env = getenv("PASSDB"); if (env == NULL) i_fatal("PASSDB environment is unset");
--- a/src/auth/auth.h Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/auth.h Sat Jan 08 18:56:04 2005 +0200 @@ -21,6 +21,8 @@ char username_chars[256]; char username_translation[256]; int ssl_require_client_cert; + + int verbose, verbose_debug; }; const string_t *auth_mechanisms_get_list(struct auth *auth);
--- a/src/auth/common.h Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/common.h Sat Jan 08 18:56:04 2005 +0200 @@ -8,7 +8,6 @@ #define LOGIN_LISTEN_FD 3 extern struct ioloop *ioloop; -extern int verbose, verbose_debug; extern int standalone; #endif
--- a/src/auth/db-passwd-file.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/db-passwd-file.c Sat Jan 08 18:56:04 2005 +0200 @@ -223,12 +223,8 @@ passwd_file_sync(pw); pu = hash_lookup(pw->users, request->user); - if (pu == NULL) { - if (verbose) { - i_info("passwd-file(%s): unknown user", - get_log_prefix(request)); - } - } + if (pu == NULL) + auth_request_log_info(request, "passwd-file", "unknown user"); return pu; }
--- a/src/auth/main.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/main.c Sat Jan 08 18:56:04 2005 +0200 @@ -24,7 +24,6 @@ #include <sys/stat.h> struct ioloop *ioloop; -int verbose = FALSE, verbose_debug = FALSE; int standalone = FALSE; static buffer_t *masters_buf; @@ -170,9 +169,6 @@ static void drop_privileges(void) { - verbose = getenv("VERBOSE") != NULL; - verbose_debug = getenv("VERBOSE_DEBUG") != NULL; - open_logfile(); /* Open /dev/urandom before chrooting */
--- a/src/auth/mech-anonymous.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/mech-anonymous.c Sat Jan 08 18:56:04 2005 +0200 @@ -10,13 +10,12 @@ { i_assert(request->auth->anonymous_username != NULL); - if (verbose) { + if (request->auth->verbose) { /* temporarily set the user to the one that was given, so that the log message goes right */ request->user = p_strndup(pool_datastack_create(), data, data_size); - i_info("anonymous(%s): login", - get_log_prefix(request)); + auth_request_log_info(request, "anonymous", "login"); } request->callback = callback;
--- a/src/auth/mech-apop.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/mech-apop.c Sat Jan 08 18:56:04 2005 +0200 @@ -83,10 +83,8 @@ if (data_size == 0) { /* Should never happen */ - if (verbose) { - i_info("apop(%s): no initial respone", - get_log_prefix(auth_request)); - } + auth_request_log_info(auth_request, "apop", + "no initial respone"); auth_request_fail(auth_request); return; } @@ -103,10 +101,8 @@ str = t_strdup_printf("<%x.%x.", auth_request->conn->master->pid, auth_request->conn->connect_uid); if (memcmp(data, str, strlen(str)) != 0) { - if (verbose) { - i_info("apop(%s): invalid challenge", - get_log_prefix(auth_request)); - } + auth_request_log_info(auth_request, "apop", + "invalid challenge"); auth_request_fail(auth_request); return; } @@ -120,10 +116,7 @@ if (tmp + 1 + 16 != end) { /* Should never happen */ - if (verbose) { - i_info("apop(%s): malformed data", - get_log_prefix(auth_request)); - } + auth_request_log_info(auth_request, "apop", "malformed data"); auth_request_fail(auth_request); return; } @@ -131,10 +124,7 @@ if (!auth_request_set_username(auth_request, (const char *)username, &error)) { - if (verbose) { - i_info("apop(%s): %s", - get_log_prefix(auth_request), error); - } + auth_request_log_info(auth_request, "apop", "%s", error); auth_request_fail(auth_request); return; }
--- a/src/auth/mech-cram-md5.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/mech-cram-md5.c Sat Jan 08 18:56:04 2005 +0200 @@ -60,8 +60,8 @@ context_digest, sizeof(context_digest)); if (hex_to_binary(credentials, context_digest_buf) < 0) { - i_error("cram-md5(%s): passdb credentials are not in hex", - get_log_prefix(&request->auth_request)); + auth_request_log_error(&request->auth_request, "cram-md5", + "passdb credentials are not in hex"); return FALSE; } @@ -72,10 +72,8 @@ response_hex = binary_to_hex(digest, 16); if (memcmp(response_hex, request->response, 32) != 0) { - if (verbose) { - i_info("cram-md5(%s): password mismatch", - get_log_prefix(&request->auth_request)); - } + auth_request_log_info(&request->auth_request, "cram-md5", + "password mismatch"); return FALSE; } @@ -156,8 +154,7 @@ if (error == NULL) error = "authentication failed"; - if (verbose) - i_info("cram-md5(%s): %s", get_log_prefix(auth_request), error); + auth_request_log_info(auth_request, "cram-md5", "%s", error); auth_request_fail(auth_request); }
--- a/src/auth/mech-digest-md5.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/mech-digest-md5.c Sat Jan 08 18:56:04 2005 +0200 @@ -120,16 +120,16 @@ /* get the MD5 password */ if (strlen(credentials) != sizeof(digest)*2) { - i_error("digest-md5(%s): passdb credentials' length is wrong", - get_log_prefix(&request->auth_request)); + auth_request_log_error(&request->auth_request, "digest-md5", + "passdb credentials' length is wrong"); return FALSE; } digest_buf = buffer_create_data(pool_datastack_create(), digest, sizeof(digest)); if (hex_to_binary(credentials, digest_buf) < 0) { - i_error("digest-md5(%s): passdb credentials are not in hex", - get_log_prefix(&request->auth_request)); + auth_request_log_error(&request->auth_request, "digest-md5", + "passdb credentials are not in hex"); return FALSE; } @@ -207,13 +207,9 @@ if (i == 0) { /* verify response */ if (memcmp(response_hex, request->response, 32) != 0) { - if (verbose) { - struct auth_request *auth_request = - &request->auth_request; - i_info("digest-md5(%s): " - "password mismatch", - get_log_prefix(auth_request)); - } + auth_request_log_info(&request->auth_request, + "digest-md5", + "password mismatch"); return FALSE; } } else { @@ -576,10 +572,8 @@ } } - if (verbose && error != NULL) { - i_info("digest-md5(%s): %s", - get_log_prefix(auth_request), error); - } + if (error != NULL) + auth_request_log_info(auth_request, "digest-md5", "%s", error); auth_request_fail(auth_request); }
--- a/src/auth/mech-login.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/mech-login.c Sat Jan 08 18:56:04 2005 +0200 @@ -44,10 +44,7 @@ username = t_strndup(data, data_size); if (!auth_request_set_username(request, username, &error)) { - if (verbose) { - i_info("login(%s): %s", - get_log_prefix(request), error); - } + auth_request_log_info(request, "login", "%s", error); auth_request_fail(request); return; }
--- a/src/auth/mech-ntlm.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/mech-ntlm.c Sat Jan 08 18:56:04 2005 +0200 @@ -47,16 +47,16 @@ client_response = ntlmssp_buffer_data(request->response, lm_response); if (response_length < LM_RESPONSE_SIZE) { - i_error("ntlm(%s): passdb credentials' length is too small", - get_log_prefix(&request->auth_request)); + auth_request_log_error(&request->auth_request, "ntlm", + "passdb credentials' length is too small"); return FALSE; } hash_buffer = buffer_create_data(request->auth_request.pool, hash, sizeof(hash)); if (hex_to_binary(credentials, hash_buffer) < 0) { - i_error("ntlm(%s): passdb credentials are not in hex", - get_log_prefix(&request->auth_request)); + auth_request_log_error(&request->auth_request, "ntlm", + "passdb credentials are not in hex"); return FALSE; } @@ -198,11 +198,8 @@ uint32_t flags; if (!ntlmssp_check_request(ntlm_request, data_size, &error)) { - if (verbose) { - i_info("ntlm(%s): invalid NTLM request, %s", - get_log_prefix(auth_request), - error); - } + auth_request_log_info(auth_request, "ntlm", + "invalid NTLM request: %s", error); auth_request_fail(auth_request); return; } @@ -223,11 +220,8 @@ const char *username; if (!ntlmssp_check_response(response, data_size, &error)) { - if (verbose) { - i_info("ntlm(%s): invalid NTLM response, %s", - get_log_prefix(auth_request), - error); - } + auth_request_log_info(auth_request, "ntlm", + "invalid NTLM response: %s", error); auth_request_fail(auth_request); return; } @@ -239,10 +233,8 @@ request->unicode_negotiated); if (!auth_request_set_username(auth_request, username, &error)) { - if (verbose) { - i_info("ntlm(%s): %s", - get_log_prefix(auth_request), error); - } + auth_request_log_info(auth_request, "ntlm", + "%s", error); auth_request_fail(auth_request); return; }
--- a/src/auth/mech-plain.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/mech-plain.c Sat Jan 08 18:56:04 2005 +0200 @@ -54,18 +54,12 @@ if (count != 2) { /* invalid input */ - if (verbose) { - i_info("plain(%s): invalid input", - get_log_prefix(request)); - } + auth_request_log_info(request, "plain", "invalid input"); auth_request_fail(request); } else { if (!auth_request_set_username(request, authenid, &error)) { /* invalid username */ - if (verbose) { - i_info("plain(%s): %s", - get_log_prefix(request), error); - } + auth_request_log_info(request, "plain", "%s", error); auth_request_fail(request); } else { auth_request_verify_plain(request, pass,
--- a/src/auth/mech-rpa.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/mech-rpa.c Sat Jan 08 18:56:04 2005 +0200 @@ -446,10 +446,8 @@ const char *service, *error; if (!rpa_parse_token1(data, data_size, &error)) { - if (verbose) { - i_info("rpa(%s): invalid token 1, %s", - get_log_prefix(auth_request), error); - } + auth_request_log_info(auth_request, "rpa", + "invalid token 1: %s", error); auth_request_fail(auth_request); return; } @@ -478,10 +476,8 @@ const char *error; if (!rpa_parse_token3(request, data, data_size, &error)) { - if (verbose) { - i_info("rpa(%s): invalid token 3, %s", - get_log_prefix(auth_request), error); - } + auth_request_log_info(auth_request, "rpa", + "invalid token 3: %s", error); auth_request_fail(auth_request); return; } @@ -498,10 +494,8 @@ if ((data_size != sizeof(client_ack)) || (memcmp(data, client_ack, sizeof(client_ack)) != 0)) { - if (verbose) { - i_info("rpa(%s): invalid token 5 or client rejects us", - get_log_prefix(auth_request)); - } + auth_request_log_info(auth_request, "rpa", + "invalid token 5 or client rejects us"); auth_request_fail(auth_request); } else { auth_request_success(auth_request, NULL, 0);
--- a/src/auth/passdb-bsdauth.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-bsdauth.c Sat Jan 08 18:56:04 2005 +0200 @@ -23,19 +23,14 @@ pw = getpwnam(request->user); if (pw == NULL) { - if (verbose) { - i_info("passwd(%s): unknown user", - get_log_prefix(request)); - } + auth_request_log_info(request, "bsdauth", "unknown user"); callback(PASSDB_RESULT_USER_UNKNOWN, request); return; } if (!IS_VALID_PASSWD(pw->pw_passwd)) { - if (verbose) { - i_info("passwd(%s): invalid password field '%s'", - get_log_prefix(request), pw->pw_passwd); - } + auth_request_log_info(request, "bsdauth", + "invalid password field"); callback(PASSDB_RESULT_USER_DISABLED, request); return; } @@ -48,10 +43,7 @@ safe_memset(pw->pw_passwd, 0, strlen(pw->pw_passwd)); if (!result) { - if (verbose) { - i_info("passwd(%s): password mismatch", - get_log_prefix(request)); - } + auth_request_log_info(request, "bsdauth", "password mismatch"); callback(PASSDB_RESULT_PASSWORD_MISMATCH, request); return; }
--- a/src/auth/passdb-cache.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-cache.c Sat Jan 08 18:56:04 2005 +0200 @@ -69,13 +69,10 @@ ret = password_verify(password, cached_pw, scheme, request->user); if (ret < 0) { - i_error("cache(%s): Unknown password scheme %s", - get_log_prefix(request), scheme); + auth_request_log_error(request, "cache", + "Unknown password scheme %s", scheme); } else if (ret == 0) { - if (verbose) { - i_info("cache(%s): Password mismatch", - get_log_prefix(request)); - } + auth_request_log_info(request, "cache", "Password mismatch"); } *result_r = ret > 0 ? PASSDB_RESULT_OK :
--- a/src/auth/passdb-checkpassword.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-checkpassword.c Sat Jan 08 18:56:04 2005 +0200 @@ -248,8 +248,8 @@ fd_in[0] = -1; if (pipe(fd_in) < 0 || pipe(fd_out) < 0) { - i_error("checkpassword(%s): pipe() failed: %m", - get_log_prefix(request)); + auth_request_log_error(request, "checkpassword", + "pipe() failed: %m"); callback(PASSDB_RESULT_INTERNAL_FAILURE, request); if (fd_in[0] != -1) { (void)close(fd_in[0]); @@ -260,8 +260,8 @@ pid = fork(); if (pid == -1) { - i_error("checkpassword(%s): fork() failed: %m", - get_log_prefix(request)); + auth_request_log_error(request, "checkpassword", + "fork() failed: %m"); callback(PASSDB_RESULT_INTERNAL_FAILURE, request); (void)close(fd_in[0]); (void)close(fd_in[1]); @@ -277,12 +277,12 @@ } if (close(fd_in[1]) < 0) { - i_error("checkpassword(%s): close(fd_in[1]) failed: %m", - get_log_prefix(request)); + auth_request_log_error(request, "checkpassword", + "close(fd_in[1]) failed: %m"); } if (close(fd_out[0]) < 0) { - i_error("checkpassword(%s): close(fd_out[0]) failed: %m", - get_log_prefix(request)); + auth_request_log_error(request, "checkpassword", + "close(fd_out[0]) failed: %m"); } auth_request_ref(request);
--- a/src/auth/passdb-ldap.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-ldap.c Sat Jan 08 18:56:04 2005 +0200 @@ -68,9 +68,9 @@ if (res != NULL) { ret = ldap_result2error(conn->ld, res, 0); if (ret != LDAP_SUCCESS) { - i_error("ldap(%s): ldap_search() failed: %s", - get_log_prefix(auth_request), - ldap_err2string(ret)); + auth_request_log_error(auth_request, "ldap", + "ldap_search() failed: %s", + ldap_err2string(ret)); result = PASSDB_RESULT_INTERNAL_FAILURE; res = NULL; @@ -79,9 +79,9 @@ entry = res == NULL ? NULL : ldap_first_entry(conn->ld, res); if (entry == NULL) { - if (res != NULL && verbose) { - i_info("ldap(%s): unknown user", - get_log_prefix(auth_request)); + if (res != NULL) { + auth_request_log_info(auth_request, "ldap", + "unknown user"); } } else { attr = ldap_first_attribute(conn->ld, entry, &ber); @@ -100,11 +100,11 @@ } if (password == NULL) { - i_error("ldap(%s): No password in reply", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "ldap", + "No password in reply"); } else if (ldap_next_entry(conn->ld, entry) != NULL) { - i_error("ldap(%s): Multiple password replies", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "ldap", + "Multiple password replies"); password = NULL; } } @@ -136,13 +136,11 @@ ret = password_verify(ldap_request->password, password, scheme, user); if (ret < 0) { - i_error("ldap(%s): Unknown password scheme %s", - get_log_prefix(auth_request), scheme); + auth_request_log_error(auth_request, "ldap", + "Unknown password scheme %s", scheme); } else if (ret == 0) { - if (verbose) { - i_info("ldap(%s): password mismatch", - get_log_prefix(auth_request)); - } + auth_request_log_info(auth_request, "ldap", + "password mismatch"); } ldap_request->callback.verify_plain(ret > 0 ? PASSDB_RESULT_OK : @@ -154,13 +152,14 @@ struct ldap_request *ldap_request) { struct ldap_connection *conn = passdb_ldap_conn->conn; + const char **attr_names = (const char **)passdb_ldap_conn->attr_names; const char *filter; string_t *str; if (conn->set.pass_filter == NULL) { filter = t_strdup_printf("(&(objectClass=posixAccount)(%s=%s))", - passdb_ldap_conn->attr_names[ATTR_VIRTUAL_USER], - ldap_escape(auth_request->user)); + attr_names[ATTR_VIRTUAL_USER], + ldap_escape(auth_request->user)); } else { str = t_str_new(512); var_expand(str, conn->set.pass_filter, @@ -173,13 +172,10 @@ ldap_request->callback = handle_request; ldap_request->context = auth_request; - if (verbose_debug) { - i_info("ldap(%s): base=%s scope=%s filter=%s fields=%s", - get_log_prefix(auth_request), conn->set.base, - conn->set.scope, filter, - t_strarray_join((const char **) - passdb_ldap_conn->attr_names, ",")); - } + auth_request_log_debug(auth_request, "ldap", + "base=%s scope=%s filter=%s fields=%s", + conn->set.base, conn->set.scope, filter, + t_strarray_join(attr_names, ",")); db_ldap_search(conn, conn->set.base, conn->set.ldap_scope, filter, passdb_ldap_conn->attr_names,
--- a/src/auth/passdb-pam.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-pam.c Sat Jan 08 18:56:04 2005 +0200 @@ -239,8 +239,6 @@ if ((status2 = pam_end(pamh, status)) == PAM_SUCCESS) { /* FIXME: check for PASSDB_RESULT_UNKNOWN_USER somehow? */ - if (!verbose) - str = NULL; result = status == PAM_SUCCESS ? PASSDB_RESULT_OK : PASSDB_RESULT_PASSWORD_MISMATCH; } else { @@ -274,17 +272,17 @@ We rely on that. */ ret = read(request->fd, buf, sizeof(buf)-1); if (ret < 0) { - i_error("pam(%s): read() from child process failed: %m", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "pam", + "read() from child process failed: %m"); result = PASSDB_RESULT_INTERNAL_FAILURE; } else if (ret == 0) { /* it died */ - i_error("pam(%s): Child process died", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "pam", + "Child process died"); result = PASSDB_RESULT_INTERNAL_FAILURE; } else if ((size_t)ret < sizeof(result)) { - i_error("pam(%s): Child process returned only %d bytes", - get_log_prefix(auth_request), ret); + auth_request_log_error(auth_request, "pam", + "Child process returned only %d bytes", ret); result = PASSDB_RESULT_INTERNAL_FAILURE; } else { memcpy(&result, buf, sizeof(result)); @@ -294,20 +292,18 @@ buf[ret] = '\0'; if (result == PASSDB_RESULT_INTERNAL_FAILURE) { - i_error("pam(%s): %s", - get_log_prefix(auth_request), - buf + sizeof(result)); + auth_request_log_error(auth_request, "pam", + "%s", buf + sizeof(result)); } else { - i_info("pam(%s): %s", - get_log_prefix(auth_request), - buf + sizeof(result)); + auth_request_log_info(auth_request, "pam", + "%s", buf + sizeof(result)); } } } if (close(request->fd) < 0) { - i_error("pam(%s): close(child input) failed: %m", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "pam", + "close(child input) failed: %m"); } if (auth_request_unref(auth_request)) @@ -351,14 +347,14 @@ service = service_name != NULL ? service_name : request->service; if (pipe(fd) < 0) { - i_error("pam(%s): pipe() failed: %m", get_log_prefix(request)); + auth_request_log_error(request, "pam", "pipe() failed: %m"); callback(PASSDB_RESULT_INTERNAL_FAILURE, request); return; } pid = fork(); if (pid == -1) { - i_error("pam(%s): fork() failed: %m", get_log_prefix(request)); + auth_request_log_error(request, "pam", "fork() failed: %m"); callback(PASSDB_RESULT_INTERNAL_FAILURE, request); (void)close(fd[0]); (void)close(fd[1]); @@ -372,8 +368,8 @@ } if (close(fd[1]) < 0) { - i_error("pam(%s): close(fd[1]) failed: %m", - get_log_prefix(request)); + auth_request_log_error(request, "pam", + "close(fd[1]) failed: %m"); } auth_request_ref(request);
--- a/src/auth/passdb-passwd-file.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-passwd-file.c Sat Jan 08 18:56:04 2005 +0200 @@ -36,11 +36,11 @@ callback(PASSDB_RESULT_OK, request); else { if (ret < 0) { - i_error("passwd-file(%s): Unknown password scheme %s", - get_log_prefix(request), scheme); - } else if (verbose) { - i_info("passwd-file(%s): %s password mismatch", - get_log_prefix(request), scheme); + auth_request_log_error(request, "passwd-file", + "unknown password scheme %s", scheme); + } else { + auth_request_log_info(request, "passwd-file", + "password mismatch"); } callback(PASSDB_RESULT_PASSWORD_MISMATCH, request); }
--- a/src/auth/passdb-passwd.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-passwd.c Sat Jan 08 18:56:04 2005 +0200 @@ -21,19 +21,14 @@ pw = getpwnam(request->user); if (pw == NULL) { - if (verbose) { - i_info("passwd(%s): unknown user", - get_log_prefix(request)); - } + auth_request_log_info(request, "passwd", "unknown user"); callback(PASSDB_RESULT_USER_UNKNOWN, request); return; } if (!IS_VALID_PASSWD(pw->pw_passwd)) { - if (verbose) { - i_info("passwd(%s): invalid password field '%s'", - get_log_prefix(request), pw->pw_passwd); - } + auth_request_log_info(request, "passwd", + "invalid password field '%s'", pw->pw_passwd); callback(PASSDB_RESULT_USER_DISABLED, request); return; } @@ -45,10 +40,7 @@ safe_memset(pw->pw_passwd, 0, strlen(pw->pw_passwd)); if (!result) { - if (verbose) { - i_info("passwd(%s): password mismatch", - get_log_prefix(request)); - } + auth_request_log_info(request, "passwd", "password mismatch"); callback(PASSDB_RESULT_PASSWORD_MISMATCH, request); return; }
--- a/src/auth/passdb-shadow.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-shadow.c Sat Jan 08 18:56:04 2005 +0200 @@ -21,19 +21,14 @@ spw = getspnam(request->user); if (spw == NULL) { - if (verbose) { - i_info("shadow(%s): unknown user", - get_log_prefix(request)); - } + auth_request_log_info(request, "shadow", "unknown user"); callback(PASSDB_RESULT_USER_UNKNOWN, request); return; } if (!IS_VALID_PASSWD(spw->sp_pwdp)) { - if (verbose) { - i_info("shadow(%s): invalid password field '%s'", - get_log_prefix(request), spw->sp_pwdp); - } + auth_request_log_info(request, "shadow", + "invalid password field"); callback(PASSDB_RESULT_USER_DISABLED, request); return; } @@ -45,10 +40,7 @@ safe_memset(spw->sp_pwdp, 0, strlen(spw->sp_pwdp)); if (!result) { - if (verbose) { - i_info("shadow(%s): password mismatch", - get_log_prefix(request)); - } + auth_request_log_info(request, "shadow", "password mismatch"); callback(PASSDB_RESULT_PASSWORD_MISMATCH, request); return; }
--- a/src/auth/passdb-sql.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-sql.c Sat Jan 08 18:56:04 2005 +0200 @@ -67,22 +67,19 @@ ret = sql_result_next_row(result); if (ret < 0) { - i_error("sql(%s): Password query failed: %s", - get_log_prefix(auth_request), - sql_result_get_error(result)); + auth_request_log_error(auth_request, "sql", + "Password query failed: %s", + sql_result_get_error(result)); passdb_result = PASSDB_RESULT_INTERNAL_FAILURE; } else if (ret == 0) { - if (verbose) { - i_info("sql(%s): Unknown user", - get_log_prefix(auth_request)); - } + auth_request_log_info(auth_request, "sql", "unknown user"); if (passdb_cache != NULL) { auth_cache_insert(passdb_cache, auth_request, passdb_sql_cache_key, ""); } } else if ((idx = sql_result_find_field(result, "password")) < 0) { - i_error("sql(%s): Password query must return a field named " - "\"password\"", get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "sql", + "Password query must return a field named 'password'"); } else { password = t_strdup(sql_result_get_field_value(result, idx)); result_save_extra_fields(result, sql_request, auth_request); @@ -91,8 +88,8 @@ if (ret > 0) { /* make sure there was only one row returned */ if (sql_result_next_row(result) > 0) { - i_error("sql(%s): Password query returned multiple " - "matches", get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "sql", + "Password query returned multiple matches"); password = NULL; } } @@ -121,13 +118,10 @@ ret = password_verify(sql_request->password, password, scheme, user); if (ret < 0) { - i_error("sql(%s): Unknown password scheme %s", - get_log_prefix(auth_request), scheme); + auth_request_log_error(auth_request, "sql", + "Unknown password scheme %s", scheme); } else if (ret == 0) { - if (verbose) { - i_info("sql(%s): Password mismatch", - get_log_prefix(auth_request)); - } + auth_request_log_info(auth_request, "sql", "Password mismatch"); } sql_request->callback.verify_plain(ret > 0 ? PASSDB_RESULT_OK : @@ -145,10 +139,8 @@ auth_request_get_var_expand_table(sql_request->auth_request, str_escape)); - if (verbose_debug) { - i_info("sql(%s): query: %s", - get_log_prefix(sql_request->auth_request), str_c(query)); - } + auth_request_log_debug(sql_request->auth_request, "sql", + "query: %s", str_c(query)); sql_query(passdb_sql_conn->db, str_c(query), sql_query_callback, sql_request);
--- a/src/auth/passdb-vpopmail.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb-vpopmail.c Sat Jan 08 18:56:04 2005 +0200 @@ -26,8 +26,7 @@ const char *scheme; int ret; - vpw = vpopmail_lookup_vqp(request->user, - vpop_user, vpop_domain); + vpw = vpopmail_lookup_vqp(request, vpop_user, vpop_domain); if (vpw == NULL) { callback(PASSDB_RESULT_USER_UNKNOWN, request); return; @@ -37,18 +36,14 @@ strcmp(request->service, "IMAP") == 0) || ((vpw->pw_gid & NO_POP) != 0 && strcmp(request->service, "POP3") == 0)) { - if (verbose) { - i_info("vpopmail(%s): %s disabled", - get_log_prefix(request), request->service); - } + auth_request_log_info(request, "vpopmail", + "%s disabled", request->service); callback(PASSDB_RESULT_USER_DISABLED, request); return; } - if (verbose_debug) { - i_info("vpopmail(%s): crypted password=%s", - get_log_prefix(request), vpw->pw_passwd); - } + auth_request_log_debug(request, "vpopmail", + "crypted password=%s", vpw->pw_passwd); crypted_pass = vpw->pw_passwd; scheme = password_get_scheme(&crypted_pass); @@ -64,11 +59,11 @@ if (ret <= 0) { if (ret < 0) { - i_error("vpopmail(%s): Unknown password scheme %s", - get_log_prefix(request), scheme); - } else if (verbose) { - i_info("vpopmail(%s): password mismatch", - get_log_prefix(request)); + auth_request_log_error(request, "vpopmail", + "Unknown password scheme %s", scheme); + } else { + auth_request_log_info(request, "vpopmail", + "password mismatch"); } callback(PASSDB_RESULT_PASSWORD_MISMATCH, request); return;
--- a/src/auth/passdb.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/passdb.c Sat Jan 08 18:56:04 2005 +0200 @@ -99,12 +99,9 @@ if (strcasecmp(scheme, wanted_scheme) != 0) { if (strcasecmp(scheme, "PLAIN") != 0 && strcasecmp(scheme, "CLEARTEXT") != 0) { - if (verbose) { - i_info("password(%s): Requested %s " - "scheme, but we have only %s", - auth_request->user, - wanted_scheme, scheme); - } + auth_request_log_info(auth_request, "password", + "Requested %s scheme, but we have only %s", + wanted_scheme, scheme); callback(PASSDB_RESULT_SCHEME_NOT_AVAILABLE, NULL, auth_request); return;
--- a/src/auth/userdb-ldap.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/userdb-ldap.c Sat Jan 08 18:56:04 2005 +0200 @@ -56,8 +56,8 @@ } if (i == ATTR_COUNT) { - i_error("ldap(%s): Unknown attribute '%s'", - get_log_prefix(auth_request), attr); + auth_request_log_error(auth_request, "ldap", + "Unknown attribute '%s'", attr); return; } @@ -100,8 +100,8 @@ ret = ldap_result2error(conn->ld, res, 0); if (ret != LDAP_SUCCESS) { - i_error("ldap(%s): ldap_search() failed: %s", - get_log_prefix(auth_request), ldap_err2string(ret)); + auth_request_log_error(auth_request, "ldap", + "ldap_search() failed: %s", ldap_err2string(ret)); urequest->userdb_callback(NULL, request->context); return; } @@ -109,8 +109,8 @@ entry = res == NULL ? NULL : ldap_first_entry(conn->ld, res); if (entry == NULL) { if (res != NULL) { - i_error("ldap(%s): Authenticated user not found", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "ldap", + "Authenticated user not found"); } urequest->userdb_callback(NULL, request->context); return; @@ -136,17 +136,19 @@ } if (user.virtual_user == NULL) - i_error("ldap(%s): No username in reply", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "ldap", + "No username in reply"); else if (user.uid == (uid_t)-1) { - i_error("ldap(%s): uidNumber not set and no default given in " - "user_global_uid", get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "ldap", + "uidNumber not set and no default given in " + "user_global_uid"); } else if (user.gid == (gid_t)-1) { - i_error("ldap(%s): gidNumber not set and no default given in " - "user_global_gid", get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "ldap", + "gidNumber not set and no default given in " + "user_global_gid"); } else if (ldap_next_entry(conn->ld, entry) != NULL) { - i_error("ldap(%s): Multiple replies found for user", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "ldap", + "Multiple replies found for user"); } else { urequest->userdb_callback(&user, request->context); t_pop(); @@ -162,14 +164,15 @@ userdb_callback_t *callback, void *context) { struct ldap_connection *conn = userdb_ldap_conn->conn; + const char **attr_names = (const char **)userdb_ldap_conn->attr_names; struct userdb_ldap_request *request; const char *filter; string_t *str; if (conn->set.user_filter == NULL) { filter = t_strdup_printf("(&(objectClass=posixAccount)(%s=%s))", - userdb_ldap_conn->attr_names[ATTR_VIRTUAL_USER], - ldap_escape(auth_request->user)); + attr_names[ATTR_VIRTUAL_USER], + ldap_escape(auth_request->user)); } else { str = t_str_new(512); var_expand(str, conn->set.user_filter, @@ -184,13 +187,10 @@ request->auth_request = auth_request; request->userdb_callback = callback; - if (verbose_debug) { - i_info("ldap(%s): base=%s scope=%s filter=%s fields=%s", - get_log_prefix(auth_request), conn->set.base, - conn->set.scope, filter, - t_strarray_join((const char **) - userdb_ldap_conn->attr_names, ",")); - } + auth_request_log_debug(auth_request, "ldap", + "base=%s scope=%s filter=%s fields=%s", + conn->set.base, conn->set.scope, filter, + t_strarray_join(attr_names, ",")); db_ldap_search(conn, conn->set.base, conn->set.ldap_scope, filter, userdb_ldap_conn->attr_names,
--- a/src/auth/userdb-passdb.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/userdb-passdb.c Sat Jan 08 18:56:04 2005 +0200 @@ -48,12 +48,12 @@ } if (!uid_seen) { - i_error("passdb(%s): userdb_uid not returned", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "passdb", + "userdb_uid not returned"); } if (!gid_seen) { - i_error("passdb(%s): userdb_gid not returned", - get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "passdb", + "userdb_gid not returned"); } if (data.uid == (uid_t)-1 || data.gid == (gid_t)-1)
--- a/src/auth/userdb-passwd.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/userdb-passwd.c Sat Jan 08 18:56:04 2005 +0200 @@ -18,10 +18,7 @@ pw = getpwnam(auth_request->user); if (pw == NULL) { - if (verbose) { - i_info("passwd(%s): unknown user", - get_log_prefix(auth_request)); - } + auth_request_log_info(auth_request, "passwd", "unknown user"); callback(NULL, context); return; }
--- a/src/auth/userdb-sql.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/userdb-sql.c Sat Jan 08 18:56:04 2005 +0200 @@ -34,24 +34,22 @@ uid = gid = NULL; ret = sql_result_next_row(result); if (ret < 0) { - i_error("sql(%s): User query failed: %s", - get_log_prefix(auth_request), - sql_result_get_error(result)); + auth_request_log_error(auth_request, "sql", + "User query failed: %s", sql_result_get_error(result)); } else if (ret == 0) { - if (verbose) { - i_error("sql(%s): User not found", - get_log_prefix(auth_request)); - } + auth_request_log_info(auth_request, "sql", "User not found"); } else { uid = sql_result_find_field_value(result, "uid"); if (uid == NULL) { - i_error("sql(%s): Password query didn't return uid, " - "or it was NULL", get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "sql", + "Password query didn't return uid, " + "or it was NULL"); } gid = sql_result_find_field_value(result, "gid"); if (gid == NULL) { - i_error("sql(%s): Password query didn't return gid, " - "or it was NULL", get_log_prefix(auth_request)); + auth_request_log_error(auth_request, "sql", + "Password query didn't return gid, " + "or it was NULL"); } } @@ -91,10 +89,7 @@ sql_request->context = context; sql_request->auth_request = auth_request; - if (verbose_debug) { - i_info("sql(%s): query: %s", - get_log_prefix(auth_request), str_c(query)); - } + auth_request_log_debug(auth_request, "sql", "%s", str_c(query)); sql_query(userdb_sql_conn->db, str_c(query), sql_query_callback, sql_request);
--- a/src/auth/userdb-vpopmail.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/userdb-vpopmail.c Sat Jan 08 18:56:04 2005 +0200 @@ -11,7 +11,7 @@ #include "userdb.h" #include "userdb-vpopmail.h" -struct vqpasswd *vpopmail_lookup_vqp(const char *user, +struct vqpasswd *vpopmail_lookup_vqp(struct auth_request *request, char vpop_user[VPOPMAIL_LIMIT], char vpop_domain[VPOPMAIL_LIMIT]) { @@ -23,21 +23,16 @@ memset(vpop_user, '\0', VPOPMAIL_LIMIT); memset(vpop_domain, '\0', VPOPMAIL_LIMIT); - if (parse_email(t_strdup_noconst(user), vpop_user, vpop_domain, + if (parse_email(auth_request->user, vpop_user, vpop_domain, VPOPMAIL_LIMIT-1) < 0) { - if (verbose) { - i_info("vpopmail(%s): parse_email() failed", - user); - } + auth_request_log_info(request, "vpopmail", + "parse_email() failed"); return NULL; } vpw = vauth_getpw(vpop_user, vpop_domain); if (vpw == NULL) { - if (verbose) { - i_info("vpopmail(%s): unknown user (%s@%s)", - user, vpop_user, vpop_domain); - } + auth_request_log_info(request, "vpopmail", "unknown user"); return NULL; } @@ -56,7 +51,7 @@ gid_t gid; pool_t pool; - vpw = vpopmail_lookup_vqp(auth_request->user, vpop_user, vpop_domain); + vpw = vpopmail_lookup_vqp(auth_request, vpop_user, vpop_domain); if (vpw == NULL) { callback(NULL, context); return; @@ -65,24 +60,21 @@ /* we have to get uid/gid separately, because the gid field in struct vqpasswd isn't really gid at all but just some flags... */ if (vget_assign(vpop_domain, NULL, 0, &uid, &gid) == NULL) { - if (verbose) { - i_info("vpopmail(%s): vget_assign(%s) failed", - auth_request->user, vpop_domain); - } + auth_request_log_info(request, "vpopmail", + "vget_assign(%s) failed", vpop_domain); callback(NULL, context); return; } if (vpw->pw_dir == NULL || vpw->pw_dir[0] == '\0') { /* user's homedir doesn't exist yet, create it */ - if (verbose) { - i_info("vpopmail(%s): pw_dir isn't set, creating", - auth_request->user); - } + auth_request_log_info(request, "vpopmail", + "pw_dir isn't set, creating"); if (make_user_dir(vpop_user, vpop_domain, uid, gid) == NULL) { - i_error("vpopmail(%s): make_user_dir(%s, %s) failed", - auth_request->user, vpop_user, vpop_domain); + auth_request_log_error(request, "vpopmail", + "make_user_dir(%s, %s) failed", + vpop_user, vpop_domain); callback(NULL, context); return; }
--- a/src/auth/userdb-vpopmail.h Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/userdb-vpopmail.h Sat Jan 08 18:56:04 2005 +0200 @@ -10,7 +10,7 @@ overflows. */ #define VPOPMAIL_LIMIT 81 -struct vqpasswd *vpopmail_lookup_vqp(const char *user, +struct vqpasswd *vpopmail_lookup_vqp(struct auth_request *request, char vpop_user[VPOPMAIL_LIMIT], char vpop_domain[VPOPMAIL_LIMIT]);
--- a/src/auth/userdb.c Sat Jan 08 17:59:49 2005 +0200 +++ b/src/auth/userdb.c Sat Jan 08 18:56:04 2005 +0200 @@ -51,8 +51,8 @@ pw = getpwnam(str); if (pw == NULL) { if (request != NULL) { - i_error("userdb(%s): Invalid UID field '%s'", - get_log_prefix(request), str); + auth_request_log_error(request, "userdb", + "Invalid UID field '%s'", str); } return (uid_t)-1; } @@ -69,8 +69,8 @@ gr = getgrnam(str); if (gr == NULL) { if (request != NULL) { - i_error("userdb(%s): Invalid GID field '%s'", - get_log_prefix(request), str); + auth_request_log_error(request, "userdb", + "Invalid GID field '%s'", str); } return (gid_t)-1; }