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

Problems Enabling Authentication using Cyrus SASL



Hi all

    I tried to enable SASL authentication using Cyrus SASL  to both connect to openldap server and to authenticate users as this document explains:
        http://www.arschkrebs.de/slides/surviving_cyrus_sasl-handout.pdf
    I studied openldap and Cyrus SASL documentations with no success
    
    when I try to test my configuration with ldapwhoami I get this error: (with a second terminal running this cyrus sasl command: saslauthd -d -V -a ldap -r -O /etc/saslauthd.conf)
    
    firewall:~ # ldapwhoami -U proxyuser -X u:test -Y digest-md5
    SASL/DIGEST-MD5 authentication started
    Please enter your password:
    ldap_sasl_interactive_bind_s: Invalid credentials (49)
            additional info: SASL(-13): user not found: no secret in database

I enabled full login (please see OPENLDAP LOGS below) and I realized that the 'proxyuser' is handled perfectly according to my configuration, but when trying to authenticate then 'test' user gets the error show above (OPENLDAP LOGS lines 138 to 141).
I also realized that there is an strange error on line 123 (OPENLDAP LOGS):

    Nov 11 17:19:10 firewall slapd[11011]: slap_ap_lookup: str2ad(cmusaslsecretDIGEST-MD5): attribute type undefined

I will appreciate any hints to fix this problem

thanks in advance

Below are all software used, configuration files, data stored on ldap server and the openldap logs

            SOFTWARE USED
Opensuse 11.3
openldap2-client-2.4.21-9.1.i586
openldap2-2.4.21-9.1.i586
cyrus-sasl-gssapi-2.1.23-11.1.i586
cyrus-sasl-ldap-auxprop-2.1.23-11.2.i586
cyrus-sasl-saslauthd-2.1.23-11.2.i586
cyrus-sasl-2.1.23-11.1.i586
cyrus-sasl-plain-2.1.23-11.1.i586
cyrus-sasl-digestmd5-2.1.23-11.1.i586
cyrus-sasl-crammd5-2.1.23-11.1.i586

            CONFIGURATION FILES
    /etc/saslauthd.conf
ldap_servers: ldap://127.0.0.1/ ldap://192.168.1.2/
ldap_search_base: ou=people,dc=plainjoe,dc=org
ldap_filter: (userPrincipalName=%u)
ldap_bind_dn: uid=proxyuser,ou=people,dc=plainjoe,dc=org
ldap_password: secret

    /etc/openldap/slapd.conf
include         /etc/openldap/schema/core.schema
include         /etc/openldap/schema/cosine.schema
include         /etc/openldap/schema/inetorgperson.schema
include         /etc/openldap/schema/rfc2307bis.schema
include         /etc/openldap/schema/yast.schema
loglevel        -1
pidfile         /var/run/slapd/slapd.pid
argsfile        /var/run/slapd/slapd.args
access to attrs=userPassword,userPKCS12
        by self write
        by anonymous auth
        by dn.base="uid=proxyuser,ou=people,dc=plainjoe,dc=org" manage
        by users read
        by * none
access to *
        by * read
database        bdb
suffix          "dc=plainjoe,dc=org"
checkpoint      1024    5
cachesize       10000
rootdn          "cn=Manager,dc=plainjoe,dc=org"
# the password is: secret
rootpw  {MD5}Xr4ilOzQ4PCOq3aQ0qbuaQ==
directory       /var/lib/ldap
index   objectClass         eq
index   cn,sn,mail          eq,sub
index   departmentNumber    eq
password-hash {CLEARTEXT}
authz-regexp
   uid=([^,]*),cn=[^,]*,cn=auth
   uid=$1,ou=people,dc=plainjoe,dc=org
authz-policy to
sasl-authz-policy to
sasl-regexp
   uid=(.*),cn=DIGEST-MD5,cn=auth
   uid=$1,ou=people,dc=plainjoe,dc=org
sasl-auxprops slapd
sasl-host localhost

    /etc/sasl2/slapd.conf
log_level: 7
mech_list: DIGEST-MD5
pwcheck_method: saslauthd
saslauthd_path: /var/run/sasl2/mux
#pwcheck_method: auxprop
#auxprop_plugin: slapd
#   auxprop_plugin: ldapdb
ldapdb_uri: ldap://localhost
ldapdb_id: proxyuser
ldapdb_pw: secret
ldapdb_mech: DIGEST-MD5

            DATA STORED ON LDAP SERVER
