[Samba] winbind authentication mystery

[Chris Thielen]

Greetings,
	I'm running Fedora 11 (Samba 3.3.2) and am trying to configure winbind
authentication against a Windows 2003 server.
	I've run kinit and net join successfully, and can wbinfo -u, -g, and -t
successfully, as well as getent passwd and getent group successfully. I
can even use passwd to change domain user passwords.
	However, when I try to log in via gdm, ssh, or even su, I do not
succeed. I believe am I suffering from one, possibly two separate
issues.
	The first is that all users except the Administrator are told that
their password is expiring, which is not true. Here are the logs of this
event:

Jun 24 15:29:58 history-20 sshd[4656]: pam_unix(sshd:auth):
authentication failure; logname= uid=0 euid=0 tty=ssh ruser=
rhost=localhost.localdomain  user=cmthielen
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:auth): [pamh:
0x1f06f48] ENTER: pam_sm_authenticate (flags: 0x0001)
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:auth): getting
password (0x00000011)
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:auth):
pam_get_item returned a password
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:auth): Verify
user 'cmthielen'
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:auth): request
wbcLogonUser succeeded
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:auth): user
'cmthielen' granted access
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:auth): Password
has expired (Password was last set: 1245880658, the policy says it
should expire here 1245880657 (now it's: 1245882598))
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:auth): [pamh:
0x1f06f48] LEAVE: pam_sm_authenticate returning 0 (PAM_SUCCESS)
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:account): [pamh:
0x1f06f48] ENTER: pam_sm_acct_mgmt (flags: 0x0000)
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:account):
pam_sm_acct_mgmt success but PAM_WINBIND_NEW_AUTHTOK_REQD is set
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:account): user
'cmthielen' needs new password
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:account): [pamh:
0x1f06f48] LEAVE: pam_sm_acct_mgmt returning 12 (PAM_NEW_AUTHTOK_REQD)
Jun 24 15:29:58 history-20 sshd[4656]: Accepted password for cmthielen
from 127.0.0.1 port 36881 ssh2
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:setcred): [pamh:
0x1f06f48] ENTER: pam_sm_setcred (flags: 0x0002)
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:setcred):
PAM_ESTABLISH_CRED not implemented
Jun 24 15:29:58 history-20 sshd[4656]: pam_winbind(sshd:setcred): [pamh:
0x1f06f48] LEAVE: pam_sm_setcred returning 0 (PAM_SUCCESS)
Jun 24 15:29:58 history-20 sshd[4656]: pam_unix(sshd:session): session
opened for user cmthielen by (uid=0)
Jun 24 15:29:58 history-20 sshd[4660]: pam_winbind(sshd:setcred): [pamh:
0x1f06f48] ENTER: pam_sm_setcred (flags: 0x0002)
Jun 24 15:29:58 history-20 sshd[4660]: pam_winbind(sshd:setcred):
PAM_ESTABLISH_CRED not implemented
Jun 24 15:29:58 history-20 sshd[4660]: pam_winbind(sshd:setcred): [pamh:
0x1f06f48] LEAVE: pam_sm_setcred returning 0 (PAM_SUCCESS)
Jun 24 15:29:58 history-20 passwd: pam_unix(passwd:chauthtok): user
"cmthielen" does not exist in /etc/passwd
Jun 24 15:29:58 history-20 passwd: pam_winbind(passwd:chauthtok):
getting password (0x00000020)
Jun 24 15:30:01 history-20 passwd: pam_winbind(passwd:chauthtok): user
'cmthielen' granted access
Jun 24 15:30:05 history-20 passwd: pam_unix(passwd:chauthtok): user
"cmthielen" does not exist in /etc/passwd
Jun 24 15:30:05 history-20 passwd: pam_winbind(passwd:chauthtok):
getting password (0x00000000)
Jun 24 15:30:11 history-20 passwd: pam_winbind(passwd:chauthtok): user
'cmthielen' OK
Jun 24 15:30:11 history-20 passwd: pam_winbind(passwd:chauthtok): user
'cmthielen' password changed
Jun 24 15:30:11 history-20 passwd: pam_winbind(passwd:chauthtok): user
'cmthielen' granted access
Jun 24 15:30:11 history-20 passwd: Couldn't access gnome keyring
socket: /tmp/keyring-4jRNoE/socket: Permission denied
Jun 24 15:30:11 history-20 passwd: gkr-pam: couldn't change password for
'login' keyring: 255
Jun 24 15:30:13 history-20 sshd[4656]: pam_winbind(sshd:setcred): [pamh:
0x1f06f48] ENTER: pam_sm_setcred (flags: 0x0004)
Jun 24 15:30:13 history-20 sshd[4656]: pam_winbind(sshd:setcred): [pamh:
0x1f06f48] ENTER: _pam_delete_cred (flags: 0x0004)

