Bug 120694 - pam_unix logs pointless authentication failures when using LDAP
pam_unix logs pointless authentication failures when using LDAP
Status: CLOSED UPSTREAM
Product: Red Hat Enterprise Linux 3
Classification: Red Hat
Component: pam (Show other bugs)
3.0
All Linux
medium Severity low
: ---
: ---
Assigned To: Tomas Mraz
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2004-04-12 22:15 EDT by Terry Griffin
Modified: 2007-11-30 17:07 EST (History)
5 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2005-01-05 04:00:54 EST
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Terry Griffin 2004-04-12 22:15:18 EDT
Description of problem:

When configured for LDAP authentication, pam_unix is cluttering
the /var/log/messages with authentication failures when in fact
no such failure is really happening. I assume it thinks there's a 
failure because the user is not listed in /etc/passwd. But that's
just its narrow view of the world. If the client application (ipop3d
for example) subsequently authenticates the user via LDAP then
there has been no actual authentication failure. Why not leave it to
the client app to log success or failure after it has tried all the
various ways of authenticating? Logging the failure from the narrow
view of a PAM module gives misleading results and clutters the
system log file.

Version-Release number of selected component (if applicable):

pam-0.75-51

How reproducible:

100%

Steps to Reproduce:
1. Configure for LDAP authentication.
2. Create an LDAP account (no /etc/passwd entry)
3. Perform POP3 or IMAP queries on the account (imap-2002d
in my case)
  
Actual results:

pam_unix.so (on behalf of ipop3d or imapd) logs user-unknown
authentication failures to /var/log/messages with each POP or IMAP
query even when user authentication ultimately succeeds.

Expected results:

No authentication failures logged unless there is a real
authentication failure, after checking all possible authentication
sources (/etc/passwd, LDAP, NIS, whatever)

Additional info:

I'm guessing that this logging feature in pam_unix is the root
cause of #120368.
Comment 1 Andy Jacobson 2004-06-17 12:36:36 EDT
I can confirm this bug in RHEL3, and would like to suggest that its
underlying cause is creating more trouble than just annoying log
messages.  I think this bug also allows unprivileged users to crash
the cron service by simply editing their crontabs.

The ipop3d and imapd services seem to try authenticating twice.  They
fail on the pam_unix.so line in system-auth, but succeed on the next
try which calls pam_ldap.so.  Cron appears to try once, and fails for
non-local users--those that need to be authenticated via ldap:

Jun 17 11:40:31 bengal crontab[3025]: (andyj) BEGIN EDIT (andyj) 
Jun 17 11:40:59 bengal crontab[3025]: (andyj) REPLACE (andyj) 
Jun 17 11:40:59 bengal crontab[3025]: (andyj) END EDIT (andyj) 
Jun 17 11:41:00 bengal crond[2762]: nss_ldap: reconnecting to LDAP
server...
Jun 17 11:41:00 bengal crond[2762]: nss_ldap: reconnected to LDAP
server after 1 attempt(s)

At this point the cron daemon is dead.

I have reversed the order of the pam_unix.so and pam_ldap.so lines in
my /etc/pam.d/system-auth file.  This eliminates both the annoying log
messages from imap3 and ipop3d and fixes the problem with cron. My
experimental system-auth contains:

auth        sufficient    /lib/security/$ISA/pam_ldap.so 
auth        sufficient    /lib/security/$ISA/pam_unix.so likeauth
nullok use_first_pass

We're using vixie-cron-3.0.1.  This isn't a manifestation of #5160, is it?
Comment 2 Douglas Furlong 2004-10-11 06:22:35 EDT
Andy, I may be very wrong on this.

But, if the user lookup in LDAP fails, or the server is unavailable to
answer, how will that inpact the system once you have reversed the
entries?

I'm just wondering if you'll run in to problems when you are unable to
cleanly shutdown the system, or log in as root when the LDAP server is
non-responsive.

doug
Comment 3 David Lehman 2004-10-13 17:35:03 EDT
This is in response to Comment #1, which I realize is probably in vain.

