samba - Nov 2024 - pam_winbind Appears to need a Network Connection to Succeed at Offline Authentication

When I put winbindd in offline mode,

 ??? terra ~ # smbcontrol winbindd offline
 ??? terra ~ # smbcontrol winbindd onlinestatus
 ??? PID 20664: global:Offline BUILTIN:Online TERRA:Online HOME:Offline

I can successfully log in (with the test shown in the PAM Offline 
Authentication Wiki article):

 ??? terra ~ # ssh SAMDOM\\jgraham at localhost
 ??? (SAMDOM\jgraham at localhost) Password:
 ??? Domain Controller unreachable, using cached credentials instead. 
Network resources may be unavailable
 ??? Domain Controller unreachable, using cached credentials instead. 
Network resources may be unavailable

Log entries in /var/log/messages look normal to my eye and seem to 
confirm the use of cached credentials:

 ??? Nov 27 09:32:42 terra sshd-session[16687]: pam_winbind(sshd:auth): 
[pamh: 0x55dc18bc2780] ENTER: pam_sm_authenticate (flags: 0x0001)
 ??? Nov 27 09:32:42 terra sshd-session[16687]: pam_winbind(sshd:auth): 
getting password (0x00004389)
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
Verify user 'SAMDOM\jgraham'
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
CONFIG file: krb5_ccache_type 'FILE'
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
enabling krb5 login flag
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
enabling cached login flag
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
enabling request for a FILE krb5 ccache
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
request wbcLogonUser succeeded
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
user 'SAMDOM\jgraham' granted access
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
User SAMDOM\jgraham logged on using cached credentials
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
request returned KRB5CCNAME: FILE:/tmp/krb5cc_10000
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
Returned user was 'SAMDOM\jgraham'
 ??? Nov 27 09:32:47 terra sshd-session[16687]: pam_winbind(sshd:auth): 
[pamh: 0x55dc18bc2780] LEAVE: pam_sm_authenticate returning 0 (PAM_SUCCESS)
 ??? Nov 27 09:32:47 terra sshd-session[16687]: 
pam_winbind(sshd:account): [pamh: 0x55dc18bc2780] ENTER: 
pam_sm_acct_mgmt (flags: 0x0000)
 ??? Nov 27 09:32:47 terra sshd-session[16687]: 
pam_winbind(sshd:account): user 'SAMDOM\jgraham' granted access
 ??? Nov 27 09:32:47 terra sshd-session[16687]: 
pam_winbind(sshd:account): [pamh: 0x55dc18bc2780] LEAVE: 
pam_sm_acct_mgmt returning 0 (PAM_SUCCESS)
 ??? Nov 27 09:32:47 terra sshd-session[16674]: Accepted 
keyboard-interactive/pam for SAMDOM\\jgraham from 127.0.0.1 port 37410 ssh2
 ??? Nov 27 09:32:47 terra sshd-session[16674]: 
pam_winbind(sshd:setcred): [pamh: 0x55dc18bc2780] ENTER: pam_sm_setcred 
(flags: 0x0002)
 ??? Nov 27 09:32:47 terra sshd-session[16674]: 
pam_winbind(sshd:setcred): PAM_ESTABLISH_CRED not implemented
 ??? Nov 27 09:32:47 terra sshd-session[16674]: 
pam_winbind(sshd:setcred): [pamh: 0x55dc18bc2780] LEAVE: pam_sm_setcred 
returning 0 (PAM_SUCCESS)
 ??? Nov 27 09:32:47 terra sshd-session[16674]: pam_unix(sshd:session): 
session opened for user SAMDOM\jgraham(uid=10000) by SAMDOM\jgraham(uid=0)
 ??? Nov 27 09:32:47 terra elogind-daemon[3814]: New session 22 of user 
SAMDOM\jgraham.

But this is done with the network connection up. When I unplug the 
cable, the behavior is very different:

 ??? terra ~ # ssh SAMDOM\\jgraham at localhost
 ??? (SAMDOM\jgraham at localhost) Password:
 ??? (SAMDOM\jgraham at localhost) Password:
 ??? Connection closed by 127.0.0.1 port 22

