[SOLVED] OpenLDAP SHA hashed passwords won't work

h.ka · 01-24-2011, 02:42 PM

I have recently installed openldap on a server to use for authentication but I'm unable to get SHA/SSHA password hashes to work. I'm able to authenticate against it when the user have a CRYPT password.

We had an old badly maintained openldap server that SHA worked on so I ran slapcat on that one and built that database on the new openldap server and was able to authenticate with SHA hashed passwords. So I'm quite confident that my slapd.conf works.

I suppose it's something in the ldif file I use to setup the database that is missing but I can't figure out what. It's quite large and I don't really know what parts of it would be relevant. If anyone could give me a pointer I'd really appreciate it.

quanta · 01-26-2011, 11:00 PM

Enable the LDAP log to see what's happen.

h.ka · 01-27-2011, 01:31 PM

What loglevel should I use to get relevant information?

One other thing, SSHA works fine for the root user.

Maybe this could be something?

How it looks when I connect with a user with CRYPT password:

Code:

Jan 27 19:39:56 localhost slapd[2189]: bdb_search: 132 does not match filter
Jan 27 19:39:56 localhost slapd[2189]: send_ldap_result: conn=1000 op=4 p=3
Jan 27 19:39:56 localhost slapd[2189]: send_ldap_result: err=0 matched="" text=""
Jan 27 19:39:56 localhost slapd[2189]: send_ldap_response: msgid=5 tag=101 err=0
Jan 27 19:39:56 localhost slapd[2189]: conn=1000 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jan 27 19:39:56 localhost slapd[2189]: daemon: activity on 1 descriptor
Jan 27 19:39:56 localhost slapd[2189]: daemon: activity on:
Jan 27 19:39:56 localhost slapd[2189]: 
Jan 27 19:39:56 localhost slapd[2189]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jan 27 19:39:56 localhost slapd[2189]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jan 27 19:39:56 localhost slapd[2189]: daemon: activity on 1 descriptor
Jan 27 19:39:56 localhost slapd[2189]: daemon: activity on:
Jan 27 19:39:56 localhost slapd[2189]:  13r
Jan 27 19:39:56 localhost slapd[2189]: 
Jan 27 19:39:56 localhost slapd[2189]: daemon: read active on 13
Jan 27 19:39:56 localhost slapd[2189]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jan 27 19:39:56 localhost slapd[2189]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jan 27 19:39:56 localhost slapd[2189]: connection_get(13)
Jan 27 19:39:56 localhost slapd[2189]: connection_get(13): got connid=1000
Jan 27 19:39:56 localhost slapd[2189]: connection_read(13): checking for input on id=1000
Jan 27 19:39:56 localhost slapd[2189]: op tag 0x63, time 1296153596
Jan 27 19:39:56 localhost slapd[2189]: conn=1000 op=5 do_search
Jan 27 19:39:56 localhost slapd[2189]: >>> dnPrettyNormal: <dc=domain,dc=se>
Jan 27 19:39:56 localhost slapd[2189]: <<< dnPrettyNormal: <dc=domain,dc=se>, <dc=domain,dc=se>
Jan 27 19:39:56 localhost slapd[2189]: SRCH "dc=domain,dc=se" 2 0
Jan 27 19:39:56 localhost slapd[2189]:     1 0 0
Jan 27 19:39:56 localhost slapd[2189]: begin get_filter
Jan 27 19:39:56 localhost slapd[2189]: AND
Jan 27 19:39:56 localhost slapd[2189]: begin get_filter_list
Jan 27 19:39:56 localhost slapd[2189]: begin get_filter
Jan 27 19:39:56 localhost slapd[2189]: EQUALITY
Jan 27 19:39:56 localhost slapd[2189]: end get_filter 0
Jan 27 19:39:56 localhost slapd[2189]: begin get_filter
Jan 27 19:39:56 localhost slapd[2189]: EQUALITY
Jan 27 19:39:56 localhost slapd[2189]: end get_filter 0
Jan 27 19:39:56 localhost slapd[2189]: end get_filter_list
Jan 27 19:39:56 localhost slapd[2189]: end get_filter 0
Jan 27 19:39:56 localhost slapd[2189]:     filter: (&(objectClass=posixAccount)(uid=name))
Jan 27 19:39:56 localhost slapd[2189]:     attrs:
Jan 27 19:39:56 localhost slapd[2189]:  uid
Jan 27 19:39:56 localhost slapd[2189]:  userPassword
Jan 27 19:39:56 localhost slapd[2189]:  uidNumber
Jan 27 19:39:56 localhost slapd[2189]:  gidNumber
Jan 27 19:39:56 localhost slapd[2189]:  cn
Jan 27 19:39:56 localhost slapd[2189]:  homeDirectory
Jan 27 19:39:56 localhost slapd[2189]:  loginShell
Jan 27 19:39:56 localhost slapd[2189]:  gecos
Jan 27 19:39:56 localhost slapd[2189]:  description
Jan 27 19:39:56 localhost slapd[2189]:  objectClass

How the log looks when I connect with a user with SSHA password:

Code:

