Ticket was cloned from Red Hat Bugzilla (product Fedora): Bug 1456043
I'm currently testing upgrades of Fedora 25 FreeIPA servers to Fedora 26, and noticing several problems. One is that, during the update process, named-pkcs11.service seems to start up and try to contact the KDC before the KDC itself is started: May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: starting BIND 9.11.0-P5-RedHat-9.11.0-8.P5.fc26 <id:ad4fb79> May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: running on Linux x86_64 4.10.17-200.fc25.x86_64 #1 SMP Mon May 22 18:12:57 UTC 2017 May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: built with '--build=x86_64-redhat-linux-gnu' '--host=x86_64-redhat-linux-gnu' '--program-prefix=' '--disable-dependency-tracking' '--prefix=/usr' '--exec-prefix=/usr' '--bindir=/usr May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: running as: named-pkcs11 -u named May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: ---------------------------------------------------- May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: BIND 9 is maintained by Internet Systems Consortium, May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: Inc. (ISC), a non-profit 501(c)(3) public-benefit May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: corporation. Support and training for BIND 9 are May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: available at https://www.isc.org/support May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: ---------------------------------------------------- May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: adjusted limit on open files from 4096 to 1048576 May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: found 2 CPUs, using 2 worker threads May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: using 1 UDP listener per interface May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: using up to 21000 sockets May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: loading configuration from '/etc/named.conf' May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: reading built-in trusted keys from file '/etc/named.iscdlv.key' May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: initializing GeoIP Country (IPv4) (type 1) DB May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GEO-106FREE 20170502 Build 1 Copyright (c) 2017 MaxMind Inc All Rights Reserved May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP Country (IPv6) (type 12) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP City (IPv4) (type 2) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP City (IPv4) (type 6) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP City (IPv6) (type 30) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP City (IPv6) (type 31) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP Region (type 3) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP Region (type 7) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP ISP (type 4) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP Org (type 5) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP AS (type 9) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP Domain (type 11) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: GeoIP NetSpeed (type 10) DB not available May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: using default UDP/IPv4 port range: [32768, 60999] May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: using default UDP/IPv6 port range: [32768, 60999] May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: listening on IPv6 interfaces, port 53 May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: listening on IPv4 interface lo, 127.0.0.1#53 May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: listening on IPv4 interface eth0, 10.0.2.100#53 May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: generating session key for dynamic DNS May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: sizing zone task pool based on 6 zones May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: zone 'localhost.localdomain' allows updates by IP address, which is insecure May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: zone 'localhost' allows updates by IP address, which is insecure May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: zone '1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.ip6.arpa' allows updates by IP address, which is insecure May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: zone '1.0.0.127.in-addr.arpa' allows updates by IP address, which is insecure May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: zone '0.in-addr.arpa' allows updates by IP address, which is insecure May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: 'max-cache-size 90%' - setting to 1799MB (out of 1999MB) May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: set up managed keys zone for view _default, file '/var/named/dynamic/managed-keys.bind' May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: loading DynDB instance 'ipa' driver '/usr/lib64/bind/ldap.so' May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: bind-dyndb-ldap version 11.1 compiled at 13:01:09 Mar 13 2017, compiler 7.0.1 20170225 (Red Hat 7.0.1-0.10) May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: Failed to get initial credentials (TGT) using principal 'DNS/ipa001.domain.local' and keytab 'FILE:/etc/named.keytab' (Cannot contact any KDC for realm 'DOMAIN.LOCAL') May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: Failed to get initial credentials (TGT) using principal 'DNS/ipa001.domain.local' and keytab 'FILE:/etc/named.keytab' (Cannot contact any KDC for realm 'DOMAIN.LOCAL') May 26 11:39:27 ipa001.domain.local named-pkcs11[15998]: ldap_sync_prepare() failed, retrying in 1 second: socket is not connected ... May 26 11:40:28 ipa001.domain.local named-pkcs11[15998]: Failed to get initial credentials (TGT) using principal 'DNS/ipa001.domain.local' and keytab 'FILE:/etc/named.keytab' (Cannot contact any KDC for realm 'DOMAIN.LOCAL') May 26 11:40:28 ipa001.domain.local named-pkcs11[15998]: ldap_syncrepl will reconnect in 60 seconds ... then it seems like the service is restarted, for some reason, still without KDC being started, and the error happens again: May 26 11:41:28 ipa001.domain.local named-pkcs11[15998]: exiting May 26 11:41:28 ipa001.domain.local systemd[1]: Stopped Berkeley Internet Name Domain (DNS) with native PKCS#11. May 26 11:41:28 ipa001.domain.local systemd[1]: Starting Generate rndc key for BIND (DNS)... May 26 11:41:28 ipa001.domain.local audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=named-pkcs11 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res= May 26 11:41:28 ipa001.domain.local audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=named-pkcs11 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=s May 26 11:41:28 ipa001.domain.local systemd[1]: Started Generate rndc key for BIND (DNS). May 26 11:41:28 ipa001.domain.local audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=named-setup-rndc comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? May 26 11:41:28 ipa001.domain.local audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=named-setup-rndc comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? r May 26 11:41:28 ipa001.domain.local systemd[1]: Starting Berkeley Internet Name Domain (DNS) with native PKCS#11... May 26 11:41:28 ipa001.domain.local bash[16165]: zone localhost.localdomain/IN: loaded serial 0 May 26 11:41:28 ipa001.domain.local bash[16165]: zone localhost/IN: loaded serial 0 May 26 11:41:28 ipa001.domain.local bash[16165]: zone 1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.ip6.arpa/IN: loaded serial 0 May 26 11:41:28 ipa001.domain.local bash[16165]: zone 1.0.0.127.in-addr.arpa/IN: loaded serial 0 May 26 11:41:28 ipa001.domain.local bash[16165]: zone 0.in-addr.arpa/IN: loaded serial 0 May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: starting BIND 9.11.0-P5-RedHat-9.11.0-8.P5.fc26 <id:ad4fb79> ... May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: bind-dyndb-ldap version 11.1 compiled at 13:01:09 Mar 13 2017, compiler 7.0.1 20170225 (Red Hat 7.0.1-0.10) May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: Failed to get initial credentials (TGT) using principal 'DNS/ipa001.domain.local' and keytab 'FILE:/etc/named.keytab' (Cannot contact any KDC for realm 'DOMAIN.LOCAL') May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: Failed to get initial credentials (TGT) using principal 'DNS/ipa001.domain.local' and keytab 'FILE:/etc/named.keytab' (Cannot contact any KDC for realm 'DOMAIN.LOCAL') May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 10.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 16.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 17.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 18.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 19.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 20.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 21.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 22.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 23.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 24.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: automatic empty zone: 25.172.IN-ADDR.ARPA May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: ldap_sync_prepare() failed, retrying in 1 second: socket is not connected Then the service seems to stop again, with some more errors: May 26 11:41:28 ipa001.domain.local systemd[1]: Stopping Berkeley Internet Name Domain (DNS) with native PKCS#11... May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: received control channel command 'stop' May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: shutting down: flushing changes May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: stopping command channel on 127.0.0.1#953 May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: stopping command channel on ::1#953 May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: error writing NTA file for view '_default': permission denied May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: error writing NTA file for view '_bind': permission denied May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: unloading DynDB instance 'ipa' May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: LDAP configuration synchronization failed: socket is not connected May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: no longer listening on ::#53 May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: no longer listening on 127.0.0.1#53 May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: no longer listening on 10.0.2.100#53 May 26 11:41:28 ipa001.domain.local named-pkcs11[16172]: exiting May 26 11:41:28 ipa001.domain.local systemd[1]: Stopped Berkeley Internet Name Domain (DNS) with native PKCS#11. Then finally the KDC is started a half minute later: May 26 11:42:09 ipa001.domain.local systemd[1]: Starting Kerberos 5 KDC... May 26 11:42:09 ipa001.domain.local systemd[1]: Started Kerberos 5 KDC. It then does seem like named-pkcs11 gets started *again*, and the sync seems to work this time: May 26 11:42:09 ipa001.domain.local systemd[1]: Starting Berkeley Internet Name Domain (DNS) with native PKCS#11... May 26 11:42:09 ipa001.domain.local bash[16803]: zone localhost.localdomain/IN: loaded serial 0 May 26 11:42:09 ipa001.domain.local bash[16803]: zone localhost/IN: loaded serial 0 May 26 11:42:09 ipa001.domain.local bash[16803]: zone 1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.ip6.arpa/IN: loaded serial 0 May 26 11:42:09 ipa001.domain.local bash[16803]: zone 1.0.0.127.in-addr.arpa/IN: loaded serial 0 May 26 11:42:09 ipa001.domain.local bash[16803]: zone 0.in-addr.arpa/IN: loaded serial 0 May 26 11:42:09 ipa001.domain.local named-pkcs11[16808]: starting BIND 9.11.0-P5-RedHat-9.11.0-8.P5.fc26 <id:ad4fb79> ... May 26 11:42:09 ipa001.domain.local named-pkcs11[16808]: all zones loaded May 26 11:42:09 ipa001.domain.local named-pkcs11[16808]: running May 26 11:42:09 ipa001.domain.local named-pkcs11[16808]: LDAP configuration for instance 'ipa' synchronized May 26 11:42:09 ipa001.domain.local named-pkcs11[16808]: GSSAPI client step 1 May 26 11:42:09 ipa001.domain.local named-pkcs11[16808]: GSSAPI client step 1 May 26 11:42:09 ipa001.domain.local named-pkcs11[16808]: GSSAPI client step 1 May 26 11:42:09 ipa001.domain.local named-pkcs11[16808]: GSSAPI client step 2 May 26 11:42:09 ipa001.domain.local named-pkcs11[16808]: LDAP data for instance 'ipa' are being synchronized, please ignore message 'all zones loaded' So this may not be critical, but I'm not sure, and figured it should still be reported. I'll attach the whole journal from the upgrade boot, and also the ipaupgrade.log file.
Metadata Update from @stlaz: - Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1456043
Metadata Update from @stlaz: - Issue assigned to stlaz
BZ closed with this reasoning:
There are many restarts of named in upgrade, I don't see this as issue because at the end of upgrade named is working
Metadata Update from @rcritten: - Issue close_status updated to: wontfix - Issue set to the milestone: None - Issue status updated to: Closed (was: Open)
Login to comment on this ticket.