/var/log/messages shows:

 ??? Nov 27 09:41:17 terra sshd-session[29098]: Invalid user 
SAMDOM\\jgraham from 127.0.0.1 port 50306
 ??? Nov 27 09:41:39 terra sshd-session[30699]: pam_faillock(sshd:auth): 
User unknown
 ??? Nov 27 09:41:39 terra sshd-session[30699]: pam_winbind(sshd:auth): 
[pamh: 0x55c233e7bc70] ENTER: pam_sm_authenticate (flags: 0x0001)
 ??? Nov 27 09:41:39 terra sshd-session[30699]: pam_winbind(sshd:auth): 
getting password (0x00004389)
 ??? Nov 27 09:41:39 terra sshd-session[29098]: Postponed 
keyboard-interactive for invalid user SAMDOM\\\\jgraham from 127.0.0.1 
port 50306 ssh2 [preauth]
 ??? Nov 27 09:41:52 terra sshd-session[30699]: pam_winbind(sshd:auth): 
Verify user 'SAMDOM\jgraham'
 ??? Nov 27 09:41:52 terra sshd-session[30699]: pam_winbind(sshd:auth): 
CONFIG file: krb5_ccache_type 'FILE'
 ??? Nov 27 09:42:03 terra sshd-session[30699]: pam_winbind(sshd:auth): 
[pamh: 0x55c233e7bc70] LEAVE: pam_sm_authenticate returning 10 
(PAM_USER_UNKNOWN)
 ??? Nov 27 09:42:14 terra sshd-session[30699]: pam_unix(sshd:auth): 
check pass; user unknown
 ??? Nov 27 09:42:14 terra sshd-session[30699]: pam_unix(sshd:auth): 
authentication failure; logname= uid=0 euid=0 tty=ssh ruser= 
rhost=127.0.0.1
 ??? Nov 27 09:42:25 terra sshd-session[30699]: pam_faillock(sshd:auth): 
User unknown
 ??? Nov 27 09:42:27 terra sshd-session[29098]: error: PAM: User not 
known to the underlying authentication module for illegal user 
SAMDOM\\jgraham from 127.0.0.1
 ??? Nov 27 09:42:27 terra sshd-session[29098]: Failed 
keyboard-interactive/pam for invalid user SAMDOM\\jgraham from 127.0.0.1 
port 50306 ssh2
 ??? Nov 27 09:42:49 terra sshd-session[7489]: pam_faillock(sshd:auth): 
User unknown
 ??? Nov 27 09:42:49 terra sshd-session[7489]: pam_winbind(sshd:auth): 
[pamh: 0x55c233e7bc70] ENTER: pam_sm_authenticate (flags: 0x0001)
 ??? Nov 27 09:42:49 terra sshd-session[7489]: pam_winbind(sshd:auth): 
getting password (0x00004389)
 ??? Nov 27 09:42:49 terra sshd-session[29098]: Postponed 
keyboard-interactive for invalid user SAMDOM\\\\jgraham from 127.0.0.1 
port 50306 ssh2 [preauth]
 ??? Nov 27 09:43:01 terra sshd-session[7489]: pam_winbind(sshd:auth): 
Verify user 'SAMDOM\jgraham'
 ??? Nov 27 09:43:01 terra sshd-session[7489]: pam_winbind(sshd:auth): 
CONFIG file: krb5_ccache_type 'FILE'
 ??? Nov 27 09:43:06 terra sshd[3801]: Timeout before authentication for 
connection from 127.0.0.1 to 127.0.0.1, pid = 29098

Is this still looking like a PAM configuration issue?

There are other related things misbehaving with the network cable 
unplugged. For instance previously logged in sessions appear to lose 
access to their home directories (which are owned by the domain user).

For the record, it's samba 4.21.1.

- John

