It looks like it is only happening when apache2 is involved. Although, other login methods are far less common. I have a suspicion it may be related to the mod_auth_pam module but what I don't understand is why it is happening. Mod_auth_pam makes dozens of requests to winbind for each session. Why do some work and others don't? Could it be that winbind is overwhelmed and thus doesn't return anything?
-----Original Message----- From: Scott Lovenberg [mailto:[EMAIL PROTECTED] Sent: Tuesday, February 12, 2008 9:09 PM To: Trimble, Ronald D Cc: samba@lists.samba.org Subject: Re: [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/channe > ls [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/channe > ls [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/channe > ls > > 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? -- To unsubscribe from this list go to the following URL and read the instructions: https://lists.samba.org/mailman/listinfo/samba
