[Pkg-openldap-devel] Bug#860947: Bug#860947: slapd: Slapd fails to stop sometimes

Tue Apr 25 10:07:34 UTC 2017

Sorry for the delay.

Server is:
VM with 8 vCPU (ESXi 5.5 hypervisor)  host server is with 2*6 physical
core. VM has 6GiB RAM.

During normal operation: no significant CPU usage, each vCPU is below 5
percent, with peaks around 15 percent.

I attached partial config about the databases ( olcAccess and olcDbIndex
rows deleted for brevity, DNs, server names are redacted) and a graph
about the replication betweens which was made by a co-worker.

First and forth databases are master-slave (master is ldap1), second and
third are multimaster.

If it stalls again, I will do more backtrace.

Dancsa

On 2017-04-23 21:21, Ryan Tandy wrote:
> On Sun, Apr 23, 2017 at 09:34:00AM +0200, GALAMBOS Daniel wrote:
>> Which I forgot to mention is that the slapd process uses one CPU core to
>> 100 percent when this happens.
> 
> Noted. But you don't observe that CPU usage during normal operation? I'm
> assuming this loop gets triggered when you ask slapd to shut down?
> 
>> We use Heimdal, so I installed cyrus-sasl2-dbg,cyrus-sasl2-heimdal-dbg
>> (i didn't notice the missing symbols from the first stacktrace)
> 
> Thanks.
> 
>> Frame #1  (counting from zero):
>> (gdb) info locals
>> plugcount = 1
>> pluglist = 0x7f326c4ca040 <plain_client_plugins>
>> mech = 0x7f312413b950
>> mp = 0x7f312412e090
>> result = <optimized out>
>> version = 4
>> lupe = 0
>>
>> Which seems weird as we use GSSAPI. But I'm not familiar with the sasl
>> and slapd source, so it may be okay.
> 
> I'm not really familiar with the cyrus-sasl code either, but it looks
> like it might just be scanning/loading all the available plugins, and
> you happened to stop it at this point.
> 
>> #4  0x00007f3271b297b1 in sasl_client_init
>> (callbacks=callbacks at entry=0x0) at ../../lib/client.c:311
>>        ret = <optimized out>
>>        ep_list = {{entryname = 0x7f3271b36bbd "sasl_client_plug_init",
>> add_plugin = 0x7f3271b28e80 <sasl_client_add_plugin>}, {entryname =
>> 0x7f3271b36bd3 "sasl_canonuser_init",
>>            add_plugin = 0x7f3271b27590 <sasl_canonuser_add_plugin>},
>> {entryname = 0x0, add_plugin = 0x0}}
>> #5  0x00007f327279fb3c in ldap_int_sasl_init () at cyrus.c:98
>>        sasl_initialized = 1
>>        sasl_initialized = 1
> 
> This looks strange to me. ldap_int_sasl_init sets sasl_initialized to 1
> _after_ sasl_client_init returns, and shouldn't call it again after
> that. So I have to wonder whether this somehow got called from multiple
> threads... That also suggests to me that this particular thread might be
> getting stuck inside sasl_client_init, maybe.
> 
> What does your config look like on this server? Do you perhaps have
> multiple syncrepl clients all using GSSAPI?
> 
> If you can catch slapd during this loop again, maybe you could capture
> multiple stack traces? It would be really good if we could identify
> which stack frame contains the loop - especially whether it's in slapd
> or in cyrus-sasl.
> 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: ldaps.png
Type: image/png
Size: 39745 bytes
Desc: not available
URL: <http://lists.alioth.debian.org/pipermail/pkg-openldap-devel/attachments/20170425/ec7bb33a/attachment-0001.png>
-------------- next part --------------

17 olcDatabase={1}mdb,cn=config
objectClass: olcDatabaseConfig
objectClass: olcMdbConfig
olcDatabase: {1}mdb
olcDbDirectory: /var/lib/ldap/mdb1
olcSuffix: dc=...,dc=hu
olcAddContentAcl: FALSE
olcLastMod: TRUE
olcMaxDerefDepth: 15
olcReadOnly: FALSE
olcRootDN: cn=admin,...,dc=hu
olcSizeLimit: unlimited
olcSyncUseSubentry: FALSE
olcMonitoring: FALSE
olcDbNoSync: FALSE
olcDbIndex: dc eq
olcDbIndex: ou pres,eq
olcDbMaxSize: 3048000000
olcDbMode: 0600

18 olcOverlay={0}ppolicy,olcDatabase={1}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcPPolicyConfig
olcOverlay: {0}ppolicy
olcPPolicyHashCleartext: TRUE
olcPPolicyUseLockout: FALSE
olcPPolicyForwardUpdates: FALSE

19 olcOverlay={0}syncprov,olcDatabase={1}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcSyncProvConfig
olcOverlay: {0}syncprov
olcSpCheckpoint: 100 5
olcSpSessionlog: 5000

20 olcDatabase={2}mdb,cn=config
objectClass: olcDatabaseConfig
objectClass: olcMdbConfig
olcDatabase: {2}mdb
olcDbDirectory: /var/lib/ldap/mdb2
olcSuffix: ou=...,c=hu
olcAddContentAcl: FALSE
olcLastMod: TRUE
olcMaxDerefDepth: 15
olcReadOnly: FALSE
olcRootDN: cn=...,dc=hu
olcSizeLimit: unlimited
olcSyncUseSubentry: FALSE
olcSyncrepl: {0}rid=212 provider=ldaps://ldap2.<...>.hu bindmethod=sasl saslmech=GSSAPI timeout=0 network-timeout=0 binddn="<...>" secprops=noactive realm=<...> authcID="<...>" keepalive=10:30:60 starttls=no tls_cert="/etc/ldap/ssl/cert.pem" tls_key="/etc/ldap/ssl/key.pem" tls_cacert="/etc/ldap/ssl/chain.pem" tls_reqcert=demand filter="objectClass=*" searchbase="<...>" scope=sub attrs="*,+" schemachecking=off type=refreshAndPersist retry="10 50 60 +"
olcSyncrepl: {1}rid=312 provider=ldaps://ldap3.<...>.hu bindmethod=sasl saslmech=GSSAPI timeout=0 network-timeout=0 binddn="<...>" secprops=noactive realm=<...> authcID="<...>" keepalive=10:30:60 starttls=no tls_cert="/etc/ldap/ssl/cert.pem" tls_key="/etc/ldap/ssl/key.pem" tls_cacert="/etc/ldap/ssl/chain.pem" tls_reqcert=demand filter="objectClass=*" searchbase="<...>" scope=sub attrs="*,+" schemachecking=off type=refreshAndPersist retry="10 50 60 +"
olcMirrorMode: TRUE
olcMonitoring: FALSE
olcDbNoSync: FALSE
olcDbMaxSize: 1024000000
olcDbMode: 0600

21 olcOverlay={0}ppolicy,olcDatabase={2}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcPPolicyConfig
olcOverlay: {0}ppolicy
olcPPolicyHashCleartext: TRUE
olcPPolicyUseLockout: FALSE
olcPPolicyForwardUpdates: FALSE

22 olcOverlay={0}syncprov,olcDatabase={2}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcSyncProvConfig
olcOverlay: {0}syncprov
olcSpCheckpoint: 100 5
olcSpSessionlog: 5000

23 olcDatabase={3}mdb,cn=config
objectClass: olcDatabaseConfig
objectClass: olcMdbConfig
olcDatabase: {3}mdb
olcDbDirectory: /var/lib/ldap/mdb3
olcSuffix: ou=<...>,c=hu
olcAddContentAcl: FALSE
olcLastMod: TRUE
olcMaxDerefDepth: 15
olcReadOnly: FALSE
olcRootDN: cn=<...>,c=hu
olcSizeLimit: unlimited
olcSyncUseSubentry: FALSE
olcSyncrepl: {0}rid=213 provider=ldaps://ldap2...hu bindmethod=sasl saslmech=GSSAPI timeout=0 network-timeout=0 binddn="<...>" secprops=noactive realm=<...> authcID="ldap/ldap1.<...>.hu" keepalive=10:30:60 starttls=no tls_cert="/etc/ldap/ssl/cert.pem" tls_key="/etc/ldap/ssl/key.pem" tls_cacert="/etc/ldap/ssl/chain.pem" tls_reqcert=demand filter="objectClass=*" searchbase="<...>" scope=sub attrs="*,+" schemachecking=off  type=refreshAndPersist retry="10 50 60 +"
olcSyncrepl: {1}rid=313 provider=ldaps://ldap3...hu bindmethod=sasl saslmech=GSSAPI timeout=0 network-timeout=0 binddn="<...>" secprops=noactive realm=<...> authcID="ldap/ldap1...hu" keepalive=10:30:60 starttls=no tls_cert="/etc/ldap/ssl/cert.pem" tls_key="/etc/ldap/ssl/key.pem" tls_cacert="/etc/ldap/ssl/chain.pem" tls_reqcert=demand filter="objectClass=*" searchbase="<...>" scope=sub attrs="*,+" schemachecking=off  type=refreshAndPersist retry="10 50 60 +"
olcMirrorMode: TRUE
olcMonitoring: FALSE
olcDbNoSync: FALSE
olcDbMaxSize: 102400000
olcDbMode: 0600

24 olcOverlay={0}ppolicy,olcDatabase={3}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcPPolicyConfig
olcOverlay: {0}ppolicy
olcPPolicyHashCleartext: TRUE
olcPPolicyUseLockout: FALSE
olcPPolicyForwardUpdates: FALSE

25 olcOverlay={0}syncprov,olcDatabase={3}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcSyncProvConfig
olcOverlay: {0}syncprov
olcSpCheckpoint: 100 5
olcSpSessionlog: 5000

26 olcDatabase={4}mdb,cn=config
objectClass: olcDatabaseConfig
objectClass: olcMdbConfig
olcDatabase: {4}mdb
olcDbDirectory: /var/lib/ldap/mdb4
olcSuffix: c=hu
olcAddContentAcl: FALSE
olcLastMod: TRUE
olcMaxDerefDepth: 15
olcReadOnly: FALSE
olcRootDN: cn=<...>
olcSizeLimit: unlimited
olcSyncUseSubentry: FALSE
olcMonitoring: FALSE
olcDbNoSync: FALSE
olcDbMaxSize: 1024000000
olcDbMode: 0600

27 olcOverlay={0}ppolicy,olcDatabase={4}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcPPolicyConfig
olcOverlay: {0}ppolicy
olcPPolicyHashCleartext: TRUE
olcPPolicyUseLockout: FALSE
olcPPolicyForwardUpdates: FALSE

28 olcOverlay={0}syncprov,olcDatabase={4}mdb,cn=config
objectClass: olcOverlayConfig
objectClass: olcSyncProvConfig
olcOverlay: {0}syncprov
olcSpCheckpoint: 100 5
olcSpSessionlog: 5000

29 olcDatabase={5}monitor,cn=config
objectClass: olcDatabaseConfig
olcDatabase: {5}monitor
olcAccess: {0}to * by dn.exact=gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth manage by dn.exact=cn=ldapmonitoring,ou=accounts,<...>,c=hu read
olcAccess: {1}to *  by * none
olcRootDN: cn=<...>