ntp.confの実験 (2009/09/24)
ntp_config.cのソースファイルを見ていたら、"maxpoll: provided value (%d) is above maximum (%d)"というメッセージがあった。
maxpollの最大値は16とされているので、ntp.conf内で"maxpoll 20"と設定をするとエラーメッセージが出力されると思ってテストした。
開発1号機:ntp-4.1.2-4.EL3.1
開発2号機:ntp-4.2.0.a.20040617-4.EL4.1
試みその一
試してみました。"maxpoll 20"で。
結果(1号機):
ntpd.log
"
15 Sep 12:57:51 ntpd[31704]: running as uid(38)/gid(38) euid(38)/egid(38).
15 Sep 12:57:51 ntpd[31704]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
15 Sep 12:57:53 ntpd[31704]: peer 123.456.789.098 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 12:58:06 ntpd[31704]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 12:59:00 ntpd[31704]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_ntp, 2 events, event_restart' (0xc621)
15 Sep 12:59:00 ntpd[31704]: kernel time discipline status change 41
15 Sep 12:59:00 ntpd[31704]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_ntp, 3 events, event_peer/strat_chg' (0x634)
15 Sep 12:59:00 ntpd[31704]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_ntp, 4 events, event_sync_chg' (0x643)
15 Sep 12:59:34 ntpd[31704]: kernel time discipline status change 1
15 Sep 13:57:50 ntpd[31704]: offset 0.000048 sec freq 7.999 ppm error 0.000052 poll 4
15 Sep 14:57:51 ntpd[31704]: offset -0.000238 sec freq 9.235 ppm error 0.000054 poll 5
15 Sep 15:57:51 ntpd[31704]: offset 0.000064 sec freq 8.666 ppm error 0.000020 poll 6
15 Sep 16:57:51 ntpd[31704]: offset -0.000692 sec freq 8.988 ppm error 0.002022 poll 7
15 Sep 17:57:51 ntpd[31704]: offset -0.000660 sec freq 8.863 ppm error 0.000429 poll 10
15 Sep 18:57:51 ntpd[31704]: offset -0.000444 sec freq 8.859 ppm error 0.000740 poll 11
15 Sep 19:36:13 ntpd[31704]: kernel time discipline status change 9
15 Sep 19:57:51 ntpd[31704]: offset -0.008352 sec freq 8.179 ppm error 0.003542 poll 11
15 Sep 20:57:51 ntpd[31704]: offset 0.002172 sec freq 8.547 ppm error 0.004831 poll 12
15 Sep 21:57:51 ntpd[31704]: offset 0.000417 sec freq 8.598 ppm error 0.004275 poll 12
15 Sep 22:57:51 ntpd[31704]: offset 0.000660 sec freq 8.638 ppm error 0.003704 poll 12
15 Sep 23:57:51 ntpd[31704]: offset -0.000731 sec freq 8.594 ppm error 0.003282 poll 13
16 Sep 00:57:51 ntpd[31704]: offset -0.000750 sec freq 8.548 ppm error 0.002843 poll 13
16 Sep 01:57:51 ntpd[31704]: offset -0.000750 sec freq 8.548 ppm error 0.002843 poll 13
16 Sep 02:57:51 ntpd[31704]: offset -0.000750 sec freq 8.548 ppm error 0.002843 poll 13
16 Sep 03:57:51 ntpd[31704]: offset -0.008941 sec freq 8.275 ppm error 0.004778 poll 13
16 Sep 04:57:51 ntpd[31704]: offset -0.008941 sec freq 8.275 ppm error 0.004778 poll 13
16 Sep 05:57:51 ntpd[31704]: offset 0.004730 sec freq 8.419 ppm error 0.007990 poll 14
16 Sep 06:57:51 ntpd[31704]: offset 0.004730 sec freq 8.419 ppm error 0.007990 poll 14
16 Sep 07:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 08:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 09:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 10:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 11:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 12:57:51 ntpd[31704]: offset -0.005281 sec freq 8.317 ppm error 0.006833 poll 14
16 Sep 13:57:51 ntpd[31704]: offset -0.005281 sec freq 8.317 ppm error 0.006833 poll 14
16 Sep 14:57:51 ntpd[31704]: offset -0.005281 sec freq 8.317 ppm error 0.006833 poll 14
16 Sep 15:57:51 ntpd[31704]: offset -0.005281 sec freq 8.317 ppm error 0.006833 poll 14
16 Sep 16:57:51 ntpd[31704]: offset 0.011501 sec freq 8.492 ppm error 0.010268 poll 15
16 Sep 17:57:51 ntpd[31704]: offset 0.011501 sec freq 8.492 ppm error 0.010268 poll 15
~中略~
17 Sep 13:57:52 ntpd[31704]: offset -0.001231 sec freq 8.443 ppm error 0.009870 poll 15
17 Sep 14:57:52 ntpd[31704]: offset -0.001231 sec freq 8.443 ppm error 0.009870 poll 15
17 Sep 15:57:52 ntpd[31704]: offset -0.004637 sec freq 8.407 ppm error 0.008715 poll 16
17 Sep 16:57:52 ntpd[31704]: offset -0.004637 sec freq 8.407 ppm error 0.008715 poll 16
~中略~
18 Sep 16:57:53 ntpd[31704]: offset -0.001362 sec freq 8.397 ppm error 0.007723 poll 16
18 Sep 17:57:53 ntpd[31704]: offset -0.001362 sec freq 8.397 ppm error 0.007723 poll 16
18 Sep 18:57:53 ntpd[31704]: offset 0.000106 sec freq 8.397 ppm error 0.006729 poll 17
18 Sep 19:57:53 ntpd[31704]: offset 0.000106 sec freq 8.397 ppm error 0.006729 poll 17
~中略~
19 Sep 10:57:53 ntpd[31704]: offset 0.000106 sec freq 8.397 ppm error 0.006729 poll 17
19 Sep 11:57:53 ntpd[31704]: offset 0.000106 sec freq 8.397 ppm error 0.006729 poll 17
19 Sep 12:57:53 ntpd[31704]: offset -0.002818 sec freq 8.386 ppm error 0.006008 poll 16
19 Sep 13:57:53 ntpd[31704]: offset -0.002818 sec freq 8.386 ppm error 0.006008 poll 16
~中略~
21 Sep 17:57:55 ntpd[31704]: offset 0.004329 sec freq 8.395 ppm error 0.006312 poll 16
21 Sep 18:57:55 ntpd[31704]: offset 0.004329 sec freq 8.395 ppm error 0.006312 poll 16
21 Sep 19:57:55 ntpd[31704]: offset 0.000772 sec freq 8.398 ppm error 0.005748 poll 17
21 Sep 20:57:55 ntpd[31704]: offset 0.000772 sec freq 8.398 ppm error 0.005748 poll 17
~中略~
22 Sep 11:57:56 ntpd[31704]: offset 0.000772 sec freq 8.398 ppm error 0.005748 poll 17
22 Sep 12:57:56 ntpd[31704]: offset 0.000772 sec freq 8.398 ppm error 0.005748 poll 17
22 Sep 13:57:56 ntpd[31704]: offset -0.004090 sec freq 8.382 ppm error 0.005540 poll 16
22 Sep 14:57:56 ntpd[31704]: offset -0.004090 sec freq 8.382 ppm error 0.005540 poll 16
~中略~
23 Sep 21:57:57 ntpd[31704]: offset -0.004090 sec freq 8.382 ppm error 0.005540 poll 16
23 Sep 22:57:57 ntpd[31704]: offset -0.004090 sec freq 8.382 ppm error 0.005540 poll 16
23 Sep 23:33:31 ntpd[31704]: kernel time discipline status change 1
23 Sep 23:57:57 ntpd[31704]: offset 0.000000 sec freq 8.382 ppm error 0.000203 poll 6
24 Sep 00:57:57 ntpd[31704]: offset 0.000000 sec freq 8.382 ppm error 0.000005 poll 6
24 Sep 01:57:57 ntpd[31704]: offset 0.000000 sec freq 8.382 ppm error 0.000005 poll 6
24 Sep 02:57:57 ntpd[31704]: offset 0.000624 sec freq 7.146 ppm error 0.000218 poll 9
24 Sep 03:57:57 ntpd[31704]: offset 0.003131 sec freq 7.178 ppm error 0.000655 poll 10
24 Sep 04:57:57 ntpd[31704]: offset 0.004188 sec freq 7.312 ppm error 0.000528 poll 8
24 Sep 05:57:57 ntpd[31704]: offset 0.000421 sec freq 8.024 ppm error 0.000102 poll 9
24 Sep 06:57:57 ntpd[31704]: offset 0.000054 sec freq 8.189 ppm error 0.000016 poll 6
24 Sep 07:57:57 ntpd[31704]: offset 0.000132 sec freq 8.311 ppm error 0.000022 poll 7
24 Sep 08:57:57 ntpd[31704]: offset -0.000058 sec freq 8.335 ppm error 0.001162 poll 9
"
ntpq -p
なぜ途中でpolling 16から6に戻ってしまったのかはこのログからだと不明です。"kernel time discipline status change 1"はntpデーモンを起動したときにも出てくるメッセージなので、もしかしたら途中でデーモンが落ちた??謎です。
そもそも期待していたエラーが出なかったのが残念でした。
結果(2号機):
ntpd.log
"
15 Sep 12:57:23 ntpd[20341]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
15 Sep 12:57:24 ntpd[20341]: peer 123.456.789.098 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 12:57:25 ntpd[20341]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 13:00:09 ntpd[20341]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_ntp, 2 events, event_restart' (0xc621)
15 Sep 13:00:09 ntpd[20341]: synchronized to 123.456.789.098, stratum 2
15 Sep 13:00:09 ntpd[20341]: kernel time sync disabled 0041
15 Sep 13:00:09 ntpd[20341]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_ntp, 3 events, event_peer/strat_chg' (0x634)
15 Sep 13:00:09 ntpd[20341]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_ntp, 4 events, event_sync_chg' (0x643)
15 Sep 13:01:14 ntpd[20341]: kernel time sync enabled 0001
15 Sep 13:57:26 ntpd[20341]: offset 0.000076 sec freq -10.358 ppm error 0.000500 poll 7
15 Sep 14:57:29 ntpd[20341]: offset 0.001830 sec freq -10.103 ppm error 0.000667 poll 8
15 Sep 15:57:32 ntpd[20341]: offset 0.000819 sec freq -10.060 ppm error 0.000518 poll 9
15 Sep 16:57:35 ntpd[20341]: offset 0.003252 sec freq -10.038 ppm error 0.001683 poll 10
15 Sep 17:16:59 ntpd[20341]: kernel time sync enabled 0009
15 Sep 17:57:38 ntpd[20341]: offset 0.000493 sec freq -9.740 ppm error 0.000456 poll 11
15 Sep 18:57:41 ntpd[20341]: offset 0.001259 sec freq -9.586 ppm error 0.000766 poll 12
15 Sep 19:57:44 ntpd[20341]: offset -0.007421 sec freq -10.491 ppm error 0.008680 poll 12
15 Sep 20:57:48 ntpd[20341]: offset 0.001426 sec freq -10.404 ppm error 0.008847 poll 12
15 Sep 21:57:51 ntpd[20341]: offset 0.005827 sec freq -10.049 ppm error 0.004401 poll 13
15 Sep 22:57:54 ntpd[20341]: offset 0.000494 sec freq -10.019 ppm error 0.005333 poll 13
15 Sep 23:57:57 ntpd[20341]: offset 0.000494 sec freq -10.019 ppm error 0.005333 poll 13
16 Sep 00:58:00 ntpd[20341]: offset 0.000733 sec freq -9.997 ppm error 0.000239 poll 13
16 Sep 01:58:03 ntpd[20341]: offset 0.000733 sec freq -9.997 ppm error 0.000239 poll 13
16 Sep 02:58:06 ntpd[20341]: offset -0.007565 sec freq -10.227 ppm error 0.008298 poll 14
16 Sep 03:58:09 ntpd[20341]: offset -0.007565 sec freq -10.227 ppm error 0.008298 poll 14
16 Sep 04:58:12 ntpd[20341]: offset -0.007565 sec freq -10.227 ppm error 0.008298 poll 14
16 Sep 05:58:15 ntpd[20341]: offset 0.006732 sec freq -10.022 ppm error 0.014298 poll 14
16 Sep 06:58:18 ntpd[20341]: offset 0.006732 sec freq -10.022 ppm error 0.014298 poll 14
16 Sep 07:58:21 ntpd[20341]: offset 0.006732 sec freq -10.022 ppm error 0.014298 poll 14
16 Sep 08:58:24 ntpd[20341]: offset 0.006732 sec freq -10.022 ppm error 0.014298 poll 14
16 Sep 09:58:27 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 10:58:30 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 11:58:33 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 12:58:36 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 13:58:39 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 14:58:42 ntpd[20341]: offset -0.000757 sec freq -10.004 ppm error 0.002667 poll 15
16 Sep 15:58:45 ntpd[20341]: offset -0.000757 sec freq -10.004 ppm error 0.002667 poll 15
~中略~
17 Sep 11:59:45 ntpd[20341]: offset 0.029060 sec freq -9.779 ppm error 0.028832 poll 15
17 Sep 12:59:48 ntpd[20341]: offset 0.029060 sec freq -9.779 ppm error 0.028832 poll 15
17 Sep 13:59:52 ntpd[20341]: offset 0.019983 sec freq -9.627 ppm error 0.009077 poll 16
17 Sep 14:59:55 ntpd[20341]: offset 0.019983 sec freq -9.627 ppm error 0.009077 poll 16
~中略~
18 Sep 15:01:07 ntpd[20341]: offset 0.021678 sec freq -9.462 ppm error 0.001695 poll 16
18 Sep 16:01:10 ntpd[20341]: offset 0.021678 sec freq -9.462 ppm error 0.001695 poll 16
18 Sep 17:01:13 ntpd[20341]: offset 0.001315 sec freq -9.457 ppm error 0.020363 poll 17
18 Sep 18:01:16 ntpd[20341]: offset 0.001315 sec freq -9.457 ppm error 0.020363 poll 17
~中略~
24 Sep 08:08:02 ntpd[20341]: offset 0.096578 sec freq -9.175 ppm error 0.051412 poll 17
24 Sep 09:08:05 ntpd[20341]: offset 0.096578 sec freq -9.175 ppm error 0.051412 poll 17
"
ntpq -p
1号機とは違い、こちらはずっと安定してpolling 17となっています。polling 16から17になるまでに丸一日。polling 17になってからすでに五日半経っているのにまだ18にならない。
でも、36時間に一度の時刻調整でも数十ミリ秒のずれなんだからなかなかすごいと思う(開発サーバーで今回の実験中ほとんど無負荷だったのも影響しているだろうが)。
こちらのサーバーでも期待していたエラーは出力されませんでした。何かテストの仕方が間違っているのかも・・・
試みその二
ついでなので、maxpollとminpollの値が逆になるようにも設定してみました。"minpoll 14 maxpoll 10"で。
こちらは結果が出るのがとても早かったです。
結果(開発1号機):
ntpd.log
"
14 Sep 13:27:34 ntpd[16798]: running as uid(38)/gid(38) euid(38)/egid(38).
14 Sep 13:27:34 ntpd[16798]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
14 Sep 13:27:43 ntpd[16798]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
14 Sep 13:30:55 ntpd[16798]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_local_proto, 2 events, event_restart' (0xc521)
14 Sep 13:30:55 ntpd[16798]: kernel time discipline status change 41
14 Sep 13:30:55 ntpd[16798]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_local_proto, 3 events, event_peer/strat_chg' (0x534)
14 Sep 13:30:55 ntpd[16798]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_local_proto, 4 events, event_sync_chg' (0x543)
14 Sep 13:31:58 ntpd[16798]: kernel time discipline status change 1
14 Sep 14:27:34 ntpd[16798]: offset 0.000000 sec freq 8.386 ppm error 0.000011 poll 6
"
ntpq -p
結果(開発2号機):
ntpd.log
"
15 Sep 09:41:59 ntpd[19023]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
15 Sep 09:42:00 ntpd[19023]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 09:45:14 ntpd[19023]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_local_proto, 2 events, event_restart' (0xc521)
15 Sep 09:45:14 ntpd[19023]: synchronized to LOCAL(0), stratum 10
15 Sep 09:45:14 ntpd[19023]: kernel time sync disabled 0041
15 Sep 09:45:14 ntpd[19023]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_local_proto, 3 events, event_peer/strat_chg' (0x534)
15 Sep 09:45:14 ntpd[19023]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_local_proto, 4 events, event_sync_chg' (0x543)
15 Sep 09:46:20 ntpd[19023]: kernel time sync enabled 0001
"
ntpq -p
エラーログは出力されなかったけれども、指定した時刻サーバーとは同期されませんでした。どうやら、minpollがmaxpollを上回る設定になっていると、時刻同期サーバーはLOCALとして動くようです(その他設定が間違っているときもそうなるのかはまた別の機会に調べます)。
maxpollの最大値は16とされているので、ntp.conf内で"maxpoll 20"と設定をするとエラーメッセージが出力されると思ってテストした。
開発1号機:ntp-4.1.2-4.EL3.1
開発2号機:ntp-4.2.0.a.20040617-4.EL4.1
試みその一
試してみました。"maxpoll 20"で。
結果(1号機):
ntpd.log
"
15 Sep 12:57:51 ntpd[31704]: running as uid(38)/gid(38) euid(38)/egid(38).
15 Sep 12:57:51 ntpd[31704]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
15 Sep 12:57:53 ntpd[31704]: peer 123.456.789.098 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 12:58:06 ntpd[31704]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 12:59:00 ntpd[31704]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_ntp, 2 events, event_restart' (0xc621)
15 Sep 12:59:00 ntpd[31704]: kernel time discipline status change 41
15 Sep 12:59:00 ntpd[31704]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_ntp, 3 events, event_peer/strat_chg' (0x634)
15 Sep 12:59:00 ntpd[31704]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_ntp, 4 events, event_sync_chg' (0x643)
15 Sep 12:59:34 ntpd[31704]: kernel time discipline status change 1
15 Sep 13:57:50 ntpd[31704]: offset 0.000048 sec freq 7.999 ppm error 0.000052 poll 4
15 Sep 14:57:51 ntpd[31704]: offset -0.000238 sec freq 9.235 ppm error 0.000054 poll 5
15 Sep 15:57:51 ntpd[31704]: offset 0.000064 sec freq 8.666 ppm error 0.000020 poll 6
15 Sep 16:57:51 ntpd[31704]: offset -0.000692 sec freq 8.988 ppm error 0.002022 poll 7
15 Sep 17:57:51 ntpd[31704]: offset -0.000660 sec freq 8.863 ppm error 0.000429 poll 10
15 Sep 18:57:51 ntpd[31704]: offset -0.000444 sec freq 8.859 ppm error 0.000740 poll 11
15 Sep 19:36:13 ntpd[31704]: kernel time discipline status change 9
15 Sep 19:57:51 ntpd[31704]: offset -0.008352 sec freq 8.179 ppm error 0.003542 poll 11
15 Sep 20:57:51 ntpd[31704]: offset 0.002172 sec freq 8.547 ppm error 0.004831 poll 12
15 Sep 21:57:51 ntpd[31704]: offset 0.000417 sec freq 8.598 ppm error 0.004275 poll 12
15 Sep 22:57:51 ntpd[31704]: offset 0.000660 sec freq 8.638 ppm error 0.003704 poll 12
15 Sep 23:57:51 ntpd[31704]: offset -0.000731 sec freq 8.594 ppm error 0.003282 poll 13
16 Sep 00:57:51 ntpd[31704]: offset -0.000750 sec freq 8.548 ppm error 0.002843 poll 13
16 Sep 01:57:51 ntpd[31704]: offset -0.000750 sec freq 8.548 ppm error 0.002843 poll 13
16 Sep 02:57:51 ntpd[31704]: offset -0.000750 sec freq 8.548 ppm error 0.002843 poll 13
16 Sep 03:57:51 ntpd[31704]: offset -0.008941 sec freq 8.275 ppm error 0.004778 poll 13
16 Sep 04:57:51 ntpd[31704]: offset -0.008941 sec freq 8.275 ppm error 0.004778 poll 13
16 Sep 05:57:51 ntpd[31704]: offset 0.004730 sec freq 8.419 ppm error 0.007990 poll 14
16 Sep 06:57:51 ntpd[31704]: offset 0.004730 sec freq 8.419 ppm error 0.007990 poll 14
16 Sep 07:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 08:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 09:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 10:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 11:57:51 ntpd[31704]: offset -0.000711 sec freq 8.397 ppm error 0.007436 poll 14
16 Sep 12:57:51 ntpd[31704]: offset -0.005281 sec freq 8.317 ppm error 0.006833 poll 14
16 Sep 13:57:51 ntpd[31704]: offset -0.005281 sec freq 8.317 ppm error 0.006833 poll 14
16 Sep 14:57:51 ntpd[31704]: offset -0.005281 sec freq 8.317 ppm error 0.006833 poll 14
16 Sep 15:57:51 ntpd[31704]: offset -0.005281 sec freq 8.317 ppm error 0.006833 poll 14
16 Sep 16:57:51 ntpd[31704]: offset 0.011501 sec freq 8.492 ppm error 0.010268 poll 15
16 Sep 17:57:51 ntpd[31704]: offset 0.011501 sec freq 8.492 ppm error 0.010268 poll 15
~中略~
17 Sep 13:57:52 ntpd[31704]: offset -0.001231 sec freq 8.443 ppm error 0.009870 poll 15
17 Sep 14:57:52 ntpd[31704]: offset -0.001231 sec freq 8.443 ppm error 0.009870 poll 15
17 Sep 15:57:52 ntpd[31704]: offset -0.004637 sec freq 8.407 ppm error 0.008715 poll 16
17 Sep 16:57:52 ntpd[31704]: offset -0.004637 sec freq 8.407 ppm error 0.008715 poll 16
~中略~
18 Sep 16:57:53 ntpd[31704]: offset -0.001362 sec freq 8.397 ppm error 0.007723 poll 16
18 Sep 17:57:53 ntpd[31704]: offset -0.001362 sec freq 8.397 ppm error 0.007723 poll 16
18 Sep 18:57:53 ntpd[31704]: offset 0.000106 sec freq 8.397 ppm error 0.006729 poll 17
18 Sep 19:57:53 ntpd[31704]: offset 0.000106 sec freq 8.397 ppm error 0.006729 poll 17
~中略~
19 Sep 10:57:53 ntpd[31704]: offset 0.000106 sec freq 8.397 ppm error 0.006729 poll 17
19 Sep 11:57:53 ntpd[31704]: offset 0.000106 sec freq 8.397 ppm error 0.006729 poll 17
19 Sep 12:57:53 ntpd[31704]: offset -0.002818 sec freq 8.386 ppm error 0.006008 poll 16
19 Sep 13:57:53 ntpd[31704]: offset -0.002818 sec freq 8.386 ppm error 0.006008 poll 16
~中略~
21 Sep 17:57:55 ntpd[31704]: offset 0.004329 sec freq 8.395 ppm error 0.006312 poll 16
21 Sep 18:57:55 ntpd[31704]: offset 0.004329 sec freq 8.395 ppm error 0.006312 poll 16
21 Sep 19:57:55 ntpd[31704]: offset 0.000772 sec freq 8.398 ppm error 0.005748 poll 17
21 Sep 20:57:55 ntpd[31704]: offset 0.000772 sec freq 8.398 ppm error 0.005748 poll 17
~中略~
22 Sep 11:57:56 ntpd[31704]: offset 0.000772 sec freq 8.398 ppm error 0.005748 poll 17
22 Sep 12:57:56 ntpd[31704]: offset 0.000772 sec freq 8.398 ppm error 0.005748 poll 17
22 Sep 13:57:56 ntpd[31704]: offset -0.004090 sec freq 8.382 ppm error 0.005540 poll 16
22 Sep 14:57:56 ntpd[31704]: offset -0.004090 sec freq 8.382 ppm error 0.005540 poll 16
~中略~
23 Sep 21:57:57 ntpd[31704]: offset -0.004090 sec freq 8.382 ppm error 0.005540 poll 16
23 Sep 22:57:57 ntpd[31704]: offset -0.004090 sec freq 8.382 ppm error 0.005540 poll 16
23 Sep 23:33:31 ntpd[31704]: kernel time discipline status change 1
23 Sep 23:57:57 ntpd[31704]: offset 0.000000 sec freq 8.382 ppm error 0.000203 poll 6
24 Sep 00:57:57 ntpd[31704]: offset 0.000000 sec freq 8.382 ppm error 0.000005 poll 6
24 Sep 01:57:57 ntpd[31704]: offset 0.000000 sec freq 8.382 ppm error 0.000005 poll 6
24 Sep 02:57:57 ntpd[31704]: offset 0.000624 sec freq 7.146 ppm error 0.000218 poll 9
24 Sep 03:57:57 ntpd[31704]: offset 0.003131 sec freq 7.178 ppm error 0.000655 poll 10
24 Sep 04:57:57 ntpd[31704]: offset 0.004188 sec freq 7.312 ppm error 0.000528 poll 8
24 Sep 05:57:57 ntpd[31704]: offset 0.000421 sec freq 8.024 ppm error 0.000102 poll 9
24 Sep 06:57:57 ntpd[31704]: offset 0.000054 sec freq 8.189 ppm error 0.000016 poll 6
24 Sep 07:57:57 ntpd[31704]: offset 0.000132 sec freq 8.311 ppm error 0.000022 poll 7
24 Sep 08:57:57 ntpd[31704]: offset -0.000058 sec freq 8.335 ppm error 0.001162 poll 9
"
ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
*123.456.789.098 123.456.789.1 2 u 429 512 377 0.135 -0.022 0.028
LOCAL(0) LOCAL(0) 11 l 41 64 377 0.000 0.000 0.004
なぜ途中でpolling 16から6に戻ってしまったのかはこのログからだと不明です。"kernel time discipline status change 1"はntpデーモンを起動したときにも出てくるメッセージなので、もしかしたら途中でデーモンが落ちた??謎です。
そもそも期待していたエラーが出なかったのが残念でした。
結果(2号機):
ntpd.log
"
15 Sep 12:57:23 ntpd[20341]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
15 Sep 12:57:24 ntpd[20341]: peer 123.456.789.098 event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 12:57:25 ntpd[20341]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 13:00:09 ntpd[20341]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_ntp, 2 events, event_restart' (0xc621)
15 Sep 13:00:09 ntpd[20341]: synchronized to 123.456.789.098, stratum 2
15 Sep 13:00:09 ntpd[20341]: kernel time sync disabled 0041
15 Sep 13:00:09 ntpd[20341]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_ntp, 3 events, event_peer/strat_chg' (0x634)
15 Sep 13:00:09 ntpd[20341]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_ntp, 4 events, event_sync_chg' (0x643)
15 Sep 13:01:14 ntpd[20341]: kernel time sync enabled 0001
15 Sep 13:57:26 ntpd[20341]: offset 0.000076 sec freq -10.358 ppm error 0.000500 poll 7
15 Sep 14:57:29 ntpd[20341]: offset 0.001830 sec freq -10.103 ppm error 0.000667 poll 8
15 Sep 15:57:32 ntpd[20341]: offset 0.000819 sec freq -10.060 ppm error 0.000518 poll 9
15 Sep 16:57:35 ntpd[20341]: offset 0.003252 sec freq -10.038 ppm error 0.001683 poll 10
15 Sep 17:16:59 ntpd[20341]: kernel time sync enabled 0009
15 Sep 17:57:38 ntpd[20341]: offset 0.000493 sec freq -9.740 ppm error 0.000456 poll 11
15 Sep 18:57:41 ntpd[20341]: offset 0.001259 sec freq -9.586 ppm error 0.000766 poll 12
15 Sep 19:57:44 ntpd[20341]: offset -0.007421 sec freq -10.491 ppm error 0.008680 poll 12
15 Sep 20:57:48 ntpd[20341]: offset 0.001426 sec freq -10.404 ppm error 0.008847 poll 12
15 Sep 21:57:51 ntpd[20341]: offset 0.005827 sec freq -10.049 ppm error 0.004401 poll 13
15 Sep 22:57:54 ntpd[20341]: offset 0.000494 sec freq -10.019 ppm error 0.005333 poll 13
15 Sep 23:57:57 ntpd[20341]: offset 0.000494 sec freq -10.019 ppm error 0.005333 poll 13
16 Sep 00:58:00 ntpd[20341]: offset 0.000733 sec freq -9.997 ppm error 0.000239 poll 13
16 Sep 01:58:03 ntpd[20341]: offset 0.000733 sec freq -9.997 ppm error 0.000239 poll 13
16 Sep 02:58:06 ntpd[20341]: offset -0.007565 sec freq -10.227 ppm error 0.008298 poll 14
16 Sep 03:58:09 ntpd[20341]: offset -0.007565 sec freq -10.227 ppm error 0.008298 poll 14
16 Sep 04:58:12 ntpd[20341]: offset -0.007565 sec freq -10.227 ppm error 0.008298 poll 14
16 Sep 05:58:15 ntpd[20341]: offset 0.006732 sec freq -10.022 ppm error 0.014298 poll 14
16 Sep 06:58:18 ntpd[20341]: offset 0.006732 sec freq -10.022 ppm error 0.014298 poll 14
16 Sep 07:58:21 ntpd[20341]: offset 0.006732 sec freq -10.022 ppm error 0.014298 poll 14
16 Sep 08:58:24 ntpd[20341]: offset 0.006732 sec freq -10.022 ppm error 0.014298 poll 14
16 Sep 09:58:27 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 10:58:30 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 11:58:33 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 12:58:36 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 13:58:39 ntpd[20341]: offset 0.001910 sec freq -9.993 ppm error 0.004822 poll 14
16 Sep 14:58:42 ntpd[20341]: offset -0.000757 sec freq -10.004 ppm error 0.002667 poll 15
16 Sep 15:58:45 ntpd[20341]: offset -0.000757 sec freq -10.004 ppm error 0.002667 poll 15
~中略~
17 Sep 11:59:45 ntpd[20341]: offset 0.029060 sec freq -9.779 ppm error 0.028832 poll 15
17 Sep 12:59:48 ntpd[20341]: offset 0.029060 sec freq -9.779 ppm error 0.028832 poll 15
17 Sep 13:59:52 ntpd[20341]: offset 0.019983 sec freq -9.627 ppm error 0.009077 poll 16
17 Sep 14:59:55 ntpd[20341]: offset 0.019983 sec freq -9.627 ppm error 0.009077 poll 16
~中略~
18 Sep 15:01:07 ntpd[20341]: offset 0.021678 sec freq -9.462 ppm error 0.001695 poll 16
18 Sep 16:01:10 ntpd[20341]: offset 0.021678 sec freq -9.462 ppm error 0.001695 poll 16
18 Sep 17:01:13 ntpd[20341]: offset 0.001315 sec freq -9.457 ppm error 0.020363 poll 17
18 Sep 18:01:16 ntpd[20341]: offset 0.001315 sec freq -9.457 ppm error 0.020363 poll 17
~中略~
24 Sep 08:08:02 ntpd[20341]: offset 0.096578 sec freq -9.175 ppm error 0.051412 poll 17
24 Sep 09:08:05 ntpd[20341]: offset 0.096578 sec freq -9.175 ppm error 0.051412 poll 17
"
ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
*123.456.789.098 123.456.789.1 2 u 9h 36h 377 1.188 96.578 51.412
LOCAL(0) LOCAL(0) 10 l 64 64 377 0.000 0.000 0.004
1号機とは違い、こちらはずっと安定してpolling 17となっています。polling 16から17になるまでに丸一日。polling 17になってからすでに五日半経っているのにまだ18にならない。
でも、36時間に一度の時刻調整でも数十ミリ秒のずれなんだからなかなかすごいと思う(開発サーバーで今回の実験中ほとんど無負荷だったのも影響しているだろうが)。
こちらのサーバーでも期待していたエラーは出力されませんでした。何かテストの仕方が間違っているのかも・・・
試みその二
ついでなので、maxpollとminpollの値が逆になるようにも設定してみました。"minpoll 14 maxpoll 10"で。
こちらは結果が出るのがとても早かったです。
結果(開発1号機):
ntpd.log
"
14 Sep 13:27:34 ntpd[16798]: running as uid(38)/gid(38) euid(38)/egid(38).
14 Sep 13:27:34 ntpd[16798]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
14 Sep 13:27:43 ntpd[16798]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
14 Sep 13:30:55 ntpd[16798]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_local_proto, 2 events, event_restart' (0xc521)
14 Sep 13:30:55 ntpd[16798]: kernel time discipline status change 41
14 Sep 13:30:55 ntpd[16798]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_local_proto, 3 events, event_peer/strat_chg' (0x534)
14 Sep 13:30:55 ntpd[16798]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_local_proto, 4 events, event_sync_chg' (0x543)
14 Sep 13:31:58 ntpd[16798]: kernel time discipline status change 1
14 Sep 14:27:34 ntpd[16798]: offset 0.000000 sec freq 8.386 ppm error 0.000011 poll 6
"
ntpq -p
# ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
*LOCAL(0) LOCAL(0) 11 l 4 64 377 0.000 0.000 0.008
結果(開発2号機):
ntpd.log
"
15 Sep 09:41:59 ntpd[19023]: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
15 Sep 09:42:00 ntpd[19023]: peer LOCAL(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
15 Sep 09:45:14 ntpd[19023]: system event 'event_peer/strat_chg' (0x04) status 'sync_alarm, sync_local_proto, 2 events, event_restart' (0xc521)
15 Sep 09:45:14 ntpd[19023]: synchronized to LOCAL(0), stratum 10
15 Sep 09:45:14 ntpd[19023]: kernel time sync disabled 0041
15 Sep 09:45:14 ntpd[19023]: system event 'event_sync_chg' (0x03) status 'leap_none, sync_local_proto, 3 events, event_peer/strat_chg' (0x534)
15 Sep 09:45:14 ntpd[19023]: system event 'event_peer/strat_chg' (0x04) status 'leap_none, sync_local_proto, 4 events, event_sync_chg' (0x543)
15 Sep 09:46:20 ntpd[19023]: kernel time sync enabled 0001
"
ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
*LOCAL(0) LOCAL(0) 10 l 5 64 377 0.000 0.000 0.004
エラーログは出力されなかったけれども、指定した時刻サーバーとは同期されませんでした。どうやら、minpollがmaxpollを上回る設定になっていると、時刻同期サーバーはLOCALとして動くようです(その他設定が間違っているときもそうなるのかはまた別の機会に調べます)。