[Samba] pam_winbind fails to authenticate domain users on my debian wheezy domain member servers

[Georg Vorlaufer]

Dear list members,

I am running a small active directory domain for my home network.
Everything is working as expected, except for the authentication of active
directory users on my machines running debian wheezy.

Here is my setup:

1) Active Directory Domain Controller is running on a raspberrypi
(raspbian) with samba compiled from source (v4-1-stable from git repository)
2) WIndows 7 machines can join the domain, domain users can log in
3) OpenSuSE 13.1 machines can join the domain, domain users can log in -- I
am using the samba packages provided with the distribution and winbind for
nss/pam

4a) A (virtual) machine running Debian Wheezy (x86_64) using the samba4.1.3
packages from sernet and
4b) A (qnap nas) machine running Debian Wheezy (armel kirkwood) using samba
compiled from source (v4-1-stable from git repository)

For both machines I have configured nss and pam to use winbind

Both machines can successfully join the domain as a domain member.
'wbinfo -u' lists all domain users
'getent passwd user1' and 'id user1' works
Obtaining kerberos tickets works

However, when I try to login via ssh to either of the two machines using my
domain account (georg), I get rejected by the pam_winbind module. However,
the kerberos ticket cache is created during the ssh authentication process
(i.e. the file /tmp/krb5cc_10001, where 10001 is the numeric uid of user
georg, is created and contains a valid ticket)

Here is the relevant portion of /var/log/auth.log

Jan  2 12:23:55 websrv sshd[3541]: pam_unix(sshd:auth): authentication
failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.0.107
user=georg
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] ENTER: pam_sm_authenticate (flags: 0x0001)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7f1d54caa2e0)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_USER) = "georg" (0x7f1d54ca9f00)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_TTY) = "ssh" (0x7f1d54cb21d0)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_RHOST) = "192.168.0.107" (0x7f1d54cb21b0)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_AUTHTOK) = 0x7f1d54ca83e0
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_CONV) = 0x7f1d54cb2210
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): getting password
(0x00001189)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): pam_get_item
returned a password
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): Verify user
'georg'
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): PAM config:
krb5_ccache_type 'FILE'
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): enabling krb5
login flag
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): enabling request
for a FILE krb5 ccache
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): request
wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_SYSTEM_ERR (4),
NTSTATUS: NT_STATUS_CONNECTION_DISCONNECTED, Error message was:
NT_STATUS_CONNECTION_DISCONNECTED
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): internal module
error (retval = PAM_SYSTEM_ERR(4), user = 'georg')
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] LEAVE: pam_sm_authenticate returning 4 (PAM_SYSTEM_ERR)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_SERVICE) = "sshd" (0x7f1d54caa2e0)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_USER) = "georg" (0x7f1d54ca9f00)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_TTY) = "ssh" (0x7f1d54cb21d0)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_RHOST) = "192.168.0.107" (0x7f1d54cb21b0)
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_AUTHTOK) = 0x7f1d54ca83e0
Jan  2 12:23:55 websrv sshd[3541]: pam_winbind(sshd:auth): [pamh:
0x7f1d54cb2030] STATE: ITEM(PAM_CONV) = 0x7f1d54cb2210
Jan  2 12:23:56 websrv sshd[3541]: Failed password for georg from
192.168.0.107 port 49619 ssh2

And here is the pam config (/etc/pam.d/common-auth)

#
# /etc/pam.d/common-auth - authentication settings common to all services
#
# This file is included from other service-specific PAM config files,
# and should contain a list of the authentication modules that define
# the central authentication scheme for use on the system
# (e.g., /etc/shadow, LDAP, Kerberos, etc.).  The default is to use the
# traditional Unix authentication mechanisms.
#
# As of pam 1.0.1-6, this file is managed by pam-auth-update by default.
# To take advantage of this, it is recommended that you configure any
# local modules either before or after the default block, and use
# pam-auth-update to manage selection of other modules.  See
# pam-auth-update(8) for details.

# here are the per-package modules (the "Primary" block)
auth    [success=2 default=ignore]    pam_unix.so nullok_secure
auth    [success=1 default=ignore]    pam_winbind.so krb5_auth
krb5_ccache_type=FILE try_first_pass
# here's the fallback if no module succeeds
auth    requisite            pam_deny.so
# prime the stack with a positive return value if there isn't one already;
# this avoids us returning an error just because nothing sets a success code
# since the modules above will each just jump around
auth    required            pam_permit.so
# and here are more per-package modules (the "Additional" block)
# end of pam-auth-update config


My question is, if this is a known behaviour (of pam_winbind) or if I am
doing something fundamentally wrong here?

With kind regards,

Georg