firewall:~/openldap # slapcat
bdb_monitor_db_open: monitoring disabled; configure monitor database to enable
dn: dc=plainjoe,dc=org
dc: plainjoe
objectClass: dcObject
objectClass: organizationalUnit
ou: PlainJoe Dot Org
structuralObjectClass: organizationalUnit
entryUUID: 0335be26-7c73-102f-8bd2-599020d843b8
creatorsName: cn=Manager,dc=plainjoe,dc=org
createTimestamp: 20101104152159Z
entryCSN: 20101104152159.733766Z#000000#000#000000
modifiersName: cn=Manager,dc=plainjoe,dc=org
modifyTimestamp: 20101104152159Z

dn: ou=people,dc=plainjoe,dc=org
ou: people
objectClass: organizationalUnit
structuralObjectClass: organizationalUnit
entryUUID: 033e9352-7c73-102f-8bd3-599020d843b8
creatorsName: cn=Manager,dc=plainjoe,dc=org
createTimestamp: 20101104152159Z
entryCSN: 20101105231448.878588Z#000000#000#000000
modifiersName: cn=Manager,dc=plainjoe,dc=org
modifyTimestamp: 20101105231448Z

dn: cn=Gerald W. Carter,ou=people,dc=plainjoe,dc=org
cn: Gerald W. Carter
sn: Carter
mail: jerry@plainjoe.org
labeledURI: http://www.plainjoe.org/
roomNumber: 1234 Dudley Hall
departmentNumber: Engineering
telephoneNumber: 222-555-2345
pager: 222-555-6789
mobile: 222-555-1011
objectClass: inetOrgPerson
structuralObjectClass: inetOrgPerson
entryUUID: 6d8be49c-7c7a-102f-8bd4-599020d843b8
creatorsName: cn=Manager,dc=plainjoe,dc=org
createTimestamp: 20101104161504Z
entryCSN: 20101104162307.381290Z#000000#000#000000
modifiersName: cn=Manager,dc=plainjoe,dc=org
modifyTimestamp: 20101104162307Z

dn: cn=Gerry Carter,ou=people,dc=plainjoe,dc=org
sn: Carter
mail: carter@nowhere.net
objectClass: inetOrgPerson
structuralObjectClass: inetOrgPerson
entryUUID: 6da59928-7c7a-102f-8bd5-599020d843b8
creatorsName: cn=Manager,dc=plainjoe,dc=org
createTimestamp: 20101104161504Z
labeledURI: http://www.plainjoe.org/~jerry/
telephoneNumber: 234-555-6789 begin_of_the_skype_highlighting            234-555-6789      end_of_the_skype_highlighting
cn: Gerry Carter
userPassword:: Z2Vycnk=
entryCSN: 20101104212850.439996Z#000000#000#000000
modifiersName: cn=Manager,dc=plainjoe,dc=org
modifyTimestamp: 20101104212850Z

dn: uid=fernandito,ou=people,dc=plainjoe,dc=org
uid: fernandito
cn: Fernandito Torrez
gidNumber: 10000
uidNumber: 10000
homeDirectory: /dev/null
objectClass: account
objectClass: posixAccount
userPassword:: e21kNX1kZDAyYzdjMjIzMjc1OTg3NGUxYzIwNTU4NzAxN2JlZA==
structuralObjectClass: account
entryUUID: 44afffcc-7f90-102f-8d26-bf24473f4596
creatorsName: cn=Manager,dc=plainjoe,dc=org
createTimestamp: 20101108142858Z
entryCSN: 20101108142858.480384Z#000000#000#000000
modifiersName: cn=Manager,dc=plainjoe,dc=org
modifyTimestamp: 20101108142858Z

dn: uid=test,ou=people,dc=plainjoe,dc=org
uid: test
cn: testeo principal
gidNumber: 10001
uidNumber: 10001
homeDirectory: /dev/null
objectClass: account
objectClass: posixAccount
structuralObjectClass: account
entryUUID: b3b5d6f4-8133-102f-9b9b-294e4b3fed35
creatorsName: cn=Manager,dc=plainjoe,dc=org
createTimestamp: 20101110163123Z
userPassword:: e01ENX1DWTlyelVZaDAzUEszazZESmllMDlnPT0=
entryCSN: 20101110190152.065873Z#000000#000#000000
modifiersName: cn=Manager,dc=plainjoe,dc=org
modifyTimestamp: 20101110190152Z

