Guest User!

You are not Sophos Staff.

[v7.360] Problems authenticating with OpenLDAP Server

Hi All,

I've got an OpenLDAP server running on SUSE Enterprise Linux 10 server which I'd like to authenticate against.

I've got into Users -> Authentication -> LDAP, and filled in all the correct details for my server, and using the Test button, I get the response "Authentication test passed. No groups found for this user". (Do there need to be any groups associated with the user to ASG's purposes?)

I've got automatic user creation turned on for everything under the global settings for Authentication.  Yet when I try to use the same login details that I did with the testing button above to login to the user portal, I'm refused with the generic message "Invalid username/password, or access denied by a policy".

Looking at the Authentication Daemon logs, there's not enough info to give me any clues:

[SIZE="1"][FONT="Courier New"]2008:12:08-21:48:40 (none) aua[15080]: id="3006" severity="info" sys="System" sub="auth" name="checking if benh is enabled"
2008:12:08-21:48:40 (none) aua[15080]: id="3006" severity="info" sys="System" sub="auth" name="user is enabled. Calling do_auth()"
2008:12:08-21:48:40 (none) aua[15080]: id="3005" severity="warn" sys="System" sub="auth" name="Authentication failed" srcip="10.0.10.20" user="benh" caller="portal" reason="DENIED"
[/FONT][/SIZE]

I turned on heavy logging on the LDAP server side as well and this is what I found:

2 attachments - one is the LDAP server logs when the "Test Login" button is used successfully on the LDAP Settings screen, the other are the server logs generated when a portal login is attempted with the same user account - both BIND successfully!  I'm at a loss why portal is coming back with a login result of "DENIED".

There's no local user with clashing email or login details.

Does anything jump out to you guys as to why the same results from the LDAP server (successful search and BIND) would give a positive test result, but fail to create an automatic user for the User Portal web pages? Or is there extra places I can be looking for clues as to why LDAP authentication is failing? (tried with multiple LDAP users)....

Cheers,

Ben
Parents
  • A few more log entries from ASG that show the difference between testing the user and trying to login to the user portal with the same credentials:

    [SIZE="1"][FONT="Courier New"]2008:12:08-22:02:34 (none) aua[15702]: id="3006" severity="info" sys="System" sub="auth" name="Spawned child for authentication test"
    2008:12:08-22:02:34 (none) aua[15702]: id="3006" severity="info" sys="System" sub="auth" name="Bind test request: ldap"
    2008:12:08-22:02:34 (none) aua[15702]: id="3006" severity="info" sys="System" sub="auth" name="Bind test successfull. Method: ldap"
    2008:12:08-22:02:45 (none) aua[15704]: id="3006" severity="info" sys="System" sub="auth" name="Spawned child for authentication test"
    2008:12:08-22:02:45 (none) aua[15704]: id="3006" severity="info" sys="System" sub="auth" name="Authentication test request: m:ldap, f:none, u:benh, ip:0.0.0.0"
    2008:12:08-22:02:45 (none) aua[15704]: id="3006" severity="info" sys="System" sub="auth" name="Testing method ldap"
    2008:12:08-22:02:45 (none) aua[15704]: id="3006" severity="info" sys="System" sub="auth" name="Authentication test successfull"
    2008:12:08-22:07:56 (none) aua[15882]: id="3006" severity="info" sys="System" sub="auth" name="Spawned child for authentication test"
    2008:12:08-22:07:56 (none) aua[15882]: id="3006" severity="info" sys="System" sub="auth" name="Bind test request: ldap"
    2008:12:08-22:07:56 (none) aua[15882]: id="3006" severity="info" sys="System" sub="auth" name="Bind test successfull. Method: ldap"
    2008:12:08-22:08:03 (none) aua[15883]: id="3006" severity="info" sys="System" sub="auth" name="Spawned child for authentication test"
    2008:12:08-22:08:03 (none) aua[15883]: id="3006" severity="info" sys="System" sub="auth" name="Authentication test request: m:ldap, f:none, u:benh, ip:0.0.0.0"
    2008:12:08-22:08:03 (none) aua[15883]: id="3006" severity="info" sys="System" sub="auth" name="Testing method ldap"
    2008:12:08-22:08:03 (none) aua[15883]: id="3006" severity="info" sys="System" sub="auth" name="Authentication test successfull"
    2008:12:08-22:11:09 (none) aua[15994]: id="3006" severity="info" sys="System" sub="auth" name="checking if benh is enabled"
    2008:12:08-22:11:09 (none) aua[15994]: id="3006" severity="info" sys="System" sub="auth" name="user is enabled. Calling do_auth()"
    2008:12:08-22:11:09 (none) aua[15994]: id="3005" severity="warn" sys="System" sub="auth" name="Authentication failed" srcip="10.0.10.20" user="benh" caller="portal" reason="DENIED"
    2008:12:08-22:33:05 (none) aua[16886]: id="3006" severity="info" sys="System" sub="auth" name="checking if testuser is enabled"
    2008:12:08-22:33:05 (none) aua[16886]: id="3006" severity="info" sys="System" sub="auth" name="user is enabled. Calling do_auth()"
    2008:12:08-22:33:05 (none) aua[16886]: id="3005" severity="warn" sys="System" sub="auth" name="Authentication failed" srcip="10.0.10.20" user="testuser" caller="portal" reason="DENIED"
    2008:12:08-22:33:43 (none) aua[16897]: id="3006" severity="info" sys="System" sub="auth" name="checking if testuser is enabled"
    2008:12:08-22:33:43 (none) aua[16897]: id="3006" severity="info" sys="System" sub="auth" name="user is enabled. Calling do_auth()"
    2008:12:08-22:33:43 (none) aua[16897]: id="3005" severity="warn" sys="System" sub="auth" name="Authentication failed" srcip="10.0.10.20" user="testuser" caller="portal" reason="DENIED"
    2008:12:08-22:34:09 (none) aua[16931]: id="3006" severity="info" sys="System" sub="auth" name="checking if admin is enabled"
    2008:12:08-22:34:09 (none) aua[16931]: id="3006" severity="info" sys="System" sub="auth" name="user is enabled. Calling do_auth()"
    2008:12:08-22:34:09 (none) aua[16931]: id="3004" severity="info" sys="System" sub="auth" name="Authentication successful" srcip="10.0.10.20" user="admin" caller="webadmin" engine="local"
    [/FONT][/SIZE]
