Authentication against LDAP fails if SSL or TLS is used

Authentication against LDAP fails if SSL or TLS is used

am 02.03.2010 13:45:08 von Mxrgus Pxrt

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)

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=ria,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=ria,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=ria,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=RIA,dc=ria,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












------------------------------------------------------------ ---------
The official User-To-User support forum of the Apache HTTP Server Project.
See for more info.
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
" from the digest: users-digest-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org