Bug 742368

Summary:	Sometimes the plugin reconnects anonymously to ldap
Product:	Red Hat Enterprise Linux 6	Reporter:	Simo Sorce <ssorce>
Component:	bind-dyndb-ldap	Assignee:	Adam Tkac <atkac>
Status:	CLOSED ERRATA	QA Contact:	IDM QE LIST <seceng-idm-qe-list>
Severity:	urgent	Docs Contact:
Priority:	urgent
Version:	6.1	CC:	dpal, jgalipea, mgregg, ovasik, syeghiay
Target Milestone:	rc
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2011-12-06 17:57:12 UTC	Type:	---
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	747120

Description Simo Sorce 2011-09-29 20:42:23 UTC

bind-dyndb-ldap can be configured to use SASL/GSSAPI authentication to connect to the Directory.

Apparently though it doesn;t always perform authentication. Sometimes the plugin reconnects to LDAP (after the LDAP server has been restarted) w/o performing any bind and therefore implicitly connecting anonymously.

When IPA is configured to disallow anonymous binds, all requests from the plugin fail and the DNS server returns server fail errors.

Comment 3 Jenny Severance 2011-09-29 21:11:04 UTC

Can you please add steps to reproduce this issue

Comment 4 Adam Tkac 2011-09-30 09:19:15 UTC