Reply
  • A few more log entries from ASG that show the difference between testing the user and trying to login to the user portal with the same credentials:

    [SIZE="1"][FONT="Courier New"]2008:12:08-22:02:34 (none) aua[15702]: id="3006" severity="info" sys="System" sub="auth" name="Spawned child for authentication test"
    2008:12:08-22:02:34 (none) aua[15702]: id="3006" severity="info" sys="System" sub="auth" name="Bind test request: ldap"
    2008:12:08-22:02:34 (none) aua[15702]: id="3006" severity="info" sys="System" sub="auth" name="Bind test successfull. Method: ldap"
    2008:12:08-22:02:45 (none) aua[15704]: id="3006" severity="info" sys="System" sub="auth" name="Spawned child for authentication test"
    2008:12:08-22:02:45 (none) aua[15704]: id="3006" severity="info" sys="System" sub="auth" name="Authentication test request: m:ldap, f:none, u:benh, ip:0.0.0.0"
    2008:12:08-22:02:45 (none) aua[15704]: id="3006" severity="info" sys="System" sub="auth" name="Testing method ldap"
    2008:12:08-22:02:45 (none) aua[15704]: id="3006" severity="info" sys="System" sub="auth" name="Authentication test successfull"
    2008:12:08-22:07:56 (none) aua[15882]: id="3006" severity="info" sys="System" sub="auth" name="Spawned child for authentication test"
    2008:12:08-22:07:56 (none) aua[15882]: id="3006" severity="info" sys="System" sub="auth" name="Bind test request: ldap"
    2008:12:08-22:07:56 (none) aua[15882]: id="3006" severity="info" sys="System" sub="auth" name="Bind test successfull. Method: ldap"
    2008:12:08-22:08:03 (none) aua[15883]: id="3006" severity="info" sys="System" sub="auth" name="Spawned child for authentication test"
    2008:12:08-22:08:03 (none) aua[15883]: id="3006" severity="info" sys="System" sub="auth" name="Authentication test request: m:ldap, f:none, u:benh, ip:0.0.0.0"
    2008:12:08-22:08:03 (none) aua[15883]: id="3006" severity="info" sys="System" sub="auth" name="Testing method ldap"
    2008:12:08-22:08:03 (none) aua[15883]: id="3006" severity="info" sys="System" sub="auth" name="Authentication test successfull"
    2008:12:08-22:11:09 (none) aua[15994]: id="3006" severity="info" sys="System" sub="auth" name="checking if benh is enabled"
    2008:12:08-22:11:09 (none) aua[15994]: id="3006" severity="info" sys="System" sub="auth" name="user is enabled. Calling do_auth()"
    2008:12:08-22:11:09 (none) aua[15994]: id="3005" severity="warn" sys="System" sub="auth" name="Authentication failed" srcip="10.0.10.20" user="benh" caller="portal" reason="DENIED"
    2008:12:08-22:33:05 (none) aua[16886]: id="3006" severity="info" sys="System" sub="auth" name="checking if testuser is enabled"
    2008:12:08-22:33:05 (none) aua[16886]: id="3006" severity="info" sys="System" sub="auth" name="user is enabled. Calling do_auth()"
    2008:12:08-22:33:05 (none) aua[16886]: id="3005" severity="warn" sys="System" sub="auth" name="Authentication failed" srcip="10.0.10.20" user="testuser" caller="portal" reason="DENIED"
    2008:12:08-22:33:43 (none) aua[16897]: id="3006" severity="info" sys="System" sub="auth" name="checking if testuser is enabled"
    2008:12:08-22:33:43 (none) aua[16897]: id="3006" severity="info" sys="System" sub="auth" name="user is enabled. Calling do_auth()"
    2008:12:08-22:33:43 (none) aua[16897]: id="3005" severity="warn" sys="System" sub="auth" name="Authentication failed" srcip="10.0.10.20" user="testuser" caller="portal" reason="DENIED"
    2008:12:08-22:34:09 (none) aua[16931]: id="3006" severity="info" sys="System" sub="auth" name="checking if admin is enabled"
    2008:12:08-22:34:09 (none) aua[16931]: id="3006" severity="info" sys="System" sub="auth" name="user is enabled. Calling do_auth()"
    2008:12:08-22:34:09 (none) aua[16931]: id="3004" severity="info" sys="System" sub="auth" name="Authentication successful" srcip="10.0.10.20" user="admin" caller="webadmin" engine="local"
    [/FONT][/SIZE]
Children
No Data