svn commit: samba r21012 - in branches/SAMBA_3_0/source/nsswitch: .
jerry at samba.org
jerry at samba.org
Thu Jan 25 01:56:36 GMT 2007
Author: jerry
Date: 2007-01-25 01:56:34 +0000 (Thu, 25 Jan 2007)
New Revision: 21012
WebSVN: http://websvn.samba.org/cgi-bin/viewcvs.cgi?view=rev&root=samba&rev=21012
Log:
Patch from Danilo Almeida @ Centeris (via me):
Details: Improve PAM logging
- The improved logging is far tracking down PAM-related bugs
- PAM_SILENT was being mis-used to suppress syslog output instead of
suppressing user output. This lets PAM_SILENT still log to syslog.
- Allow logging of item & data state via debug_state config file option.
- Logging tracks the pam handle used.
Modified:
branches/SAMBA_3_0/source/nsswitch/pam_winbind.c
branches/SAMBA_3_0/source/nsswitch/pam_winbind.h
Changeset:
Modified: branches/SAMBA_3_0/source/nsswitch/pam_winbind.c
===================================================================
--- branches/SAMBA_3_0/source/nsswitch/pam_winbind.c 2007-01-25 01:18:31 UTC (rev 21011)
+++ branches/SAMBA_3_0/source/nsswitch/pam_winbind.c 2007-01-25 01:56:34 UTC (rev 21012)
@@ -12,6 +12,18 @@
#include "pam_winbind.h"
+#define _PAM_LOG_FUNCTION_ENTER(function, pamh, ctrl, flags) \
+ do { \
+ _pam_log_debug(pamh, ctrl, LOG_DEBUG, "[pamh: 0x%08x] ENTER: " function " (flags: 0x%04x)", (uint32) pamh, flags); \
+ _pam_log_state(pamh, ctrl); \
+ } while (0)
+
+#define _PAM_LOG_FUNCTION_LEAVE(function, pamh, ctrl, retval) \
+ do { \
+ _pam_log_debug(pamh, ctrl, LOG_DEBUG, "[pamh: 0x%08x] LEAVE: " function " returning %d", (uint32) pamh, retval); \
+ _pam_log_state(pamh, ctrl); \
+ } while (0)
+
/* data tokens */
#define MAX_PASSWD_TRIES 3
@@ -61,11 +73,16 @@
}
#endif /* HAVE_PAM_VSYSLOG */
+static inline int _pam_log_is_silent(int ctrl)
+{
+ return (ctrl & WINBIND_SILENT) ? 1 : 0;
+}
+
static void _pam_log(const pam_handle_t *pamh, int ctrl, int err, const char *format, ...)
{
va_list args;
- if (ctrl & WINBIND_SILENT) {
+ if (_pam_log_is_silent(ctrl)) {
return;
}
@@ -74,15 +91,37 @@
va_end(args);
}
-static void _pam_log_debug(const pam_handle_t *pamh, int ctrl, int err, const char *format, ...)
+static inline int _pam_log_is_debug_enabled(int ctrl)
{
- va_list args;
+ if (ctrl == -1) {
+ return 0;
+ }
- if (ctrl & WINBIND_SILENT) {
- return;
+ if (_pam_log_is_silent(ctrl)) {
+ return 0;
}
if (!(ctrl & WINBIND_DEBUG_ARG)) {
+ return 0;
+ }
+
+ return 1;
+}
+
+static inline int _pam_log_is_debug_state_enabled(int ctrl)
+{
+ if (!(ctrl & WINBIND_DEBUG_STATE)) {
+ return 0;
+ }
+
+ return _pam_log_is_debug_enabled(ctrl);
+}
+
+static void _pam_log_debug(const pam_handle_t *pamh, int ctrl, int err, const char *format, ...)
+{
+ va_list args;
+
+ if (!_pam_log_is_debug_enabled(ctrl)) {
return;
}
@@ -91,6 +130,74 @@
va_end(args);
}
+static void _pam_log_state_datum(const pam_handle_t *pamh, int ctrl, int item_type, const char *key, int is_string)
+{
+ const void *data = NULL;
+ if (item_type != 0) {
+ pam_get_item(pamh, item_type, &data);
+ } else {
+ pam_get_data(pamh, key, &data);
+ }
+ if (data != NULL) {
+ const char *type = (item_type != 0) ? "ITEM" : "DATA";
+ if (is_string != 0) {
+ _pam_log_debug(pamh, ctrl, LOG_DEBUG, "[pamh: 0x%08x] STATE: %s(%s) = \"%s\" (0x%08x)", (uint32) pamh, type, key, (const char *) data, (uint32) data);
+ } else {
+ _pam_log_debug(pamh, ctrl, LOG_DEBUG, "[pamh: 0x%08x] STATE: %s(%s) = 0x%08x", (uint32) pamh, type, key, (uint32) data);
+ }
+ }
+}
+
+#define _PAM_LOG_STATE_DATA_POINTER(pamh, ctrl, module_data_name) \
+ _pam_log_state_datum(pamh, ctrl, 0, module_data_name, 0)
+
+#define _PAM_LOG_STATE_DATA_STRING(pamh, ctrl, module_data_name) \
+ _pam_log_state_datum(pamh, ctrl, 0, module_data_name, 1)
+
+#define _PAM_LOG_STATE_ITEM_POINTER(pamh, ctrl, item_type) \
+ _pam_log_state_datum(pamh, ctrl, item_type, #item_type, 0)
+
+#define _PAM_LOG_STATE_ITEM_STRING(pamh, ctrl, item_type) \
+ _pam_log_state_datum(pamh, ctrl, item_type, #item_type, 1)
+
+#ifdef DEBUG_PASSWORD
+#define _LOG_PASSWORD_AS_STRING 1
+#else
+#define _LOG_PASSWORD_AS_STRING 0
+#endif
+
+#define _PAM_LOG_STATE_ITEM_PASSWORD(pamh, ctrl, item_type) \
+ _pam_log_state_datum(pamh, ctrl, item_type, #item_type, _LOG_PASSWORD_AS_STRING)
+
+static void _pam_log_state(const pam_handle_t *pamh, int ctrl)
+{
+ if (!_pam_log_is_debug_state_enabled(ctrl)) {
+ return;
+ }
+
+ _PAM_LOG_STATE_ITEM_STRING(pamh, ctrl, PAM_SERVICE);
+ _PAM_LOG_STATE_ITEM_STRING(pamh, ctrl, PAM_USER);
+ _PAM_LOG_STATE_ITEM_STRING(pamh, ctrl, PAM_TTY);
+ _PAM_LOG_STATE_ITEM_STRING(pamh, ctrl, PAM_RHOST);
+ _PAM_LOG_STATE_ITEM_STRING(pamh, ctrl, PAM_RUSER);
+ _PAM_LOG_STATE_ITEM_PASSWORD(pamh, ctrl, PAM_OLDAUTHTOK);
+ _PAM_LOG_STATE_ITEM_PASSWORD(pamh, ctrl, PAM_AUTHTOK);
+ _PAM_LOG_STATE_ITEM_STRING(pamh, ctrl, PAM_USER_PROMPT);
+ _PAM_LOG_STATE_ITEM_POINTER(pamh, ctrl, PAM_CONV);
+#ifdef PAM_FAIL_DELAY
+ _PAM_LOG_STATE_ITEM_POINTER(pamh, ctrl, PAM_FAIL_DELAY);
+#endif
+#ifdef PAM_REPOSITORY
+ _PAM_LOG_STATE_ITEM_POINTER(pamh, ctrl, PAM_REPOSITORY);
+#endif
+
+ _PAM_LOG_STATE_DATA_STRING(pamh, ctrl, PAM_WINBIND_HOMEDIR);
+ _PAM_LOG_STATE_DATA_STRING(pamh, ctrl, PAM_WINBIND_LOGONSCRIPT);
+ _PAM_LOG_STATE_DATA_STRING(pamh, ctrl, PAM_WINBIND_PROFILEPATH);
+ _PAM_LOG_STATE_DATA_STRING(pamh, ctrl, PAM_WINBIND_NEW_AUTHTOK_REQD); /* Use atoi to get PAM result code */
+ _PAM_LOG_STATE_DATA_POINTER(pamh, ctrl, PAM_WINBIND_PWD_LAST_SET);
+}
+
static int _pam_parse(const pam_handle_t *pamh, int flags, int argc, const char **argv, dictionary **result_d)
{
int ctrl = 0;
@@ -124,6 +231,10 @@
ctrl |= WINBIND_DEBUG_ARG;
}
+ if (iniparser_getboolean(d, "global:debug_state", False)) {
+ ctrl |= WINBIND_DEBUG_STATE;
+ }
+
if (iniparser_getboolean(d, "global:cached_login", False)) {
ctrl |= WINBIND_CACHED_LOGIN;
}
@@ -139,7 +250,7 @@
if (iniparser_getstr(d, "global:krb5_ccache_type") != NULL) {
ctrl |= WINBIND_KRB5_CCACHE_TYPE;
}
-
+
if ((iniparser_getstr(d, "global:require-membership-of") != NULL) ||
(iniparser_getstr(d, "global:require_membership_of") != NULL)) {
ctrl |= WINBIND_REQUIRED_MEMBERSHIP;
@@ -194,6 +305,10 @@
static void _pam_winbind_cleanup_func(pam_handle_t *pamh, void *data, int error_status)
{
+ int ctrl = _pam_parse(pamh, 0, 0, NULL, NULL);
+ if (_pam_log_is_debug_state_enabled(ctrl)) {
+ _pam_log_debug(pamh, ctrl, LOG_DEBUG, "[pamh: 0x%08x] CLEAN: cleaning up PAM data 0x%08x (error_status = %d)", (uint32) pamh, (uint32) data, error_status);
+ }
SAFE_FREE(data);
}
@@ -275,21 +390,33 @@
return retval;
}
-static int _make_remark_format(pam_handle_t * pamh, int type, const char *format, ...)
+static int _make_remark_v(pam_handle_t * pamh, int type, const char *format, va_list args)
{
- va_list args;
char *var;
int ret;
- va_start(args, format);
- vasprintf(&var, format, args);
- va_end(args);
+ ret = vasprintf(&var, format, args);
+ if (ret < 0) {
+ _pam_log(pamh, 0, LOG_ERR, "memory allocation failure");
+ return ret;
+ }
ret = _make_remark(pamh, type, var);
SAFE_FREE(var);
return ret;
}
+static int _make_remark_format(pam_handle_t * pamh, int type, const char *format, ...)
+{
+ int ret;
+ va_list args;
+
+ va_start(args, format);
+ ret = _make_remark_v(pamh, type, format, args);
+ va_end(args);
+ return ret;
+}
+
static int pam_winbind_request(pam_handle_t * pamh, int ctrl,
enum winbindd_cmd req_type,
struct winbindd_request *request,
@@ -972,6 +1099,8 @@
const char *item;
char *token;
+ _pam_log(pamh, ctrl, LOG_DEBUG, "getting password (0x%08x)", ctrl);
+
/*
* make sure nothing inappropriate gets returned
*/
@@ -999,6 +1128,8 @@
} else if (item != NULL) { /* we have a password! */
*pass = item;
item = NULL;
+ _pam_log(pamh, ctrl, LOG_DEBUG,
+ "pam_get_item returned a password");
return PAM_SUCCESS;
} else if (on(WINBIND_USE_FIRST_PASS_ARG, ctrl)) {
return PAM_AUTHTOK_RECOVER_ERR; /* didn't work */
@@ -1188,7 +1319,7 @@
goto out;
}
- _pam_log_debug(pamh, ctrl, LOG_DEBUG, "pam_winbind: pam_sm_authenticate (flags: 0x%04x)", flags);
+ _PAM_LOG_FUNCTION_ENTER("pam_sm_authenticate", pamh, ctrl, flags);
/* Get the username */
retval = pam_get_user(pamh, &username, NULL);
@@ -1249,6 +1380,13 @@
if (d) {
iniparser_freedict(d);
}
+
+ if (!new_authtok_required) {
+ pam_set_data(pamh, PAM_WINBIND_NEW_AUTHTOK_REQD, NULL, NULL);
+ }
+
+ _PAM_LOG_FUNCTION_LEAVE("pam_sm_authenticate", pamh, ctrl, retval);
+
return retval;
}
@@ -1266,7 +1404,7 @@
goto out;
}
- _pam_log_debug(pamh, ctrl, LOG_DEBUG, "pam_winbind: pam_sm_setcred (flags: 0x%04x)", flags);
+ _PAM_LOG_FUNCTION_ENTER("pam_sm_setcred", pamh, ctrl, flags);
switch (flags & ~PAM_SILENT) {
@@ -1295,10 +1433,8 @@
iniparser_freedict(d);
}
- if (!new_authtok_required) {
- pam_set_data(pamh, PAM_WINBIND_NEW_AUTHTOK_REQD, NULL, NULL);
- }
-
+ _PAM_LOG_FUNCTION_LEAVE("pam_sm_setcred", pamh, ctrl, ret);
+
return ret;
}
@@ -1321,7 +1457,7 @@
return PAM_SYSTEM_ERR;
}
- _pam_log_debug(pamh, ctrl, LOG_DEBUG, "pam_winbind: pam_sm_acct_mgmt (flags: 0x%04x)", flags);
+ _PAM_LOG_FUNCTION_ENTER("pam_sm_acct_mgmt", pamh, ctrl, flags);
/* Get the username */
@@ -1391,6 +1527,8 @@
iniparser_freedict(d);
}
+ _PAM_LOG_FUNCTION_LEAVE("pam_sm_acct_mgmt", pamh, ctrl, ret);
+
return ret;
}
@@ -1408,7 +1546,7 @@
goto out;
}
- _pam_log_debug(pamh, ctrl, LOG_DEBUG, "pam_winbind: pam_sm_open_session handler (flags: 0x%04x)", flags);
+ _PAM_LOG_FUNCTION_ENTER("pam_sm_open_session", pamh, ctrl, flags);
ret = PAM_SUCCESS;
@@ -1417,6 +1555,8 @@
iniparser_freedict(d);
}
+ _PAM_LOG_FUNCTION_LEAVE("pam_sm_open_session", pamh, ctrl, ret);
+
return ret;
}
@@ -1434,7 +1574,7 @@
goto out;
}
- _pam_log_debug(pamh, ctrl, LOG_DEBUG, "pam_winbind: pam_sm_close_session handler (flags: 0x%04x)", flags);
+ _PAM_LOG_FUNCTION_ENTER("pam_sm_close_session", pamh, ctrl, flags);
if (!(flags & PAM_DELETE_CRED)) {
retval = PAM_SUCCESS;
@@ -1497,6 +1637,9 @@
if (d) {
iniparser_freedict(d);
}
+
+ _PAM_LOG_FUNCTION_LEAVE("pam_sm_close_session", pamh, ctrl, retval);
+
return retval;
}
@@ -1526,7 +1669,7 @@
goto out;
}
- _pam_log_debug(pamh, ctrl, LOG_DEBUG, "pam_winbind: pam_sm_chauthtok (flags: 0x%04x)", flags);
+ _PAM_LOG_FUNCTION_ENTER("pam_sm_chauthtok", pamh, ctrl, flags);
/* clearing offline bit for the auth in the password change */
ctrl &= ~WINBIND_CACHED_LOGIN;
@@ -1739,6 +1882,9 @@
if (d) {
iniparser_freedict(d);
}
+
+ _PAM_LOG_FUNCTION_LEAVE("pam_sm_chauthtok", pamh, ctrl, ret);
+
return ret;
}
Modified: branches/SAMBA_3_0/source/nsswitch/pam_winbind.h
===================================================================
--- branches/SAMBA_3_0/source/nsswitch/pam_winbind.h 2007-01-25 01:18:31 UTC (rev 21011)
+++ branches/SAMBA_3_0/source/nsswitch/pam_winbind.h 2007-01-25 01:56:34 UTC (rev 21012)
@@ -86,6 +86,7 @@
#define WINBIND_CACHED_LOGIN (1<<9)
#define WINBIND_CONFIG_FILE (1<<10)
#define WINBIND_SILENT (1<<11)
+#define WINBIND_DEBUG_STATE (1<<12)
/*
* here is the string to inform the user that the new passwords they
More information about the samba-cvs
mailing list