Authentication against LDAP fails if SSL or TLS is used
Hello,
I have following problem:
Precondition:
- Some Location is protected with authentication against LDAP
- Apache is configured to connect LDAP server over SSL (LDAPS on port 686)
Steps:
- Open https://server/protected_url
- Input username of existing user (must be defined in LDAP base) and
WRONG PASSWORD
Result:
- After entering wrong password (sometimes you have to do it more than
once), Internal Error 500 is displayed in browser
- For all the clients server is going to show Internal Error 500 error
(you have to restart Apache to solve the problem)
Notes:
- Problem does not appear, if using 389 without crypt
- If using 389 with STARTTLS problem exists
Has anyone delt with similar problem?
Detailed information:
Installed packages:
ii apache2 2.2.9-10+lenny6 Apache
HTTP Server metapackage
ii apache2-mpm-worker 2.2.9-10+lenny6 Apache
HTTP Server - high speed threaded model
ii apache2-utils 2.2.9-10+lenny6 utility
programs for webservers
ii apache2.2-common 2.2.9-10+lenny6 Apache
HTTP Server common files
ii libapache2-svn 1.5.1dfsg1-4
Subversion server modules for Apache
ii libgnutls26 2.4.2-6+lenny2 the GNU
TLS library - runtime library
ii libneon27-gnutls 0.28.2-6.1 An HTTP
and WebDAV client library (GnuTLS enabled)
ii ldap-utils 2.4.11-1+lenny1
OpenLDAP utilities
ii libldap-2.4-2 2.4.11-1+lenny1
OpenLDAP libraries
Log:
IN CASE USER DOES NOT EXIST:
Ldap:
Mar 2 14:28:52 ldap.server slapd[26521]: conn=0 fd=16 ACCEPT from
IP=http.server:36293 (IP=0.0.0.0:636)
Mar 2 14:28:52 ldap.server slapd[26521]: conn=0 fd=16 TLS established
tls_ssf=128 ssf=128
Mar 2 14:28:52 ldap.server slapd[26521]: conn=0 op=0 BIND dn="" method=128
Mar 2 14:28:52 ldap.server slapd[26521]: conn=0 op=0 RESULT tag=97
err=0 text=
Mar 2 14:28:52 ldap.server slapd[26521]: conn=0 op=1 SRCH
base="dc=cia,dc=ee" scope=0 deref=0 filter="(objectClass=*)"
Mar 2 14:28:52 ldap.server slapd[26521]: conn=0 op=1 SEARCH RESULT
tag=101 err=0 nentries=1 text=
Mar 2 14:28:52 ldap.server slapd[26521]: conn=0 op=2 UNBIND
Mar 2 14:28:52 ldap.server slapd[26521]: conn=0 fd=16 closed
Mar 2 14:28:59 ldap.server slapd[26521]: conn=1 fd=16 ACCEPT from
IP=http.server:34546 (IP=0.0.0.0:636)
Mar 2 14:28:59 ldap.server slapd[26521]: conn=1 fd=16 TLS established
tls_ssf=128 ssf=128
Mar 2 14:28:59 ldap.server slapd[26521]: conn=1 op=0 BIND dn="" method=128
Mar 2 14:28:59 ldap.server slapd[26521]: conn=1 op=0 RESULT tag=97
err=0 text=
Mar 2 14:28:59 ldap.server slapd[26521]: conn=1 op=1 SRCH
base="dc=cia,dc=ee" scope=2 deref=3
filter="(&(objectClass=*)(uid=userdoesnotexist))"
Mar 2 14:28:59 ldap.server slapd[26521]: conn=1 op=1 SRCH attr=uid
Mar 2 14:28:59 ldap.server slapd[26521]: <= bdb_equality_candidates:
(uid) not indexed
Mar 2 14:28:59 ldap.server slapd[26521]: conn=1 op=1 SEARCH RESULT
tag=101 err=0 nentries=0 text=
Apache:
==> /srv/log/apache2/http.server-access.log <==
client.address - - [02/Mar/2010:14:28:52 +0200] "GET /test/ HTTP/1.1"
401 290 "-" "Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9.1.7)
Gecko/20100106 Ubuntu/9.10 (karmic) Firefox/3.5.7"
client.address - userdoesnotexist [02/Mar/2010:14:29:00 +0200] "GET
/test/ HTTP/1.1" 401 290 "-" "Mozilla/5.0 (X11; U; Linux i686; en-US;
rv:1.9.1.7) Gecko/20100106 Ubuntu/9.10 (karmic) Firefox/3.5.7"
==> /srv/log/apache2/http.server-error.log <==
[Tue Mar 02 14:29:00 2010] [warn] [client client.address] [12246]
auth_ldap authenticate: user userdoesnotexist authentication failed; URI
/test/ [User not found][No such object]
[Tue Mar 02 14:29:00 2010] [error] [client client.address] user
userdoesnotexist not found: /test/
IN CASE USER EXISTS:
Ldap:
ar 2 14:29:20 ldap.server slapd[26521]: conn=16 fd=18 ACCEPT from
IP=http.server:34547 (IP=0.0.0.0:636)
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 op=0 BIND dn="" method=128
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 op=0 RESULT tag=97
err=0 text=
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 op=1 SRCH
base="dc=cia,dc=ee" scope=2 deref=3
filter="(&(objectClass=*)(uid=mxrguspxrt))"
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 op=1 SRCH attr=uid
Mar 2 14:29:20 ldap.server slapd[26521]: <= bdb_equality_candidates:
(uid) not indexed
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 op=1 SEARCH RESULT
tag=101 err=0 nentries=1 text=
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 op=2 BIND
dn="cn=Margus Pärt,ou=people,ou=Infrastruktuur,ou=cia,dc=cia,dc=ee"
method=128
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 op=2 RESULT tag=97
err=49 text=
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 op=3 UNBIND
Mar 2 14:29:20 ldap.server slapd[26521]: conn=16 fd=18 closed
Mar 2 14:29:27 ldap.server slapd[26521]: conn=17 fd=18 ACCEPT from
IP=http.server:34548 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=17 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=17 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=18 fd=18 ACCEPT from
IP=http.server:34549 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=18 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=18 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=19 fd=18 ACCEPT from
IP=http.server:34550 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=19 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=19 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=20 fd=18 ACCEPT from
IP=http.server:34551 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=20 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=20 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=21 fd=18 ACCEPT from
IP=http.server:34552 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=21 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=21 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=22 fd=18 ACCEPT from
IP=http.server:34553 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=22 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=22 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=23 fd=18 ACCEPT from
IP=http.server:34554 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=23 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=23 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=24 fd=18 ACCEPT from
IP=http.server:34555 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=24 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=24 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=25 fd=18 ACCEPT from
IP=http.server:34556 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=25 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=25 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=26 fd=18 ACCEPT from
IP=http.server:34557 (IP=0.0.0.0:636)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=26 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:27 ldap.server slapd[26521]: conn=26 fd=18 closed
(connection lost)
Mar 2 14:29:27 ldap.server slapd[26521]: conn=27 fd=18 ACCEPT from
IP=http.server:34558 (IP=0.0.0.0:636)
Mar 2 14:29:28 ldap.server slapd[26521]: conn=27 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:28 ldap.server slapd[26521]: conn=27 fd=18 closed
(connection lost)
Mar 2 14:29:28 ldap.server slapd[26521]: conn=28 fd=18 ACCEPT from
IP=http.server:34559 (IP=0.0.0.0:636)
Mar 2 14:29:28 ldap.server slapd[26521]: conn=28 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:28 ldap.server slapd[26521]: conn=28 fd=18 closed
(connection lost)
Mar 2 14:29:28 ldap.server slapd[26521]: conn=29 fd=18 ACCEPT from
IP=http.server:34560 (IP=0.0.0.0:636)
Mar 2 14:29:28 ldap.server slapd[26521]: conn=29 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:28 ldap.server slapd[26521]: conn=29 fd=18 closed
(connection lost)
Mar 2 14:29:28 ldap.server slapd[26521]: conn=30 fd=18 ACCEPT from
IP=http.server:34561 (IP=0.0.0.0:636)
Mar 2 14:29:28 ldap.server slapd[26521]: conn=30 fd=18 TLS established
tls_ssf=128 ssf=128
Mar 2 14:29:28 ldap.server slapd[26521]: conn=30 fd=18 closed
(connection lost)
Apache:
First time:
==> /srv/log/apache2/http.server-access.log <==
client.address - mxrguspxrt [02/Mar/2010:14:29:21 +0200] "GET /test/
HTTP/1.1" 401 290 "-" "Mozilla/5.0 (X11; U; Linux i686; en-US;
rv:1.9.1.7) Gecko/20100106 Ubuntu/9.10 (karmic) Firefox/3.5.7"
==> /srv/log/apache2/http.server-error.log <==
[Tue Mar 02 14:29:21 2010] [warn] [client client.address] [12251]
auth_ldap authenticate: user mxrguspxrt authentication failed; URI
/test/ [ldap_simple_bind_s() to check user credentials failed][Invalid
credentials]
[Tue Mar 02 14:29:21 2010] [error] [client client.address] user
mxrguspxrt: authentication failure for "/test/": Password Mismatch
Second time:
==> /srv/log/apache2/http.server-access.log <==
client.address - mxrguspxrt [02/Mar/2010:14:29:28 +0200] "GET /test/
HTTP/1.1" 500 341 "-" "Mozilla/5.0 (X11; U; Linux i686; en-US;
rv:1.9.1.7) Gecko/20100106 Ubuntu/9.10 (karmic) Firefox/3.5.7"
==> /srv/log/apache2/http.server-error.log <==
[Tue Mar 02 14:29:29 2010] [warn] [client client.address] [12251]
auth_ldap authenticate: user mxrguspxrt authentication failed; URI
/test/ [LDAP: ldap_simple_bind_s() failed][Can't contact LDAP server]
^C
Best regards,
Margus
Reply to: