[Date Prev][Date Next] [Chronological] [Thread] [Top]

SASL pass-through fails

Hey all,

I've been using OpenLDAP and Kerberos for central authentication for a while now, but I have a couple programs that can't use GSSAPI directly and I want to setup SASL pass-through authentication to allow those services to use my Kerberos passwords, but I'm having trouble getting saslauthd to work correctly.

I can authentication as myself using GSSAPI without any issue:

jschaeffer@zipmaster07 ~/Downloads $ ldapwhoami
SASL/GSSAPI authentication started
SASL username: jschaeffer@HARMONYWAVE.COM
SASL SSF: 56
SASL data security layer installed.
dn:uid=jschaeffer,ou=end users,ou=people,dc=harmonywave,dc=com

But whenever I run the testsaslauthd command I can't get a successful authentication:

root@baneling:~# testsaslauthd -u jschaeffer@HARMONYWAVE.COM -p <password>
0: NO "authentication failed"

Here are my SASL settings:

root@baneling:~# cat /etc/default/saslauthd | grep -v '^$\|^\s*\#'
START=yes
DESC="SASL Authentication Daemon"
NAME="saslauthd"
MECHANISMS="kerberos5"
MECH_OPTIONS=""
THREADS=5
OPTIONS="-c -m /var/run/saslauthd"

root@baneling:~# cat /etc/ldap/sasl2/slapd.conf
pwcheck_method:    saslauthd
saslauthd_path:    /var/run/saslauthd/mux

I can see my saslauthd socket listening and what I find really odd is that I can see a successful authentication attempt from Kerberos's logs:

root@baneling:~# netstat -a I | grep sasl
unix  2      [ ACC ]     STREAM     LISTENING     25552431 /var/run/saslauthd/mux

I get this immediately after issuing the testsaslauthd command:

Sep 17 13:09:13 immortal krb5kdc[1210](info): AS_REQ (6 etypes {18 17 16 23 25 26}) 10.1.30.18: NEEDED_PREAUTH: jschaeffer@HARMONYWAVE.COM for krbtgt/HARMONYWAVE.COM@HARMONYWAVE.COM, Additional pre-authentication required
Sep 17 13:09:13 immortal krb5kdc[1210](info): AS_REQ (6 etypes {18 17 16 23 25 26}) 10.1.30.18: ISSUE: authtime 1474139353, etypes {rep=18 tkt=18 ses=18}, jschaeffer@HARMONYWAVE.COM for krbtgt/HARMONYWAVE.COM@HARMONYWAVE.COM

You can also see it in the slapd logs:

Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=197 SRCH base="dc=harmonywave,dc=com" scope=2 deref=0 filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=jschaeffer@HARMONYWAVE.COM))"
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=197 SRCH attr=krbprincipalname krbcanonicalname objectclass krbprincipalkey krbmaxrenewableage krbmaxticketlife krbticketflags krbprincipalexpiration krbticketpolicyreference krbUpEnabled krbpwdpolicyreference krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount krbLastSuccessfulAuth krbLastPwdChange krbLastAdminUnlock krbExtraData krbObjectReferences krbAllowedToDelegateTo
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=197 SEARCH RESULT tag=101 err=0 nentries=1 text=
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=198 SRCH base="dc=harmonywave,dc=com" scope=2 deref=0 filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=krbtgt/HARMONYWAVE.COM@HARMONYWAVE.COM))"
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=198 SRCH attr=krbprincipalname krbcanonicalname objectclass krbprincipalkey krbmaxrenewableage krbmaxticketlife krbticketflags krbprincipalexpiration krbticketpolicyreference krbUpEnabled krbpwdpolicyreference krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount krbLastSuccessfulAuth krbLastPwdChange krbLastAdminUnlock krbExtraData krbObjectReferences krbAllowedToDelegateTo
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=198 SEARCH RESULT tag=101 err=0 nentries=1 text=
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=199 SRCH base="cn=default,cn=HARMONYWAVE.COM,cn=krbContainer,dc=harmonywave,dc=com" scope=0 deref=0 filter="(objectClass=krbPwdPolicy)"
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=199 SRCH attr=cn krbmaxpwdlife krbminpwdlife krbpwdmindiffchars krbpwdminlength krbpwdhistorylength krbpwdmaxfailure krbpwdfailurecountinterval krbpwdlockoutduration krbpwdattributes krbpwdmaxlife krbpwdmaxrenewablelife krbpwdallowedkeysalts
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=199 SEARCH RESULT tag=101 err=0 nentries=1 text=
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=200 SRCH base="dc=harmonywave,dc=com" scope=2 deref=0 filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=jschaeffer@HARMONYWAVE.COM))"
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=200 SRCH attr=krbprincipalname krbcanonicalname objectclass krbprincipalkey krbmaxrenewableage krbmaxticketlife krbticketflags krbprincipalexpiration krbticketpolicyreference krbUpEnabled krbpwdpolicyreference krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount krbLastSuccessfulAuth krbLastPwdChange krbLastAdminUnlock krbExtraData krbObjectReferences krbAllowedToDelegateTo
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=200 SEARCH RESULT tag=101 err=0 nentries=1 text=
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=201 SRCH base="dc=harmonywave,dc=com" scope=2 deref=0 filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=krbtgt/HARMONYWAVE.COM@HARMONYWAVE.COM))"
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=201 SRCH attr=krbprincipalname krbcanonicalname objectclass krbprincipalkey krbmaxrenewableage krbmaxticketlife krbticketflags krbprincipalexpiration krbticketpolicyreference krbUpEnabled krbpwdpolicyreference krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount krbLastSuccessfulAuth krbLastPwdChange krbLastAdminUnlock krbExtraData krbObjectReferences krbAllowedToDelegateTo
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=201 SEARCH RESULT tag=101 err=0 nentries=1 text=
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=202 SRCH base="cn=default,cn=HARMONYWAVE.COM,cn=krbContainer,dc=harmonywave,dc=com" scope=0 deref=0 filter="(objectClass=krbPwdPolicy)"
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=202 SRCH attr=cn krbmaxpwdlife krbminpwdlife krbpwdmindiffchars krbpwdminlength krbpwdhistorylength krbpwdmaxfailure krbpwdfailurecountinterval krbpwdlockoutduration krbpwdattributes krbpwdmaxlife krbpwdmaxrenewablelife krbpwdallowedkeysalts
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=202 SEARCH RESULT tag=101 err=0 nentries=1 text=
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=203 SRCH base="cn=default,cn=HARMONYWAVE.COM,cn=krbContainer,dc=harmonywave,dc=com" scope=0 deref=0 filter="(objectClass=krbPwdPolicy)"
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=203 SRCH attr=cn krbmaxpwdlife krbminpwdlife krbpwdmindiffchars krbpwdminlength krbpwdhistorylength krbpwdmaxfailure krbpwdfailurecountinterval krbpwdlockoutduration krbpwdattributes krbpwdmaxlife krbpwdmaxrenewablelife krbpwdallowedkeysalts
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=203 SEARCH RESULT tag=101 err=0 nentries=1 text=
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=204 SRCH base="krbPrincipalName=jschaeffer@HARMONYWAVE.COM,cn=HARMONYWAVE.COM,cn=krbContainer,dc=harmonywave,dc=com" scope=0 deref=0 filter="(objectClass=*)"
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=204 SRCH attr=objectclass
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=204 SEARCH RESULT tag=101 err=0 nentries=1 text=
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=205 MOD dn="krbPrincipalName=jschaeffer@HARMONYWAVE.COM,cn=HARMONYWAVE.COM,cn=krbContainer,dc=harmonywave,dc=com"
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=205 MOD attr=krbLastSuccessfulAuth krbExtraData krbLastAdminUnlock
Sep 17 13:10:27 baneling slapd[2166]: conn=1002 op=205 RESULT tag=103 err=0 text=

When I debug the saslauthd daemon all i get is this:

root@baneling:~# saslauthd -a kerberos5 -m /var/run/saslauthd -n 5 -d
saslauthd[1121] :main            : num_procs  : 5
saslauthd[1121] :main            : mech_option: NULL
saslauthd[1121] :main            : run_path   : /var/run/saslauthd
saslauthd[1121] :main            : auth_mech  : kerberos5
saslauthd[1121] :ipc_init        : using accept lock file: /var/run/saslauthd/mux.accept
saslauthd[1121] :detach_tty      : master pid is: 0
saslauthd[1121] :ipc_init        : listening on socket: /var/run/saslauthd/mux
saslauthd[1121] :main            : using process model
saslauthd[1121] :have_baby       : forked child: 1122
saslauthd[1122] :get_accept_lock : acquired accept lock
saslauthd[1121] :have_baby       : forked child: 1123
saslauthd[1121] :have_baby       : forked child: 1124
saslauthd[1121] :have_baby       : forked child: 1125
saslauthd[1122] :rel_accept_lock : released accept lock
saslauthd[1124] :get_accept_lock : acquired accept lock
saslauthd[1122] :do_auth         : auth failure: [user=jschaeffer@HARMONYWAVE.COM] [service=imap] [realm=] [mech=kerberos5] [reason=saslauthd internal error]

Kinda at a loss at what else I should look at. Any tips would be appreciated.

Thanks,
Joshua Schaeffer