Jan 27 19:34:09 localhost slapd[2150]: bdb_search: 132 does not match filter
Jan 27 19:34:09 localhost slapd[2150]: send_ldap_result: conn=1000 op=4 p=3
Jan 27 19:34:09 localhost slapd[2150]: send_ldap_result: err=0 matched="" text=""
Jan 27 19:34:09 localhost slapd[2150]: send_ldap_response: msgid=5 tag=101 err=0
Jan 27 19:34:09 localhost slapd[2150]: conn=1000 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jan 27 19:34:11 localhost slapd[2150]: daemon: activity on 1 descriptor
Jan 27 19:34:11 localhost slapd[2150]: daemon: activity on:
Jan 27 19:34:11 localhost slapd[2150]:  15r
Jan 27 19:34:11 localhost slapd[2150]: 
Jan 27 19:34:11 localhost slapd[2150]: daemon: read active on 15
Jan 27 19:34:11 localhost slapd[2150]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jan 27 19:34:11 localhost slapd[2150]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jan 27 19:34:11 localhost slapd[2150]: connection_get(15)
Jan 27 19:34:11 localhost slapd[2150]: connection_get(15): got connid=1001
Jan 27 19:34:11 localhost slapd[2150]: connection_read(15): checking for input on id=1001
Jan 27 19:34:11 localhost slapd[2150]: op tag 0x42, time 1296153251
Jan 27 19:34:11 localhost slapd[2150]: ber_get_next on fd 15 failed errno=0 (Success)
Jan 27 19:34:11 localhost slapd[2150]: connection_read(15): input error=-2 id=1001, closing.
Jan 27 19:34:11 localhost slapd[2150]: connection_closing: readying conn=1001 sd=15 for close
Jan 27 19:34:11 localhost slapd[2150]: connection_close: deferring conn=1001 sd=15
Jan 27 19:34:11 localhost slapd[2150]: conn=1001 op=4 do_unbind
Jan 27 19:34:11 localhost slapd[2150]: conn=1001 op=4 UNBIND
Jan 27 19:34:11 localhost slapd[2150]: connection_resched: attempting closing conn=1001 sd=15
Jan 27 19:34:11 localhost slapd[2150]: connection_close: conn=1001 sd=15
Jan 27 19:34:11 localhost slapd[2150]: daemon: removing 15
Jan 27 19:34:11 localhost slapd[2150]: conn=1001 fd=15 closed
Jan 27 19:34:11 localhost slapd[2150]: daemon: activity on 1 descriptor
Jan 27 19:34:11 localhost slapd[2150]: daemon: activity on:
Jan 27 19:34:11 localhost slapd[2150]: 
Jan 27 19:34:11 localhost slapd[2150]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jan 27 19:34:11 localhost slapd[2150]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jan 27 19:34:11 localhost slapd[2150]: daemon: activity on 1 descriptor
Jan 27 19:34:11 localhost slapd[2150]: daemon: activity on:
Jan 27 19:34:11 localhost slapd[2150]:  13r
Jan 27 19:34:11 localhost slapd[2150]: 
Jan 27 19:34:11 localhost slapd[2150]: daemon: read active on 13
Jan 27 19:34:11 localhost slapd[2150]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jan 27 19:34:11 localhost slapd[2150]: daemon: epoll: listen=8 active_threads=0 tvp=NULL
Jan 27 19:34:11 localhost slapd[2150]: connection_get(13)
Jan 27 19:34:11 localhost slapd[2150]: connection_get(13): got connid=1000
Jan 27 19:34:11 localhost slapd[2150]: connection_read(13): checking for input on id=1000
Jan 27 19:34:11 localhost slapd[2150]: ber_get_next on fd 13 failed errno=0 (Success)
Jan 27 19:34:11 localhost slapd[2150]: connection_read(13): input error=-2 id=1000, closing.
Jan 27 19:34:11 localhost slapd[2150]: connection_closing: readying conn=1000 sd=13 for close
Jan 27 19:34:11 localhost slapd[2150]: connection_close: conn=1000 sd=13
Jan 27 19:34:11 localhost slapd[2150]: daemon: removing 13
Jan 27 19:34:11 localhost slapd[2150]: conn=1000 fd=13 closed (connection lost)
Jan 27 19:34:11 localhost slapd[2150]: daemon: activity on 1 descriptor
Jan 27 19:34:11 localhost slapd[2150]: daemon: activity on:
Jan 27 19:34:11 localhost slapd[2150]: 
Jan 27 19:34:11 localhost slapd[2150]: daemon: epoll: listen=7 active_threads=0 tvp=NULL
Jan 27 19:34:11 localhost slapd[2150]: daemon: epoll: listen=8 active_threads=0 tvp=NULL

quanta · 01-27-2011, 11:41 PM

Where did you get the above logs? Try to enable the LDAP log by adding the below into the /etc/syslog.conf:

Code:

local4.*						/var/log/ldap.log

h.ka · 01-28-2011, 03:42 AM

I've got syslog-ng confed to put the log in /var/log/ldap.log. I got the above logs from setting log level to -1 in slapd.conf and then trying to log in with one user with crypt hashed password and one user with ssha hashed password. I restarted slapd between the two tries and grabbed the two log files. Then I diffed them against each other and the two extracts above show where they start to differ.

If it is possible to get a logfile that is easier to read with an other loglevel and if I should filter it in some way do tell. I'm quite lost as to what to look for in it. The entire log when I run with loglevel -1 is ~10k rows for the failed try with ssha and ~40k rows for the crypt try.

h.ka · 02-27-2011, 06:27 PM

I made some changes to my cyrus-sasl installation and all of a sudden ssha started working. Not quite sure what did it, but it is solved now anyway.