#9138 [Tracker] named-pkcs11 can crash on restart
Opened by brianjmurrell. Modified

Description of problem:
During the weekly log processing, named-pkcs11 failed to [re-]start:

Apr 10 03:18:40 server named-pkcs11[4055230]: zone 0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.b.9.f.f.4.6.0.0.ip6.arpa/IN: (master) removed
Apr 10 03:18:40 server named-pkcs11[4055230]: reloading configuration succeeded
Apr 10 03:18:40 server named-pkcs11[4055230]: reloading zones succeeded
Apr 10 03:18:40 server sh[1898975]: server reload successful
Apr 10 03:18:40 server systemd[1]: Reloaded Berkeley Internet Name Domain (DNS) with native PKCS#11.
Apr 10 03:18:41 server named-pkcs11[4055230]: ldap_helper.c:3767: INSIST(task == inst->task) failed, back trace
Apr 10 03:18:41 server named-pkcs11[4055230]: #0 0x55681471fa54 in ??
Apr 10 03:18:41 server named-pkcs11[4055230]: #1 0x7f48d4ee6fd0 in ??
Apr 10 03:18:41 server named-pkcs11[4055230]: #2 0x7f48c3d21fa8 in ??
Apr 10 03:18:41 server named-pkcs11[4055230]: #3 0x7f48d4f0e0ef in ??
Apr 10 03:18:41 server named-pkcs11[4055230]: #4 0x7f48d230417a in ??
Apr 10 03:18:41 server named-pkcs11[4055230]: #5 0x7f48d1ccbdc3 in ??
Apr 10 03:18:41 server named-pkcs11[4055230]: exiting (due to assertion failure)
Apr 10 03:22:10 server systemd[1]: named-pkcs11.service: Main process exited, code=killed, status=6/ABRT
Apr 10 03:22:10 server systemd[1]: named-pkcs11.service: Failed with result 'signal'.

Version-Release number of selected component (if applicable):
bind-pkcs11-9.11.26-6.el8.x86_64

How reproducible:
Unknown

Steps to Reproduce:
N/A

Actual results:
named-pkcs11 crashes on restart

Expected results:
named-pkcs11 should be able to restart reliably

Additional info:
Simply restarting it a few hours later, after it has been noticed as having failed to restart and it started successfully.

Sadly, this is the SECOND major release of EL in which one could not rely on named-pkcs11 being able to start reliably. For almost the entire release cycle of EL7, named-pkcs11 was unable to restart reliably.

This track record makes it very difficult to use this package with any confidence and without hacks like:

[Service]
Restart=on-failure

in it's unit file. I had hoped to put the above to bed with the upgrade to EL8 but I guess I will have to re-instate it until this can be fixed.


I'm adding the Tracker label because the issue has also been reported in BZ #2073771 against RHEL 8 / bind-dyndb-ldap component.

Metadata Update from @frenaud:
- Issue tagged with: tracker

Metadata Update from @frenaud:
- Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=2073771

We were seeing this more weeks than not, always during the log processing restart.

Jan 18 06:26:51 freeipa0.idm.example.com systemd[1]: Stopped Berkeley Internet Name Domain (DNS).
Jan 18 06:26:51 freeipa0.idm.example.com systemd[1]: named.service: Failed with result 'core-dump'.
Jan 18 06:26:51 freeipa0.idm.example.com systemd[1]: named.service: Main process exited, code=dumped, status=6/ABRT
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: exiting (due to assertion failure)
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #13 0x7f67ed50ed40 in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #12 0x7f67ed489d22 in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #11 0x7f67ee35168a in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #10 0x7f67ee33eb5b in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #9 0x7f67ee266568 in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #8 0x7f67ee27c85e in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #7 0x7f67ee260afd in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #6 0x7f67ee33f297 in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #5 0x7f67ee33eaa5 in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #4 0x7f67ee33e929 in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #3 0x7f67ee3538ad in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #2 0x7f67e8165f53 in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #1 0x7f67ee3184e0 in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: #0 0x55ee86caa6a1 in ??
Jan 18 06:26:51 freeipa0.idm.example.com named[76769]: ldap_helper.c:3773: INSIST(task == inst->task) failed, back trace
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: stopping command channel on ::1#953
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: stopping command channel on 127.0.0.1#953
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: shutting down: flushing changes
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: no longer listening on fe80::7643:eccd:4a74:cd53%3#53
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: no longer listening on fd7a:115c:a1e0::9e01:e63d#53
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: no longer listening on fe80::e6ad:3242:46f4:ddbd%2#53
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: no longer listening on ::1#53
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: no longer listening on 10.2.0.11#53
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: no longer listening on 127.0.0.1#53
Jan 18 06:26:48 freeipa0.idm.example.com named[76769]: received control channel command 'stop'
Jan 18 06:26:48 freeipa0.idm.example.com systemd[1]: Stopping Berkeley Internet Name Domain (DNS)...

It would happen on all of our freeipa nodes all at the same time.

Metadata