#6108 /var/log/messages file displays traceback for ipa-dnskeysyncd service during ipa-server-install
Closed: worksforme 5 years ago Opened 7 years ago by pvoborni.

Ticket was cloned from Red Hat Bugzilla (product Red Hat Enterprise Linux 7): Bug 1356626

Description of problem:/var/log/messages file displays traceback  for
ipa-dnskeysyncd  during ipa-server-install

Version-Release number of selected component (if applicable):
ipa-server-4.4.0-1.el7.x86_64

How reproducible:Always


Steps to Reproduce:
1. ipa-server-install
2. Check the logging done in /var/log/messages file


Actual results:
Jul 14 17:14:23 server systemd: Stopping 389 Directory Server TESTRELM-TEST....
Jul 14 17:14:24 server ns-slapd: [14/Jul/2016:17:14:24.214272576 +051800] slapd
shutting down - signaling operation threads - op stack size 7 max work q size 2
max work q stack size 2
Jul 14 17:14:24 server ns-slapd: [14/Jul/2016:17:14:24.313968684 +051800] slapd
shutting down - closing down internal subsystems and plugins
Jul 14 17:14:24 server ns-slapd: [14/Jul/2016:17:14:24.472691535 +051800]
Waiting for 4 database threads to stop
Jul 14 17:14:25 server ns-slapd: [14/Jul/2016:17:14:25.287364336 +051800] All
database threads now stopped
Jul 14 17:14:25 server ipa-dnskeysyncd: ipa         : ERROR    syncrepl_poll:
LDAP error ({'desc': "Can't contact LDAP server"})
Jul 14 17:14:25 server ipa-dnskeysyncd: Traceback (most recent call last):
Jul 14 17:14:25 server ipa-dnskeysyncd: File
"/usr/libexec/ipa/ipa-dnskeysyncd", line 110, in <module>
Jul 14 17:14:25 server ipa-dnskeysyncd: while
ldap_connection.syncrepl_poll(all=1, msgid=ldap_search):
Jul 14 17:14:25 server ipa-dnskeysyncd: File
"/usr/lib64/python2.7/site-packages/ldap/syncrepl.py", line 348, in
syncrepl_poll
Jul 14 17:14:25 server ipa-dnskeysyncd: add_intermediates=1, add_ctrls=1, all =
0
Jul 14 17:14:25 server ipa-dnskeysyncd: File
"/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 476, in result4
Jul 14 17:14:25 server ipa-dnskeysyncd: ldap_result = self._ldap_call(self._l.r
esult4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
Jul 14 17:14:25 server ipa-dnskeysyncd: File
"/usr/lib64/python2.7/site-packages/ldap/ldapobject.py", line 99, in _ldap_call
Jul 14 17:14:25 server ipa-dnskeysyncd: result = func(*args,**kwargs)
Jul 14 17:14:25 server ipa-dnskeysyncd: SERVER_DOWN: {'desc': "Can't contact
LDAP server"}
Jul 14 17:14:25 server named-pkcs11[19634]: LDAP error: Can't contact LDAP
server: ldap_sync_poll() failed
Jul 14 17:14:25 server named-pkcs11[19634]: ldap_syncrepl will reconnect in 60
seconds
Jul 14 17:14:25 server ns-slapd: [14/Jul/2016:17:14:25.423626626 +051800] slapd
shutting down - freed 2 work q stack objects - freed 7 op stack objects

Expected results:
Although ipactl status shows the command running, /var/log/messages file
reports this traceback that it cannot connect to ldap server.

[root@server ~]# systemctl status ipa-dnskeysyncd.service -l
? ipa-dnskeysyncd.service - IPA key daemon
   Loaded: loaded (/usr/lib/systemd/system/ipa-dnskeysyncd.service; disabled;
vendor preset: disabled)
   Active: active (running) since Thu 2016-07-14 17:15:26 IST; 1h 47min ago
 Main PID: 20282 (ipa-dnskeysyncd)
   CGroup: /system.slice/ipa-dnskeysyncd.service
           ??20282 /usr/bin/python2 /usr/libexec/ipa/ipa-dnskeysyncd

Jul 14 17:15:29 server.testrelm.test python2[20282]: GSSAPI client step 1
Jul 14 17:15:29 server.testrelm.test python2[20282]: GSSAPI client step 1
Jul 14 17:15:29 server.testrelm.test python2[20282]: GSSAPI client step 1
Jul 14 17:15:30 server.testrelm.test python2[20282]: GSSAPI client step 2
Jul 14 17:15:30 server.testrelm.test ipa-dnskeysyncd[20282]: ipa         : INFO
Commencing sync process
Jul 14 17:15:33 server.testrelm.test ipa-dnskeysyncd[20282]:
ipa.ipapython.dnssec.keysyncer.KeySyncer: INFO     Initial LDAP dump is done,
sychronizing with ODS and BIND
Jul 14 17:15:37 server.testrelm.test python2[20299]: GSSAPI client step 1
Jul 14 17:15:37 server.testrelm.test python2[20299]: GSSAPI client step 1
Jul 14 17:15:37 server.testrelm.test python2[20299]: GSSAPI client step 1
Jul 14 17:15:38 server.testrelm.test python2[20299]: GSSAPI client step 2

[root@server ~]# ipactl status
Directory Service: RUNNING
krb5kdc Service: RUNNING
kadmin Service: RUNNING
named Service: RUNNING
ipa_memcached Service: RUNNING
httpd Service: RUNNING
ipa-custodia Service: RUNNING
ntpd Service: RUNNING
pki-tomcatd Service: RUNNING
ipa-otpd Service: RUNNING
ipa-dnskeysyncd Service: RUNNING
ipa: INFO: The ipactl command was successful

Additional info:

A triage note

    pspacek: The 'fix' in ipa-dnskeysyncd would hide the real problem that we are killing LDAP server while some other services are depending on it. We should rather fix IPA service handling so it properly shuts down and restarts services as needed.
    pspacek: more general issue, bind has also problem with restarts of LDAP during server install
    pspacek, good to do together with other service mgmt issues we have

Metadata Update from @pvoborni:
- Issue assigned to someone
- Issue set to the milestone: Future Releases

7 years ago

This issue hasn't been seen recently, and the suggestion from BZ comment 3 has already been implemented (slapd is stopped last) hence closing as worksforme.

Metadata Update from @frenaud:
- Issue close_status updated to: worksforme
- Issue status updated to: Closed (was: Open)

5 years ago

Login to comment on this ticket.

Metadata