1:28 a.m.
Hey,
I'm looking for advice how to analyse/debug this.
On one of the masters the dirsrv is unresponsive. It runs, but every
attempt to connect it hangs.
The command "systemctl status" does not show anything alarming
● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server EXAMPLE-COM.
Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; enabled; vendor preset:
disabled)
Active: active (running) since vr 2020-04-17 13:46:25 CEST; 1h 33min ago
Process: 3123 ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl
/etc/dirsrv/slapd-%i/dse.ldif (code=exited, status=0/SUCCESS)
Main PID: 3134 (ns-slapd)
Status: "slapd started: Ready to process requests"
CGroup: /system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
└─3134 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-EXAMPLE-COM -i
/var/run/dirsrv/slapd-EXAMPLE-COM.pid
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 2
apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 2
However, an ldapsearch command hangs forever
[root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
Enter LDAP Password:
Even if I use the socket (ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket) the ldapsearch
command hangs.
"ipactl status" hangs
"kinit" hangs
--
Kees Bakker
2:09 a.m.
On 4/20/20 8:28 AM, Kees Bakker via FreeIPA-users wrote:
Hey,
I'm looking for advice how to analyse/debug this.
On one of the masters the dirsrv is unresponsive. It runs, but every
attempt to connect it hangs.
The command "systemctl status" does not show anything alarming
● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server EXAMPLE-COM.
Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; enabled; vendor preset:
disabled)
Active: active (running) since vr 2020-04-17 13:46:25 CEST; 1h 33min ago
Process: 3123 ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl
/etc/dirsrv/slapd-%i/dse.ldif (code=exited, status=0/SUCCESS)
Main PID: 3134 (ns-slapd)
Status: "slapd started: Ready to process requests"
CGroup: /system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
└─3134 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-EXAMPLE-COM -i
/var/run/dirsrv/slapd-EXAMPLE-COM.pid
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 2
apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 2
However, an ldapsearch command hangs forever
[root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
Enter LDAP Password:
Even if I use the socket (ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket) the
ldapsearch
command hangs.
"ipactl status" hangs
"kinit" hangs
Hi,
you can start by having a look at dirsrv error log in
/var/log/dirsrv-slapd-YOUR_DOMAIN/errors, and the journal.
The FAQ page of 389 also explains a few troubleshooting steps:
http://www.port389.org/docs/389ds/FAQ/faq.html#Troubleshooting
HTH,
flo
_______________________________________________
FreeIPA-users mailing list -- freeipa-users(a)lists.fedorahosted.org
To unsubscribe send an email to freeipa-users-leave(a)lists.fedorahosted.org
Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives:
https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedoraho...
2:58 a.m.
On 20-04-2020 09:09, Florence Blanc-Renaud wrote:
On 4/20/20 8:28 AM, Kees Bakker via FreeIPA-users wrote:
> Hey,
>
> I'm looking for advice how to analyse/debug this.
>
> On one of the masters the dirsrv is unresponsive. It runs, but every
> attempt to connect it hangs.
>
> The command "systemctl status" does not show anything alarming
>
> ● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server EXAMPLE-COM.
> Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; enabled; vendor preset:
disabled)
> Active: active (running) since vr 2020-04-17 13:46:25 CEST; 1h 33min ago
> Process: 3123 ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl
/etc/dirsrv/slapd-%i/dse.ldif (code=exited, status=0/SUCCESS)
> Main PID: 3134 (ns-slapd)
> Status: "slapd started: Ready to process requests"
> CGroup: /system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
> └─3134 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-EXAMPLE-COM -i
/var/run/dirsrv/slapd-EXAMPLE-COM.pid
>
> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 2
> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 2
>
> However, an ldapsearch command hangs forever
>
> [root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
> Enter LDAP Password:
>
> Even if I use the socket (ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket) the
ldapsearch
> command hangs.
>
> "ipactl status" hangs
>
> "kinit" hangs
>
>
Hi,
you can start by having a look at dirsrv error log in
/var/log/dirsrv-slapd-YOUR_DOMAIN/errors, and the journal.
The FAQ page of 389 also explains a few troubleshooting steps:
http://www.port389.org/docs/389ds/FAQ/faq.html#Troubleshooting
I did exactly that, look at the "errors" log, but there was no clue, at least
not for me. Strange enough it kept running for a few hours and then it
was hanging again.
I tried the command "ipctl restart", but that was hanging forever.
However "systemctl restart dirsrv@MY-DOMAIN" was able to restart
it after several minutes. Meanwhile the sn-slapd process was using 100%
CPU.
Another remark I want to make. Every ldap connection (ldapsearch, whatever)
hangs for ever. No timeout, nothing.
When it rains, it pours, they say. There is another master with the same symptom.
I'm getting nervous now.
Thanks for the Troubleshooting link. I'll have to dive into the deep, I guess.
--
Kees
4:44 a.m.
On 20-04-2020 09:58, Kees Bakker via FreeIPA-users wrote:
On 20-04-2020 09:09, Florence Blanc-Renaud wrote:
> On 4/20/20 8:28 AM, Kees Bakker via FreeIPA-users wrote:
>> Hey,
>>
>> I'm looking for advice how to analyse/debug this.
>>
>> On one of the masters the dirsrv is unresponsive. It runs, but every
>> attempt to connect it hangs.
>>
>> The command "systemctl status" does not show anything alarming
>>
>> ● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server EXAMPLE-COM.
>> Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; enabled; vendor
preset: disabled)
>> Active: active (running) since vr 2020-04-17 13:46:25 CEST; 1h 33min ago
>> Process: 3123 ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl
/etc/dirsrv/slapd-%i/dse.ldif (code=exited, status=0/SUCCESS)
>> Main PID: 3134 (ns-slapd)
>> Status: "slapd started: Ready to process requests"
>> CGroup: /system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
>> └─3134 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-EXAMPLE-COM -i
/var/run/dirsrv/slapd-EXAMPLE-COM.pid
>>
>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 2
>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 2
>>
>> However, an ldapsearch command hangs forever
>>
>> [root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
>> Enter LDAP Password:
>>
>> Even if I use the socket (ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket) the
ldapsearch
>> command hangs.
>>
>> "ipactl status" hangs
>>
>> "kinit" hangs
>>
>>
> Hi,
> you can start by having a look at dirsrv error log in
> /var/log/dirsrv-slapd-YOUR_DOMAIN/errors, and the journal.
>
> The FAQ page of 389 also explains a few troubleshooting steps:
> http://www.port389.org/docs/389ds/FAQ/faq.html#Troubleshooting
I did exactly that, look at the "errors" log, but there was no clue, at least
not for me. Strange enough it kept running for a few hours and then it
was hanging again.
I tried the command "ipctl restart", but that was hanging forever.
However "systemctl restart dirsrv@MY-DOMAIN" was able to restart
it after several minutes. Meanwhile the sn-slapd process was using 100%
CPU.
Another remark I want to make. Every ldap connection (ldapsearch, whatever)
hangs for ever. No timeout, nothing.
When it rains, it pours, they say. There is another master with the same symptom.
I'm getting nervous now.
Thanks for the Troubleshooting link. I'll have to dive into the deep, I guess.
Could it be a deadlock?
[root@linge ~]# grep -a1 '^#0.*lock' slapd-stacktrace.1587374239.txt
Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
--
Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
--
Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
--
Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
#0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
#1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
Without debuginfo the trace of these threads look like this:
Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
#4 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
#5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
#6 0x0000562454427bbe in do_search ()
#7 0x000056245441595a in connection_threadmain ()
#8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
#9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
#10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
#4 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
#5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
#6 0x0000562454427bbe in do_search ()
#7 0x000056245441595a in connection_threadmain ()
#8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
#9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
#10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
#4 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
#5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
#6 0x0000562454427bbe in do_search ()
#7 0x000056245441595a in connection_threadmain ()
#8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
#9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
#10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
#0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
#1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
#3 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
#4 0x00007ff91b08ac88 in ldbm_back_delete () at
/usr/lib64/dirsrv/plugins/libback-ldbm.so
#5 0x00007ff92bc89feb in op_shared_delete () at /usr/lib64/dirsrv/libslapd.so.0
#6 0x00007ff92bc8a1c8 in delete_internal_pb () at /usr/lib64/dirsrv/libslapd.so.0
#7 0x00007ff9196f131e in delete_changerecord () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
#8 0x00007ff9196f1605 in changelog_trim_thread_fn () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
#9 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
#10 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
#11 0x00007ff928ad888d in clone () at /lib64/libc.so.6
With the following (stripped) debuginfo you can see that it is hanging while deleting
a changerecord.
Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
#0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
#1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff92bcd9028 in plugin_call_func (list=0x5624565a3340,
operation=operation@entry=453, pb=pb@entry=0x5624629c28
40, call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
n = <optimized out>
func = 0x7ff9190b65a0 <backend_be_pre_write_cb>
rc = <optimized out>
return_value = 0
count = 0
#3 0x00007ff92bcd92e3 in plugin_call_list (pb=0x5624629c2840, operation=453,
list=<optimized out>) at ldap/servers/slap
d/plugin.c:1972
p = 0x5624564ea2c0
locked = <optimized out>
plugin_list_number = 3
rc = 0
do_op = <optimized out>
#4 0x00007ff92bcd92e3 in plugin_call_plugins (pb=pb@entry=0x5624629c2840,
whichfunction=whichfunction@entry=453) at lda
p/servers/slapd/plugin.c:442
p = 0x5624564ea2c0
locked = <optimized out>
plugin_list_number = 3
rc = 0
do_op = <optimized out>
#5 0x00007ff91b08ac88 in ldbm_back_delete (pb=0x5624629c2840) at
ldap/servers/slapd/back-ldbm/ldbm_delete.c:373
be = 0x5624564fc000
inst = 0x56245635c680
li = 0x5624562d3a40
e = 0x562462377810
tombstone = 0x0
original_tombstone = 0x0
tmptombstone = 0x0
dn = 0x56245d90fa70 "changenumber=879530,cn=changelog"
txn = {back_txn_txn = 0x562459c2cc60}
parent_txn = 0x0
retval = 0
msg = <optimized out>
errbuf = 0x0
retry_count = <optimized out>
disk_full = 0
parent_found = <optimized out>
ruv_c_init = 0
parent_modify_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0, attr_encrypt =
0}
ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0, attr_encrypt = 0}
...
--
Kees
7:51 a.m.
Kees Bakker via FreeIPA-users wrote:
On 20-04-2020 09:58, Kees Bakker via FreeIPA-users wrote:
> On 20-04-2020 09:09, Florence Blanc-Renaud wrote:
>> On 4/20/20 8:28 AM, Kees Bakker via FreeIPA-users wrote:
>>> Hey,
>>>
>>> I'm looking for advice how to analyse/debug this.
>>>
>>> On one of the masters the dirsrv is unresponsive. It runs, but every
>>> attempt to connect it hangs.
>>>
>>> The command "systemctl status" does not show anything alarming
>>>
>>> ● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server EXAMPLE-COM.
>>> Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; enabled; vendor
preset: disabled)
>>> Active: active (running) since vr 2020-04-17 13:46:25 CEST; 1h 33min ago
>>> Process: 3123 ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl
/etc/dirsrv/slapd-%i/dse.ldif (code=exited, status=0/SUCCESS)
>>> Main PID: 3134 (ns-slapd)
>>> Status: "slapd started: Ready to process requests"
>>> CGroup: /system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
>>> └─3134 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-EXAMPLE-COM -i
/var/run/dirsrv/slapd-EXAMPLE-COM.pid
>>>
>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 2
>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 2
>>>
>>> However, an ldapsearch command hangs forever
>>>
>>> [root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
>>> Enter LDAP Password:
>>>
>>> Even if I use the socket (ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket)
the ldapsearch
>>> command hangs.
>>>
>>> "ipactl status" hangs
>>>
>>> "kinit" hangs
>>>
>>>
>> Hi,
>> you can start by having a look at dirsrv error log in
>> /var/log/dirsrv-slapd-YOUR_DOMAIN/errors, and the journal.
>>
>> The FAQ page of 389 also explains a few troubleshooting steps:
>> http://www.port389.org/docs/389ds/FAQ/faq.html#Troubleshooting
> I did exactly that, look at the "errors" log, but there was no clue, at
least
> not for me. Strange enough it kept running for a few hours and then it
> was hanging again.
>
> I tried the command "ipctl restart", but that was hanging forever.
> However "systemctl restart dirsrv@MY-DOMAIN" was able to restart
> it after several minutes. Meanwhile the sn-slapd process was using 100%
> CPU.
>
> Another remark I want to make. Every ldap connection (ldapsearch, whatever)
> hangs for ever. No timeout, nothing.
>
> When it rains, it pours, they say. There is another master with the same symptom.
> I'm getting nervous now.
>
> Thanks for the Troubleshooting link. I'll have to dive into the deep, I guess.
Could it be a deadlock?
[root@linge ~]# grep -a1 '^#0.*lock' slapd-stacktrace.1587374239.txt
Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
--
Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
--
Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
--
Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
#0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
#1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
Without debuginfo the trace of these threads look like this:
Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
#4 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
#5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
#6 0x0000562454427bbe in do_search ()
#7 0x000056245441595a in connection_threadmain ()
#8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
#9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
#10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
#4 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
#5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
#6 0x0000562454427bbe in do_search ()
#7 0x000056245441595a in connection_threadmain ()
#8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
#9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
#10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
#0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
#4 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
#5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
#6 0x0000562454427bbe in do_search ()
#7 0x000056245441595a in connection_threadmain ()
#8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
#9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
#10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
#0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
#1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
#3 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
#4 0x00007ff91b08ac88 in ldbm_back_delete () at
/usr/lib64/dirsrv/plugins/libback-ldbm.so
#5 0x00007ff92bc89feb in op_shared_delete () at /usr/lib64/dirsrv/libslapd.so.0
#6 0x00007ff92bc8a1c8 in delete_internal_pb () at /usr/lib64/dirsrv/libslapd.so.0
#7 0x00007ff9196f131e in delete_changerecord () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
#8 0x00007ff9196f1605 in changelog_trim_thread_fn () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
#9 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
#10 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
#11 0x00007ff928ad888d in clone () at /lib64/libc.so.6
With the following (stripped) debuginfo you can see that it is hanging while deleting
a changerecord.
Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
#0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
#1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007ff92bcd9028 in plugin_call_func (list=0x5624565a3340,
operation=operation@entry=453, pb=pb@entry=0x5624629c28
40, call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
n = <optimized out>
func = 0x7ff9190b65a0 <backend_be_pre_write_cb>
rc = <optimized out>
return_value = 0
count = 0
#3 0x00007ff92bcd92e3 in plugin_call_list (pb=0x5624629c2840, operation=453,
list=<optimized out>) at ldap/servers/slap
d/plugin.c:1972
p = 0x5624564ea2c0
locked = <optimized out>
plugin_list_number = 3
rc = 0
do_op = <optimized out>
#4 0x00007ff92bcd92e3 in plugin_call_plugins (pb=pb@entry=0x5624629c2840,
whichfunction=whichfunction@entry=453) at lda
p/servers/slapd/plugin.c:442
p = 0x5624564ea2c0
locked = <optimized out>
plugin_list_number = 3
rc = 0
do_op = <optimized out>
#5 0x00007ff91b08ac88 in ldbm_back_delete (pb=0x5624629c2840) at
ldap/servers/slapd/back-ldbm/ldbm_delete.c:373
be = 0x5624564fc000
inst = 0x56245635c680
li = 0x5624562d3a40
e = 0x562462377810
tombstone = 0x0
original_tombstone = 0x0
tmptombstone = 0x0
dn = 0x56245d90fa70 "changenumber=879530,cn=changelog"
txn = {back_txn_txn = 0x562459c2cc60}
parent_txn = 0x0
retval = 0
msg = <optimized out>
errbuf = 0x0
retry_count = <optimized out>
disk_full = 0
parent_found = <optimized out>
ruv_c_init = 0
parent_modify_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0, attr_encrypt =
0}
ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0, attr_encrypt = 0}
...
What distribution are you using and what version of 389-ds?
rob
8:02 a.m.
On 20-04-2020 14:51, Rob Crittenden wrote:
*** EXTERNAL E-MAIL ***
Kees Bakker via FreeIPA-users wrote:
> On 20-04-2020 09:58, Kees Bakker via FreeIPA-users wrote:
>> On 20-04-2020 09:09, Florence Blanc-Renaud wrote:
>>> On 4/20/20 8:28 AM, Kees Bakker via FreeIPA-users wrote:
>>>> Hey,
>>>>
>>>> I'm looking for advice how to analyse/debug this.
>>>>
>>>> On one of the masters the dirsrv is unresponsive. It runs, but every
>>>> attempt to connect it hangs.
>>>>
>>>> The command "systemctl status" does not show anything alarming
>>>>
>>>> ● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server EXAMPLE-COM.
>>>> Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service; enabled;
vendor preset: disabled)
>>>> Active: active (running) since vr 2020-04-17 13:46:25 CEST; 1h 33min
ago
>>>> Process: 3123 ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl
/etc/dirsrv/slapd-%i/dse.ldif (code=exited, status=0/SUCCESS)
>>>> Main PID: 3134 (ns-slapd)
>>>> Status: "slapd started: Ready to process requests"
>>>> CGroup: /system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
>>>> └─3134 /usr/sbin/ns-slapd -D /etc/dirsrv/slapd-EXAMPLE-COM -i
/var/run/dirsrv/slapd-EXAMPLE-COM.pid
>>>>
>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step 2
>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 1
>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step 2
>>>>
>>>> However, an ldapsearch command hangs forever
>>>>
>>>> [root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
>>>> Enter LDAP Password:
>>>>
>>>> Even if I use the socket
(ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket) the ldapsearch
>>>> command hangs.
>>>>
>>>> "ipactl status" hangs
>>>>
>>>> "kinit" hangs
>>>>
>>>>
>>> Hi,
>>> you can start by having a look at dirsrv error log in
>>> /var/log/dirsrv-slapd-YOUR_DOMAIN/errors, and the journal.
>>>
>>> The FAQ page of 389 also explains a few troubleshooting steps:
>>> http://www.port389.org/docs/389ds/FAQ/faq.html#Troubleshooting
>> I did exactly that, look at the "errors" log, but there was no clue, at
least
>> not for me. Strange enough it kept running for a few hours and then it
>> was hanging again.
>>
>> I tried the command "ipctl restart", but that was hanging forever.
>> However "systemctl restart dirsrv@MY-DOMAIN" was able to restart
>> it after several minutes. Meanwhile the sn-slapd process was using 100%
>> CPU.
>>
>> Another remark I want to make. Every ldap connection (ldapsearch, whatever)
>> hangs for ever. No timeout, nothing.
>>
>> When it rains, it pours, they say. There is another master with the same
symptom.
>> I'm getting nervous now.
>>
>> Thanks for the Troubleshooting link. I'll have to dive into the deep, I
guess.
> Could it be a deadlock?
>
> [root@linge ~]# grep -a1 '^#0.*lock' slapd-stacktrace.1587374239.txt
> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> --
> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> --
> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> --
> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>
> Without debuginfo the trace of these threads look like this:
>
> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
> #5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
> #6 0x0000562454427bbe in do_search ()
> #7 0x000056245441595a in connection_threadmain ()
> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>
> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
> #5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
> #6 0x0000562454427bbe in do_search ()
> #7 0x000056245441595a in connection_threadmain ()
> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>
> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
> #5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
> #6 0x0000562454427bbe in do_search ()
> #7 0x000056245441595a in connection_threadmain ()
> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>
> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #2 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
> #3 0x00007ff92bcd92e3 in plugin_call_plugins () at /usr/lib64/dirsrv/libslapd.so.0
> #4 0x00007ff91b08ac88 in ldbm_back_delete () at
/usr/lib64/dirsrv/plugins/libback-ldbm.so
> #5 0x00007ff92bc89feb in op_shared_delete () at /usr/lib64/dirsrv/libslapd.so.0
> #6 0x00007ff92bc8a1c8 in delete_internal_pb () at /usr/lib64/dirsrv/libslapd.so.0
> #7 0x00007ff9196f131e in delete_changerecord () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
> #8 0x00007ff9196f1605 in changelog_trim_thread_fn () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
> #9 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
> #10 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
> #11 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>
> With the following (stripped) debuginfo you can see that it is hanging while
deleting
> a changerecord.
>
> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #2 0x00007ff92bcd9028 in plugin_call_func (list=0x5624565a3340,
operation=operation@entry=453, pb=pb@entry=0x5624629c28
> 40, call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
> n = <optimized out>
> func = 0x7ff9190b65a0 <backend_be_pre_write_cb>
> rc = <optimized out>
> return_value = 0
> count = 0
> #3 0x00007ff92bcd92e3 in plugin_call_list (pb=0x5624629c2840, operation=453,
list=<optimized out>) at ldap/servers/slap
> d/plugin.c:1972
> p = 0x5624564ea2c0
> locked = <optimized out>
> plugin_list_number = 3
> rc = 0
> do_op = <optimized out>
> #4 0x00007ff92bcd92e3 in plugin_call_plugins (pb=pb@entry=0x5624629c2840,
whichfunction=whichfunction@entry=453) at lda
> p/servers/slapd/plugin.c:442
> p = 0x5624564ea2c0
> locked = <optimized out>
> plugin_list_number = 3
> rc = 0
> do_op = <optimized out>
> #5 0x00007ff91b08ac88 in ldbm_back_delete (pb=0x5624629c2840) at
ldap/servers/slapd/back-ldbm/ldbm_delete.c:373
> be = 0x5624564fc000
> inst = 0x56245635c680
> li = 0x5624562d3a40
> e = 0x562462377810
> tombstone = 0x0
> original_tombstone = 0x0
> tmptombstone = 0x0
> dn = 0x56245d90fa70 "changenumber=879530,cn=changelog"
> txn = {back_txn_txn = 0x562459c2cc60}
> parent_txn = 0x0
> retval = 0
> msg = <optimized out>
> errbuf = 0x0
> retry_count = <optimized out>
> disk_full = 0
> parent_found = <optimized out>
> ruv_c_init = 0
> parent_modify_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0,
attr_encrypt = 0}
> ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0, attr_encrypt = 0}
> ...
>
What distribution are you using and what version of 389-ds?
Centos7
[root@linge ~]# rpm -qa 389\*
389-ds-base-debuginfo-1.3.9.1-13.el7_7.x86_64
389-ds-base-libs-1.3.9.1-13.el7_7.x86_64
389-ds-base-1.3.9.1-13.el7_7.x86_64
[root@linge ~]# rpm -qa centos-release
centos-release-7-7.1908.0.el7.centos.x86_64
8:16 a.m.
On 4/20/20 3:02 PM, Kees Bakker wrote:
On 20-04-2020 14:51, Rob Crittenden wrote:
> *** EXTERNAL E-MAIL ***
>
>
> Kees Bakker via FreeIPA-users wrote:
>> On 20-04-2020 09:58, Kees Bakker via FreeIPA-users wrote:
>>> On 20-04-2020 09:09, Florence Blanc-Renaud wrote:
>>>> On 4/20/20 8:28 AM, Kees Bakker via FreeIPA-users wrote:
>>>>> Hey,
>>>>>
>>>>> I'm looking for advice how to analyse/debug this.
>>>>>
>>>>> On one of the masters the dirsrv is unresponsive. It runs, but every
>>>>> attempt to connect it hangs.
>>>>>
>>>>> The command "systemctl status" does not show anything
alarming
>>>>>
>>>>> ● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server EXAMPLE-COM.
>>>>> Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service;
enabled; vendor preset: disabled)
>>>>> Active: active (running) since vr 2020-04-17 13:46:25 CEST; 1h
33min ago
>>>>> Process: 3123 ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl
/etc/dirsrv/slapd-%i/dse.ldif (code=exited, status=0/SUCCESS)
>>>>> Main PID: 3134 (ns-slapd)
>>>>> Status: "slapd started: Ready to process requests"
>>>>> CGroup:
/system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
>>>>> └─3134 /usr/sbin/ns-slapd -D
/etc/dirsrv/slapd-EXAMPLE-COM -i /var/run/dirsrv/slapd-EXAMPLE-COM.pid
>>>>>
>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step
1
>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step
1
>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step
1
>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step
1
>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client step
2
>>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step
1
>>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client step
1
>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step
1
>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step
1
>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client step
2
>>>>>
>>>>> However, an ldapsearch command hangs forever
>>>>>
>>>>> [root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
>>>>> Enter LDAP Password:
>>>>>
>>>>> Even if I use the socket
(ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket) the ldapsearch
>>>>> command hangs.
>>>>>
>>>>> "ipactl status" hangs
>>>>>
>>>>> "kinit" hangs
>>>>>
>>>>>
>>>> Hi,
>>>> you can start by having a look at dirsrv error log in
>>>> /var/log/dirsrv-slapd-YOUR_DOMAIN/errors, and the journal.
>>>>
>>>> The FAQ page of 389 also explains a few troubleshooting steps:
>>>> http://www.port389.org/docs/389ds/FAQ/faq.html#Troubleshooting
>>> I did exactly that, look at the "errors" log, but there was no
clue, at least
>>> not for me. Strange enough it kept running for a few hours and then it
>>> was hanging again.
>>>
>>> I tried the command "ipctl restart", but that was hanging forever.
>>> However "systemctl restart dirsrv@MY-DOMAIN" was able to restart
>>> it after several minutes. Meanwhile the sn-slapd process was using 100%
>>> CPU.
>>>
>>> Another remark I want to make. Every ldap connection (ldapsearch, whatever)
>>> hangs for ever. No timeout, nothing.
>>>
>>> When it rains, it pours, they say. There is another master with the same
symptom.
>>> I'm getting nervous now.
>>>
>>> Thanks for the Troubleshooting link. I'll have to dive into the deep, I
guess.
>> Could it be a deadlock?
>>
>> [root@linge ~]# grep -a1 '^#0.*lock' slapd-stacktrace.1587374239.txt
>> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> --
>> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> --
>> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> --
>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>
>> Without debuginfo the trace of these threads look like this:
>>
>> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>> #5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
>> #6 0x0000562454427bbe in do_search ()
>> #7 0x000056245441595a in connection_threadmain ()
>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>
>> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>> #5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
>> #6 0x0000562454427bbe in do_search ()
>> #7 0x000056245441595a in connection_threadmain ()
>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>
>> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #3 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>> #5 0x00007ff92bccc0d7 in op_shared_search () at /usr/lib64/dirsrv/libslapd.so.0
>> #6 0x0000562454427bbe in do_search ()
>> #7 0x000056245441595a in connection_threadmain ()
>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>
>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #2 0x00007ff92bcd9028 in plugin_call_func () at /usr/lib64/dirsrv/libslapd.so.0
>> #3 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>> #4 0x00007ff91b08ac88 in ldbm_back_delete () at
/usr/lib64/dirsrv/plugins/libback-ldbm.so
>> #5 0x00007ff92bc89feb in op_shared_delete () at /usr/lib64/dirsrv/libslapd.so.0
>> #6 0x00007ff92bc8a1c8 in delete_internal_pb () at
/usr/lib64/dirsrv/libslapd.so.0
>> #7 0x00007ff9196f131e in delete_changerecord () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
>> #8 0x00007ff9196f1605 in changelog_trim_thread_fn () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
>> #9 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>> #10 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>> #11 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>
>> With the following (stripped) debuginfo you can see that it is hanging while
deleting
>> a changerecord.
>>
>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #2 0x00007ff92bcd9028 in plugin_call_func (list=0x5624565a3340,
operation=operation@entry=453, pb=pb@entry=0x5624629c28
>> 40, call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
>> n = <optimized out>
>> func = 0x7ff9190b65a0 <backend_be_pre_write_cb>
>> rc = <optimized out>
>> return_value = 0
>> count = 0
>> #3 0x00007ff92bcd92e3 in plugin_call_list (pb=0x5624629c2840, operation=453,
list=<optimized out>) at ldap/servers/slap
>> d/plugin.c:1972
>> p = 0x5624564ea2c0
>> locked = <optimized out>
>> plugin_list_number = 3
>> rc = 0
>> do_op = <optimized out>
>> #4 0x00007ff92bcd92e3 in plugin_call_plugins (pb=pb@entry=0x5624629c2840,
whichfunction=whichfunction@entry=453) at lda
>> p/servers/slapd/plugin.c:442
>> p = 0x5624564ea2c0
>> locked = <optimized out>
>> plugin_list_number = 3
>> rc = 0
>> do_op = <optimized out>
>> #5 0x00007ff91b08ac88 in ldbm_back_delete (pb=0x5624629c2840) at
ldap/servers/slapd/back-ldbm/ldbm_delete.c:373
>> be = 0x5624564fc000
>> inst = 0x56245635c680
>> li = 0x5624562d3a40
>> e = 0x562462377810
>> tombstone = 0x0
>> original_tombstone = 0x0
>> tmptombstone = 0x0
>> dn = 0x56245d90fa70 "changenumber=879530,cn=changelog"
>> txn = {back_txn_txn = 0x562459c2cc60}
>> parent_txn = 0x0
>> retval = 0
>> msg = <optimized out>
>> errbuf = 0x0
>> retry_count = <optimized out>
>> disk_full = 0
>> parent_found = <optimized out>
>> ruv_c_init = 0
>> parent_modify_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0,
attr_encrypt = 0}
>> ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0, attr_encrypt =
0}
>> ...
>>
> What distribution are you using and what version of 389-ds?
>
Centos7
[root@linge ~]# rpm -qa 389\*
389-ds-base-debuginfo-1.3.9.1-13.el7_7.x86_64
389-ds-base-libs-1.3.9.1-13.el7_7.x86_64
389-ds-base-1.3.9.1-13.el7_7.x86_64
[root@linge ~]# rpm -qa centos-release
centos-release-7-7.1908.0.el7.centos.x86_64
This is a known bug [1].
With the same bug there are two deadlock scenario but only one is fixed
(for example in slapi-nis-0.56.4-1 [2]).
A fix for the second one is under tests.
At the moment I would recommend the workaround [3]. The drawback is a
growth of the retroCL database but unless you have a very high rate of
update it should not be a concern.
[1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
[2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
[3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
best regards
thierry
8:35 a.m.
On 20-04-2020 15:16, thierry bordaz wrote:
On 4/20/20 3:02 PM, Kees Bakker wrote:
> On 20-04-2020 14:51, Rob Crittenden wrote:
>> Kees Bakker via FreeIPA-users wrote:
>>> On 20-04-2020 09:58, Kees Bakker via FreeIPA-users wrote:
>>>> On 20-04-2020 09:09, Florence Blanc-Renaud wrote:
>>>>> On 4/20/20 8:28 AM, Kees Bakker via FreeIPA-users wrote:
>>>>>> Hey,
>>>>>>
>>>>>> I'm looking for advice how to analyse/debug this.
>>>>>>
>>>>>> On one of the masters the dirsrv is unresponsive. It runs, but
every
>>>>>> attempt to connect it hangs.
>>>>>>
>>>>>> The command "systemctl status" does not show anything
alarming
>>>>>>
>>>>>> ● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server EXAMPLE-COM.
>>>>>> Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service;
enabled; vendor preset: disabled)
>>>>>> Active: active (running) since vr 2020-04-17 13:46:25 CEST;
1h 33min ago
>>>>>> Process: 3123
ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl /etc/dirsrv/slapd-%i/dse.ldif
(code=exited, status=0/SUCCESS)
>>>>>> Main PID: 3134 (ns-slapd)
>>>>>> Status: "slapd started: Ready to process
requests"
>>>>>> CGroup:
/system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
>>>>>> └─3134 /usr/sbin/ns-slapd -D
/etc/dirsrv/slapd-EXAMPLE-COM -i /var/run/dirsrv/slapd-EXAMPLE-COM.pid
>>>>>>
>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client
step 1
>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client
step 1
>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client
step 1
>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client
step 1
>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI client
step 2
>>>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client
step 1
>>>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI client
step 1
>>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client
step 1
>>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client
step 1
>>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI client
step 2
>>>>>>
>>>>>> However, an ldapsearch command hangs forever
>>>>>>
>>>>>> [root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
>>>>>> Enter LDAP Password:
>>>>>>
>>>>>> Even if I use the socket
(ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket) the ldapsearch
>>>>>> command hangs.
>>>>>>
>>>>>> "ipactl status" hangs
>>>>>>
>>>>>> "kinit" hangs
>>>>>>
>>>>>>
>>>>> Hi,
>>>>> you can start by having a look at dirsrv error log in
>>>>> /var/log/dirsrv-slapd-YOUR_DOMAIN/errors, and the journal.
>>>>>
>>>>> The FAQ page of 389 also explains a few troubleshooting steps:
>>>>> http://www.port389.org/docs/389ds/FAQ/faq.html#Troubleshooting
>>>> I did exactly that, look at the "errors" log, but there was no
clue, at least
>>>> not for me. Strange enough it kept running for a few hours and then it
>>>> was hanging again.
>>>>
>>>> I tried the command "ipctl restart", but that was hanging
forever.
>>>> However "systemctl restart dirsrv@MY-DOMAIN" was able to
restart
>>>> it after several minutes. Meanwhile the sn-slapd process was using 100%
>>>> CPU.
>>>>
>>>> Another remark I want to make. Every ldap connection (ldapsearch,
whatever)
>>>> hangs for ever. No timeout, nothing.
>>>>
>>>> When it rains, it pours, they say. There is another master with the same
symptom.
>>>> I'm getting nervous now.
>>>>
>>>> Thanks for the Troubleshooting link. I'll have to dive into the deep,
I guess.
>>> Could it be a deadlock?
>>>
>>> [root@linge ~]# grep -a1 '^#0.*lock' slapd-stacktrace.1587374239.txt
>>> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> --
>>> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> --
>>> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> --
>>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
>>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>
>>> Without debuginfo the trace of these threads look like this:
>>>
>>> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> #3 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #5 0x00007ff92bccc0d7 in op_shared_search () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #6 0x0000562454427bbe in do_search ()
>>> #7 0x000056245441595a in connection_threadmain ()
>>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>
>>> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> #3 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #5 0x00007ff92bccc0d7 in op_shared_search () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #6 0x0000562454427bbe in do_search ()
>>> #7 0x000056245441595a in connection_threadmain ()
>>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>
>>> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> #3 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #5 0x00007ff92bccc0d7 in op_shared_search () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #6 0x0000562454427bbe in do_search ()
>>> #7 0x000056245441595a in connection_threadmain ()
>>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>
>>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
>>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> #2 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #3 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #4 0x00007ff91b08ac88 in ldbm_back_delete () at
/usr/lib64/dirsrv/plugins/libback-ldbm.so
>>> #5 0x00007ff92bc89feb in op_shared_delete () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #6 0x00007ff92bc8a1c8 in delete_internal_pb () at
/usr/lib64/dirsrv/libslapd.so.0
>>> #7 0x00007ff9196f131e in delete_changerecord () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
>>> #8 0x00007ff9196f1605 in changelog_trim_thread_fn () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
>>> #9 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>> #10 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>> #11 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>
>>> With the following (stripped) debuginfo you can see that it is hanging while
deleting
>>> a changerecord.
>>>
>>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
>>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>> #2 0x00007ff92bcd9028 in plugin_call_func (list=0x5624565a3340,
operation=operation@entry=453, pb=pb@entry=0x5624629c28
>>> 40, call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
>>> n = <optimized out>
>>> func = 0x7ff9190b65a0 <backend_be_pre_write_cb>
>>> rc = <optimized out>
>>> return_value = 0
>>> count = 0
>>> #3 0x00007ff92bcd92e3 in plugin_call_list (pb=0x5624629c2840, operation=453,
list=<optimized out>) at ldap/servers/slap
>>> d/plugin.c:1972
>>> p = 0x5624564ea2c0
>>> locked = <optimized out>
>>> plugin_list_number = 3
>>> rc = 0
>>> do_op = <optimized out>
>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins (pb=pb@entry=0x5624629c2840,
whichfunction=whichfunction@entry=453) at lda
>>> p/servers/slapd/plugin.c:442
>>> p = 0x5624564ea2c0
>>> locked = <optimized out>
>>> plugin_list_number = 3
>>> rc = 0
>>> do_op = <optimized out>
>>> #5 0x00007ff91b08ac88 in ldbm_back_delete (pb=0x5624629c2840) at
ldap/servers/slapd/back-ldbm/ldbm_delete.c:373
>>> be = 0x5624564fc000
>>> inst = 0x56245635c680
>>> li = 0x5624562d3a40
>>> e = 0x562462377810
>>> tombstone = 0x0
>>> original_tombstone = 0x0
>>> tmptombstone = 0x0
>>> dn = 0x56245d90fa70 "changenumber=879530,cn=changelog"
>>> txn = {back_txn_txn = 0x562459c2cc60}
>>> parent_txn = 0x0
>>> retval = 0
>>> msg = <optimized out>
>>> errbuf = 0x0
>>> retry_count = <optimized out>
>>> disk_full = 0
>>> parent_found = <optimized out>
>>> ruv_c_init = 0
>>> parent_modify_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0,
attr_encrypt = 0}
>>> ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0, attr_encrypt
= 0}
>>> ...
>>>
>> What distribution are you using and what version of 389-ds?
>>
> Centos7
>
> [root@linge ~]# rpm -qa 389\*
> 389-ds-base-debuginfo-1.3.9.1-13.el7_7.x86_64
> 389-ds-base-libs-1.3.9.1-13.el7_7.x86_64
> 389-ds-base-1.3.9.1-13.el7_7.x86_64
>
> [root@linge ~]# rpm -qa centos-release
> centos-release-7-7.1908.0.el7.centos.x86_64
>
>
This is a known bug [1].
With the same bug there are two deadlock scenario but only one is fixed (for example in
slapi-nis-0.56.4-1 [2]).
A fix for the second one is under tests.
At the moment I would recommend the workaround [3]. The drawback is a growth of the
retroCL database but unless you have a very high rate of update it should not be a
concern.
[1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
[2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
[3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
OK, thanks for the help. I will try that.
Two remarks.
1) I did an update a few days ago. (1.3.8.4-18.el7_6 => 1.3.9.1-13.el7_7). Then two
days after the update this hang started to happen.
2) the nasty thing about this is, that 398-ds was still alive, but all connections to it
hang forever (even "ipactl restart")
--
Kees
8:42 a.m.
On 20-04-2020 15:35, Kees Bakker via FreeIPA-users wrote:
On 20-04-2020 15:16, thierry bordaz wrote:
> On 4/20/20 3:02 PM, Kees Bakker wrote:
>> On 20-04-2020 14:51, Rob Crittenden wrote:
>>> Kees Bakker via FreeIPA-users wrote:
>>>> On 20-04-2020 09:58, Kees Bakker via FreeIPA-users wrote:
>>>>> On 20-04-2020 09:09, Florence Blanc-Renaud wrote:
>>>>>> On 4/20/20 8:28 AM, Kees Bakker via FreeIPA-users wrote:
>>>>>>> Hey,
>>>>>>>
>>>>>>> I'm looking for advice how to analyse/debug this.
>>>>>>>
>>>>>>> On one of the masters the dirsrv is unresponsive. It runs,
but every
>>>>>>> attempt to connect it hangs.
>>>>>>>
>>>>>>> The command "systemctl status" does not show
anything alarming
>>>>>>>
>>>>>>> ● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server
EXAMPLE-COM.
>>>>>>> Loaded: loaded (/usr/lib/systemd/system/dirsrv@.service;
enabled; vendor preset: disabled)
>>>>>>> Active: active (running) since vr 2020-04-17 13:46:25
CEST; 1h 33min ago
>>>>>>> Process: 3123
ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl /etc/dirsrv/slapd-%i/dse.ldif
(code=exited, status=0/SUCCESS)
>>>>>>> Main PID: 3134 (ns-slapd)
>>>>>>> Status: "slapd started: Ready to process
requests"
>>>>>>> CGroup:
/system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
>>>>>>> └─3134 /usr/sbin/ns-slapd -D
/etc/dirsrv/slapd-EXAMPLE-COM -i /var/run/dirsrv/slapd-EXAMPLE-COM.pid
>>>>>>>
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 2
>>>>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI
client step 2
>>>>>>>
>>>>>>> However, an ldapsearch command hangs forever
>>>>>>>
>>>>>>> [root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
>>>>>>> Enter LDAP Password:
>>>>>>>
>>>>>>> Even if I use the socket
(ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket) the ldapsearch
>>>>>>> command hangs.
>>>>>>>
>>>>>>> "ipactl status" hangs
>>>>>>>
>>>>>>> "kinit" hangs
>>>>>>>
>>>>>>>
>>>>>> Hi,
>>>>>> you can start by having a look at dirsrv error log in
>>>>>> /var/log/dirsrv-slapd-YOUR_DOMAIN/errors, and the journal.
>>>>>>
>>>>>> The FAQ page of 389 also explains a few troubleshooting steps:
>>>>>> http://www.port389.org/docs/389ds/FAQ/faq.html#Troubleshooting
>>>>> I did exactly that, look at the "errors" log, but there was
no clue, at least
>>>>> not for me. Strange enough it kept running for a few hours and then
it
>>>>> was hanging again.
>>>>>
>>>>> I tried the command "ipctl restart", but that was hanging
forever.
>>>>> However "systemctl restart dirsrv@MY-DOMAIN" was able to
restart
>>>>> it after several minutes. Meanwhile the sn-slapd process was using
100%
>>>>> CPU.
>>>>>
>>>>> Another remark I want to make. Every ldap connection (ldapsearch,
whatever)
>>>>> hangs for ever. No timeout, nothing.
>>>>>
>>>>> When it rains, it pours, they say. There is another master with the
same symptom.
>>>>> I'm getting nervous now.
>>>>>
>>>>> Thanks for the Troubleshooting link. I'll have to dive into the
deep, I guess.
>>>> Could it be a deadlock?
>>>>
>>>> [root@linge ~]# grep -a1 '^#0.*lock'
slapd-stacktrace.1587374239.txt
>>>> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> --
>>>> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> --
>>>> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> --
>>>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>>>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>>
>>>> Without debuginfo the trace of these threads look like this:
>>>>
>>>> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #3 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #5 0x00007ff92bccc0d7 in op_shared_search () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #6 0x0000562454427bbe in do_search ()
>>>> #7 0x000056245441595a in connection_threadmain ()
>>>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>>
>>>> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #3 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #5 0x00007ff92bccc0d7 in op_shared_search () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #6 0x0000562454427bbe in do_search ()
>>>> #7 0x000056245441595a in connection_threadmain ()
>>>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>>
>>>> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #3 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #5 0x00007ff92bccc0d7 in op_shared_search () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #6 0x0000562454427bbe in do_search ()
>>>> #7 0x000056245441595a in connection_threadmain ()
>>>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>>
>>>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>>>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #3 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #4 0x00007ff91b08ac88 in ldbm_back_delete () at
/usr/lib64/dirsrv/plugins/libback-ldbm.so
>>>> #5 0x00007ff92bc89feb in op_shared_delete () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #6 0x00007ff92bc8a1c8 in delete_internal_pb () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #7 0x00007ff9196f131e in delete_changerecord () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
>>>> #8 0x00007ff9196f1605 in changelog_trim_thread_fn () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
>>>> #9 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>>> #10 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>>> #11 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>>
>>>> With the following (stripped) debuginfo you can see that it is hanging
while deleting
>>>> a changerecord.
>>>>
>>>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>>>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff92bcd9028 in plugin_call_func (list=0x5624565a3340,
operation=operation@entry=453, pb=pb@entry=0x5624629c28
>>>> 40, call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
>>>> n = <optimized out>
>>>> func = 0x7ff9190b65a0 <backend_be_pre_write_cb>
>>>> rc = <optimized out>
>>>> return_value = 0
>>>> count = 0
>>>> #3 0x00007ff92bcd92e3 in plugin_call_list (pb=0x5624629c2840,
operation=453, list=<optimized out>) at ldap/servers/slap
>>>> d/plugin.c:1972
>>>> p = 0x5624564ea2c0
>>>> locked = <optimized out>
>>>> plugin_list_number = 3
>>>> rc = 0
>>>> do_op = <optimized out>
>>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins
(pb=pb@entry=0x5624629c2840, whichfunction=whichfunction@entry=453) at lda
>>>> p/servers/slapd/plugin.c:442
>>>> p = 0x5624564ea2c0
>>>> locked = <optimized out>
>>>> plugin_list_number = 3
>>>> rc = 0
>>>> do_op = <optimized out>
>>>> #5 0x00007ff91b08ac88 in ldbm_back_delete (pb=0x5624629c2840) at
ldap/servers/slapd/back-ldbm/ldbm_delete.c:373
>>>> be = 0x5624564fc000
>>>> inst = 0x56245635c680
>>>> li = 0x5624562d3a40
>>>> e = 0x562462377810
>>>> tombstone = 0x0
>>>> original_tombstone = 0x0
>>>> tmptombstone = 0x0
>>>> dn = 0x56245d90fa70
"changenumber=879530,cn=changelog"
>>>> txn = {back_txn_txn = 0x562459c2cc60}
>>>> parent_txn = 0x0
>>>> retval = 0
>>>> msg = <optimized out>
>>>> errbuf = 0x0
>>>> retry_count = <optimized out>
>>>> disk_full = 0
>>>> parent_found = <optimized out>
>>>> ruv_c_init = 0
>>>> parent_modify_c = {old_entry = 0x0, new_entry = 0x0, smods =
0x0, attr_encrypt = 0}
>>>> ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0,
attr_encrypt = 0}
>>>> ...
>>>>
>>> What distribution are you using and what version of 389-ds?
>>>
>> Centos7
>>
>> [root@linge ~]# rpm -qa 389\*
>> 389-ds-base-debuginfo-1.3.9.1-13.el7_7.x86_64
>> 389-ds-base-libs-1.3.9.1-13.el7_7.x86_64
>> 389-ds-base-1.3.9.1-13.el7_7.x86_64
>>
>> [root@linge ~]# rpm -qa centos-release
>> centos-release-7-7.1908.0.el7.centos.x86_64
>>
>>
> This is a known bug [1].
> With the same bug there are two deadlock scenario but only one is fixed (for example
in slapi-nis-0.56.4-1 [2]).
> A fix for the second one is under tests.
>
> At the moment I would recommend the workaround [3]. The drawback is a growth of the
retroCL database but unless you have a very high rate of update it should not be a
concern.
>
> [1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
> [2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
> [3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
OK, thanks for the help. I will try that.
Two remarks.
1) I did an update a few days ago. (1.3.8.4-18.el7_6 => 1.3.9.1-13.el7_7). Then two
days after the update this hang started to happen.
2) the nasty thing about this is, that 398-ds was still alive, but all connections to it
hang forever (even "ipactl restart")
Current setting... 2d, what a coincidence, ha ha
dn: cn=Retro Changelog Plugin,cn=plugins,cn=config
cn: Retro Changelog Plugin
nsslapd-changelogmaxage: 2d
--
Kees
8:42 a.m.
On 4/20/20 3:35 PM, Kees Bakker wrote:
On 20-04-2020 15:16, thierry bordaz wrote:
> On 4/20/20 3:02 PM, Kees Bakker wrote:
>> On 20-04-2020 14:51, Rob Crittenden wrote:
>>> Kees Bakker via FreeIPA-users wrote:
>>>> On 20-04-2020 09:58, Kees Bakker via FreeIPA-users wrote:
>>>>> On 20-04-2020 09:09, Florence Blanc-Renaud wrote:
>>>>>> On 4/20/20 8:28 AM, Kees Bakker via FreeIPA-users wrote:
>>>>>>> Hey,
>>>>>>>
>>>>>>> I'm looking for advice how to analyse/debug this.
>>>>>>>
>>>>>>> On one of the masters the dirsrv is unresponsive. It runs,
but every
>>>>>>> attempt to connect it hangs.
>>>>>>>
>>>>>>> The command "systemctl status" does not show
anything alarming
>>>>>>>
>>>>>>> ● dirsrv(a)EXAMPLE-COM.service - 389 Directory Server
EXAMPLE-COM.
>>>>>>> Loaded: loaded
(/usr/lib/systemd/system/dirsrv@.service; enabled; vendor preset: disabled)
>>>>>>> Active: active (running) since vr 2020-04-17 13:46:25
CEST; 1h 33min ago
>>>>>>> Process: 3123
ExecStartPre=/usr/sbin/ds_systemd_ask_password_acl /etc/dirsrv/slapd-%i/dse.ldif
(code=exited, status=0/SUCCESS)
>>>>>>> Main PID: 3134 (ns-slapd)
>>>>>>> Status: "slapd started: Ready to process
requests"
>>>>>>> CGroup:
/system.slice/system-dirsrv.slice/dirsrv(a)EXAMPLE-COM.service
>>>>>>> └─3134 /usr/sbin/ns-slapd -D
/etc/dirsrv/slapd-EXAMPLE-COM -i /var/run/dirsrv/slapd-EXAMPLE-COM.pid
>>>>>>>
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:13:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 2
>>>>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:18:54 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI
client step 1
>>>>>>> apr 17 15:18:55 linge.example.com ns-slapd[3134]: GSSAPI
client step 2
>>>>>>>
>>>>>>> However, an ldapsearch command hangs forever
>>>>>>>
>>>>>>> [root@rotte ~]# ldapsearch -H ldaps://linge.example.com -D
uid=keesbtest,cn=users,cn=accounts,dc=example,dc=com -W -LLL -o ldif-wrap=no -b
cn=users,cn=accounts,dc=example,dc=com
'(&(objectClass=person)(memberOf=cn=admins,cn=groups,cn=accounts,dc=example,dc=com))'
uid
>>>>>>> Enter LDAP Password:
>>>>>>>
>>>>>>> Even if I use the socket
(ldapi://%2fvar%2frun%2fslapd-EXAMPLE-COM.socket) the ldapsearch
>>>>>>> command hangs.
>>>>>>>
>>>>>>> "ipactl status" hangs
>>>>>>>
>>>>>>> "kinit" hangs
>>>>>>>
>>>>>>>
>>>>>> Hi,
>>>>>> you can start by having a look at dirsrv error log in
>>>>>> /var/log/dirsrv-slapd-YOUR_DOMAIN/errors, and the journal.
>>>>>>
>>>>>> The FAQ page of 389 also explains a few troubleshooting steps:
>>>>>> http://www.port389.org/docs/389ds/FAQ/faq.html#Troubleshooting
>>>>> I did exactly that, look at the "errors" log, but there was
no clue, at least
>>>>> not for me. Strange enough it kept running for a few hours and then
it
>>>>> was hanging again.
>>>>>
>>>>> I tried the command "ipctl restart", but that was hanging
forever.
>>>>> However "systemctl restart dirsrv@MY-DOMAIN" was able to
restart
>>>>> it after several minutes. Meanwhile the sn-slapd process was using
100%
>>>>> CPU.
>>>>>
>>>>> Another remark I want to make. Every ldap connection (ldapsearch,
whatever)
>>>>> hangs for ever. No timeout, nothing.
>>>>>
>>>>> When it rains, it pours, they say. There is another master with the
same symptom.
>>>>> I'm getting nervous now.
>>>>>
>>>>> Thanks for the Troubleshooting link. I'll have to dive into the
deep, I guess.
>>>> Could it be a deadlock?
>>>>
>>>> [root@linge ~]# grep -a1 '^#0.*lock'
slapd-stacktrace.1587374239.txt
>>>> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> --
>>>> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> --
>>>> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> --
>>>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>>>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>>
>>>> Without debuginfo the trace of these threads look like this:
>>>>
>>>> Thread 23 (Thread 0x7ff8ff265700 (LWP 14474)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #3 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #5 0x00007ff92bccc0d7 in op_shared_search () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #6 0x0000562454427bbe in do_search ()
>>>> #7 0x000056245441595a in connection_threadmain ()
>>>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>>
>>>> Thread 7 (Thread 0x7ff8f7255700 (LWP 14490)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #3 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #5 0x00007ff92bccc0d7 in op_shared_search () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #6 0x0000562454427bbe in do_search ()
>>>> #7 0x000056245441595a in connection_threadmain ()
>>>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>>
>>>> Thread 4 (Thread 0x7ff8f5a52700 (LWP 14493)):
>>>> #0 0x00007ff929430144 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190cc49c in map_rdlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff9190b8745 in backend_search_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #3 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #5 0x00007ff92bccc0d7 in op_shared_search () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #6 0x0000562454427bbe in do_search ()
>>>> #7 0x000056245441595a in connection_threadmain ()
>>>> #8 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>>> #9 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>>> #10 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>>
>>>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>>>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff92bcd9028 in plugin_call_func () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #3 0x00007ff92bcd92e3 in plugin_call_plugins () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #4 0x00007ff91b08ac88 in ldbm_back_delete () at
/usr/lib64/dirsrv/plugins/libback-ldbm.so
>>>> #5 0x00007ff92bc89feb in op_shared_delete () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #6 0x00007ff92bc8a1c8 in delete_internal_pb () at
/usr/lib64/dirsrv/libslapd.so.0
>>>> #7 0x00007ff9196f131e in delete_changerecord () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
>>>> #8 0x00007ff9196f1605 in changelog_trim_thread_fn () at
/usr/lib64/dirsrv/plugins/libretrocl-plugin.so
>>>> #9 0x00007ff929a8cc5b in _pt_root () at /lib64/libnspr4.so
>>>> #10 0x00007ff92942ce65 in start_thread () at /lib64/libpthread.so.0
>>>> #11 0x00007ff928ad888d in clone () at /lib64/libc.so.6
>>>>
>>>> With the following (stripped) debuginfo you can see that it is hanging
while deleting
>>>> a changerecord.
>>>>
>>>> Thread 2 (Thread 0x7ff92c355700 (LWP 15679)):
>>>> #0 0x00007ff92943035e in pthread_rwlock_wrlock () at
/lib64/libpthread.so.0
>>>> #1 0x00007ff9190b6639 in backend_be_pre_write_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>>>> #2 0x00007ff92bcd9028 in plugin_call_func (list=0x5624565a3340,
operation=operation@entry=453, pb=pb@entry=0x5624629c28
>>>> 40, call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
>>>> n = <optimized out>
>>>> func = 0x7ff9190b65a0 <backend_be_pre_write_cb>
>>>> rc = <optimized out>
>>>> return_value = 0
>>>> count = 0
>>>> #3 0x00007ff92bcd92e3 in plugin_call_list (pb=0x5624629c2840,
operation=453, list=<optimized out>) at ldap/servers/slap
>>>> d/plugin.c:1972
>>>> p = 0x5624564ea2c0
>>>> locked = <optimized out>
>>>> plugin_list_number = 3
>>>> rc = 0
>>>> do_op = <optimized out>
>>>> #4 0x00007ff92bcd92e3 in plugin_call_plugins
(pb=pb@entry=0x5624629c2840, whichfunction=whichfunction@entry=453) at lda
>>>> p/servers/slapd/plugin.c:442
>>>> p = 0x5624564ea2c0
>>>> locked = <optimized out>
>>>> plugin_list_number = 3
>>>> rc = 0
>>>> do_op = <optimized out>
>>>> #5 0x00007ff91b08ac88 in ldbm_back_delete (pb=0x5624629c2840) at
ldap/servers/slapd/back-ldbm/ldbm_delete.c:373
>>>> be = 0x5624564fc000
>>>> inst = 0x56245635c680
>>>> li = 0x5624562d3a40
>>>> e = 0x562462377810
>>>> tombstone = 0x0
>>>> original_tombstone = 0x0
>>>> tmptombstone = 0x0
>>>> dn = 0x56245d90fa70
"changenumber=879530,cn=changelog"
>>>> txn = {back_txn_txn = 0x562459c2cc60}
>>>> parent_txn = 0x0
>>>> retval = 0
>>>> msg = <optimized out>
>>>> errbuf = 0x0
>>>> retry_count = <optimized out>
>>>> disk_full = 0
>>>> parent_found = <optimized out>
>>>> ruv_c_init = 0
>>>> parent_modify_c = {old_entry = 0x0, new_entry = 0x0, smods =
0x0, attr_encrypt = 0}
>>>> ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0,
attr_encrypt = 0}
>>>> ...
>>>>
>>> What distribution are you using and what version of 389-ds?
>>>
>> Centos7
>>
>> [root@linge ~]# rpm -qa 389\*
>> 389-ds-base-debuginfo-1.3.9.1-13.el7_7.x86_64
>> 389-ds-base-libs-1.3.9.1-13.el7_7.x86_64
>> 389-ds-base-1.3.9.1-13.el7_7.x86_64
>>
>> [root@linge ~]# rpm -qa centos-release
>> centos-release-7-7.1908.0.el7.centos.x86_64
>>
>>
> This is a known bug [1].
> With the same bug there are two deadlock scenario but only one is fixed (for example
in slapi-nis-0.56.4-1 [2]).
> A fix for the second one is under tests.
>
> At the moment I would recommend the workaround [3]. The drawback is a growth of the
retroCL database but unless you have a very high rate of update it should not be a
concern.
>
> [1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
> [2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
> [3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
OK, thanks for the help. I will try that.
Two remarks.
1) I did an update a few days ago. (1.3.8.4-18.el7_6 => 1.3.9.1-13.el7_7). Then two
days after the update this hang started to happen.
2) the nasty thing about this is, that 398-ds was still alive, but all connections to it
hang forever (even "ipactl restart")
Thanks. Indeed DS keeps accepting incoming connections but operation are
very likely to be stuck by the deadlock.
The problem is in one DS plugin from slapi-nis package. Starting 0.56.3,
this plugin can hit the deadlock.
regards
thierry
7:40 a.m.
Sorry to revive an old thread. I'm getting deadlocks again. See below
On 20-04-2020 15:16, thierry bordaz wrote:
[...]This is a known bug [1].
With the same bug there are two deadlock scenario but only one is fixed (for example in
slapi-nis-0.56.4-1 [2]).
A fix for the second one is under tests.
At the moment I would recommend the workaround [3]. The drawback is a growth of the
retroCL database but unless you have a very high rate of update it should not be a
concern.
[1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
[2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
[3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
best regards
thierry
I followed the recommendation to set nsslapd-changelogmaxage to -1. The system
has been running successfully for a year.
Recently I upgraded all packages in this CentOS7 system. Ever since that moment
the server is quite unusable.
[root@linge ~]# gdb -ex 'set confirm off' -ex 'set pagination off' -ex
'thread apply all bt full' -ex 'quit' /usr/sbin/ns-slapd `pidof ns-slapd`
|& grep '^#0.*lock'
#0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0
#0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
[root@linge ~]# rpm -qa 389\*
389-ds-base-libs-1.3.10.2-10.el7_9.x86_64
389-ds-base-1.3.10.2-10.el7_9.x86_64
389-ds-base-debuginfo-1.3.10.2-10.el7_9.x86_64
[root@linge ~]# rpm -qa slapi\*
slapi-nis-0.56.5-3.el7_9.x86_64
[root@linge ~]# rpm -qa centos-release
centos-release-7-9.2009.1.el7.centos.x86_64
Are there any new hints to avoid the deadlock?
--
Kees
8:49 a.m.
Hi Kees,
Is changelogmaxage=-1 after the upgrade ?
would you send a full pstack when it hangs ? If pthread_rwlock_wrlock is
trim_changelog then you may hit another flavor of [1] (without known
reason).
regards
thierry
On 5/12/21 2:40 PM, Kees Bakker wrote:
Sorry to revive an old thread. I'm getting deadlocks again. See
below
On 20-04-2020 15:16, thierry bordaz wrote:
> [...]This is a known bug [1].
> With the same bug there are two deadlock scenario but only one is
> fixed (for example in slapi-nis-0.56.4-1 [2]).
> A fix for the second one is under tests.
>
> At the moment I would recommend the workaround [3]. The drawback is a
> growth of the retroCL database but unless you have a very high rate
> of update it should not be a concern.
>
> [1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
> [2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
> [3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
>
> best regards
> thierry
>
I followed the recommendation to set nsslapd-changelogmaxage to -1.
The system
has been running successfully for a year.
Recently I upgraded all packages in this CentOS7 system. Ever since
that moment
the server is quite unusable.
[root@linge ~]# gdb -ex 'set confirm off' -ex 'set pagination off' -ex
'thread apply all bt full' -ex 'quit' /usr/sbin/ns-slapd `pidof
ns-slapd` |& grep '^#0.*lock'
#0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
/lib64/libpthread.so.0
#0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
/lib64/libpthread.so.0
[root@linge ~]# rpm -qa 389\*
389-ds-base-libs-1.3.10.2-10.el7_9.x86_64
389-ds-base-1.3.10.2-10.el7_9.x86_64
389-ds-base-debuginfo-1.3.10.2-10.el7_9.x86_64
[root@linge ~]# rpm -qa slapi\*
slapi-nis-0.56.5-3.el7_9.x86_64
[root@linge ~]# rpm -qa centos-release
centos-release-7-9.2009.1.el7.centos.x86_64
Are there any new hints to avoid the deadlock?
9:55 a.m.
Hi Thierry,
Just to be clear, changelogmaxage was changed to -1 by me after the upgrade and I've
confirmed it is now set to -1.
The reason for me to change the value was because of the deadlock.
Apparently, it did not make much of a difference. It still gets into a deadlock
with the value -1.
BTW. I've sent the whole stacktrace directly to you to avoid the 4000+ lines to
this mailing list.
Here is the stack trace of one of the threads. The one that hangs in trim_changelog
Thread 2 (Thread 0x7f96ede68700 (LWP 2151)):
#0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0
#1 0x00007f96da9d281f in map_wrlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007f96da9c1e58 in backend_shr_delete_cb.part.5 () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#3 0x00007f96da9c1fd1 in backend_shr_betxn_post_delete_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#4 0x00007f96ed7ec688 in plugin_call_func (list=0x55cb03cdd8c0,
operation=operation@entry=563, pb=pb@entry=0x55cb4c670fc0, call_one=call_one@entry=0) at
ldap/servers/slapd/plugin.c:2028
n = <optimized out>
func = 0x7f96da9c1f70 <backend_shr_betxn_post_delete_cb>
rc = <optimized out>
return_value = 0
count = 2
#5 0x00007f96ed7ec943 in plugin_call_list (pb=0x55cb4c670fc0, operation=563,
list=<optimized out>) at ldap/servers/slapd/plugin.c:1972
p = 0x55cb03cb0000
locked = <optimized out>
plugin_list_number = 21
rc = 0
do_op = <optimized out>
#6 0x00007f96ed7ec943 in plugin_call_plugins (pb=pb@entry=0x55cb4c670fc0,
whichfunction=whichfunction@entry=563) at ldap/servers/slapd/plugin.c:442
p = 0x55cb03cb0000
locked = <optimized out>
plugin_list_number = 21
rc = 0
do_op = <optimized out>
#7 0x00007f96dc990def in ldbm_back_delete (pb=0x55cb4c670fc0) at
ldap/servers/slapd/back-ldbm/ldbm_delete.c:1267
be = 0x55cb03c31040
inst = 0x55cb03a8c680
li = 0x55cb03a017c0
e = 0x55cb15499a40
tombstone = 0x0
original_tombstone = 0x0
tmptombstone = 0x0
dn = 0x55cb1742a600 "changenumber=891343,cn=changelog"
txn = {back_txn_txn = 0x55cb2b7b6dc0}
parent_txn = 0x0
retval = 0
msg = <optimized out>
errbuf = 0x0
retry_count = <optimized out>
disk_full = 0
parent_found = <optimized out>
ruv_c_init = 0
parent_modify_c = {old_entry = 0x55cb159982a0, new_entry = 0x55cb19e03030, smods
= 0x55cb47da1ae0, attr_encrypt = 1}
ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0, attr_encrypt = 0}
rc = 0
ldap_result_code = 0
ldap_result_message = 0x0
sdnp = 0x55cb5fd93bc0
e_uniqueid = 0x0
nscpEntrySDN = {flag = 0 '\000', udn = 0x0, dn = 0x0, ndn = 0x0, ndn_len
= 0}
operation = 0x55cb5ef86000
opcsn = 0x0
is_fixup_operation = 0
is_ruv = 0
is_replicated_operation = 0
is_tombstone_entry = <optimized out>
delete_tombstone_entry = 0
create_tombstone_entry = 0
addr = 0x55cb5ef86100
addordel_flags = 38
entryusn_str = 0x0
orig_entry = 0x0
parentsdn = {flag = 2 '\002', udn = 0x0, dn = 0x55cb516c3580
"cn=changelog", ndn = 0x0, ndn_len = 12}
opreturn = 0
free_delete_existing_entry = 1
not_an_error = 0
parent_switched = 0
myrc = 0
conn_id = 0
tombstone_csn = <optimized out>
deletion_csn_str =
"\247\001\000\000\000\000\000\000\000T\334YHi\365\357\300\017g", <incomplete
sequence \313>
op_id = 0
ep_id = <optimized out>
tomb_ep_id = 0
result_sent = 0
pb_conn = 0x0
parent_op = 1
parent_time = {tv_sec = 183860, tv_nsec = 41743941}
#8 0x00007f96ed79d3bb in op_shared_delete (pb=pb@entry=0x55cb4c670fc0) at
ldap/servers/slapd/delete.c:324
rc = 0
rawdn = 0x55cb5b28de00 "changenumber=891343, cn=changelog"
dn = <optimized out>
be = 0x55cb03c31040
internal_op = 32
sdn = 0x55cb5fd93bc0
operation = 0x55cb5ef86000
referral = 0x0
ecopy = 0x0
errorbuf = "\000\066\062\062Z\nmodifyTime", '\000' <repeats
16 times>, "\071\063\066\062\062Z\nnsUniqueI", '\000' <repeats 16
times>,
"\327\320~\003ڇ\316c!\f=\037$z\215\301;\215\006\065\341\n\310V\300\006\365I\344|x\210\216\f\215\060e\243S\350\000T\334YHi\365\357\016\237V\202\332PG\347\300\070\314\003\313U\000\000\300\070\314\003\313U\000\000\000T\334YHi\365\357\000\000\000\000\000\000\000\000\300\070\314\003\313U\000\000\300\070\314\003\313U\000\000\240<\250\355\226\177\000\000\000\243\002\000\000\000\000\000p|\346\355\226\177\000\000ϙ\r\000\000\000\000\000\312\360"...
err = <optimized out>
proxydn = 0x0
proxystr = 0x0
proxy_err = <optimized out>
errtext = 0x0
#9 0x00007f96ed79d598 in delete_internal_pb (pb=pb@entry=0x55cb4c670fc0) at
ldap/servers/slapd/delete.c:208
controls = 0x0
op = 0x55cb5ef86000
opresult = 0
#10 0x00007f96ed79d813 in slapi_delete_internal_pb (pb=pb@entry=0x55cb4c670fc0) at
ldap/servers/slapd/delete.c:151
#11 0x00007f96daff731e in delete_changerecord (cnum=cnum@entry=891343) at
ldap/servers/plugins/retrocl/retrocl_trim.c:89
pb = 0x55cb4c670fc0
dnbuf = 0x55cb5b28de00 "changenumber=891343, cn=changelog"
delrc = 32662
#12 0x00007f96daff7605 in trim_changelog () at
ldap/servers/plugins/retrocl/retrocl_trim.c:290
did_delete = 0
done = 0
last_in_log = <optimized out>
me = 172800
lt = <optimized out>
ldrc = <optimized out>
now = 1620819600
first_in_log = 891343
num_deleted = 3655
#13 0x00007f96daff7605 in changelog_trim_thread_fn (arg=<optimized out>) at
ldap/servers/plugins/retrocl/retrocl_trim.c:333
#14 0x00007f96eb595c5b in _pt_root () at /lib64/libnspr4.so
#15 0x00007f96eaf35ea5 in start_thread () at /lib64/libpthread.so.0
#16 0x00007f96ea5e19fd in clone () at /lib64/libc.so.6
-- Kees
On 12-05-2021 15:49, Thierry Bordaz wrote:
Hi Kees,
Is changelogmaxage=-1 after the upgrade ?
would you send a full pstack when it hangs ? If pthread_rwlock_wrlock is
trim_changelog then you may hit another flavor of [1] (without known
reason).
regards
thierry
On 5/12/21 2:40 PM, Kees Bakker wrote:
> Sorry to revive an old thread. I'm getting deadlocks again. See below
>
> On 20-04-2020 15:16, thierry bordaz wrote:
>> [...]This is a known bug [1].
>> With the same bug there are two deadlock scenario but only one is
>> fixed (for example in slapi-nis-0.56.4-1 [2]).
>> A fix for the second one is under tests.
>>
>> At the moment I would recommend the workaround [3]. The drawback is a
>> growth of the retroCL database but unless you have a very high rate
>> of update it should not be a concern.
>>
>> [1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
>> [2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
>> [3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
>>
>> best regards
>> thierry
>>
>
> I followed the recommendation to set nsslapd-changelogmaxage to -1.
> The system
> has been running successfully for a year.
>
> Recently I upgraded all packages in this CentOS7 system. Ever since
> that moment
> the server is quite unusable.
>
> [root@linge ~]# gdb -ex 'set confirm off' -ex 'set pagination off'
-ex
> 'thread apply all bt full' -ex 'quit' /usr/sbin/ns-slapd `pidof
> ns-slapd` |& grep '^#0.*lock'
> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
> /lib64/libpthread.so.0
> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
> /lib64/libpthread.so.0
>
> [root@linge ~]# rpm -qa 389\*
> 389-ds-base-libs-1.3.10.2-10.el7_9.x86_64
> 389-ds-base-1.3.10.2-10.el7_9.x86_64
> 389-ds-base-debuginfo-1.3.10.2-10.el7_9.x86_64
>
> [root@linge ~]# rpm -qa slapi\*
> slapi-nis-0.56.5-3.el7_9.x86_64
>
> [root@linge ~]# rpm -qa centos-release
> centos-release-7-9.2009.1.el7.centos.x86_64
>
> Are there any new hints to avoid the deadlock?
12:44 p.m.
On 5/12/21 4:55 PM, Kees Bakker wrote:
Hi Thierry,
Just to be clear, changelogmaxage was changed to -1 by me after the
upgrade and I've
confirmed it is now set to -1.
The reason for me to change the value was because of the deadlock.
Apparently, it did not make much of a difference. It still gets into a
deadlock
with the value -1.
Did you set nsslapd-changelogmaxage=-1 in the retroCL config entry ?
BTW. I've sent the whole stacktrace directly to you to avoid the 4000+
lines to
this mailing list.
Here is the stack trace of one of the threads. The one that hangs in
trim_changelog
Something weird is that the same hang occurs
https://bugzilla.redhat.com/show_bug.cgi?id=1751295.
If I am correct it is between thread 14th and 2nd.
As you are running with a fixed version (> slapi-nis-0.56.5), that means
the fix is incomplete. It would require to debug a dump core to know why
the fix fails.
regards
thierry
Thread 2 (Thread 0x7f96ede68700 (LWP 2151)):
#0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
/lib64/libpthread.so.0
#1 0x00007f96da9d281f in map_wrlock () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#2 0x00007f96da9c1e58 in backend_shr_delete_cb.part.5 () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#3 0x00007f96da9c1fd1 in backend_shr_betxn_post_delete_cb () at
/usr/lib64/dirsrv/plugins/schemacompat-plugin.so
#4 0x00007f96ed7ec688 in plugin_call_func (list=0x55cb03cdd8c0,
operation=operation@entry=563, pb=pb@entry=0x55cb4c670fc0,
call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
n = <optimized out>
func = 0x7f96da9c1f70 <backend_shr_betxn_post_delete_cb>
rc = <optimized out>
return_value = 0
count = 2
#5 0x00007f96ed7ec943 in plugin_call_list (pb=0x55cb4c670fc0,
operation=563, list=<optimized out>) at ldap/servers/slapd/plugin.c:1972
p = 0x55cb03cb0000
locked = <optimized out>
plugin_list_number = 21
rc = 0
do_op = <optimized out>
#6 0x00007f96ed7ec943 in plugin_call_plugins
(pb=pb@entry=0x55cb4c670fc0, whichfunction=whichfunction@entry=563) at
ldap/servers/slapd/plugin.c:442
p = 0x55cb03cb0000
locked = <optimized out>
plugin_list_number = 21
rc = 0
do_op = <optimized out>
#7 0x00007f96dc990def in ldbm_back_delete (pb=0x55cb4c670fc0) at
ldap/servers/slapd/back-ldbm/ldbm_delete.c:1267
be = 0x55cb03c31040
inst = 0x55cb03a8c680
li = 0x55cb03a017c0
e = 0x55cb15499a40
tombstone = 0x0
original_tombstone = 0x0
tmptombstone = 0x0
dn = 0x55cb1742a600 "changenumber=891343,cn=changelog"
txn = {back_txn_txn = 0x55cb2b7b6dc0}
parent_txn = 0x0
retval = 0
msg = <optimized out>
errbuf = 0x0
retry_count = <optimized out>
disk_full = 0
parent_found = <optimized out>
ruv_c_init = 0
parent_modify_c = {old_entry = 0x55cb159982a0, new_entry =
0x55cb19e03030, smods = 0x55cb47da1ae0, attr_encrypt = 1}
ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0,
attr_encrypt = 0}
rc = 0
ldap_result_code = 0
ldap_result_message = 0x0
sdnp = 0x55cb5fd93bc0
e_uniqueid = 0x0
nscpEntrySDN = {flag = 0 '\000', udn = 0x0, dn = 0x0, ndn =
0x0, ndn_len = 0}
operation = 0x55cb5ef86000
opcsn = 0x0
is_fixup_operation = 0
is_ruv = 0
is_replicated_operation = 0
is_tombstone_entry = <optimized out>
delete_tombstone_entry = 0
create_tombstone_entry = 0
addr = 0x55cb5ef86100
addordel_flags = 38
entryusn_str = 0x0
orig_entry = 0x0
parentsdn = {flag = 2 '\002', udn = 0x0, dn = 0x55cb516c3580
"cn=changelog", ndn = 0x0, ndn_len = 12}
opreturn = 0
free_delete_existing_entry = 1
not_an_error = 0
parent_switched = 0
myrc = 0
conn_id = 0
tombstone_csn = <optimized out>
deletion_csn_str =
"\247\001\000\000\000\000\000\000\000T\334YHi\365\357\300\017g",
<incomplete sequence \313>
op_id = 0
ep_id = <optimized out>
tomb_ep_id = 0
result_sent = 0
pb_conn = 0x0
parent_op = 1
parent_time = {tv_sec = 183860, tv_nsec = 41743941}
#8 0x00007f96ed79d3bb in op_shared_delete
(pb=pb@entry=0x55cb4c670fc0) at ldap/servers/slapd/delete.c:324
rc = 0
rawdn = 0x55cb5b28de00 "changenumber=891343, cn=changelog"
dn = <optimized out>
be = 0x55cb03c31040
internal_op = 32
sdn = 0x55cb5fd93bc0
operation = 0x55cb5ef86000
referral = 0x0
ecopy = 0x0
errorbuf = "\000\066\062\062Z\nmodifyTime", '\000' <repeats
16
times>, "\071\063\066\062\062Z\nnsUniqueI", '\000' <repeats 16
times>,
"\327\320~\003ڇ\316c!\f=\037$z\215\301;\215\006\065\341\n\310V\300\006\365I\344|x\210\216\f\215\060e\243S\350\000T\334YHi\365\357\016\237V\202\332PG\347\300\070\314\003\313U\000\000\300\070\314\003\313U\000\000\000T\334YHi\365\357\000\000\000\000\000\000\000\000\300\070\314\003\313U\000\000\300\070\314\003\313U\000\000\240<\250\355\226\177\000\000\000\243\002\000\000\000\000\000p|\346\355\226\177\000\000ϙ\r\000\000\000\000\000\312\360"...
err = <optimized out>
proxydn = 0x0
proxystr = 0x0
proxy_err = <optimized out>
errtext = 0x0
#9 0x00007f96ed79d598 in delete_internal_pb
(pb=pb@entry=0x55cb4c670fc0) at ldap/servers/slapd/delete.c:208
controls = 0x0
op = 0x55cb5ef86000
opresult = 0
#10 0x00007f96ed79d813 in slapi_delete_internal_pb
(pb=pb@entry=0x55cb4c670fc0) at ldap/servers/slapd/delete.c:151
#11 0x00007f96daff731e in delete_changerecord (cnum=cnum@entry=891343)
at ldap/servers/plugins/retrocl/retrocl_trim.c:89
pb = 0x55cb4c670fc0
dnbuf = 0x55cb5b28de00 "changenumber=891343, cn=changelog"
delrc = 32662
#12 0x00007f96daff7605 in trim_changelog () at
ldap/servers/plugins/retrocl/retrocl_trim.c:290
did_delete = 0
done = 0
last_in_log = <optimized out>
me = 172800
lt = <optimized out>
ldrc = <optimized out>
now = 1620819600
first_in_log = 891343
num_deleted = 3655
#13 0x00007f96daff7605 in changelog_trim_thread_fn (arg=<optimized
out>) at ldap/servers/plugins/retrocl/retrocl_trim.c:333
#14 0x00007f96eb595c5b in _pt_root () at /lib64/libnspr4.so
#15 0x00007f96eaf35ea5 in start_thread () at /lib64/libpthread.so.0
#16 0x00007f96ea5e19fd in clone () at /lib64/libc.so.6
-- Kees
On 12-05-2021 15:49, Thierry Bordaz wrote:
> Hi Kees,
>
> Is changelogmaxage=-1 after the upgrade ?
>
> would you send a full pstack when it hangs ? If pthread_rwlock_wrlock is
> trim_changelog then you may hit another flavor of [1] (without known
> reason).
>
> regards
> thierry
>
> On 5/12/21 2:40 PM, Kees Bakker wrote:
>> Sorry to revive an old thread. I'm getting deadlocks again. See below
>>
>> On 20-04-2020 15:16, thierry bordaz wrote:
>>> [...]This is a known bug [1].
>>> With the same bug there are two deadlock scenario but only one is
>>> fixed (for example in slapi-nis-0.56.4-1 [2]).
>>> A fix for the second one is under tests.
>>>
>>> At the moment I would recommend the workaround [3]. The drawback is a
>>> growth of the retroCL database but unless you have a very high rate
>>> of update it should not be a concern.
>>>
>>> [1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
>>> [2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
>>> [3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
>>>
>>> best regards
>>> thierry
>>>
>>
>> I followed the recommendation to set nsslapd-changelogmaxage to -1.
>> The system
>> has been running successfully for a year.
>>
>> Recently I upgraded all packages in this CentOS7 system. Ever since
>> that moment
>> the server is quite unusable.
>>
>> [root@linge ~]# gdb -ex 'set confirm off' -ex 'set pagination
off' -ex
>> 'thread apply all bt full' -ex 'quit' /usr/sbin/ns-slapd `pidof
>> ns-slapd` |& grep '^#0.*lock'
>> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>> /lib64/libpthread.so.0
>> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
>> /lib64/libpthread.so.0
>>
>> [root@linge ~]# rpm -qa 389\*
>> 389-ds-base-libs-1.3.10.2-10.el7_9.x86_64
>> 389-ds-base-1.3.10.2-10.el7_9.x86_64
>> 389-ds-base-debuginfo-1.3.10.2-10.el7_9.x86_64
>>
>> [root@linge ~]# rpm -qa slapi\*
>> slapi-nis-0.56.5-3.el7_9.x86_64
>>
>> [root@linge ~]# rpm -qa centos-release
>> centos-release-7-9.2009.1.el7.centos.x86_64
>>
>> Are there any new hints to avoid the deadlock?
>
1:41 p.m.
On 12-05-2021 19:44, Thierry Bordaz wrote:
On 5/12/21 4:55 PM, Kees Bakker wrote:
> Hi Thierry,
>
> Just to be clear, changelogmaxage was changed to -1 by me after the
> upgrade and I've
> confirmed it is now set to -1.
>
> The reason for me to change the value was because of the deadlock.
> Apparently, it did not make much of a difference. It still gets into a
> deadlock
> with the value -1.
Did you set nsslapd-changelogmaxage=-1 in the retroCL config entry ?
I've used this input file for ldapmodify
[root@linge ~]# cat change-nsslapd-changelogmaxage.txt
dn: cn=Retro Changelog Plugin,cn=plugins,cn=config
changetype: modify
replace: nsslapd-changelogmaxage
nsslapd-changelogmaxage: -1
After that
[root@linge ~]# ldapsearch -H ldapi://%2fvar%2frun%2fslapd-GHS-NL.socket -LLL -o
ldif-wrap=no -b 'cn=Retro Changelog Plugin,cn=plugins,cn=config'
SASL/EXTERNAL authentication started
SASL username: gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
SASL SSF: 0
dn: cn=Retro Changelog Plugin,cn=plugins,cn=config
cn: Retro Changelog Plugin
nsslapd-attribute: nsuniqueid:targetUniqueId
nsslapd-changelogmaxage: -1
nsslapd-include-suffix: cn=dns,dc=ghs,dc=nl
nsslapd-plugin-depends-on-named: Class of Service
nsslapd-plugin-depends-on-type: database
nsslapd-pluginDescription: Retrocl Plugin
nsslapd-pluginEnabled: on
nsslapd-pluginId: retrocl
nsslapd-pluginInitfunc: retrocl_plugin_init
nsslapd-pluginPath: libretrocl-plugin
nsslapd-pluginType: object
nsslapd-pluginVendor: 389 Project
nsslapd-pluginVersion: 1.3.10.2
nsslapd-pluginbetxn: on
nsslapd-pluginprecedence: 25
objectClass: top
objectClass: nsSlapdPlugin
objectClass: extensibleObject
>
> BTW. I've sent the whole stacktrace directly to you to avoid the 4000+
> lines to
> this mailing list.
>
> Here is the stack trace of one of the threads. The one that hangs in
> trim_changelog
Something weird is that the same hang occurs
https://bugzilla.redhat.com/show_bug.cgi?id=1751295.
If I am correct it is between thread 14th and 2nd.
As you are running with a fixed version (> slapi-nis-0.56.5), that means
the fix is incomplete. It would require to debug a dump core to know why
the fix fails.
[root@linge ~]# rpm -qa slapi\*
slapi-nis-0.56.5-3.el7_9.x86_64
So, that is not > 0.56.5, but it is the newest available for CentOS7. No?
At the moment I killed it and restarted. No deadlock yet, but the system is extreemly
slow. And there is just ns-slapd using CPU cycles.
regards
thierry
>
>
> Thread 2 (Thread 0x7f96ede68700 (LWP 2151)):
> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
> /lib64/libpthread.so.0
> #1 0x00007f96da9d281f in map_wrlock () at
> /usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #2 0x00007f96da9c1e58 in backend_shr_delete_cb.part.5 () at
> /usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #3 0x00007f96da9c1fd1 in backend_shr_betxn_post_delete_cb () at
> /usr/lib64/dirsrv/plugins/schemacompat-plugin.so
> #4 0x00007f96ed7ec688 in plugin_call_func (list=0x55cb03cdd8c0,
> operation=operation@entry=563, pb=pb@entry=0x55cb4c670fc0,
> call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
> n = <optimized out>
> func = 0x7f96da9c1f70 <backend_shr_betxn_post_delete_cb>
> rc = <optimized out>
> return_value = 0
> count = 2
> #5 0x00007f96ed7ec943 in plugin_call_list (pb=0x55cb4c670fc0,
> operation=563, list=<optimized out>) at ldap/servers/slapd/plugin.c:1972
> p = 0x55cb03cb0000
> locked = <optimized out>
> plugin_list_number = 21
> rc = 0
> do_op = <optimized out>
> #6 0x00007f96ed7ec943 in plugin_call_plugins
> (pb=pb@entry=0x55cb4c670fc0, whichfunction=whichfunction@entry=563) at
> ldap/servers/slapd/plugin.c:442
> p = 0x55cb03cb0000
> locked = <optimized out>
> plugin_list_number = 21
> rc = 0
> do_op = <optimized out>
> #7 0x00007f96dc990def in ldbm_back_delete (pb=0x55cb4c670fc0) at
> ldap/servers/slapd/back-ldbm/ldbm_delete.c:1267
> be = 0x55cb03c31040
> inst = 0x55cb03a8c680
> li = 0x55cb03a017c0
> e = 0x55cb15499a40
> tombstone = 0x0
> original_tombstone = 0x0
> tmptombstone = 0x0
> dn = 0x55cb1742a600 "changenumber=891343,cn=changelog"
> txn = {back_txn_txn = 0x55cb2b7b6dc0}
> parent_txn = 0x0
> retval = 0
> msg = <optimized out>
> errbuf = 0x0
> retry_count = <optimized out>
> disk_full = 0
> parent_found = <optimized out>
> ruv_c_init = 0
> parent_modify_c = {old_entry = 0x55cb159982a0, new_entry =
> 0x55cb19e03030, smods = 0x55cb47da1ae0, attr_encrypt = 1}
> ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0,
> attr_encrypt = 0}
> rc = 0
> ldap_result_code = 0
> ldap_result_message = 0x0
> sdnp = 0x55cb5fd93bc0
> e_uniqueid = 0x0
> nscpEntrySDN = {flag = 0 '\000', udn = 0x0, dn = 0x0, ndn =
> 0x0, ndn_len = 0}
> operation = 0x55cb5ef86000
> opcsn = 0x0
> is_fixup_operation = 0
> is_ruv = 0
> is_replicated_operation = 0
> is_tombstone_entry = <optimized out>
> delete_tombstone_entry = 0
> create_tombstone_entry = 0
> addr = 0x55cb5ef86100
> addordel_flags = 38
> entryusn_str = 0x0
> orig_entry = 0x0
> parentsdn = {flag = 2 '\002', udn = 0x0, dn = 0x55cb516c3580
> "cn=changelog", ndn = 0x0, ndn_len = 12}
> opreturn = 0
> free_delete_existing_entry = 1
> not_an_error = 0
> parent_switched = 0
> myrc = 0
> conn_id = 0
> tombstone_csn = <optimized out>
> deletion_csn_str =
> "\247\001\000\000\000\000\000\000\000T\334YHi\365\357\300\017g",
> <incomplete sequence \313>
> op_id = 0
> ep_id = <optimized out>
> tomb_ep_id = 0
> result_sent = 0
> pb_conn = 0x0
> parent_op = 1
> parent_time = {tv_sec = 183860, tv_nsec = 41743941}
> #8 0x00007f96ed79d3bb in op_shared_delete
> (pb=pb@entry=0x55cb4c670fc0) at ldap/servers/slapd/delete.c:324
> rc = 0
> rawdn = 0x55cb5b28de00 "changenumber=891343, cn=changelog"
> dn = <optimized out>
> be = 0x55cb03c31040
> internal_op = 32
> sdn = 0x55cb5fd93bc0
> operation = 0x55cb5ef86000
> referral = 0x0
> ecopy = 0x0
> errorbuf = "\000\066\062\062Z\nmodifyTime", '\000'
<repeats 16
> times>, "\071\063\066\062\062Z\nnsUniqueI", '\000' <repeats
16 times>,
>
"\327\320~\003ڇ\316c!\f=\037$z\215\301;\215\006\065\341\n\310V\300\006\365I\344|x\210\216\f\215\060e\243S\350\000T\334YHi\365\357\016\237V\202\332PG\347\300\070\314\003\313U\000\000\300\070\314\003\313U\000\000\000T\334YHi\365\357\000\000\000\000\000\000\000\000\300\070\314\003\313U\000\000\300\070\314\003\313U\000\000\240<\250\355\226\177\000\000\000\243\002\000\000\000\000\000p|\346\355\226\177\000\000ϙ\r\000\000\000\000\000\312\360"...
> err = <optimized out>
> proxydn = 0x0
> proxystr = 0x0
> proxy_err = <optimized out>
> errtext = 0x0
> #9 0x00007f96ed79d598 in delete_internal_pb
> (pb=pb@entry=0x55cb4c670fc0) at ldap/servers/slapd/delete.c:208
> controls = 0x0
> op = 0x55cb5ef86000
> opresult = 0
> #10 0x00007f96ed79d813 in slapi_delete_internal_pb
> (pb=pb@entry=0x55cb4c670fc0) at ldap/servers/slapd/delete.c:151
> #11 0x00007f96daff731e in delete_changerecord (cnum=cnum@entry=891343)
> at ldap/servers/plugins/retrocl/retrocl_trim.c:89
> pb = 0x55cb4c670fc0
> dnbuf = 0x55cb5b28de00 "changenumber=891343, cn=changelog"
> delrc = 32662
> #12 0x00007f96daff7605 in trim_changelog () at
> ldap/servers/plugins/retrocl/retrocl_trim.c:290
> did_delete = 0
> done = 0
> last_in_log = <optimized out>
> me = 172800
> lt = <optimized out>
> ldrc = <optimized out>
> now = 1620819600
> first_in_log = 891343
> num_deleted = 3655
> #13 0x00007f96daff7605 in changelog_trim_thread_fn (arg=<optimized
> out>) at ldap/servers/plugins/retrocl/retrocl_trim.c:333
> #14 0x00007f96eb595c5b in _pt_root () at /lib64/libnspr4.so
> #15 0x00007f96eaf35ea5 in start_thread () at /lib64/libpthread.so.0
> #16 0x00007f96ea5e19fd in clone () at /lib64/libc.so.6
>
> -- Kees
>
> On 12-05-2021 15:49, Thierry Bordaz wrote:
>> Hi Kees,
>>
>> Is changelogmaxage=-1 after the upgrade ?
>>
>> would you send a full pstack when it hangs ? If pthread_rwlock_wrlock is
>> trim_changelog then you may hit another flavor of [1] (without known
>> reason).
>>
>> regards
>> thierry
>>
>> On 5/12/21 2:40 PM, Kees Bakker wrote:
>>> Sorry to revive an old thread. I'm getting deadlocks again. See below
>>>
>>> On 20-04-2020 15:16, thierry bordaz wrote:
>>>> [...]This is a known bug [1].
>>>> With the same bug there are two deadlock scenario but only one is
>>>> fixed (for example in slapi-nis-0.56.4-1 [2]).
>>>> A fix for the second one is under tests.
>>>>
>>>> At the moment I would recommend the workaround [3]. The drawback is a
>>>> growth of the retroCL database but unless you have a very high rate
>>>> of update it should not be a concern.
>>>>
>>>> [1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
>>>> [2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
>>>> [3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
>>>>
>>>> best regards
>>>> thierry
>>>>
>>>
>>> I followed the recommendation to set nsslapd-changelogmaxage to -1.
>>> The system
>>> has been running successfully for a year.
>>>
>>> Recently I upgraded all packages in this CentOS7 system. Ever since
>>> that moment
>>> the server is quite unusable.
>>>
>>> [root@linge ~]# gdb -ex 'set confirm off' -ex 'set pagination
off' -ex
>>> 'thread apply all bt full' -ex 'quit' /usr/sbin/ns-slapd
`pidof
>>> ns-slapd` |& grep '^#0.*lock'
>>> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>> /lib64/libpthread.so.0
>>> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
>>> /lib64/libpthread.so.0
>>>
>>> [root@linge ~]# rpm -qa 389\*
>>> 389-ds-base-libs-1.3.10.2-10.el7_9.x86_64
>>> 389-ds-base-1.3.10.2-10.el7_9.x86_64
>>> 389-ds-base-debuginfo-1.3.10.2-10.el7_9.x86_64
>>>
>>> [root@linge ~]# rpm -qa slapi\*
>>> slapi-nis-0.56.5-3.el7_9.x86_64
>>>
>>> [root@linge ~]# rpm -qa centos-release
>>> centos-release-7-9.2009.1.el7.centos.x86_64
>>>
>>> Are there any new hints to avoid the deadlock?
>>
>
1:32 a.m.
On 5/12/21 8:41 PM, Kees Bakker wrote:
On 12-05-2021 19:44, Thierry Bordaz wrote:
> On 5/12/21 4:55 PM, Kees Bakker wrote:
>> Hi Thierry,
>>
>> Just to be clear, changelogmaxage was changed to -1 by me after the
>> upgrade and I've
>> confirmed it is now set to -1.
>>
>> The reason for me to change the value was because of the deadlock.
>> Apparently, it did not make much of a difference. It still gets into a
>> deadlock
>> with the value -1.
>
>
> Did you set nsslapd-changelogmaxage=-1 in the retroCL config entry ?
I've used this input file for ldapmodify
[root@linge ~]# cat change-nsslapd-changelogmaxage.txt
dn: cn=Retro Changelog Plugin,cn=plugins,cn=config
changetype: modify
replace: nsslapd-changelogmaxage
nsslapd-changelogmaxage: -1
After that
[root@linge ~]# ldapsearch -H
ldapi://%2fvar%2frun%2fslapd-GHS-NL.socket -LLL -o ldif-wrap=no -b
'cn=Retro Changelog Plugin,cn=plugins,cn=config'
SASL/EXTERNAL authentication started
SASL username: gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
SASL SSF: 0
dn: cn=Retro Changelog Plugin,cn=plugins,cn=config
cn: Retro Changelog Plugin
nsslapd-attribute: nsuniqueid:targetUniqueId
nsslapd-changelogmaxage: -1
nsslapd-include-suffix: cn=dns,dc=ghs,dc=nl
nsslapd-plugin-depends-on-named: Class of Service
nsslapd-plugin-depends-on-type: database
nsslapd-pluginDescription: Retrocl Plugin
nsslapd-pluginEnabled: on
nsslapd-pluginId: retrocl
nsslapd-pluginInitfunc: retrocl_plugin_init
nsslapd-pluginPath: libretrocl-plugin
nsslapd-pluginType: object
nsslapd-pluginVendor: 389 Project
nsslapd-pluginVersion: 1.3.10.2
nsslapd-pluginbetxn: on
nsslapd-pluginprecedence: 25
objectClass: top
objectClass: nsSlapdPlugin
objectClass: extensibleObject
You did the right setting. I do not understand why thread 2 is trimming
records with that setting.
>
>
>>
>> BTW. I've sent the whole stacktrace directly to you to avoid the 4000+
>> lines to
>> this mailing list.
>>
>> Here is the stack trace of one of the threads. The one that hangs in
>> trim_changelog
>
>
> Something weird is that the same hang occurs
> https://bugzilla.redhat.com/show_bug.cgi?id=1751295.
> If I am correct it is between thread 14th and 2nd.
>
> As you are running with a fixed version (> slapi-nis-0.56.5), that means
> the fix is incomplete. It would require to debug a dump core to know why
> the fix fails.
[root@linge ~]# rpm -qa slapi\*
slapi-nis-0.56.5-3.el7_9.x86_64
So, that is not > 0.56.5, but it is the newest available for CentOS7. No?
reading the 'fixed version' in the bug says it if fixed starting 0.56.5
I do not know if it match centOS7 versions
At the moment I killed it and restarted. No deadlock yet, but the
system is extreemly
slow. And there is just ns-slapd using CPU cycles.
Would you give some precision what is slow ? (response time, replication
time,..)
If it is eating CPU, I would recommend 'top -H -p <pid> -b'. If it is
always the same thread(s) eating the CPU, a pstack will tell you what
it/they is/are doing. If this is various different threads likely it is
due to processed requests.
>
> regards
> thierry
>
>>
>>
>> Thread 2 (Thread 0x7f96ede68700 (LWP 2151)):
>> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
>> /lib64/libpthread.so.0
>> #1 0x00007f96da9d281f in map_wrlock () at
>> /usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #2 0x00007f96da9c1e58 in backend_shr_delete_cb.part.5 () at
>> /usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #3 0x00007f96da9c1fd1 in backend_shr_betxn_post_delete_cb () at
>> /usr/lib64/dirsrv/plugins/schemacompat-plugin.so
>> #4 0x00007f96ed7ec688 in plugin_call_func (list=0x55cb03cdd8c0,
>> operation=operation@entry=563, pb=pb@entry=0x55cb4c670fc0,
>> call_one=call_one@entry=0) at ldap/servers/slapd/plugin.c:2028
>> n = <optimized out>
>> func = 0x7f96da9c1f70 <backend_shr_betxn_post_delete_cb>
>> rc = <optimized out>
>> return_value = 0
>> count = 2
>> #5 0x00007f96ed7ec943 in plugin_call_list (pb=0x55cb4c670fc0,
>> operation=563, list=<optimized out>) at
>> ldap/servers/slapd/plugin.c:1972
>> p = 0x55cb03cb0000
>> locked = <optimized out>
>> plugin_list_number = 21
>> rc = 0
>> do_op = <optimized out>
>> #6 0x00007f96ed7ec943 in plugin_call_plugins
>> (pb=pb@entry=0x55cb4c670fc0, whichfunction=whichfunction@entry=563) at
>> ldap/servers/slapd/plugin.c:442
>> p = 0x55cb03cb0000
>> locked = <optimized out>
>> plugin_list_number = 21
>> rc = 0
>> do_op = <optimized out>
>> #7 0x00007f96dc990def in ldbm_back_delete (pb=0x55cb4c670fc0) at
>> ldap/servers/slapd/back-ldbm/ldbm_delete.c:1267
>> be = 0x55cb03c31040
>> inst = 0x55cb03a8c680
>> li = 0x55cb03a017c0
>> e = 0x55cb15499a40
>> tombstone = 0x0
>> original_tombstone = 0x0
>> tmptombstone = 0x0
>> dn = 0x55cb1742a600 "changenumber=891343,cn=changelog"
>> txn = {back_txn_txn = 0x55cb2b7b6dc0}
>> parent_txn = 0x0
>> retval = 0
>> msg = <optimized out>
>> errbuf = 0x0
>> retry_count = <optimized out>
>> disk_full = 0
>> parent_found = <optimized out>
>> ruv_c_init = 0
>> parent_modify_c = {old_entry = 0x55cb159982a0, new_entry =
>> 0x55cb19e03030, smods = 0x55cb47da1ae0, attr_encrypt = 1}
>> ruv_c = {old_entry = 0x0, new_entry = 0x0, smods = 0x0,
>> attr_encrypt = 0}
>> rc = 0
>> ldap_result_code = 0
>> ldap_result_message = 0x0
>> sdnp = 0x55cb5fd93bc0
>> e_uniqueid = 0x0
>> nscpEntrySDN = {flag = 0 '\000', udn = 0x0, dn = 0x0, ndn =
>> 0x0, ndn_len = 0}
>> operation = 0x55cb5ef86000
>> opcsn = 0x0
>> is_fixup_operation = 0
>> is_ruv = 0
>> is_replicated_operation = 0
>> is_tombstone_entry = <optimized out>
>> delete_tombstone_entry = 0
>> create_tombstone_entry = 0
>> addr = 0x55cb5ef86100
>> addordel_flags = 38
>> entryusn_str = 0x0
>> orig_entry = 0x0
>> parentsdn = {flag = 2 '\002', udn = 0x0, dn = 0x55cb516c3580
>> "cn=changelog", ndn = 0x0, ndn_len = 12}
>> opreturn = 0
>> free_delete_existing_entry = 1
>> not_an_error = 0
>> parent_switched = 0
>> myrc = 0
>> conn_id = 0
>> tombstone_csn = <optimized out>
>> deletion_csn_str =
>> "\247\001\000\000\000\000\000\000\000T\334YHi\365\357\300\017g",
>> <incomplete sequence \313>
>> op_id = 0
>> ep_id = <optimized out>
>> tomb_ep_id = 0
>> result_sent = 0
>> pb_conn = 0x0
>> parent_op = 1
>> parent_time = {tv_sec = 183860, tv_nsec = 41743941}
>> #8 0x00007f96ed79d3bb in op_shared_delete
>> (pb=pb@entry=0x55cb4c670fc0) at ldap/servers/slapd/delete.c:324
>> rc = 0
>> rawdn = 0x55cb5b28de00 "changenumber=891343, cn=changelog"
>> dn = <optimized out>
>> be = 0x55cb03c31040
>> internal_op = 32
>> sdn = 0x55cb5fd93bc0
>> operation = 0x55cb5ef86000
>> referral = 0x0
>> ecopy = 0x0
>> errorbuf = "\000\066\062\062Z\nmodifyTime", '\000'
<repeats 16
>> times>, "\071\063\066\062\062Z\nnsUniqueI", '\000'
<repeats 16 times>,
>>
"\327\320~\003ڇ\316c!\f=\037$z\215\301;\215\006\065\341\n\310V\300\006\365I\344|x\210\216\f\215\060e\243S\350\000T\334YHi\365\357\016\237V\202\332PG\347\300\070\314\003\313U\000\000\300\070\314\003\313U\000\000\000T\334YHi\365\357\000\000\000\000\000\000\000\000\300\070\314\003\313U\000\000\300\070\314\003\313U\000\000\240<\250\355\226\177\000\000\000\243\002\000\000\000\000\000p|\346\355\226\177\000\000ϙ\r\000\000\000\000\000\312\360"...
>>
>> err = <optimized out>
>> proxydn = 0x0
>> proxystr = 0x0
>> proxy_err = <optimized out>
>> errtext = 0x0
>> #9 0x00007f96ed79d598 in delete_internal_pb
>> (pb=pb@entry=0x55cb4c670fc0) at ldap/servers/slapd/delete.c:208
>> controls = 0x0
>> op = 0x55cb5ef86000
>> opresult = 0
>> #10 0x00007f96ed79d813 in slapi_delete_internal_pb
>> (pb=pb@entry=0x55cb4c670fc0) at ldap/servers/slapd/delete.c:151
>> #11 0x00007f96daff731e in delete_changerecord (cnum=cnum@entry=891343)
>> at ldap/servers/plugins/retrocl/retrocl_trim.c:89
>> pb = 0x55cb4c670fc0
>> dnbuf = 0x55cb5b28de00 "changenumber=891343, cn=changelog"
>> delrc = 32662
>> #12 0x00007f96daff7605 in trim_changelog () at
>> ldap/servers/plugins/retrocl/retrocl_trim.c:290
>> did_delete = 0
>> done = 0
>> last_in_log = <optimized out>
>> me = 172800
>> lt = <optimized out>
>> ldrc = <optimized out>
>> now = 1620819600
>> first_in_log = 891343
>> num_deleted = 3655
>> #13 0x00007f96daff7605 in changelog_trim_thread_fn (arg=<optimized
>> out>) at ldap/servers/plugins/retrocl/retrocl_trim.c:333
>> #14 0x00007f96eb595c5b in _pt_root () at /lib64/libnspr4.so
>> #15 0x00007f96eaf35ea5 in start_thread () at /lib64/libpthread.so.0
>> #16 0x00007f96ea5e19fd in clone () at /lib64/libc.so.6
>>
>> -- Kees
>>
>> On 12-05-2021 15:49, Thierry Bordaz wrote:
>>> Hi Kees,
>>>
>>> Is changelogmaxage=-1 after the upgrade ?
>>>
>>> would you send a full pstack when it hangs ? If
>>> pthread_rwlock_wrlock is
>>> trim_changelog then you may hit another flavor of [1] (without known
>>> reason).
>>>
>>> regards
>>> thierry
>>>
>>> On 5/12/21 2:40 PM, Kees Bakker wrote:
>>>> Sorry to revive an old thread. I'm getting deadlocks again. See
below
>>>>
>>>> On 20-04-2020 15:16, thierry bordaz wrote:
>>>>> [...]This is a known bug [1].
>>>>> With the same bug there are two deadlock scenario but only one is
>>>>> fixed (for example in slapi-nis-0.56.4-1 [2]).
>>>>> A fix for the second one is under tests.
>>>>>
>>>>> At the moment I would recommend the workaround [3]. The drawback
>>>>> is a
>>>>> growth of the retroCL database but unless you have a very high rate
>>>>> of update it should not be a concern.
>>>>>
>>>>> [1] https://bugzilla.redhat.com/show_bug.cgi?id=1751295
>>>>> [2] https://koji.fedoraproject.org/koji/buildinfo?buildID=1457771
>>>>> [3] https://bugzilla.redhat.com/show_bug.cgi?id=1751295#c5
>>>>>
>>>>> best regards
>>>>> thierry
>>>>>
>>>>
>>>> I followed the recommendation to set nsslapd-changelogmaxage to -1.
>>>> The system
>>>> has been running successfully for a year.
>>>>
>>>> Recently I upgraded all packages in this CentOS7 system. Ever since
>>>> that moment
>>>> the server is quite unusable.
>>>>
>>>> [root@linge ~]# gdb -ex 'set confirm off' -ex 'set pagination
off'
>>>> -ex
>>>> 'thread apply all bt full' -ex 'quit' /usr/sbin/ns-slapd
`pidof
>>>> ns-slapd` |& grep '^#0.*lock'
>>>> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf39184 in pthread_rwlock_rdlock () at
>>>> /lib64/libpthread.so.0
>>>> #0 0x00007f96eaf3939e in pthread_rwlock_wrlock () at
>>>> /lib64/libpthread.so.0
>>>>
>>>> [root@linge ~]# rpm -qa 389\*
>>>> 389-ds-base-libs-1.3.10.2-10.el7_9.x86_64
>>>> 389-ds-base-1.3.10.2-10.el7_9.x86_64
>>>> 389-ds-base-debuginfo-1.3.10.2-10.el7_9.x86_64
>>>>
>>>> [root@linge ~]# rpm -qa slapi\*
>>>> slapi-nis-0.56.5-3.el7_9.x86_64
>>>>
>>>> [root@linge ~]# rpm -qa centos-release
>>>> centos-release-7-9.2009.1.el7.centos.x86_64
>>>>
>>>> Are there any new hints to avoid the deadlock?
>>>
>>
>
1:52 a.m.
On 13-05-2021 08:32, Thierry Bordaz wrote:
On 5/12/21 8:41 PM, Kees Bakker wrote:
> On 12-05-2021 19:44, Thierry Bordaz wrote:
>> On 5/12/21 4:55 PM, Kees Bakker wrote:
>>> Hi Thierry,
>>>
>>> Just to be clear, changelogmaxage was changed to -1 by me after the
>>> upgrade and I've
>>> confirmed it is now set to -1.
>>>
>>> The reason for me to change the value was because of the deadlock.
>>> Apparently, it did not make much of a difference. It still gets into a
>>> deadlock
>>> with the value -1.
>>
>>
>> Did you set nsslapd-changelogmaxage=-1 in the retroCL config entry ?
>
> I've used this input file for ldapmodify
>
> [root@linge ~]# cat change-nsslapd-changelogmaxage.txt
> dn: cn=Retro Changelog Plugin,cn=plugins,cn=config
> changetype: modify
> replace: nsslapd-changelogmaxage
> nsslapd-changelogmaxage: -1
>
> After that
>
> [root@linge ~]# ldapsearch -H
> ldapi://%2fvar%2frun%2fslapd-GHS-NL.socket -LLL -o ldif-wrap=no -b
> 'cn=Retro Changelog Plugin,cn=plugins,cn=config'
> SASL/EXTERNAL authentication started
> SASL username: gidNumber=0+uidNumber=0,cn=peercred,cn=external,cn=auth
> SASL SSF: 0
> dn: cn=Retro Changelog Plugin,cn=plugins,cn=config
> cn: Retro Changelog Plugin
> nsslapd-attribute: nsuniqueid:targetUniqueId
> nsslapd-changelogmaxage: -1
> nsslapd-include-suffix: cn=dns,dc=ghs,dc=nl
> nsslapd-plugin-depends-on-named: Class of Service
> nsslapd-plugin-depends-on-type: database
> nsslapd-pluginDescription: Retrocl Plugin
> nsslapd-pluginEnabled: on
> nsslapd-pluginId: retrocl
> nsslapd-pluginInitfunc: retrocl_plugin_init
> nsslapd-pluginPath: libretrocl-plugin
> nsslapd-pluginType: object
> nsslapd-pluginVendor: 389 Project
> nsslapd-pluginVersion: 1.3.10.2
> nsslapd-pluginbetxn: on
> nsslapd-pluginprecedence: 25
> objectClass: top
> objectClass: nsSlapdPlugin
> objectClass: extensibleObject
You did the right setting. I do not understand why thread 2 is trimming
records with that setting.
>
>
>>
>>
>>>
>>> BTW. I've sent the whole stacktrace directly to you to avoid the 4000+
>>> lines to
>>> this mailing list.
>>>
>>> Here is the stack trace of one of the threads. The one that hangs in
>>> trim_changelog
>>
>>
>> Something weird is that the same hang occurs
>> https://bugzilla.redhat.com/show_bug.cgi?id=1751295.
>> If I am correct it is between thread 14th and 2nd.
>>
>> As you are running with a fixed version (> slapi-nis-0.56.5), that means
>> the fix is incomplete. It would require to debug a dump core to know why
>> the fix fails.
>
> [root@linge ~]# rpm -qa slapi\*
> slapi-nis-0.56.5-3.el7_9.x86_64
>
> So, that is not > 0.56.5, but it is the newest available for CentOS7. No?
reading the 'fixed version' in the bug says it if fixed starting 0.56.5
I do not know if it match centOS7 versions
>
> At the moment I killed it and restarted. No deadlock yet, but the
> system is extreemly
> slow. And there is just ns-slapd using CPU cycles.
Would you give some precision what is slow ? (response time, replication
time,..)
If it is eating CPU, I would recommend 'top -H -p <pid> -b'. If it is
always the same thread(s) eating the CPU, a pstack will tell you what
it/they is/are doing. If this is various different threads likely it is
due to processed requests.
I don't know what numbers to give to show the slowness. The load of
the system is almost 4, while the other master (identical system) has
a load of almost zero. (And the latter is used as the main LDAP server)
Right now thread 2 and thread 43 are the most active ones. Here are their
stacktraces.
Thread 43 (Thread 0x7f4baa1d0700 (LWP 3583)):
#0 0x00007f4bcc200a33 in select () at /lib64/libc.so.6
#1 0x00007f4bcf44ab09 in DS_Sleep (ticks=ticks@entry=250) at
ldap/servers/slapd/util.c:1086
mSecs = <optimized out>
tm = {tv_sec = 0, tv_usec = 26398}
#2 0x00007f4bbe587f77 in trickle_threadmain (param=<optimized out>) at
ldap/servers/slapd/back-ldbm/dblayer.c:4551
interval = 250
rval = <optimized out>
priv = 0x55f87ff28b00
li = <optimized out>
debug_checkpointing = 0
#3 0x00007f4bcd1bdc5b in _pt_root () at /lib64/libnspr4.so
#4 0x00007f4bccb5dea5 in start_thread () at /lib64/libpthread.so.0
#5 0x00007f4bcc2099fd in clone () at /lib64/libc.so.6
Thread 2 (Thread 0x7f4b93d39700 (LWP 15086)):
#0 0x00007f4bce211ef5 in tc_malloc () at /lib64/libtcmalloc.so.4
#1 0x00007f4bcf3c15a3 in slapi_ch_malloc (size=35) at ldap/servers/slapd/ch_malloc.c:95
newmem = <optimized out>
#2 0x00007f4bc57809d8 in __os_umalloc () at /lib64/libdb-5.3.so
#3 0x00007f4bc5742136 in __db_retcopy () at /lib64/libdb-5.3.so
#4 0x00007f4bc571a2b3 in __dbc_iget () at /lib64/libdb-5.3.so
#5 0x00007f4bc5728cb2 in __dbc_get_pp () at /lib64/libdb-5.3.so
#6 0x00007f4bbe5c1953 in entryrdn_lookup_dn (be=be@entry=0x55f8801ef040,
rdn=<optimized out>, id=id@entry=2092284, dn=dn@entry=0x7f4b93d34188,
psrdn=psrdn@entry=0x7f4b93d34190, txn=txn@entry=0x7f4b93d342d0) at
ldap/servers/slapd/back-ldbm/ldbm_entryrdn.c:1188
rc = <optimized out>
ai = 0x55f880232540
db = 0x55f881edaa00
cursor = 0x55f881efe240
db_txn = 0x0
key = {data = 0x55f9026082a0, size = 9, ulen = 9, dlen = 0, doff = 0, app_data =
0x0, flags = 2056}
data = {data = 0x0, size = 0, ulen = 0, dlen = 0, doff = 0, app_data = 0x0, flags
= 16}
keybuf = 0x55f9026082a0 "P2092284"
srdn = 0x55f8b9b11500
orignrdn = 0x0
nrdn = 0x55f93b909f80 "changenumber=2092283"
nrdn_len = 20
workid = 2092284
elem = <optimized out>
maybesuffix = 0
db_retry = <optimized out>
#7 0x00007f4bbe5929e7 in id2entry (be=<optimized out>, id=id@entry=2092284,
txn=txn@entry=0x7f4b93d342d0, err=err@entry=0x7f4b93d342c4) at
ldap/servers/slapd/back-ldbm/id2entry.c:346
sdn = 0x0
normdn = 0x0
srdn = 0x0
bdn = 0x0
rdn = 0x55f93efd4f40 "changenumber=2092283"
rc = <optimized out>
inst = 0x55f88004a680
db = 0x55f881ed8600
db_txn = <optimized out>
key = {data = 0x7f4b93d34200, size = 4, ulen = 0, dlen = 0, doff = 0, app_data =
0x0, flags = 0}
data = {data = 0x55f92c680000, size = 985, ulen = 0, dlen = 0, doff = 0, app_data
= 0x0, flags = 16}
e = 0x0
ee = <optimized out>
temp_id = "\000\037\354", <incomplete sequence \374>
#8 0x00007f4bbe5ceb72 in ldbm_back_next_search_entry_ext (pb=0x55f95513cd80,
use_extension=0) at ldap/servers/slapd/back-ldbm/ldbm_search.c:1627
be = 0x55f8801ef040
inst = 0x55f88004a680
li = 0x55f87ffbf7c0
scope = 2
managedsait = 0
attr = 0x0
filter = 0x55f8a42e8300
sr = 0x55f9557687c0
id = 2092284
e = 0x55f88b819960
nentries = 399583
expire_time = {tv_sec = 0, tv_nsec = 0}
tlimit = -1
llimit = -1
slimit = -1
isroot = 1
urls = 0x0
err = 0
basesdn = 0x55f8e973bbc0
target_uniqueid = 0x0
rc = 0
estimate = 0
txn = {back_txn_txn = 0x0}
pr_idx = -1
conn = 0x0
op = 0x55f8a2ce14a0
reverse_list = 0
#9 0x00007f4bcf405ff6 in iterate (send_result=1, be=0x55f8801ef040,
pr_statp=0x7f4b93d344f4, pagesize=<optimized out>, pnentries=0x7f4b93d34588,
pb=0x55f95513cd80) at ldap/servers/slapd/opshared.c:1292
ger_template_entry = 0x0
operation = 0x55f8a2ce14a0
done = 0
e = 0x55f8a82c0180
pr_stat = 0
pr_idx = -1
rc = <optimized out>
rval = 1
attrsonly = 0
attrs = 0x0
be = 0x55f8801ef040
rc = <optimized out>
#10 0x00007f4bcf405ff6 in send_results_ext (pb=pb@entry=0x55f95513cd80,
nentries=nentries@entry=0x7f4b93d34588, pagesize=-1, pr_stat=pr_stat@entry=0x7f4b93d344f4,
send_result=1) at ldap/servers/slapd/opshared.c:1645
be = 0x55f8801ef040
rc = <optimized out>
#11 0x00007f4bcf408159 in op_shared_search (pb=pb@entry=0x55f95513cd80,
send_result=send_result@entry=1) at ldap/servers/slapd/opshared.c:847
be_suffix = <optimized out>
err = 0
next_be = 0x0
base = 0x7f4bc394e4e2 "cn=changelog"
normbase = <optimized out>
fstr = 0x55f8904cc540
"(&(changenumber>=-1)(targetuniqueid=1e89eb86-e20111e8-8820f96e-fc0c60a4))"
scope = 2
be = 0x55f8801ef040
be_single = 0x0
be_list = {0x55f8801ef040, 0x0, 0x0, 0x0, 0x55f8801da740, 0x55f800000001,
0x55f900000000, 0x0 <repeats 994 times>}
referral_list = {0x0 <repeats 611 times>, 0x7f4bcdd788e3
<ber_sockbuf_ctrl+387>, 0x0, 0x0, 0x0, 0x0, 0x0, 0x7f4bcdd788e3
<ber_sockbuf_ctrl+387>, 0x0 <repeats 186 times>, 0x61e7bfe702042a36,
0x40658d47b4a41ce1, 0xad61e3a2024df476, 0xde7dadc70e0b5fd8, 0xf73159a52a48ea2c,
0x4f70cb70764a2fab, 0x674523017f57e936, 0x98badcfeefcdab89, 0xc3d2e1f010325476,
0x7f4b93d37f50, 0x683f974357510ca2, 0x559e6a9b5a8a133, 0xce1fa8c242f162a9,
0xa6643132814dc94e, 0xadde7596feaa7041, 0xca0e6a6d6158d8b, 0xeb6b73d137578f64,
0x5a6da1000aeb278e, 0x24faa792f298903b, 0xf1b60146abc162e4, 0xf55006a5ea03353b,
0x7f4b93d37f50, 0x6e2c2f26e077f9de, 0x71a715d3942421dd, 0x8000000058200514, 0x0, 0x0, 0x0,
0x0, 0x2a000000000, 0x0, 0xa12a74c04e49e800, 0x0, 0x7f4b93d37f50, 0x2, 0x7f4b93d38020,
0x7f4b93d380e0, 0x2, 0x55f9217d5e00, 0x7f4bcee55d9d <k5_sha1_hash+125>,
0xfea223f37bbd812, 0xf8ec1ab4f83d9a2b, 0x2a0e21f8c65, 0xe077f9de00000000,
0x942421dd6e2c2f26, 0x5820051471a715d3, 0x80000000, 0x0, 0x0, 0x0, 0x0,
0x2a0, 0xfffffffffffffffe, 0xa12a74c04e49e800, 0x7f4bcf07fd60, 0x55f9038e6620,
0x55f8a467c400, 0x55f8cb6cc1e0, 0x0, 0x7f4bcee713e2 <krb5int_hmac_keyblock+418>,
0x40, 0x7f4b93d38170, 0x7f4b93d380e0, 0x5, 0x14970ea702, 0x55f9038e6620, 0x2,
0x40970ea702, 0x55f9217d5e00, 0x1d99616e00000002, 0x14970ea702, 0x55f9038e6620, 0x14,
0xa12a74c04e49e800, 0x20, 0x4, 0x7f4b93d38170, 0xa12a74c04e49e800, 0x4, 0x7f4b93d38170,
0x7f4bcf07ff00 <krb5int_enc_aes256>, 0x7f4bcee6a8f6 <krb5int_dk_decrypt+406>,
0x20, 0xc00000003, 0x55f90dde5e30, 0x7f4b93d380e0, 0x55f9038e6ca0, 0x0, 0x55f8cb6cd3e0,
0x55f8cb6cc1e0, 0x1400000000, 0x55f9038e6ca0, 0x5516000000, 0xa12a74c04e49e800, 0x20,
0x7f4bcf080b00, 0x1e, 0x7f4b93d38290, 0x41ed982026117e4f, 0xb3c887fe91a43017,
0x720d385d3bc2cd56, 0x50a61fb007a7a9ca, 0xa5d3e14dc70e09bd, 0xb6ead04df0228653,
0x674523017e49db9f, 0x98badcfeefcdab89, 0xc3d2e1f010325476, 0x7f4b93d38260,
0x7234e4c832eb2e6b, 0xbab56daaa29a3c86, 0xfda5dc82799faefa, 0x7b24e8909274e0fa,
0xe1bbebd5d6ad6668, 0x6e8fa927ce38a9b, 0x816585922b509df, 0xd2e805e35f84d38d,
0xdf7f8b184e7dfaca, 0x59585d6f1926cba8, 0x59d1d26715819ef8, 0x7f4b93d38260,
0x80a891fe5f5cfd30, 0x705ca35758499ae9, 0x80000000c5f084c6, 0x0, 0x0, 0x0, 0x0,
0x2a000000000, 0x7f4b93d38320, 0xa12a74c04e49e800, 0x55f977b74fc0, 0x7f4b93d38260, 0x2,
0x7f4b93d38330, 0x7f4b93d38400, 0x2, 0x55f94e35f680, 0xa12a74c04e49e800,
0xd7c43895b01e211d, 0x7f4bcee65b20 <k5_iov_cursor_put+176>, 0x2a0f3cb812d,
0xa12a74c04e49e800, 0x58499ae980a891fe, 0x7f4b93d38340, 0x55f89b92fad0, 0x7f4b93d38350,
0x7f4b93d38330, 0x7f4b93d382e0, 0x55f901527130, 0x7f4bcee547cd
<krb5int_aes_encrypt+813>, 0x20, 0xa7ff7ad44e49e800, 0x0, 0x7f4b93d382e0,
0x7f4b93d38470, 0x4, 0x10, 0x7f4b00000000, 0x4, 0x0, 0x4, 0x0, 0x21cafd39017982c4,
0x6e273f72669afee0, 0x530d2dd27b61963b, 0xff29c39b99a71313, 0x9ecaf11f4ef579a1,
0x8cb433b09c5edc92, 0x21cafd39017982c4, 0x6e273f72669afee0, 0x0, 0xa12a74c04e49e800,
0x7f4b93d38470...}
attrlistbuf =
"\300\207ӓK\177\000\000\301\207ӓK\177\000\000\000\000\000\000K\177\000\000\034_\032\315K\177\000\000;\232F\317K\177\000\000\020\211ӓK\177\000\000\000\000\000\000\000\000\000\000P\232F\317K\177\000\000Q\232F\317K\177\000\000\356a\032\315K\177\000\000\020\210ӓK\177",
'\000' <repeats 18 times>,
"\357\206ӓK\177\000\000\360\206ӓK\177\000\000\006\000\000\000K\177\000\000@\210ӓK\177\000\000A\210ӓK\177\000\000\000\000\000\000K\177\000\000\005\214D\317\000\000\000\000\000\207ӓK\177\000\000P\204x\006\371U\000
_\232F\317K\177", '\000' <repeats 19 times>,
"\350IN\300t*\241\000"...
attrliststr = <optimized out>
attrs = 0x0
rc = 0
internal_op = <optimized out>
basesdn = 0x55f8d6a316b0
sdn = 0x55f8e973bbc0
operation = 0x55f8a2ce14a0
referral = 0x0
proxydn = 0x0
proxystr = 0x0
proxy_err = <optimized out>
errtext = 0x0
nentries = 0
pnentries = 399583
flag_search_base_found = 1
flag_no_such_object = 0
flag_referral = 0
flag_psearch = <optimized out>
err_code = 0
ctrlp = 0x0
ctl_value = 0x0
iscritical = 0
be_name = <optimized out>
index = -1
sent_result = 0
pr_stat = 0
pb_conn = 0x0
pagesize = -1
estimate = 0
curr_search_count = <optimized out>
pr_be = <optimized out>
pr_search_result = <optimized out>
pr_idx = -1
orig_sdn = 0x0
free_sdn = 1
vattr_lock_acquired = 1
#12 0x00007f4bcf419697 in search_internal_callback_pb (pb=pb@entry=0x55f95513cd80,
callback_data=callback_data@entry=0x7f4b93d38b60, prc=prc@entry=0x7f4bcf418770
<internal_plugin_result_callback>, psec=psec@entry=0x7f4bcf4187c0
<internal_plugin_search_entry_callback>, prec=prec@entry=0x7f4bcf418780
<internal_plugin_search_referral_callback>) at
ldap/servers/slapd/plugin_internal_op.c:727
controls = 0x0
op = 0x55f8a2ce14a0
filter = 0x55f8aad34480
fstr = 0x55f8a3cd7180
"(&(changenumber>=-1)(targetuniqueid=1e89eb86-e20111e8-8820f96e-fc0c60a4))"
callback_handler_data = {p_res_callback = 0x7f4bcf418770
<internal_plugin_result_callback>, p_srch_entry_callback = 0x7f4bcf4187c0
<internal_plugin_search_entry_callback>, p_ref_entry_callback = 0x7f4bcf418780
<internal_plugin_search_referral_callback>, callback_data = 0x7f4b93d38b60}
scope = 2
ifstr = 0x55f8904cc540
"(&(changenumber>=-1)(targetuniqueid=1e89eb86-e20111e8-8820f96e-fc0c60a4))"
opresult = -817789072
rc = 0
tmp_attrs = 0x0
#13 0x00007f4bcf4198e8 in search_internal_pb (pb=pb@entry=0x55f95513cd80) at
ldap/servers/slapd/plugin_internal_op.c:592
psid = {rc = -1, num_entries = 399583, num_referrals = 0, entry_list_head =
0x55f8e74c92d0, referral_list_head = 0x0}
iterator = <optimized out>
tmp = 0x7f4b93d38b60
ref_iterator = <optimized out>
ref_tmp = 0x7f4bcf6af240 <global_server_id_plg>
i = <optimized out>
opresult = 0
pb_search_entries = 0x0
pb_search_referrals = 0x0
#14 0x00007f4bcf419b33 in slapi_search_internal_pb (pb=pb@entry=0x55f95513cd80) at
ldap/servers/slapd/plugin_internal_op.c:502
#15 0x00007f4bc394bd13 in sync_cookie_get_change_number (uniqueid=<optimized out>,
lastnr=<optimized out>) at ldap/servers/plugins/sync/sync_util.c:429
srch_pb = 0x55f95513cd80
cl_entry = <optimized out>
rv = 0
filter = 0x55f8904cc540
"(&(changenumber>=-1)(targetuniqueid=1e89eb86-e20111e8-8820f96e-fc0c60a4))"
entries = 0x7f4b93d38c6c
newnr = 18446744073709551615
uniqueid = <optimized out>
attr = 0x55f96ad77e60
val = 0x55f964c56860
#16 0x00007f4bc394bd13 in sync_cookie_update (sc=0x55f8c1753040,
ec=ec@entry=0x55f9565852c0) at ldap/servers/plugins/sync/sync_util.c:514
uniqueid = <optimized out>
attr = 0x55f96ad77e60
val = 0x55f964c56860
#17 0x00007f4bc394d66d in sync_send_results (arg=<optimized out>) at
ldap/servers/plugins/sync/sync_persist.c:643
noattrs = 0x0
ec = 0x55f9565852c0
attrsonly = 0
attrs = 0x0
ectrls = 0x55f906788450
chg_type = 2
req = 0x55f9704795c0
qnode = 0x55f97ea3d320
qnodenext = <optimized out>
conn_acq_flag = <optimized out>
conn = 0x55f882282ba8
op = 0x55f880953680
rc = <optimized out>
connid = 5052
opid = 0
#18 0x00007f4bcd1bdc5b in _pt_root () at /lib64/libnspr4.so
#19 0x00007f4bccb5dea5 in start_thread () at /lib64/libpthread.so.0
#20 0x00007f4bcc2099fd in clone () at /lib64/libc.so.
>
>>
>> regards
>> thierry
>> [...]
1068
days inactive
1460
days old
freeipa-users@lists.fedorahosted.org
16 comments
5 participants
participants (5)
-
Florence Blanc-Renaud -
Kees Bakker -
Rob Crittenden -
thierry bordaz -
Thierry Bordaz