(In reply to comment #0)
> bind-dyndb-ldap can be configured to use SASL/GSSAPI authentication to connect
> to the Directory.
> 
> Apparently though it doesn;t always perform authentication. Sometimes the
> plugin reconnects to LDAP (after the LDAP server has been restarted) w/o
> performing any bind and therefore implicitly connecting anonymously.
> 
> When IPA is configured to disallow anonymous binds, all requests from the
> plugin fail and the DNS server returns server fail errors.

Would it be possible to attach /var/log/messages when this happens, please? Thanks in advance!

Comment 5 Simo Sorce 2011-09-30 13:01:55 UTC

Relevant part of the log:

Sep 29 16:26:41 dev1 named[1134]: connection to the LDAP server was lost
Sep 29 16:26:41 dev1 named[1134]: bind to LDAP server failed: Can't contact LDAP server
Sep 29 16:26:55 dev1 dbus: [system] Activating service name='org.freedesktop.PackageKit' (using servicehelper)
Sep 29 16:26:55 dev1 dbus: [system] Successfully activated service 'org.freedesktop.PackageKit'
Sep 29 16:27:11 dev1 named[1134]: bind to LDAP server failed: Can't contact LDAP server
Sep 29 16:27:41 dev1 named[1134]: bind to LDAP server failed: Can't contact LDAP server
Sep 29 16:28:11 dev1 named[1134]: bind to LDAP server failed: Can't contact LDAP server
Sep 29 16:29:11 dev1 named[1134]: bind to LDAP server failed: Can't contact LDAP server
Sep 29 16:30:41 dev1 named[1134]: bind to LDAP server failed: Can't contact LDAP server
Sep 29 16:31:41 dev1 named[1134]: bind to LDAP server failed: Can't contact LDAP server
Sep 29 16:32:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:33:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:33:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:34:04 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:34:04 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:34:05 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:34:05 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:34:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:34:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:35:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:35:13 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:35:13 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:35:16 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:35:16 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:35:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:36:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:36:14 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:36:14 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:36:15 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:36:15 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:36:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:37:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:37:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:38:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:38:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:39:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:39:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:39:45 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:39:45 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:40:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:40:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:41:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:41:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:42:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:42:41 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:42:54 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:42:54 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:42:54 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:42:54 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:43:10 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:43:11 dev1 named[1134]: LDAP error: Inappropriate authentication
Sep 29 16:43:33 dev1 named[1134]: received control channel command 'stop'
Sep 29 16:43:33 dev1 named[1134]: shutting down: flushing changes
Sep 29 16:43:33 dev1 named[1134]: stopping command channel on 127.0.0.1#953
Sep 29 16:43:33 dev1 named[1134]: stopping command channel on ::1#953
Sep 29 16:43:33 dev1 named[1134]: no longer listening on ::#53
Sep 29 16:43:33 dev1 named[1134]: no longer listening on 127.0.0.1#53
Sep 29 16:43:33 dev1 named[1134]: no longer listening on 192.168.122.26#53
Sep 29 16:43:33 dev1 named[1134]: exiting
Sep 29 16:43:39 dev1 named[3173]: starting BIND 9.8.1-RedHat-9.8.1-1.fc15 -u named

Comment 6 Simo Sorce 2011-09-30 13:05:31 UTC

Here also find the related access log for dirsrv.

As you can see the plugin connects to the ldapi socket, but then it doesn't even attempt a BIND operation. It starts to do searches immediately w/o any bind, resulting in those searches being done anonymously (and anonymous searches were disallowed on this installation so they all fail with err=48).

[29/Sep/2011:16:32:40 -0400] conn=2 fd=64 slot=64 connection from local to /var/run/slapd-IPA-SSIMO-ORG.socket
[29/Sep/2011:16:32:40 -0400] conn=2 op=0 SRCH dn="cn=dns,dc=ipa,dc=ssimo,dc=org" authzid="(null)", anonymous search not allowed
[29/Sep/2011:16:32:40 -0400] conn=2 op=0 RESULT err=48 tag=101 nentries=0 etime=0
[..]
[29/Sep/2011:16:33:10 -0400] conn=2 op=1 SRCH dn="cn=dns,dc=ipa,dc=ssimo,dc=org" authzid="(null)", anonymous search not allowed
[29/Sep/2011:16:33:10 -0400] conn=2 op=1 RESULT err=48 tag=101 nentries=0 etime=0

Comment 7 Jenny Severance 2011-09-30 13:09:12 UTC

Sometimes the
plugin reconnects to LDAP (after the LDAP server has been restarted)

When is sometimes?  Still need steps to reproduce

Comment 8 Simo Sorce 2011-09-30 13:23:45 UTC

It is still unclear.
It happened to me twice already, but it doesn't happen every time I restart dirsrv, so I do not yet have a solid way to reproduce it at will.

Comment 9 Jenny Severance 2011-09-30 13:33:16 UTC

okay, hopefully we can figure that out!

Comment 10 Adam Tkac 2011-10-05 11:19:16 UTC

There is code in the plugin which downgrades authentication method in case that strong auth method fails. I will remove this code and I'm sure this will fix this bug.

Comment 12 Adam Tkac 2011-10-05 11:53:02 UTC

http://git.fedorahosted.org/git?p=bind-dyndb-ldap.git;a=commit;h=31ac3da8d2341d9e43f5928eefa5cd1dd38b1272 should fix this issue. Backport to RHEL-6 is pretty simple.

Comment 13 Jenny Severance 2011-10-05 12:16:58 UTC

Adam, since you have a fix know ... please add steps to verify/reproduce this issue.  thanks!

Comment 14 Adam Tkac 2011-10-06 10:07:53 UTC

After more inspection we must also include this change:

http://git.fedorahosted.org/git?p=bind-dyndb-ldap.git;a=commit;h=41d21f43da799f7a93e1a2f7d87d643b60a85501

Steps to reproduce:

1. Create following ldif file:

[root@ipa ~]# cat anon.ldif 
dn: cn=config
changetype: modify
replace: nsslapd-allow-anonymous-access
nsslapd-allow-anonymous-access: off

2. run `ldapmodify -x -D "cn=directory manager" -W -f anon.ldif`
<enter DS manager passwd>

3. start or restart named service

4. stop dirsrv service

5. perform lookup for name which is stored in the zone handled by bind-dyndb-ldap (can be nonexistant name)

6. you should see error like:
06-Oct-2011 11:54:41.436 bind to LDAP server failed: Can't contact LDAP server

7. start the dirsrv service

8. ask again for the name

Now older version fails with the "Inappropriate authentication" error, the new version should connect successfully.

Comment 22 Michael Gregg 2011-11-08 18:45:27 UTC

Verified against:
bind-dyndb-ldap-0.2.0-7.el6.x86_64
ipa-server-2.1.3-8.el6.x86_64

Comment 23 errata-xmlrpc 2011-12-06 17:57:12 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2011-1715.html