On Wed, 27 Nov 2024 10:19:48 -0500
"John R. Graham via samba" <samba at lists.samba.org> wrote:
> When I put winbindd in offline mode,
> 
>  ??? terra ~ # smbcontrol winbindd offline
>  ??? terra ~ # smbcontrol winbindd onlinestatus
>  ??? PID 20664: global:Offline BUILTIN:Online TERRA:Online
> HOME:Offline
> 
> I can successfully log in (with the test shown in the PAM Offline 
> Authentication Wiki article):
> 
>  ??? terra ~ # ssh SAMDOM\\jgraham at localhost
>  ??? (SAMDOM\jgraham at localhost) Password:
>  ??? Domain Controller unreachable, using cached credentials instead. 
> Network resources may be unavailable
>  ??? Domain Controller unreachable, using cached credentials instead. 
> Network resources may be unavailable
> 
> Log entries in /var/log/messages look normal to my eye and seem to 
> confirm the use of cached credentials:
> 
>  ??? Nov 27 09:32:42 terra sshd-session[16687]:
> pam_winbind(sshd:auth): [pamh: 0x55dc18bc2780] ENTER:
> pam_sm_authenticate (flags: 0x0001) Nov 27 09:32:42 terra
> sshd-session[16687]: pam_winbind(sshd:auth): getting password
> (0x00004389) Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): Verify user 'SAMDOM\jgraham'
>  ??? Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): CONFIG file: krb5_ccache_type 'FILE'
>  ??? Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): enabling krb5 login flag
>  ??? Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): enabling cached login flag
>  ??? Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): enabling request for a FILE krb5 ccache
>  ??? Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): request wbcLogonUser succeeded
>  ??? Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): user 'SAMDOM\jgraham' granted access
>  ??? Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): User SAMDOM\jgraham logged on using cached
> credentials Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): request returned KRB5CCNAME:
> FILE:/tmp/krb5cc_10000 Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): Returned user was 'SAMDOM\jgraham'
>  ??? Nov 27 09:32:47 terra sshd-session[16687]:
> pam_winbind(sshd:auth): [pamh: 0x55dc18bc2780] LEAVE:
> pam_sm_authenticate returning 0 (PAM_SUCCESS) Nov 27 09:32:47 terra
> sshd-session[16687]: pam_winbind(sshd:account): [pamh:
> 0x55dc18bc2780] ENTER: pam_sm_acct_mgmt (flags: 0x0000)
>  ??? Nov 27 09:32:47 terra sshd-session[16687]: 
> pam_winbind(sshd:account): user 'SAMDOM\jgraham' granted access
>  ??? Nov 27 09:32:47 terra sshd-session[16687]: 
> pam_winbind(sshd:account): [pamh: 0x55dc18bc2780] LEAVE: 
> pam_sm_acct_mgmt returning 0 (PAM_SUCCESS)
>  ??? Nov 27 09:32:47 terra sshd-session[16674]: Accepted 
> keyboard-interactive/pam for SAMDOM\\jgraham from 127.0.0.1 port
> 37410 ssh2 Nov 27 09:32:47 terra sshd-session[16674]: 
> pam_winbind(sshd:setcred): [pamh: 0x55dc18bc2780] ENTER:
> pam_sm_setcred (flags: 0x0002)
>  ??? Nov 27 09:32:47 terra sshd-session[16674]: 
> pam_winbind(sshd:setcred): PAM_ESTABLISH_CRED not implemented
>  ??? Nov 27 09:32:47 terra sshd-session[16674]: 
> pam_winbind(sshd:setcred): [pamh: 0x55dc18bc2780] LEAVE:
> pam_sm_setcred returning 0 (PAM_SUCCESS)
>  ??? Nov 27 09:32:47 terra sshd-session[16674]:
> pam_unix(sshd:session): session opened for user
> SAMDOM\jgraham(uid=10000) by SAMDOM\jgraham(uid=0) Nov 27 09:32:47
> terra elogind-daemon[3814]: New session 22 of user SAMDOM\jgraham.
> 
> But this is done with the network connection up. When I unplug the 
> cable, the behavior is very different:
> 
>  ??? terra ~ # ssh SAMDOM\\jgraham at localhost
>  ??? (SAMDOM\jgraham at localhost) Password:
>  ??? (SAMDOM\jgraham at localhost) Password:
>  ??? Connection closed by 127.0.0.1 port 22
> 
> /var/log/messages shows:
> 
>  ??? Nov 27 09:41:17 terra sshd-session[29098]: Invalid user 
> SAMDOM\\jgraham from 127.0.0.1 port 50306
>  ??? Nov 27 09:41:39 terra sshd-session[30699]:
> pam_faillock(sshd:auth): User unknown
>  ??? Nov 27 09:41:39 terra sshd-session[30699]:
> pam_winbind(sshd:auth): [pamh: 0x55c233e7bc70] ENTER:
> pam_sm_authenticate (flags: 0x0001) Nov 27 09:41:39 terra
> sshd-session[30699]: pam_winbind(sshd:auth): getting password
> (0x00004389) Nov 27 09:41:39 terra sshd-session[29098]: Postponed 
> keyboard-interactive for invalid user SAMDOM\\\\jgraham from
> 127.0.0.1 port 50306 ssh2 [preauth]
>  ??? Nov 27 09:41:52 terra sshd-session[30699]:
> pam_winbind(sshd:auth): Verify user 'SAMDOM\jgraham'
>  ??? Nov 27 09:41:52 terra sshd-session[30699]:
> pam_winbind(sshd:auth): CONFIG file: krb5_ccache_type 'FILE'
>  ??? Nov 27 09:42:03 terra sshd-session[30699]:
> pam_winbind(sshd:auth): [pamh: 0x55c233e7bc70] LEAVE:
> pam_sm_authenticate returning 10 (PAM_USER_UNKNOWN)
>  ??? Nov 27 09:42:14 terra sshd-session[30699]: pam_unix(sshd:auth): 
> check pass; user unknown
>  ??? Nov 27 09:42:14 terra sshd-session[30699]: pam_unix(sshd:auth): 
> authentication failure; logname= uid=0 euid=0 tty=ssh ruser= 
> rhost=127.0.0.1
>  ??? Nov 27 09:42:25 terra sshd-session[30699]:
> pam_faillock(sshd:auth): User unknown
>  ??? Nov 27 09:42:27 terra sshd-session[29098]: error: PAM: User not 
> known to the underlying authentication module for illegal user 
> SAMDOM\\jgraham from 127.0.0.1
>  ??? Nov 27 09:42:27 terra sshd-session[29098]: Failed 
> keyboard-interactive/pam for invalid user SAMDOM\\jgraham from
> 127.0.0.1 port 50306 ssh2
>  ??? Nov 27 09:42:49 terra sshd-session[7489]:
> pam_faillock(sshd:auth): User unknown
>  ??? Nov 27 09:42:49 terra sshd-session[7489]:
> pam_winbind(sshd:auth): [pamh: 0x55c233e7bc70] ENTER:
> pam_sm_authenticate (flags: 0x0001) Nov 27 09:42:49 terra
> sshd-session[7489]: pam_winbind(sshd:auth): getting password
> (0x00004389) Nov 27 09:42:49 terra sshd-session[29098]: Postponed 
> keyboard-interactive for invalid user SAMDOM\\\\jgraham from
> 127.0.0.1 port 50306 ssh2 [preauth]
>  ??? Nov 27 09:43:01 terra sshd-session[7489]:
> pam_winbind(sshd:auth): Verify user 'SAMDOM\jgraham'
>  ??? Nov 27 09:43:01 terra sshd-session[7489]:
> pam_winbind(sshd:auth): CONFIG file: krb5_ccache_type 'FILE'
>  ??? Nov 27 09:43:06 terra sshd[3801]: Timeout before authentication
> for connection from 127.0.0.1 to 127.0.0.1, pid = 29098
> 
> Is this still looking like a PAM configuration issue?
> 
> There are other related things misbehaving with the network cable 
> unplugged. For instance previously logged in sessions appear to lose 
> access to their home directories (which are owned by the domain user).
> 
> For the record, it's samba 4.21.1.
> 
> - John
> 
> 
> 
I am not having a good day, I now seem to have replied to the wrong
thread :-(

Lets try again:

If I remember correctly, this is on Gentoo, Debian sets up PAM for you,
so can we see your PAM config files. Putting winbindd (or is it winbind
?) offline is supposed to be the same as pulling the ethernet cable or
the network going down, it should move to a cache (provided the user
has logged in at least once.

Rowland