SLES12 ntpd が Fail 起動できない <とその解決方法

SUSE Linux Enterprise 12 (SLES12) で ntpd が起動できない不具合があります。 ntpd deamon can't start under SUSE Linux Enterprise 12. How to resolve this issue ? No idea.... Orz.

※ この現象は AppAmor の不具合で SLE 12.0 でのみ発生し、12.1以降のバージョンでは発生しません。
おそらく他の AppAmor とは関係ないディストリビューションでは、同様の解決策にはならないと思います。

sles12:/var/log # rcntpd restart
Job for ntpd.service failed. See "systemctl status ntpd.service" and "journalctl -xn" for details.


sles12:/var/log # tail messages -n30
2014-12-06T12:10:25.604438+09:00 sles12 ntpd[23695]: Listen normally on 9 vif7.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:10:25.604576+09:00 sles12 ntpd[23695]: Listen normally on 10 vif5.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:10:25.604716+09:00 sles12 ntpd[23695]: Listen normally on 11 vif4.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:10:25.605537+09:00 sles12 ntpd[23695]: Listen normally on 14 br0 fe80::be5f:f4ff:fef9:d8db UDP 123
2014-12-06T12:10:25.605705+09:00 sles12 ntpd[23695]: peers refreshed
2014-12-06T12:10:25.605855+09:00 sles12 ntpd[23695]: Listening on routing socket on fd #31 for interface updates
2014-12-06T12:11:03.613150+09:00 sles12 ntpd[24146]: ntpd 4.2.6p5@1.2349-o Wed Oct 8 14:41:40 UTC 2014 (1)
2014-12-06T12:11:03.614227+09:00 sles12 start-ntpd[24135]: Starting network time protocol daemon (NTPD)
2014-12-06T12:11:03.614418+09:00 sles12 ntpd[24147]: proto: precision = 0.114 usec
2014-12-06T12:11:03.614604+09:00 sles12 ntpd[24147]: pid file /var/run/ntp/ntpd.pid: Permission denied
2014-12-06T12:11:03.614766+09:00 sles12 ntpd[24147]: ntp_io: estimated max descriptors: 1024, initial socket boundary: 16
2014-12-06T12:11:03.614917+09:00 sles12 ntpd[24147]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
2014-12-06T12:11:03.615979+09:00 sles12 ntpd[24147]: Listen and drop on 1 v6wildcard :: UDP 123
2014-12-06T12:11:03.616168+09:00 sles12 ntpd[24147]: Listen normally on 2 lo 127.0.0.1 UDP 123
2014-12-06T12:11:03.616327+09:00 sles12 ntpd[24147]: Listen normally on 3 br0 192.168.1.240 UDP 123
2014-12-06T12:11:03.616484+09:00 sles12 ntpd[24147]: Listen normally on 4 lo ::1 UDP 123
2014-12-06T12:11:03.616637+09:00 sles12 ntpd[24147]: Listen normally on 5 vif11.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:11:03.616791+09:00 sles12 ntpd[24147]: Listen normally on 6 vif10.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:11:03.616975+09:00 sles12 ntpd[24147]: Listen normally on 7 vif9.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:11:03.617126+09:00 sles12 ntpd[24147]: Listen normally on 8 vif7.0-emu fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:11:03.617272+09:00 sles12 ntpd[24147]: Listen normally on 9 vif7.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:11:03.617421+09:00 sles12 ntpd[24147]: Listen normally on 10 vif5.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:11:03.617568+09:00 sles12 ntpd[24147]: Listen normally on 11 vif4.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:11:03.617713+09:00 sles12 ntpd[24147]: Listen normally on 12 vif2.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:11:03.617857+09:00 sles12 ntpd[24147]: Listen normally on 13 vif1.0 fe80::fcff:ffff:feff:ffff UDP 123
2014-12-06T12:11:03.618004+09:00 sles12 ntpd[24147]: Listen normally on 14 br0 fe80::be5f:f4ff:fef9:d8db UDP 123
2014-12-06T12:11:03.618151+09:00 sles12 ntpd[24147]: peers refreshed
2014-12-06T12:11:03.618310+09:00 sles12 ntpd[24147]: Listening on routing socket on fd #31 for interface updates
2014-12-06T12:12:33.561820+09:00 sles12 systemd[1]: ntpd.service start operation timed out. Terminating.
2014-12-06T12:12:33.562738+09:00 sles12 systemd[1]: Failed to start NTP Server Daemon.
sles12:/var/log #




sles12:/var/log # systemctl status ntpd.service
ntpd.service - NTP Server Daemon
Loaded: loaded (/usr/lib/systemd/system/ntpd.service; enabled)
Active: activating (auto-restart) (Result: timeout) since Sat 2014-12-06 12:12:33 JST; 2min 0s ago
Docs: man:ntpd(1)
Process: 24135 ExecStart=/usr/sbin/start-ntpd start (code=exited, status=0/SUCCESS)

