samba - Jun 2025 - intermittent pam_winbind authentication failure

Hi,

We've been having an intermittent issue with pam_winbind on Ubuntu 24.04.
The test case we have to demonstrate this is to run this loop after logging in
as a domain user:

$ while sleep 1 ; do sudo -k ; sudo -K ; date ; echo "password" | sudo
-S /bin/echo "sudo success" || break ; done

The loop will run successfully, sometimes for 50+ iterations but eventually

[sudo] password for DOMAIN\user: sudo success
...
[sudo] password for DOMAIN\user: sudo success
[sudo] password for DOMAIN\user: Sorry, try again.
[sudo] password for DOMAIN\user:
sudo: no password was provided
sudo: 1 incorrect password attempt

Rejection of the correct password can also happen with a console logon or
remote ssh.  The system is joined to a Windows 2012 based domain.  Ubuntu
24.04 ships with packages based on 4.19.5 but rebuilding the packages from
25.04 (Samba 4.21.4) also has the same issue.

If I try to run winbindd with -d 3 or higher or with strace attached I'm
unable
to reproduce the issue which makes me suspect a timing issue passing the
response between winbindd and pam_winbind.  At -d 2 the winbindd logs
associated with the failure:

May 22 09:14:36 hostname winbindd[853342]: ads_krb5_mk_req:
smb_krb5_get_credentials failed for S00099-HOST$@DOMAIN.COM (Preauthentication
failed)
May 22 09:14:36 hostname winbindd[853342]: failed to get ticket for
S00099-HOST$@DOMAIN.COM: Preauthentication failed
May 22 09:14:36 hostname winbindd[853342]: _wbint_PamAuth: Plain-text
authentication for user DOMAIN\user returned NT_STATUS_LOGON_FAILURE (PAM: 7)
May 22 09:14:36 hostname winbindd[853342]: Auth: [winbind,PAM_AUTH,
PAM_WINBIND[sudo], 871758] user [DOMAIN]\[user] at [Thu, 22 May 2025
09:14:36.413942 BST] with [Plaintext] status [NT_STATUS_LOGON_FAILURE]
workstation [(null)] remote host [unix:] mapped to [(null)]\[(null)]. local host
[unix:]
May 22 09:14:36 hostname winbindd[853342]: {"timestamp":
"2025-05-22T09:14:36.424126+0100", "type":
"Authentication", "Authentication": {"version":
{"major": 1, "minor": 3}, "eventId": 4625,
"logonId": "db5db55c0b2b6903", "logonType": 8,
"status": "NT_STATUS_LOGON_FAILURE",
"localAddress": "unix:", "remoteAddress":
"unix:", "serviceDescription": "winbind",
"authDescription": "PAM_AUTH, PAM_WINBIND[sudo], 871758",
"clientDomain": "DOMAIN", "clientAccount":
"user", "workstation": null, "becameAccount":
"", "becameDomain": "", "becameSid":
null, "mappedAccount": null, "mappedDomain": null,
"netlogonComputer": null, "netlogonTrustAccount": null,
"netlogonNegotiateFlags": "0x00000000",
"netlogonSecureChannelType": 0, "netlogonTrustAccountSid":
null, "passwordType": "Plaintext",
"clientPolicyAccessCheck": null, "serverPolicyAccessCheck":
null, "duration": 98176}}

Occasionally for success I get:

Jun 03 08:27:44 hostname winbindd[774711]: final write to client failed: Broken
pipe

In the domain controller event log I get a pair of 4768 / 4769 event ids for
the proceeding success cases and the failure case (clocks are in sync so
I'm reasonably confident I've matched these up correctly) so it seems
winbindd has had a successful exchange with the domain controller.

A similar loop to the test case using `echo "pasword" | wblogin
--pam-logon="${USER}"` runs reliably.  However I don't see
anything in the
winbind logs so I'm not sure that "Attempt to authenticate a user in
the
same way pam_winbind would do." is identical in the technical
implementation.

Are there any alternative approaches I could take to try and uncover what
is happening?

Thanks,
James


/etc/pam.d/common-auth includes:

auth    [success=ignore default=die]    pam_faillock.so preauth deny=6
unlock_time=1800 silent
auth    [success=ok default=1]          pam_localuser.so 
auth    [success=3 default=ignore]      pam_unix.so try_first_pass
auth    [success=2 default=ignore]      pam_winbind.so krb5_auth
krb5_ccache_type=FILE cached_login try_first_pass debug
auth    optional        pam_faillock.so authfail deny=6 unlock_time=1800
auth    requisite                       pam_deny.so


The smb.conf we're using:

[global]
  workgroup = DOMAIN
  realm = DOMAIN.COM
  netbios name = S00099-host
  security = ads
  server role = member server
  dedicated keytab file = /etc/krb5.keytab
  kerberos method = secrets and keytab
  allow trusted domains = no
  server string = %h server (Samba, Ubuntu)
  disable netbios = yes
  password server = *
  winbind enum groups = yes
  winbind enum users = yes
  winbind nested groups = yes
  winbind refresh tickets = no
  template shell = /bin/bash
  template homedir = /home/local/%D/%U
  idmap config * : backend              = autorid
  idmap config * : range                = 2900000001-3000000000
  idmap config * : ignore builtin       = yes
  idmap config DOMAIN : backend   = rid
  idmap config DOMAIN : range     = 3000000001-3100000000
  map to guest = bad user
  guest account = nobody
  log file = /var/log/samba/log.%m
  log level = 1
  max log size = 5000
   load printers = no
   printing = bsd
   printcap name = /dev/null
   disable spoolss = yes
   dns proxy = no
   wins support = no
   domain master = no
   local master = no
   preferred master = no
   store dos attributes = yes
   map hidden = no
   map readonly = no
   map system = no
   map archive = no
   hide dot files = no
   enable core files = yes
   min receivefile size = 131072
   aio read size = 1
   aio write size = 1
   use sendfile = yes
   unix charset = UTF8
   ea support = yes
   map acl inherit = yes
   acl map full control = no
   unix extensions = no
   inherit acls = no
   follow symlinks = yes
   wide links = yes

On Tue, 3 Jun 2025 11:10:54 +0100
James Dingwall via samba <samba at lists.samba.org> wrote:
> Hi,
> 
> We've been having an intermittent issue with pam_winbind on Ubuntu
> 24.04. The test case we have to demonstrate this is to run this loop
> after logging in as a domain user:
> 
> $ while sleep 1 ; do sudo -k ; sudo -K ; date ; echo "password" |
> sudo -S /bin/echo "sudo success" || break ; done
> 
> The loop will run successfully, sometimes for 50+ iterations but
> eventually
> 
> [sudo] password for DOMAIN\user: sudo success
> ...
> [sudo] password for DOMAIN\user: sudo success
> [sudo] password for DOMAIN\user: Sorry, try again.
> [sudo] password for DOMAIN\user:
> sudo: no password was provided
> sudo: 1 incorrect password attempt
> 
> Rejection of the correct password can also happen with a console
> logon or remote ssh.  The system is joined to a Windows 2012 based
> domain.  Ubuntu 24.04 ships with packages based on 4.19.5 but
> rebuilding the packages from 25.04 (Samba 4.21.4) also has the same
> issue.
> 
> If I try to run winbindd with -d 3 or higher or with strace attached
> I'm unable to reproduce the issue which makes me suspect a timing
> issue passing the response between winbindd and pam_winbind.  At -d 2
> the winbindd logs associated with the failure:
> 
> May 22 09:14:36 hostname winbindd[853342]: ads_krb5_mk_req:
> smb_krb5_get_credentials failed for S00099-HOST$@DOMAIN.COM
> (Preauthentication failed) May 22 09:14:36 hostname winbindd[853342]:
> failed to get ticket for S00099-HOST$@DOMAIN.COM: Preauthentication
> failed May 22 09:14:36 hostname winbindd[853342]: _wbint_PamAuth:
> Plain-text authentication for user DOMAIN\user returned
> NT_STATUS_LOGON_FAILURE (PAM: 7) May 22 09:14:36 hostname
> winbindd[853342]: Auth: [winbind,PAM_AUTH, PAM_WINBIND[sudo], 871758]
> user [DOMAIN]\[user] at [Thu, 22 May 2025 09:14:36.413942 BST] with
> [Plaintext] status [NT_STATUS_LOGON_FAILURE] workstation [(null)]
> remote host [unix:] mapped to [(null)]\[(null)]. local host [unix:]
> May 22 09:14:36 hostname winbindd[853342]: {"timestamp":
> "2025-05-22T09:14:36.424126+0100", "type":
"Authentication",
> "Authentication": {"version": {"major": 1,
"minor": 3}, "eventId":
> 4625, "logonId": "db5db55c0b2b6903",
"logonType": 8, "status":
> "NT_STATUS_LOGON_FAILURE", "localAddress":
"unix:", "remoteAddress":
> "unix:", "serviceDescription": "winbind",
"authDescription":
> "PAM_AUTH, PAM_WINBIND[sudo], 871758", "clientDomain":
"DOMAIN",
> "clientAccount": "user", "workstation": null,
"becameAccount": "",
> "becameDomain": "", "becameSid": null,
"mappedAccount": null,
> "mappedDomain": null, "netlogonComputer": null,
> "netlogonTrustAccount": null, "netlogonNegotiateFlags":
"0x00000000",
> "netlogonSecureChannelType": 0,
"netlogonTrustAccountSid": null,
> "passwordType": "Plaintext",
"clientPolicyAccessCheck": null,
> "serverPolicyAccessCheck": null, "duration": 98176}}
> 
> Occasionally for success I get:
> 
> Jun 03 08:27:44 hostname winbindd[774711]: final write to client
> failed: Broken pipe
> 
> In the domain controller event log I get a pair of 4768 / 4769 event
> ids for the proceeding success cases and the failure case (clocks are
> in sync so I'm reasonably confident I've matched these up
correctly)
> so it seems winbindd has had a successful exchange with the domain
> controller.
> 
> A similar loop to the test case using `echo "pasword" | wblogin
> --pam-logon="${USER}"` runs reliably.  However I don't see
anything
> in the winbind logs so I'm not sure that "Attempt to authenticate
a
> user in the same way pam_winbind would do." is identical in the
> technical implementation.
> 
> Are there any alternative approaches I could take to try and uncover
> what is happening?
> 
> Thanks,
> James
> 
> 
> /etc/pam.d/common-auth includes:
> 
> auth    [success=ignore default=die]    pam_faillock.so preauth
> deny=6 unlock_time=1800 silent auth    [success=ok default=1]
>  pam_localuser.so auth    [success=3 default=ignore]      pam_unix.so
> try_first_pass auth    [success=2 default=ignore]      pam_winbind.so
> krb5_auth krb5_ccache_type=FILE cached_login try_first_pass debug
> auth    optional        pam_faillock.so authfail deny=6
> unlock_time=1800 auth    requisite                       pam_deny.so
> 
> 
> The smb.conf we're using:
> 
> [global]
>   workgroup = DOMAIN
>   realm = DOMAIN.COM
>   netbios name = S00099-host
>   security = ads
>   server role = member server
>   dedicated keytab file = /etc/krb5.keytab
>   kerberos method = secrets and keytab
>   allow trusted domains = no
>   server string = %h server (Samba, Ubuntu)
>   disable netbios = yes
>   password server = *
>   winbind enum groups = yes
>   winbind enum users = yes
>   winbind nested groups = yes
>   winbind refresh tickets = no
>   template shell = /bin/bash
>   template homedir = /home/local/%D/%U
>   idmap config * : backend              = autorid
>   idmap config * : range                = 2900000001-3000000000
>   idmap config * : ignore builtin       = yes
>   idmap config DOMAIN : backend   = rid
>   idmap config DOMAIN : range     = 3000000001-3100000000
>   map to guest = bad user
>   guest account = nobody
>   log file = /var/log/samba/log.%m
>   log level = 1
>   max log size = 5000
>    load printers = no
>    printing = bsd
>    printcap name = /dev/null
>    disable spoolss = yes
>    dns proxy = no
>    wins support = no
>    domain master = no
>    local master = no
>    preferred master = no
>    store dos attributes = yes
>    map hidden = no
>    map readonly = no
>    map system = no
>    map archive = no
>    hide dot files = no
>    enable core files = yes
>    min receivefile size = 131072
>    aio read size = 1
>    aio write size = 1
>    use sendfile = yes
>    unix charset = UTF8
>    ea support = yes
>    map acl inherit = yes
>    acl map full control = no
>    unix extensions = no
>    inherit acls = no
>    follow symlinks = yes
>    wide links = yes
> 
OK, I took your one line script and turned it into this:

#!/bin/bash

password=$1

counter=0
while sleep 1 ; do
	echo "TRY: $counter"
	sudo -k
	sudo -K
	date
	echo "$password" | sudo -S /bin/echo "sudo success" ||
break
	counter=$((counter+1))
done

I then ran it and it is still running, 'TRY' is now in excess of 2,500
and still going up.

I feel your problems possibly lie in your /etc/pam.d/common-auth file
and rather strange (well, strange to me) idmap config lines in smb.conf.

My common-auth contains this:

auth	[success=2 default=ignore]	pam_unix.so nullok
auth	[success=1 default=ignore]	pam_winbind.so krb5_auth krb5_ccache_type=FILE
cached_login try_first_pass
auth	requisite			pam_deny.so
auth	required			pam_permit.so

What do expect your extra/different lines to do ? 

You appear to be using both the 'autorid' and 'rid' idmap
backends and
you are telling autorid to ignore the BUILTIN domain, so what is mapping
the required BUILTIN users and groups, I haven't a clue. I suggest you
change 'autorid' to 'tdb'. I also have to ask, why are you using
such
high numbers for the ranges ?

These are my idmap config lines:

  idmap config * : backend = tdb
  idmap config * : range = 3000-7999
  idmap config SAMDOM : backend  = rid
  idmap config SAMDOM : range = 10000-999999

By the way, 'TRY' is now approaching 3,000 and still going.

Rowland