dn: uid=proxyuser,ou=people,dc=plainjoe,dc=org
uid: proxyuser
cn: proxyuser
gidNumber: 10002
uidNumber: 10002
homeDirectory: /dev/null
objectClass: account
objectClass: posixAccount
userPassword:: e01ENX1YcjRpbE96UTRQQ09xM2FRMHFidWFRPT0=
authzTo: dn.regex:uniqueIdentifier=(.*),ou=people,dc=plainjoe,dc=org
structuralObjectClass: account
entryUUID: 85999ef4-8214-102f-9c1d-411cc739a95b
creatorsName: cn=Manager,dc=plainjoe,dc=org
createTimestamp: 20101111192043Z
entryCSN: 20101111192043.279474Z#000000#000#000000
modifiersName: cn=Manager,dc=plainjoe,dc=org
modifyTimestamp: 20101111192043Z


            OPENLDAP LOGS
1    Nov 11 17:19:07 firewall slapd[11011]: daemon: activity on 1 descriptor
2    Nov 11 17:19:07 firewall slapd[11011]: daemon: activity on:
3    Nov 11 17:19:07 firewall slapd[11011]:
4    Nov 11 17:19:07 firewall slapd[11011]: slap_listener_activate(8):
5    Nov 11 17:19:07 firewall slapd[11011]: daemon: epoll: listen=7 active_threads=0 tvp=zero
6    Nov 11 17:19:07 firewall slapd[11011]: daemon: epoll: listen=8 busy
7    Nov 11 17:19:07 firewall slapd[11011]: >>> slap_listener(ldap://)
8    Nov 11 17:19:07 firewall slapd[11011]: daemon: listen=8, new connection on 12
9    Nov 11 17:19:07 firewall slapd[11011]: daemon: added 12r (active) listener=(nil)
10    Nov 11 17:19:07 firewall slapd[11011]: conn=1001 fd=12 ACCEPT from IP=[::1]:47665 (IP=[::]:389)
11    Nov 11 17:19:07 firewall slapd[11011]: daemon: activity on 1 descriptor
12    Nov 11 17:19:07 firewall slapd[11011]: daemon: activity on:
13    Nov 11 17:19:07 firewall slapd[11011]:
14    Nov 11 17:19:07 firewall slapd[11011]: daemon: epoll: listen=7 active_threads=0 tvp=zero
15    Nov 11 17:19:07 firewall slapd[11011]: daemon: epoll: listen=8 active_threads=0 tvp=zero
16    Nov 11 17:19:07 firewall slapd[11011]: daemon: activity on 1 descriptor
17    Nov 11 17:19:07 firewall slapd[11011]: daemon: activity on:
18    Nov 11 17:19:07 firewall slapd[11011]:  12r
19    Nov 11 17:19:07 firewall slapd[11011]:
20    Nov 11 17:19:07 firewall slapd[11011]: daemon: read active on 12
21    Nov 11 17:19:07 firewall slapd[11011]: daemon: epoll: listen=7 active_threads=0 tvp=zero
22    Nov 11 17:19:07 firewall slapd[11011]: daemon: epoll: listen=8 active_threads=0 tvp=zero
23    Nov 11 17:19:07 firewall slapd[11011]: connection_get(12)
24    Nov 11 17:19:07 firewall slapd[11011]: connection_get(12): got connid=1001
25    Nov 11 17:19:07 firewall slapd[11011]: connection_read(12): checking for input on id=1001
26    Nov 11 17:19:07 firewall slapd[11011]: op tag 0x60, time 1289510347
27    Nov 11 17:19:07 firewall slapd[11011]: conn=1001 op=0 do_bind
28    Nov 11 17:19:07 firewall slapd[11011]: >>> dnPrettyNormal: <>
29    Nov 11 17:19:07 firewall slapd[11011]: <<< dnPrettyNormal: <>, <>
30    Nov 11 17:19:07 firewall slapd[11011]: conn=1001 op=0 BIND dn="" method=163
31    Nov 11 17:19:07 firewall slapd[11011]: do_bind: dn () SASL mech DIGEST-MD5
32    Nov 11 17:19:07 firewall slapd[11011]: ==> sasl_bind: dn="" mech=DIGEST-MD5 datalen=0
33    Nov 11 17:19:07 firewall slapd[11011]: SASL [conn=1001] Debug: DIGEST-MD5 server step 1
34    Nov 11 17:19:07 firewall slapd[11011]: send_ldap_sasl: err=14 len=182
35    Nov 11 17:19:07 firewall slapd[11011]: send_ldap_response: msgid=1 tag=97 err=14
36    Nov 11 17:19:07 firewall slapd[11011]: conn=1001 op=0 RESULT tag=97 err=14 text=SASL(0): successful result:
37    Nov 11 17:19:07 firewall slapd[11011]: <== slap_sasl_bind: rc=14
38    Nov 11 17:19:07 firewall slapd[11011]: daemon: activity on 1 descriptor
39    Nov 11 17:19:07 firewall slapd[11011]: daemon: activity on:
40    Nov 11 17:19:07 firewall slapd[11011]:
41    Nov 11 17:19:07 firewall slapd[11011]: daemon: epoll: listen=7 active_threads=0 tvp=zero
42    Nov 11 17:19:07 firewall slapd[11011]: daemon: epoll: listen=8 active_threads=0 tvp=zero
43    Nov 11 17:19:07 firewall ldapwhoami: DIGEST-MD5 client step 2
44    Nov 11 17:19:10 firewall ldapwhoami: DIGEST-MD5 client step 2
45    Nov 11 17:19:10 firewall slapd[11011]: daemon: activity on 1 descriptor
46    Nov 11 17:19:10 firewall slapd[11011]: daemon: activity on:
47    Nov 11 17:19:10 firewall slapd[11011]:  12r
48    Nov 11 17:19:10 firewall slapd[11011]:
49    Nov 11 17:19:10 firewall slapd[11011]: daemon: read active on 12
50    Nov 11 17:19:10 firewall slapd[11011]: daemon: epoll: listen=7 active_threads=0 tvp=zero
51    Nov 11 17:19:10 firewall slapd[11011]: daemon: epoll: listen=8 active_threads=0 tvp=zero
52    Nov 11 17:19:10 firewall slapd[11011]: connection_get(12)
53    Nov 11 17:19:10 firewall slapd[11011]: connection_get(12): got connid=1001
54    Nov 11 17:19:10 firewall slapd[11011]: connection_read(12): checking for input on id=1001
55    Nov 11 17:19:10 firewall slapd[11011]: op tag 0x60, time 1289510350
56    Nov 11 17:19:10 firewall slapd[11011]: conn=1001 op=1 do_bind
57    Nov 11 17:19:10 firewall slapd[11011]: >>> dnPrettyNormal: <>
58    Nov 11 17:19:10 firewall slapd[11011]: <<< dnPrettyNormal: <>, <>
59    Nov 11 17:19:10 firewall slapd[11011]: conn=1001 op=1 BIND dn="" method=163
60    Nov 11 17:19:10 firewall slapd[11011]: do_bind: dn () SASL mech DIGEST-MD5
61    Nov 11 17:19:10 firewall slapd[11011]: ==> sasl_bind: dn="" mech=<continuing> datalen=296
62    Nov 11 17:19:10 firewall slapd[11011]: SASL [conn=1001] Debug: DIGEST-MD5 server step 2
63    Nov 11 17:19:10 firewall slapd[11011]: SASL Canonicalize [conn=1001]: authcid="proxyuser"
64    Nov 11 17:19:10 firewall slapd[11011]: slap_sasl_getdn: conn 1001 id=proxyuser [len=9]
65    Nov 11 17:19:10 firewall slapd[11011]: slap_sasl_getdn: u:id converted to uid=proxyuser,cn=DIGEST-MD5,cn=auth
66    Nov 11 17:19:10 firewall slapd[11011]: >>> dnNormalize: <uid=proxyuser,cn=DIGEST-MD5,cn=auth>
67    Nov 11 17:19:10 firewall slapd[11011]: <<< dnNormalize: <uid=proxyuser,cn=digest-md5,cn=auth>
68    Nov 11 17:19:10 firewall slapd[11011]: ==>slap_sasl2dn: converting SASL name uid=proxyuser,cn=digest-md5,cn=auth to a DN
69    Nov 11 17:19:10 firewall slapd[11011]: [rw] authid: "uid=proxyuser,cn=digest-md5,cn=auth" -> "uid=proxyuser,ou=people,dc=plainjoe,dc=org"
70    Nov 11 17:19:10 firewall slapd[11011]: slap_parseURI: parsing uid=proxyuser,ou=people,dc=plainjoe,dc=org
71    Nov 11 17:19:10 firewall slapd[11011]: >>> dnNormalize: <uid=proxyuser,ou=people,dc=plainjoe,dc=org>
72    Nov 11 17:19:10 firewall slapd[11011]: <<< dnNormalize: <uid=proxyuser,ou=people,dc=plainjoe,dc=org>
73    Nov 11 17:19:10 firewall slapd[11011]: <==slap_sasl2dn: Converted SASL name to uid=proxyuser,ou=people,dc=plainjoe,dc=org
74    Nov 11 17:19:10 firewall slapd[11011]: slap_sasl_getdn: dn:id converted to uid=proxyuser,ou=people,dc=plainjoe,dc=org
75    Nov 11 17:19:10 firewall slapd[11011]: SASL Canonicalize [conn=1001]: slapAuthcDN="uid=proxyuser,ou=people,dc=plainjoe,dc=org"
76    Nov 11 17:19:10 firewall slapd[11011]: => bdb_search
77    Nov 11 17:19:10 firewall slapd[11011]: bdb_dn2entry("uid=proxyuser,ou=people,dc=plainjoe,dc=org")
78    Nov 11 17:19:10 firewall slapd[11011]: => bdb_dn2id("dc=plainjoe,dc=org")
79    Nov 11 17:19:10 firewall slapd[11011]: daemon: activity on 1 descriptor
80    Nov 11 17:19:10 firewall slapd[11011]: daemon: activity on:
81    Nov 11 17:19:10 firewall slapd[11011]:
82    Nov 11 17:19:10 firewall slapd[11011]: daemon: epoll: listen=7 active_threads=0 tvp=zero
83    Nov 11 17:19:10 firewall slapd[11011]: daemon: epoll: listen=8 active_threads=0 tvp=zero
84    Nov 11 17:19:10 firewall slapd[11011]: <= bdb_dn2id: got id=0x1
85    Nov 11 17:19:10 firewall slapd[11011]: => bdb_dn2id("ou=people,dc=plainjoe,dc=org")
86    Nov 11 17:19:10 firewall slapd[11011]: <= bdb_dn2id: got id=0x2
87    Nov 11 17:19:10 firewall slapd[11011]: => bdb_dn2id("uid=proxyuser,ou=people,dc=plainjoe,dc=org")
88    Nov 11 17:19:10 firewall slapd[11011]: <= bdb_dn2id: got id=0x10
89    Nov 11 17:19:10 firewall slapd[11011]: entry_decode: "uid=proxyuser,ou=people,dc=plainjoe,dc=org"
90    Nov 11 17:19:10 firewall slapd[11011]: <= entry_decode(uid=proxyuser,ou=people,dc=plainjoe,dc=org)
91    Nov 11 17:19:10 firewall slapd[11011]: => access_allowed: auth access to "uid=proxyuser,ou=people,dc=plainjoe,dc=org" "entry" requested
92    Nov 11 17:19:10 firewall slapd[11011]: => acl_get: [2] attr entry
93    Nov 11 17:19:10 firewall slapd[11011]: => acl_mask: access to entry "uid=proxyuser,ou=people,dc=plainjoe,dc=org", attr "entry" requested
94    Nov 11 17:19:10 firewall slapd[11011]: => acl_mask: to all values by "", (=0)
95    Nov 11 17:19:10 firewall slapd[11011]: <= check a_dn_pat: *
96    Nov 11 17:19:10 firewall slapd[11011]: <= acl_mask: [1] applying read(=rscxd) (stop)
97    Nov 11 17:19:10 firewall slapd[11011]: <= acl_mask: [1] mask: read(=rscxd)
98    Nov 11 17:19:10 firewall slapd[11011]: => slap_access_allowed: auth access granted by read(=rscxd)
99    Nov 11 17:19:10 firewall slapd[11011]: => access_allowed: auth access granted by read(=rscxd)
100    Nov 11 17:19:10 firewall slapd[11011]: base_candidates: base: "uid=proxyuser,ou=people,dc=plainjoe,dc=org" (0x00000010)
101    Nov 11 17:19:10 firewall slapd[11011]: => test_filter
102    Nov 11 17:19:10 firewall slapd[11011]:     PRESENT
103    Nov 11 17:19:10 firewall slapd[11011]: => access_allowed: auth access to "uid=proxyuser,ou=people,dc=plainjoe,dc=org" "objectClass" requested
104    Nov 11 17:19:10 firewall slapd[11011]: => acl_get: [2] attr objectClass
105    Nov 11 17:19:10 firewall slapd[11011]: => acl_mask: access to entry "uid=proxyuser,ou=people,dc=plainjoe,dc=org", attr "objectClass" requested
106    Nov 11 17:19:10 firewall slapd[11011]: => acl_mask: to all values by "", (=0)
107    Nov 11 17:19:10 firewall slapd[11011]: <= check a_dn_pat: *
108    Nov 11 17:19:10 firewall slapd[11011]: <= acl_mask: [1] applying read(=rscxd) (stop)
109    Nov 11 17:19:10 firewall slapd[11011]: <= acl_mask: [1] mask: read(=rscxd)
110    Nov 11 17:19:10 firewall slapd[11011]: => slap_access_allowed: auth access granted by read(=rscxd)
111    Nov 11 17:19:10 firewall slapd[11011]: => access_allowed: auth access granted by read(=rscxd)
112    Nov 11 17:19:10 firewall slapd[11011]: <= test_filter 6
113    Nov 11 17:19:10 firewall slapd[11011]: => access_allowed: auth access to "uid=proxyuser,ou=people,dc=plainjoe,dc=org" "userPassword" requested
114    Nov 11 17:19:10 firewall slapd[11011]: => acl_get: [1] attr userPassword
115    Nov 11 17:19:10 firewall slapd[11011]: => acl_mask: access to entry "uid=proxyuser,ou=people,dc=plainjoe,dc=org", attr "userPassword" requested
116    Nov 11 17:19:10 firewall slapd[11011]: => acl_mask: to all values by "", (=0)
117    Nov 11 17:19:10 firewall slapd[11011]: <= check a_dn_pat: self
118    Nov 11 17:19:10 firewall slapd[11011]: <= check a_dn_pat: anonymous
119    Nov 11 17:19:10 firewall slapd[11011]: <= acl_mask: [2] applying auth(=xd) (stop)
120    Nov 11 17:19:10 firewall slapd[11011]: <= acl_mask: [2] mask: auth(=xd)
121    Nov 11 17:19:10 firewall slapd[11011]: => slap_access_allowed: auth access granted by auth(=xd)
122    Nov 11 17:19:10 firewall slapd[11011]: => access_allowed: auth access granted by auth(=xd)
123    Nov 11 17:19:10 firewall slapd[11011]: slap_ap_lookup: str2ad(cmusaslsecretDIGEST-MD5): attribute type undefined
124    Nov 11 17:19:10 firewall slapd[11011]: send_ldap_result: conn=1001 op=1 p=3
125    Nov 11 17:19:10 firewall slapd[11011]: send_ldap_result: err=0 matched="" text=""
126    Nov 11 17:19:10 firewall slapd[11011]: SASL Canonicalize [conn=1001]: authzid="u:test"
127    Nov 11 17:19:10 firewall slapd[11011]: slap_sasl_getdn: conn 1001 id=u:test [len=6]
128    Nov 11 17:19:10 firewall slapd[11011]: slap_sasl_getdn: u:id converted to uid=test,cn=DIGEST-MD5,cn=auth
129    Nov 11 17:19:10 firewall slapd[11011]: >>> dnNormalize: <uid=test,cn=DIGEST-MD5,cn=auth>
130    Nov 11 17:19:10 firewall slapd[11011]: <<< dnNormalize: <uid=test,cn=digest-md5,cn=auth>
131    Nov 11 17:19:10 firewall slapd[11011]: ==>slap_sasl2dn: converting SASL name uid=test,cn=digest-md5,cn=auth to a DN
132    Nov 11 17:19:10 firewall slapd[11011]: [rw] authid: "uid=test,cn=digest-md5,cn=auth" -> "uid=test,ou=people,dc=plainjoe,dc=org"
133    Nov 11 17:19:10 firewall slapd[11011]: slap_parseURI: parsing uid=test,ou=people,dc=plainjoe,dc=org
134    Nov 11 17:19:10 firewall slapd[11011]: >>> dnNormalize: <uid=test,ou=people,dc=plainjoe,dc=org>
135    Nov 11 17:19:10 firewall slapd[11011]: <<< dnNormalize: <uid=test,ou=people,dc=plainjoe,dc=org>
136    Nov 11 17:19:10 firewall slapd[11011]: <==slap_sasl2dn: Converted SASL name to uid=test,ou=people,dc=plainjoe,dc=org
137    Nov 11 17:19:10 firewall slapd[11011]: slap_sasl_getdn: dn:id converted to uid=test,ou=people,dc=plainjoe,dc=org
138    Nov 11 17:19:10 firewall slapd[11011]: SASL Canonicalize [conn=1001]: slapAuthzDN="uid=test,ou=people,dc=plainjoe,dc=org"
139    Nov 11 17:19:10 firewall slapd[11011]: SASL [conn=1001] Failure: no secret in database
140    Nov 11 17:19:10 firewall slapd[11011]: send_ldap_result: conn=1001 op=1 p=3
141    Nov 11 17:19:10 firewall slapd[11011]: send_ldap_result: err=49 matched="" text="SASL(-13): user not found: no secret in database"
142    Nov 11 17:19:10 firewall slapd[11011]: send_ldap_response: msgid=2 tag=97 err=49
143    Nov 11 17:19:10 firewall slapd[11011]: daemon: activity on 1 descriptor
144    Nov 11 17:19:10 firewall slapd[11011]: daemon: activity on:
145    Nov 11 17:19:10 firewall slapd[11011]:  12r
146    Nov 11 17:19:10 firewall slapd[11011]:
147    Nov 11 17:19:10 firewall slapd[11011]: daemon: read active on 12
148    Nov 11 17:19:10 firewall slapd[11011]: daemon: epoll: listen=7 active_threads=0 tvp=zero
149    Nov 11 17:19:10 firewall slapd[11011]: daemon: epoll: listen=8 active_threads=0 tvp=zero
150    Nov 11 17:19:10 firewall slapd[11011]: connection_get(12)
151    Nov 11 17:19:10 firewall slapd[11011]: connection_get(12): got connid=1001
152    Nov 11 17:19:10 firewall slapd[11011]: connection_read(12): checking for input on id=1001
153    Nov 11 17:19:10 firewall slapd[11011]: ber_get_next on fd 12 failed errno=0 (Success)
154    Nov 11 17:19:10 firewall slapd[11011]: connection_read(12): input error=-2 id=1001, closing.
155    Nov 11 17:19:10 firewall slapd[11011]: connection_closing: readying conn=1001 sd=12 for close
156    Nov 11 17:19:10 firewall slapd[11011]: connection_close: deferring conn=1001 sd=12
157    Nov 11 17:19:10 firewall slapd[11011]: daemon: activity on 1 descriptor
158    Nov 11 17:19:10 firewall slapd[11011]: daemon: activity on:
159    Nov 11 17:19:10 firewall slapd[11011]:
160    Nov 11 17:19:10 firewall slapd[11011]: daemon: epoll: listen=7 active_threads=0 tvp=zero
161    Nov 11 17:19:10 firewall slapd[11011]: daemon: epoll: listen=8 active_threads=0 tvp=zero
162    Nov 11 17:19:10 firewall slapd[11011]: conn=1001 op=1 RESULT tag=97 err=49 text=SASL(-13): user not found: no secret in database
163    Nov 11 17:19:10 firewall slapd[11011]: <== slap_sasl_bind: rc=49
164    Nov 11 17:19:10 firewall slapd[11011]: connection_resched: attempting closing conn=1001 sd=12
165    Nov 11 17:19:10 firewall slapd[11011]: connection_close: conn=1001 sd=12
166    Nov 11 17:19:10 firewall slapd[11011]: daemon: removing 12
167    Nov 11 17:19:10 firewall slapd[11011]: conn=1001 fd=12 closed (connection lost)