Dec 06 12:12:33 sles12 systemd[1]: ntpd.service start operation timed out...g.
Dec 06 12:12:33 sles12 systemd[1]: Failed to start NTP Server Daemon.
Hint: Some lines were ellipsized, use -l to show in full.
sles12:/var/log #



sles12:/var/log #
sles12:/var/log # journalctl -xn
-- Logs begin at Sat 2014-11-29 21:30:09 JST, end at Sat 2014-12-06 12:12:33 JS
Dec 06 12:11:03 sles12 ntpd[24147]: Listen normally on 9 vif7.0 fe80::fcff:fff
Dec 06 12:11:03 sles12 ntpd[24147]: Listen normally on 10 vif5.0 fe80::fcff:ff
Dec 06 12:11:03 sles12 ntpd[24147]: Listen normally on 11 vif4.0 fe80::fcff:ff
Dec 06 12:11:03 sles12 ntpd[24147]: Listen normally on 12 vif2.0 fe80::fcff:ff
Dec 06 12:11:03 sles12 ntpd[24147]: Listen normally on 13 vif1.0 fe80::fcff:ff
Dec 06 12:11:03 sles12 ntpd[24147]: Listen normally on 14 br0 fe80::be5f:f4ff:
Dec 06 12:11:03 sles12 ntpd[24147]: peers refreshed
Dec 06 12:11:03 sles12 ntpd[24147]: Listening on routing socket on fd #31 for
Dec 06 12:12:33 sles12 systemd[1]: ntpd.service start operation timed out. Ter
Dec 06 12:12:33 sles12 systemd[1]: Failed to start NTP Server Daemon.
-- Subject: Unit ntpd.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit ntpd.service has failed.
--
-- The result is failed.
sles12:/var/log #

sles12:~ # rpm -qa ntp
ntp-4.2.6p5-24.3.x86_64
sles12:~ #

どうも systemd 環境下で ntpd を動かすと、適切な権限で pid が作成されないために発生する現象の様です。

-Resolution-

NTP Service Fails to Start or Hangs on SLES12
https://www.novell.com/support/kb/doc.php?id=7015867#

SLES12.0 の ntpd が起動しない問題は "logprof"コマンドを rcntpd を実行してタイムアウトした後に実行して修正できます。

※一応これで直ったみたい。Is it work ? I wonder....? Actuary recovered.

https://forums.suse.com/showthread.php?5548-SUSE-12-ntp-fails-to-start

NTP Is Enabled but Not Starting on Boot
http://www.reddit.com/r/linuxadmin/comments/2k4odu/ntp_is_enabled_but_not_starting_on_boot_systemd/

-Resolved-

sles12:~ # rcntpd restart
Job for ntpd.service failed. See "systemctl status ntpd.service" and "journalctl -xn" for details.

-- wait ... for time out ----

sles12:~ # logprof
Reading log entries from /var/log/messages.
Updating AppArmor profiles in /etc/apparmor.d.
Enforce-mode changes:

Profile: /usr/sbin/ntpd
Path: /run/nscd/group
Mode: r
Severity: unknown


[1 - /run/nscd/group]

(A)llow / [(D)eny] / (G)lob / Glob w/(E)xt / (N)ew / Abo(r)t / (F)inish / (O)pts
Adding /run/nscd/group r to profile. <-----(A)llow

Profile: /usr/sbin/ntpd
Path: /var/lib/ntp/var/run/ntp/ntpd.pid
Mode: w
Severity: unknown


[1 - /var/lib/ntp/var/run/ntp/ntpd.pid]

(A)llow / [(D)eny] / (G)lob / Glob w/(E)xt / (N)ew / Abo(r)t / (F)inish / (O)pts
Adding /var/lib/ntp/var/run/ntp/ntpd.pid w to profile. <----- (A)llow

= Changed Local Profiles =

The following local profiles were changed. Would you like to save them?

[1 - /usr/sbin/ntpd]

(S)ave Changes / [(V)iew Changes] / Abo(r)t <-----(S)ave
Writing updated profile for /usr/sbin/ntpd.
sles12:~ #

sles12:~ # systemctl restart ntpd.service
sles12:~ # systemctl status ntpd.service
ntpd.service - NTP Server Daemon
Loaded: loaded (/usr/lib/systemd/system/ntpd.service; disabled)
Active: active (running) since Tue 2014-12-30 12:30:55 JST; 4s ago
Docs: man:ntpd(1)
Process: 1445 ExecStart=/usr/sbin/start-ntpd start (code=exited, status=0/SUCCESS)
Main PID: 1457 (ntpd)
CGroup: /system.slice/ntpd.service
└─1457 /usr/sbin/ntpd -p /var/run/ntp/ntpd.pid -g -u ntp:ntp -i /var/lib/ntp -c /etc/...

