Debugging OpenLDAP ACLs

Enable super detailed logging in OpenLDAP. Note that you may need to use “add” instead of “replace” if the attribute doesn’t already exist.

ldapmodify -QY EXTERNAL -H ldapi:/// <<EOF
dn: cn=config
changetype: modify
replace: olcLogLevel
olcLogLevel: any
EOF

To revert back to defaults:

ldapmodify -QY EXTERNAL -H ldapi:/// <<EOF
dn: cn=config
changetype: modify
delete: olcLogLevel
EOF

Sample log file excerpt from an anonymous search with filter:

Jul 13 20:19:14 lemongrab slapd[7292]: conn=1575 op=2 do_search
Jul 13 20:19:14 lemongrab slapd[7292]: >>> dnPrettyNormal: 
Jul 13 20:19:14 lemongrab slapd[7292]: <<< dnPrettyNormal: , 
Jul 13 20:19:14 lemongrab slapd[7292]: SRCH "dc=example,dc=com" 2 0
Jul 13 20:19:14 lemongrab slapd[7292]:     0 0 0
Jul 13 20:19:14 lemongrab slapd[7292]: begin get_filter
Jul 13 20:19:14 lemongrab slapd[7292]: EQUALITY
Jul 13 20:19:14 lemongrab slapd[7292]: >>> dnPretty: 
Jul 13 20:19:14 lemongrab slapd[7292]: <<< dnPretty: 
Jul 13 20:19:14 lemongrab slapd[7292]: >>> dnNormalize: 
Jul 13 20:19:14 lemongrab slapd[7292]: <<< dnNormalize: 
Jul 13 20:19:14 lemongrab slapd[7292]: end get_filter 0
Jul 13 20:19:14 lemongrab slapd[7292]:     filter: (memberOf=cn=administrators,dc=example,dc=com)
Jul 13 20:19:14 lemongrab slapd[7292]:     attrs:
Jul 13 20:19:14 lemongrab slapd[7292]:  givenName
Jul 13 20:19:14 lemongrab slapd[7292]: 
Jul 13 20:19:14 lemongrab slapd[7292]: conn=1575 op=2 SRCH base="dc=example,dc=com" scope=2 deref=0 filter="(memberOf=cn=administrators,dc=example,dc=com)"
Jul 13 20:19:14 lemongrab slapd[7292]: conn=1575 op=2 SRCH attr=givenName
Jul 13 20:19:14 lemongrab slapd[7292]: ==> limits_get: conn=1575 op=2 self="[anonymous]" this="dc=example,dc=com"
Jul 13 20:19:14 lemongrab slapd[7292]: => bdb_search
Jul 13 20:19:14 lemongrab slapd[7292]: bdb_dn2entry("dc=example,dc=com")
Jul 13 20:19:14 lemongrab slapd[7292]: => access_allowed: search access to "dc=example,dc=com" "entry" requested
Jul 13 20:19:14 lemongrab slapd[7292]: => dn: [1] dc=example,dc=com
Jul 13 20:19:14 lemongrab slapd[7292]: => acl_get: [1] matched
Jul 13 20:19:14 lemongrab slapd[7292]: => acl_get: [1] attr entry
Jul 13 20:19:14 lemongrab slapd[7292]: => acl_mask: access to entry "dc=example,dc=com", attr "entry" requested
Jul 13 20:19:14 lemongrab slapd[7292]: => acl_mask: to all values by "", (=0) 
Jul 13 20:19:14 lemongrab slapd[7292]: <= check a_dn_pat: gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
Jul 13 20:19:14 lemongrab slapd[7292]: <= check a_dn_pat: *
Jul 13 20:19:14 lemongrab slapd[7292]: <= acl_mask: [3] applying none(=0) (break)
Jul 13 20:19:14 lemongrab slapd[7292]: <= acl_mask: [3] mask: none(=0)
Jul 13 20:19:14 lemongrab slapd[7292]: => dn: [2] dc=example,dc=com
Jul 13 20:19:14 lemongrab slapd[7292]: => acl_get: [2] matched
Jul 13 20:19:14 lemongrab slapd[7292]: => dn: [3] dc=example,dc=com
Jul 13 20:19:14 lemongrab slapd[7292]: => acl_get: [3] matched
Jul 13 20:19:14 lemongrab slapd[7292]: => acl_get: [3] attr entry
Jul 13 20:19:14 lemongrab slapd[7292]: => acl_mask: access to entry "dc=example,dc=com", attr "entry" requested
Jul 13 20:19:14 lemongrab slapd[7292]: => acl_mask: to all values by "", (none(=0)) 
Jul 13 20:19:14 lemongrab slapd[7292]: <= check a_dn_pat: *
Jul 13 20:19:14 lemongrab slapd[7292]: <= acl_mask: [1] applying read(=rscxd) (stop)
Jul 13 20:19:14 lemongrab slapd[7292]: <= acl_mask: [1] mask: read(=rscxd)
Jul 13 20:19:14 lemongrab slapd[7292]: => slap_access_allowed: search access granted by read(=rscxd)
Jul 13 20:19:14 lemongrab slapd[7292]: => access_allowed: search access granted by read(=rscxd)
Jul 13 20:19:14 lemongrab slapd[7292]: search_candidates: base="dc=example,dc=com" (0x00000001) scope=2
Jul 13 20:19:14 lemongrab slapd[7292]: => bdb_dn2idl("dc=example,dc=com")
Jul 13 20:19:14 lemongrab slapd[7292]: => bdb_filter_candidates
Jul 13 20:19:14 lemongrab slapd[7292]: #011AND
Jul 13 20:19:14 lemongrab slapd[7292]: => bdb_list_candidates 0xa0
Jul 13 20:19:14 lemongrab slapd[7292]: => bdb_filter_candidates
Jul 13 20:19:14 lemongrab slapd[7292]: #011OR
Jul 13 20:19:14 lemongrab slapd[7292]: => bdb_list_candidates 0xa1
Jul 13 20:19:14 lemongrab slapd[7292]: => bdb_filter_candidates
Jul 13 20:19:14 lemongrab slapd[7292]: #011EQUALITY
Jul 13 20:19:14 lemongrab slapd[7292]: => bdb_equality_candidates (objectClass)
Jul 13 20:19:14 lemongrab slapd[7292]: => key_read
Jul 13 20:19:14 lemongrab slapd[7292]: bdb_idl_fetch_key: [b49d1940]
Jul 13 20:19:14 lemongrab slapd[7292]: <= bdb_index_read: failed (-30988)
Jul 13 20:19:14 lemongrab slapd[7292]: <= bdb_equality_candidates: id=0, first=0, last=0
Jul 13 20:19:14 lemongrab slapd[7292]: <= bdb_filter_candidates: id=0 first=0 last=0
Jul 13 20:19:14 lemongrab slapd[7292]: => bdb_filter_candidates