However, if I set my computer back two days, the timestamps work out.
The time on the Windows server is set correctly, and the box even has
it's ntpdate set to use the Windows server.

The second, or possibly the same issue, is that it simply won't log in.
If I use the administrator account, I am not told my password expires,
but my session ends immediately (note: I have use default domain turned
on, so the domain is implied here. If I turn it off and add the correct
prepend syntax, the issue is the same):

[root at history-20 pam.d]# ssh administrator at localhost
administrator at localhost's password: 
Last login: Wed Jun 24 15:13:07 2009 from localhost.localdomain
Connection to localhost closed.

The logs for this event:
Jun 24 15:32:42 history-20 sshd[4676]: pam_unix(sshd:auth):
authentication failure; logname= uid=0 euid=0 tty=ssh ruser=
rhost=history-20.ucdavis.edu  user=administrator
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:auth): [pamh:
0x13f3f68] ENTER: pam_sm_authenticate (flags: 0x0001)
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:auth): getting
password (0x00000011)
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:auth):
pam_get_item returned a password
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:auth): Verify
user 'administrator'
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:auth): request
wbcLogonUser succeeded
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:auth): user
'administrator' granted access
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:auth): Returned
user was 'administrator'
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:auth): [pamh:
0x13f3f68] LEAVE: pam_sm_authenticate returning 0 (PAM_SUCCESS)
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:account): [pamh:
0x13f3f68] ENTER: pam_sm_acct_mgmt (flags: 0x0000)
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:account): user
'administrator' granted access
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:account): [pamh:
0x13f3f68] LEAVE: pam_sm_acct_mgmt returning 0 (PAM_SUCCESS)
Jun 24 15:32:42 history-20 sshd[4676]: Accepted password for
administrator from 169.237.136.20 port 51794 ssh2
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:setcred): [pamh:
0x13f3f68] ENTER: pam_sm_setcred (flags: 0x0002)
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:setcred):
PAM_ESTABLISH_CRED not implemented
Jun 24 15:32:42 history-20 sshd[4676]: pam_winbind(sshd:setcred): [pamh:
0x13f3f68] LEAVE: pam_sm_setcred returning 0 (PAM_SUCCESS)
Jun 24 15:32:43 history-20 sshd[4676]: pam_unix(sshd:session): session
opened for user administrator by (uid=0)
Jun 24 15:32:43 history-20 sshd[4679]: pam_winbind(sshd:setcred): [pamh:
0x13f3f68] ENTER: pam_sm_setcred (flags: 0x0002)
Jun 24 15:32:43 history-20 sshd[4679]: pam_winbind(sshd:setcred):
PAM_ESTABLISH_CRED not implemented
Jun 24 15:32:43 history-20 sshd[4679]: pam_winbind(sshd:setcred): [pamh:
0x13f3f68] LEAVE: pam_sm_setcred returning 0 (PAM_SUCCESS)
Jun 24 15:32:43 history-20 sshd[4676]: pam_winbind(sshd:setcred): [pamh:
0x13f3f68] ENTER: pam_sm_setcred (flags: 0x0004)
Jun 24 15:32:43 history-20 sshd[4676]: pam_winbind(sshd:setcred): [pamh:
0x13f3f68] ENTER: _pam_delete_cred (flags: 0x0004)

As far as I can tell, I'm joined to the domain successfully (server even
shows this computer as a machine account, although I didn't add a
machine account to the server -- I don't believe in my set up I have
to), I can enumerate the users and groups, and the system even
recognizes when I type in a good vs. bad password. There's some little
last step that must be failing, but I can't seem to figure out what it
is.

Also, just for good measure, I have confirmed that these accounts work
fine when logging into a Windows box or an existing Samba fileserver.
It's really just the PAM authentication that I can't get working.

Any thoughts? Need additional files posted?

Thanks for all your help.

-Chris Thielen