Dec 30 12:30:55 sles12 ntpd[1457]: proto: precision = 0.700 usec
Dec 30 12:30:55 sles12 ntpd[1457]: ntp_io: estimated max descriptors: 1024, initial socket b...: 16
Dec 30 12:30:55 sles12 ntpd[1457]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
Dec 30 12:30:55 sles12 ntpd[1457]: Listen and drop on 1 v6wildcard :: UDP 123
Dec 30 12:30:55 sles12 ntpd[1457]: Listen normally on 2 lo 127.0.0.1 UDP 123
Dec 30 12:30:55 sles12 ntpd[1457]: Listen normally on 3 eth0 192.168.1.106 UDP 123
Dec 30 12:30:55 sles12 ntpd[1457]: Listen normally on 4 lo ::1 UDP 123
Dec 30 12:30:55 sles12 ntpd[1457]: Listen normally on 5 eth0 fe80::215:5dff:fe01:301b UDP 123
Dec 30 12:30:55 sles12 ntpd[1457]: peers refreshed
Dec 30 12:30:55 sles12 ntpd[1457]: Listening on routing socket on fd #22 for interface updates
Hint: Some lines were ellipsized, use -l to show in full.
sles12:~ #
sles12:~ # tail /var/log/messages -n20
2014-12-30T12:25:01.799524+09:00 sles12 CRON[1373]: pam_unix(crond:session): session closed for user root
2014-12-30T12:30:01.834347+09:00 sles12 cron[1394]: pam_unix(crond:session): session opened for user root by (uid=0)
2014-12-30T12:30:01.835574+09:00 sles12 kernel: [ 404.013874] type=1006 audit(1419910201.829:43): pid=1394 uid=0 old auid=4294967295 new auid=0 old ses=4294967295 new ses=3 res=1
2014-12-30T12:30:01.843309+09:00 sles12 cron[1393]: pam_unix(crond:session): session opened for user root by (uid=0)
2014-12-30T12:30:01.843903+09:00 sles12 kernel: [ 404.022834] type=1006 audit(1419910201.837:44): pid=1393 uid=0 old auid=4294967295 new auid=0 old ses=4294967295 new ses=4 res=1
2014-12-30T12:30:01.910931+09:00 sles12 CRON[1394]: pam_unix(crond:session): session closed for user root
2014-12-30T12:30:02.170278+09:00 sles12 CRON[1393]: pam_unix(crond:session): session closed for user root
2014-12-30T12:30:29.961321+09:00 sles12 kernel: [ 432.135604] type=1400 audit(1419910229.953:45): apparmor="STATUS" operation="profile_replace" name="/usr/sbin/ntpd" pid=1440 comm="apparmor_parser"
2014-12-30T12:30:55.617362+09:00 sles12 ntpd[1456]: ntpd 4.2.6p5@1.2349-o Wed Oct 8 14:41:40 UTC 2014 (1)
2014-12-30T12:30:55.618768+09:00 sles12 start-ntpd[1445]: Starting network time protocol daemon (NTPD)
2014-12-30T12:30:55.623503+09:00 sles12 ntpd[1457]: proto: precision = 0.700 usec
2014-12-30T12:30:55.631189+09:00 sles12 ntpd[1457]: ntp_io: estimated max descriptors: 1024, initial socket boundary: 16
2014-12-30T12:30:55.631466+09:00 sles12 ntpd[1457]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
2014-12-30T12:30:55.631662+09:00 sles12 ntpd[1457]: Listen and drop on 1 v6wildcard :: UDP 123
2014-12-30T12:30:55.631878+09:00 sles12 ntpd[1457]: Listen normally on 2 lo 127.0.0.1 UDP 123
2014-12-30T12:30:55.632080+09:00 sles12 ntpd[1457]: Listen normally on 3 eth0 192.168.1.106 UDP 123
2014-12-30T12:30:55.632267+09:00 sles12 ntpd[1457]: Listen normally on 4 lo ::1 UDP 123
2014-12-30T12:30:55.632448+09:00 sles12 ntpd[1457]: Listen normally on 5 eth0 fe80::215:5dff:fe01:301b UDP 123
2014-12-30T12:30:55.632625+09:00 sles12 ntpd[1457]: peers refreshed
2014-12-30T12:30:55.633183+09:00 sles12 ntpd[1457]: Listening on routing socket on fd #22 for interface updates
sles12:~ #
sles12:~ # rcntpd restart
sles12:~ #
<---- success!!

問題なく ntpd が起動できました。yast からの ntp の設定も問題なく行えます。

- 参照 -
SUSE Linux (SLES12) を YaST で NTP の設定

-Keyword-
SUSE Linux Enterprise Server 12 SLES12 ntpd restart fail solved

サブスクリプション購入はこちら


islandcenter.jp



by islandcenter | 2014-12-06 19:56 | SUSE | Comments(0)