Trimble, Ronald D
2008-Feb-13 01:44 UTC
[Samba] Problem with winbind not seeing a user as part of a group
Everyone,
Here is a challenge for all of you samba experts! Lately I have
been seeing a problem where winbind is not correctly identifying a user as a
member of a group he most certainly belong to. This is with a Domain Local
group so I know samba should support it.
Users access a HTTPS (SSL) webpage that is secured by a Domain
Local group. Sometimes they get in, others they don't. Here are some
examples from the logs.
/var/log/apache2/error_log
[Tue Feb 12 18:54:52 2008] [error] [client 172.xx.xxx.xxx] GROUP: NA\\selltc not
in required group(s)., referer:
https://ustr-linux-1/scm/spar/trac/browser/trunk/common/include/channels
[Tue Feb 12 18:55:00 2008] [error] [client 172.xx.xxx.xxx] GROUP: NA\\selltc not
in required group(s)., referer:
https://ustr-linux-1/scm/spar/trac/browser/trunk/common/include/channels
[Tue Feb 12 18:56:12 2008] [error] [client 172.xx.xxx.xxx] GROUP: NA\\selltc not
in required group(s)., referer:
https://ustr-linux-1/scm/spar/trac/browser/trunk/common/include/channels
However a little later it is mysteriously working again...
/var/log/apache2/access_log
172.xx.xxx.xxx - NA\\selltc [12/Feb/2008:20:02:37 -0500] "GET
/scm/spar/trac/chrome/common/css/trac.css HTTP/1.1" 304 -
172.xx.xxx.xxx - NA\\selltc [12/Feb/2008:20:02:37 -0500] "GET
/scm/spar/trac/chrome/common/css/browser.css HTTP/1.1" 304 -
172.xx.xxx.xxx - NA\\selltc [12/Feb/2008:20:02:37 -0500] "GET
/scm/spar/trac/chrome/common/css/diff.css HTTP/1.1" 304 -
Now obviously my example doesn't have the user accessing the same link, but
it doesn't matter. Winbind went from identifying the user as not in the
group to then identifying him as in the group and nothing changed! This is
happening several times a day and is driving us insane. What can I do to figure
this out? Has anyone else seen this?
Here is what is going on in the /var/log/samba/log.wb-NA (our domain) log at
that time for that user.
[2008/02/12 18:54:52, 10] nsswitch/winbindd_dual.c:child_process_request(479)
process_request: request fn PAM_AUTH
[2008/02/12 18:54:52, 3] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1341)
[10824]: dual pam auth NA\selltc
[2008/02/12 18:54:52, 10] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1364)
winbindd_dual_pam_auth: domain: NA last was online
[2008/02/12 18:54:52, 10]
nsswitch/winbindd_pam.c:winbindd_dual_pam_auth_samlogon(1127)
winbindd_dual_pam_auth_samlogon
[2008/02/12 18:54:52, 10] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1416)
winbindd_dual_pam_auth_samlogon succeeded
[2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(472)
refresh_sequence_number: NA time ok
[2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(506)
refresh_sequence_number: NA seq number is now 271835101
[2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(823)
wcache_save_name_to_sid: NA\SELLTC ->
S-1-5-21-725345543-2052111302-527237240-26405 (NT_STATUS_OK)
[2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(472)
refresh_sequence_number: NA time ok
[2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(506)
refresh_sequence_number: NA seq number is now 271835101
[2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:centry_expired(546)
centry_expired: Key PWD_POL/NA for domain NA is good.
[2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:wcache_fetch(630)
wcache_fetch: returning entry PWD_POL/NA for domain NA
[2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:password_policy(2108)
lockout_policy: [Cached] - cached info for domain NA status: NT_STATUS_OK
[2008/02/12 18:54:52, 5] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1546)
Setting unix username to [NA\selltc]
[2008/02/12 18:54:52, 5] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1578)
Plain-text authentication for user NA\selltc returned NT_STATUS_OK (PAM: 0)
Please let me know if you can help me figure this out.
Thanks,
Ron
Scott Lovenberg
2008-Feb-13 02:05 UTC
[Samba] Problem with winbind not seeing a user as part of a group
Trimble, Ronald D wrote:> Everyone, > Here is a challenge for all of you samba experts! Lately I have been seeing a problem where winbind is not correctly identifying a user as a member of a group he most certainly belong to. This is with a Domain Local group so I know samba should support it. > Users access a HTTPS (SSL) webpage that is secured by a Domain Local group. Sometimes they get in, others they don't. Here are some examples from the logs. > > /var/log/apache2/error_log > > [Tue Feb 12 18:54:52 2008] [error] [client 172.xx.xxx.xxx] GROUP: NA\\selltc not in required group(s)., referer: https://ustr-linux-1/scm/spar/trac/browser/trunk/common/include/channels > [Tue Feb 12 18:55:00 2008] [error] [client 172.xx.xxx.xxx] GROUP: NA\\selltc not in required group(s)., referer: https://ustr-linux-1/scm/spar/trac/browser/trunk/common/include/channels > [Tue Feb 12 18:56:12 2008] [error] [client 172.xx.xxx.xxx] GROUP: NA\\selltc not in required group(s)., referer: https://ustr-linux-1/scm/spar/trac/browser/trunk/common/include/channels > > However a little later it is mysteriously working again... > > /var/log/apache2/access_log > > 172.xx.xxx.xxx - NA\\selltc [12/Feb/2008:20:02:37 -0500] "GET /scm/spar/trac/chrome/common/css/trac.css HTTP/1.1" 304 - > 172.xx.xxx.xxx - NA\\selltc [12/Feb/2008:20:02:37 -0500] "GET /scm/spar/trac/chrome/common/css/browser.css HTTP/1.1" 304 - > 172.xx.xxx.xxx - NA\\selltc [12/Feb/2008:20:02:37 -0500] "GET /scm/spar/trac/chrome/common/css/diff.css HTTP/1.1" 304 - > > Now obviously my example doesn't have the user accessing the same link, but it doesn't matter. Winbind went from identifying the user as not in the group to then identifying him as in the group and nothing changed! This is happening several times a day and is driving us insane. What can I do to figure this out? Has anyone else seen this? > > Here is what is going on in the /var/log/samba/log.wb-NA (our domain) log at that time for that user. > > [2008/02/12 18:54:52, 10] nsswitch/winbindd_dual.c:child_process_request(479) > process_request: request fn PAM_AUTH > [2008/02/12 18:54:52, 3] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1341) > [10824]: dual pam auth NA\selltc > [2008/02/12 18:54:52, 10] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1364) > winbindd_dual_pam_auth: domain: NA last was online > [2008/02/12 18:54:52, 10] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth_samlogon(1127) > winbindd_dual_pam_auth_samlogon > [2008/02/12 18:54:52, 10] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1416) > winbindd_dual_pam_auth_samlogon succeeded > [2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(472) > refresh_sequence_number: NA time ok > [2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(506) > refresh_sequence_number: NA seq number is now 271835101 > [2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:wcache_save_name_to_sid(823) > wcache_save_name_to_sid: NA\SELLTC -> S-1-5-21-725345543-2052111302-527237240-26405 (NT_STATUS_OK) > [2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(472) > refresh_sequence_number: NA time ok > [2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:refresh_sequence_number(506) > refresh_sequence_number: NA seq number is now 271835101 > [2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:centry_expired(546) > centry_expired: Key PWD_POL/NA for domain NA is good. > [2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:wcache_fetch(630) > wcache_fetch: returning entry PWD_POL/NA for domain NA > [2008/02/12 18:54:52, 10] nsswitch/winbindd_cache.c:password_policy(2108) > lockout_policy: [Cached] - cached info for domain NA status: NT_STATUS_OK > [2008/02/12 18:54:52, 5] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1546) > Setting unix username to [NA\selltc] > [2008/02/12 18:54:52, 5] nsswitch/winbindd_pam.c:winbindd_dual_pam_auth(1578) > Plain-text authentication for user NA\selltc returned NT_STATUS_OK (PAM: 0) > > Please let me know if you can help me figure this out. > > Thanks, > Ron > >Does authentication ever fail like this from another login point (from a desktop login, or other PAM settings)? Or only when apache is involved?