Hi,
I'm setting up a new instance of openldap, and I'm running into error
(80) when trying to add new certificates.
I've checked for the usual suspects:
- certs in PEM format
- file permissions along the path OK
I'm using Symas' CentOS 7 repo: slapd 2.4.50 (Apr 28 2020 21:18:35)
I've enabled debugging on the server (logs attached), but can't get
anything out of it.
Any pointers are appreciated.
Regards,
Sami
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on 1 descriptor
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on:
Jul 8 14:45:08 ds slapd[1934]:
Jul 8 14:45:08 ds slapd[1934]: slap_listener_activate(7):
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=7 busy
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=8 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=9 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: >>> slap_listener(ldapi:///)
Jul 8 14:45:08 ds slapd[1934]: daemon: accept() = 11
Jul 8 14:45:08 ds slapd[1934]: daemon: listen=7, new connection on 11
Jul 8 14:45:08 ds slapd[1934]: daemon: added 11r (active) listener=(nil)
Jul 8 14:45:08 ds slapd[1934]: conn=1000 fd=11 ACCEPT from PATH=/var/run/ldapi
(PATH=/var/run/ldapi)
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on 2 descriptors
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on:
Jul 8 14:45:08 ds slapd[1934]: 11r
Jul 8 14:45:08 ds slapd[1934]:
Jul 8 14:45:08 ds slapd[1934]: daemon: read active on 11
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=7 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=8 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=9 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: connection_get(11)
Jul 8 14:45:08 ds slapd[1934]: connection_get(11): got connid=1000
Jul 8 14:45:08 ds slapd[1934]: connection_read(11): checking for input on
id=1000
Jul 8 14:45:08 ds slapd[1934]: op tag 0x60, time 1594215908
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=0 do_bind
Jul 8 14:45:08 ds slapd[1934]: >>> dnPrettyNormal: <>
Jul 8 14:45:08 ds slapd[1934]: <<< dnPrettyNormal: <>, <>
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=0 BIND dn="" method=163
Jul 8 14:45:08 ds slapd[1934]: do_bind: dn () SASL mech EXTERNAL
Jul 8 14:45:08 ds slapd[1934]: ==> sasl_bind: dn="" mech=EXTERNAL datalen=0
Jul 8 14:45:08 ds slapd[1934]: SASL Canonicalize [conn=1000]:
authcid="gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth"
Jul 8 14:45:08 ds slapd[1934]: slap_sasl_getdn: conn 1000
id=gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth [len=55]
Jul 8 14:45:08 ds slapd[1934]: ==>slap_sasl2dn: converting SASL name
gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth to a DN
Jul 8 14:45:08 ds slapd[1934]: <==slap_sasl2dn: Converted SASL name to
<nothing>
Jul 8 14:45:08 ds slapd[1934]: SASL Canonicalize [conn=1000]:
slapAuthcDN="gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth"
Jul 8 14:45:08 ds slapd[1934]: SASL proxy authorize [conn=1000]:
authcid="gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth"
authzid="gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth"
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=0 BIND
authcid="gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth"
authzid="gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth"
Jul 8 14:45:08 ds slapd[1934]: SASL Authorize [conn=1000]: proxy
authorization allowed authzDN=""
Jul 8 14:45:08 ds slapd[1934]: send_ldap_sasl: err=0 len=-1
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=0 BIND
dn="gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth" mech=EXTERNAL
sasl_ssf=0 ssf=71
Jul 8 14:45:08 ds slapd[1934]: do_bind: SASL/EXTERNAL bind:
dn="gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth" sasl_ssf=0
Jul 8 14:45:08 ds slapd[1934]: send_ldap_response: msgid=1 tag=97 err=0
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=0 RESULT tag=97 err=0 text=
Jul 8 14:45:08 ds slapd[1934]: <== slap_sasl_bind: rc=0
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on 1 descriptor
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on:
Jul 8 14:45:08 ds slapd[1934]:
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=7 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=8 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=9 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on 1 descriptor
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on:
Jul 8 14:45:08 ds slapd[1934]: 11r
Jul 8 14:45:08 ds slapd[1934]:
Jul 8 14:45:08 ds slapd[1934]: daemon: read active on 11
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=7 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=8 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=9 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: connection_get(11)
Jul 8 14:45:08 ds slapd[1934]: connection_get(11): got connid=1000
Jul 8 14:45:08 ds slapd[1934]: connection_read(11): checking for input on
id=1000
Jul 8 14:45:08 ds slapd[1934]: op tag 0x66, time 1594215908
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=1 do_modify
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=1 do_modify: dn (cn=config)
Jul 8 14:45:08 ds slapd[1934]: >>> dnPrettyNormal: <cn=config>
Jul 8 14:45:08 ds slapd[1934]: <<< dnPrettyNormal: <cn=config>, <cn=config>
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=1 modifications:
Jul 8 14:45:08 ds slapd[1934]: #011replace: olcTLSCACertificateFile
Jul 8 14:45:08 ds slapd[1934]: #011#011one value, length 45
Jul 8 14:45:08 ds slapd[1934]: #011replace: olcTLSCertificateKeyFile
Jul 8 14:45:08 ds slapd[1934]: #011#011one value, length 38
Jul 8 14:45:08 ds slapd[1934]: #011replace: olcTLSCertificateFile
Jul 8 14:45:08 ds slapd[1934]: #011#011one value, length 43
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=1 MOD dn="cn=config"
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=1 MOD attr=olcTLSCACertificateFile
olcTLSCertificateKeyFile olcTLSCertificateFile
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: result not in cache
(olcTLSCACertificateFile)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: delete access to "cn=config"
"olcTLSCACertificateFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_get: [1] attr olcTLSCACertificateFile
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: access to entry "cn=config", attr
"olcTLSCACertificateFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: to all values by
"gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth", (=0)
Jul 8 14:45:08 ds slapd[1934]: <= check a_dn_pat:
gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] applying manage(=mwrscxd)
(stop)
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] mask: manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => slap_access_allowed: delete access granted
by manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: delete access granted by
manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: result not in cache
(olcTLSCACertificateFile)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: add access to "cn=config"
"olcTLSCACertificateFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_get: [1] attr olcTLSCACertificateFile
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: access to entry "cn=config", attr
"olcTLSCACertificateFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: to value by
"gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth", (=0)
Jul 8 14:45:08 ds slapd[1934]: <= check a_dn_pat:
gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] applying manage(=mwrscxd)
(stop)
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] mask: manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => slap_access_allowed: add access granted by
manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: add access granted by
manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: result not in cache
(olcTLSCertificateKeyFile)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: delete access to "cn=config"
"olcTLSCertificateKeyFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_get: [1] attr olcTLSCertificateKeyFile
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: access to entry "cn=config", attr
"olcTLSCertificateKeyFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: to all values by
"gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth", (=0)
Jul 8 14:45:08 ds slapd[1934]: <= check a_dn_pat:
gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] applying manage(=mwrscxd)
(stop)
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] mask: manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => slap_access_allowed: delete access granted
by manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: delete access granted by
manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: result not in cache
(olcTLSCertificateKeyFile)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: add access to "cn=config"
"olcTLSCertificateKeyFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_get: [1] attr olcTLSCertificateKeyFile
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: access to entry "cn=config", attr
"olcTLSCertificateKeyFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: to value by
"gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth", (=0)
Jul 8 14:45:08 ds slapd[1934]: <= check a_dn_pat:
gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] applying manage(=mwrscxd)
(stop)
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] mask: manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => slap_access_allowed: add access granted by
manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: add access granted by
manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: result not in cache
(olcTLSCertificateFile)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: delete access to "cn=config"
"olcTLSCertificateFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_get: [1] attr olcTLSCertificateFile
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: access to entry "cn=config", attr
"olcTLSCertificateFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: to all values by
"gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth", (=0)
Jul 8 14:45:08 ds slapd[1934]: <= check a_dn_pat:
gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] applying manage(=mwrscxd)
(stop)
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] mask: manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => slap_access_allowed: delete access granted
by manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: delete access granted by
manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: result not in cache
(olcTLSCertificateFile)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: add access to "cn=config"
"olcTLSCertificateFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_get: [1] attr olcTLSCertificateFile
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: access to entry "cn=config", attr
"olcTLSCertificateFile" requested
Jul 8 14:45:08 ds slapd[1934]: => acl_mask: to value by
"gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth", (=0)
Jul 8 14:45:08 ds slapd[1934]: <= check a_dn_pat:
gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] applying manage(=mwrscxd)
(stop)
Jul 8 14:45:08 ds slapd[1934]: <= acl_mask: [1] mask: manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => slap_access_allowed: add access granted by
manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: => access_allowed: add access granted by
manage(=mwrscxd)
Jul 8 14:45:08 ds slapd[1934]: slap_queue_csn: queueing 0x7fa7280024c0
20200708134508.175722Z#000000#000#000000
Jul 8 14:45:08 ds slapd[1934]: oc_check_required entry (cn=config),
objectClass "olcGlobal"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "objectClass"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "cn"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "olcArgsFile"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "olcLogLevel"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "olcPidFile"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "olcTLSCACertificatePath"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "structuralObjectClass"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "entryUUID"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "creatorsName"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "createTimestamp"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "olcTLSCACertificateFile"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "olcTLSCertificateKeyFile"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "olcTLSCertificateFile"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "entryCSN"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "modifiersName"
Jul 8 14:45:08 ds slapd[1934]: oc_check_allowed type "modifyTimestamp"
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on 1 descriptor
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on:
Jul 8 14:45:08 ds slapd[1934]:
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=7 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=8 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=9 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: send_ldap_result: conn=1000 op=1 p=3
Jul 8 14:45:08 ds slapd[1934]: send_ldap_result: err=80 matched="" text=""
Jul 8 14:45:08 ds slapd[1934]: send_ldap_response: msgid=2 tag=103 err=80
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=1 RESULT tag=103 err=80 text=
Jul 8 14:45:08 ds slapd[1934]: slap_graduate_commit_csn: removing
0x7fa7280024c0 20200708134508.175722Z#000000#000#000000
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on 1 descriptor
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on:
Jul 8 14:45:08 ds slapd[1934]: 11r
Jul 8 14:45:08 ds slapd[1934]:
Jul 8 14:45:08 ds slapd[1934]: daemon: read active on 11
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=7 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=8 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=9 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on 1 descriptor
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on:
Jul 8 14:45:08 ds slapd[1934]:
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=7 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=8 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=9 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on 1 descriptor
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on:
Jul 8 14:45:08 ds slapd[1934]:
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=7 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=8 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=9 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: connection_get(11)
Jul 8 14:45:08 ds slapd[1934]: connection_get(11): got connid=1000
Jul 8 14:45:08 ds slapd[1934]: connection_read(11): checking for input on
id=1000
Jul 8 14:45:08 ds slapd[1934]: op tag 0x42, time 1594215908
Jul 8 14:45:08 ds slapd[1934]: ber_get_next on fd 11 failed errno=0 (Success)
Jul 8 14:45:08 ds slapd[1934]: connection_read(11): input error=-2 id=1000,
closing.
Jul 8 14:45:08 ds slapd[1934]: connection_closing: readying conn=1000 sd=11
for close
Jul 8 14:45:08 ds slapd[1934]: connection_close: deferring conn=1000 sd=11
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=2 do_unbind
Jul 8 14:45:08 ds slapd[1934]: conn=1000 op=2 UNBIND
Jul 8 14:45:08 ds slapd[1934]: connection_resched: attempting closing
conn=1000 sd=11
Jul 8 14:45:08 ds slapd[1934]: connection_close: conn=1000 sd=11
Jul 8 14:45:08 ds slapd[1934]: daemon: removing 11
Jul 8 14:45:08 ds slapd[1934]: conn=1000 fd=11 closed
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on 1 descriptor
Jul 8 14:45:08 ds slapd[1934]: daemon: activity on:
Jul 8 14:45:08 ds slapd[1934]:
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=7 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=8 active_threads=0
tvp=NULL
Jul 8 14:45:08 ds slapd[1934]: daemon: epoll: listen=9 active_threads=0
tvp=NULL