First, it seems worth noting that vixie-cron3.0.1 doesn't use PAM at all. 

The message you are seeing suggests the nss_ldap library is having
trouble connecting with your LDAP server (otherwise it wouldn't need
to reconnect). A related problem in nss_ldap is that LDAP libraries
generate SIGPIPE when they encounter certain connectivity problems
(I'm no LDAP expert) and nss_ldap doesn't properly ignore SIGPIPE
signals recieved during LDAP operations. So, when nss_ldap recieves
the SIGPIPE instead of ignoring it, the default action is to kill the
caller, which in this case is crond. There is a fix for this in later
upstream sources.

I'm not sure how much coincidence was involved in the resolution of
Andy's problem, and I am not absolutely certain I have the right
answer here. I am currently in the process of verifying the fix I
mention in a similar scenario.

Comment 4 Douglas Furlong 2004-10-16 09:10:32 EDT
Good morning Dave.

Can you point me towards the other ¨scenario¨ you were refering to? As
I am having the same error messages appearing in my log files, and am
also using LDAP.

The errors only appear one a user connects that is not a local users,
but IS listed in the LDAP directory.
Comment 5 David Lehman 2004-10-18 13:12:34 EDT
I've seen ssh sessions getting dropped after repeatedly expanding
~someuser (which was verified as caused by the behavior I describe
above  - https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=134567). 

I'm now seeing a case where running 'crontab -e' as an LDAP user
crashes crond (it is not yet clear that this is caused by nss_ldap).

If you are not seeing applications die your messages simply mean your
LDAP server has connectivity issues: you get those messages after
failed attempts to connect to the LDAP server.
Comment 6 Tomas Mraz 2005-01-04 09:30:56 EST
Fixed in upstream CVS - if the pam_unix module finds passwd entry but
it can't find password for that, it won't log 'user unknown' failure.
This should fix the bug in the most common circumstances.
Comment 7 Terry Griffin 2005-01-05 00:49:02 EST
The problem you describe as solved isn't the problem I reported. In
my scenario there's no passwd entry _at all_ because the user is 
defined entirely in LDAP. In that case pam_unix logs a "user unknown"
error followed by an "authentication failure" error even though the 
user is ultimately authenticated by pam_ldap.

Why do individual PAM modules have to log anything at all (except
maybe for debug mode)? When individual PAM modules in a PAM stack do
logging it leads to useless clutter in the logs files and unintended
consequences like bug #120368. (Since claimed to have been fixed but
I don't know how.) Leave it to the services (imapd etc.) do the
logging after a final authentication pass/fail result has been
returned from the PAM stack.
Comment 8 Tomas Mraz 2005-01-05 04:00:54 EST
Yes it is the problem. Maybe my comment wasn't clear. It will find a
passwd entry not directly from /etc/passwd file but by a
getpwnam/getpwuid call through nss_ldap. Otherwise your authentication
wouldn't work at all.

About your idea that all logging should be done only in debug mode -
feel free to propose it on PAM mailing list pam-list@redhat.com. But I
think that only way how it could be implemented is that you would have
to add a quiet option to all modules and if it would be present it
would disable all logging of the modules. The current default
behaviour shouldn't be changed as too many people depend on it.
Comment 9 jason pay 2006-06-14 05:10:28 EDT
I have implamented AD4UNIX, I am able to login with the AD/LDAP user, quickly 
and without errors in messages. Problem I have is that after I have connected 
with ldap account, when I sudo I get sudo: nss_ldap: reconnecting to LDAP 
server (sleeping 4
and repeats, 4,8,16,32,64 till server is unavailable,
Strange thing is, once the timeouts have finished, I get prompted for the ldap 
password and I am able to sudo.
The group which is being used as the sudo rule is also an LDAP group, so the 
authentication is actually working, but there is a delay.
Any advise would be helpfull.

Comment 10 Tomas Mraz 2006-06-14 05:16:21 EDT
Jason, that is a completely different bug or configuration problem. You can
report it against nss_ldap.

Note You need to log in before you can comment on or make changes to this bug.