本日(2015年7月1日 9:00 JST)、うるう秒挿入が実施されるので、手持ちのマシンで観測データを記録してみたいと思います。
マシン環境は次のとおりです。
[root@hoge ~]# cat /etc/centos-release
CentOS release 6.6 (Final)
[root@hoge ~]# uname -a
Linux hoge 2.6.32-504.23.4.el6.x86_64 #1 SMP Tue Jun 9 20:57:37 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux
[root@hoge ~]# dmidecode -s system-manufacturer ; dmidecode -s system-version
LENOVO
ThinkPad W520
[root@hoge ~]# ps -fC ntpd
UID PID PPID C STIME TTY TIME CMD
ntp 12778 1 0 Jun30 ? 00:00:10 ntpd -u ntp:ntp -p /var/run/ntpd.pid -g -x
[root@hoge ~]# rpm -q ntp
ntp-4.2.6p5-3.el6.centos.x86_64
ThinkPad W520 + CentOS 6.6 + ntp 4.2.6系(slewモード設定)という環境です。
まず、Leap Indicator が到着しているか確認です。予め、昨日の朝から ntpq -c readvar を定期採取するように仕込んでおきました。
[root@hoge ~]# less ntpq-c_readvar.log
...
2015-06-30 09:31:12 associd=0 status=0615 leap_none, sync_ntp, 1 event, clock_sync,
2015-06-30 09:31:12 version="ntpd 4.2.6p5@1.2349-o Mon Mar 16 14:53:03 UTC 2015 (1)",
2015-06-30 09:31:12 processor="x86_64", system="Linux/2.6.32-504.23.4.el6.x86_64", leap=00,
2015-06-30 09:31:12 stratum=3, precision=-24, rootdelay=23.151, rootdisp=315.573,
2015-06-30 09:31:12 refid=106.187.50.84,
2015-06-30 09:31:12 reftime=d93c60c7.306f0aee Tue, Jun 30 2015 9:26:47.189,
2015-06-30 09:31:12 clock=d93c61d0.45e5528d Tue, Jun 30 2015 9:31:12.273, peer=18506, tc=6,
2015-06-30 09:31:12 mintc=3, offset=-270.419, frequency=198.276, sys_jitter=4.409,
2015-06-30 09:31:12 clk_jitter=10.496, clk_wander=6.132
2015-06-30 09:32:12 associd=0 status=4615 leap_add_sec, sync_ntp, 1 event, clock_sync,
2015-06-30 09:32:12 version="ntpd 4.2.6p5@1.2349-o Mon Mar 16 14:53:03 UTC 2015 (1)",
2015-06-30 09:32:12 processor="x86_64", system="Linux/2.6.32-504.23.4.el6.x86_64", leap=01,
2015-06-30 09:32:12 stratum=3, precision=-24, rootdelay=52.667, rootdisp=321.239,
2015-06-30 09:32:12 refid=202.234.64.222,
2015-06-30 09:32:12 reftime=d93c61bd.33a3a956 Tue, Jun 30 2015 9:30:53.201,
2015-06-30 09:32:12 clock=d93c620c.4797c6d6 Tue, Jun 30 2015 9:32:12.279, peer=18505, tc=6,
2015-06-30 09:32:12 mintc=3, offset=-270.889, frequency=194.208, sys_jitter=3.803,
2015-06-30 09:32:12 clk_jitter=9.819, clk_wander=5.913
2015-06-30 09:33:12 associd=0 status=461a leap_add_sec, sync_ntp, 1 event, leap_disarmed,
2015-06-30 09:33:12 version="ntpd 4.2.6p5@1.2349-o Mon Mar 16 14:53:03 UTC 2015 (1)",
2015-06-30 09:33:12 processor="x86_64", system="Linux/2.6.32-504.23.4.el6.x86_64", leap=01,
2015-06-30 09:33:12 stratum=3, precision=-24, rootdelay=19.556, rootdisp=307.926,
2015-06-30 09:33:12 refid=122.215.240.52,
2015-06-30 09:33:12 reftime=d93c61f5.2f46436e Tue, Jun 30 2015 9:31:49.184,
2015-06-30 09:33:12 clock=d93c6248.46b5ce84 Tue, Jun 30 2015 9:33:12.276, peer=18503, tc=6,
2015-06-30 09:33:12 mintc=3, offset=-262.259, frequency=193.207, sys_jitter=5.568,
2015-06-30 09:33:12 clk_jitter=9.679, clk_wander=5.543
...
Leap Indicator は、うるう秒の 24時間前 から通知されることになってますが、わたしのマシンで認識されたのは、9時半頃だったようです。
次は、現在(6:16)の状態です。
[root@hoge ~]# date
Wed Jul 1 06:16:29 JST 2015
[root@hoge ~]# ntpq -c readvar
associd=0 status=461a leap_add_sec, sync_ntp, 1 event, leap_disarmed,
version="ntpd 4.2.6p5@1.2349-o Mon Mar 16 14:53:03 UTC 2015 (1)",
processor="x86_64", system="Linux/2.6.32-504.23.4.el6.x86_64", leap=01,
stratum=3, precision=-24, rootdelay=54.844, rootdisp=62.648,
refid=202.234.64.222,
reftime=d93d82c0.32fbf279 Wed, Jul 1 2015 6:04:00.199,
clock=d93d85b6.7bb5c81a Wed, Jul 1 2015 6:16:38.483, peer=18505, tc=7,
mintc=3, offset=-2.242, frequency=-1.742, sys_jitter=1.101,
clk_jitter=0.896, clk_wander=0.023
[root@hoge ~]# ntpq -p
remote refid st t when poll reach delay offset jitter
==============================================================================
-122x215x240x52. 133.243.238.164 2 u 124 128 377 17.892 -0.253 0.572
+chobi.paina.jp 131.112.125.48 2 u 98 128 377 19.177 -2.397 53.470
*ntp.kiba.net 193.221.26.33 2 u 107 128 373 31.772 -3.135 5.208
+gw1.kohaaloha.c 133.243.238.244 2 u 110 128 377 19.573 -1.331 0.842
[root@hoge ~]# grep ^server /etc/ntp.conf ※いじっているのは次の箇所だけです
server 0.centos.pool.ntp.org iburst maxpoll 8
server 1.centos.pool.ntp.org iburst maxpoll 8
server 2.centos.pool.ntp.org iburst maxpoll 8
server 3.centos.pool.ntp.org iburst maxpoll 8
[root@hoge ~]# ntptime
ntp_gettime() returns code 5 (ERROR)
time d93d85c3.123a8000 Wed, Jul 1 2015 6:16:51.071, (.071205),
maximum error 16000000 us, estimated error 16 us, TAI offset 0
ntp_adjtime() returns code 5 (ERROR)
modes 0x0 (),
offset 0.000 us, frequency 0.000 ppm, interval 1 s,
maximum error 16000000 us, estimated error 16 us,
status 0x41 (PLL,UNSYNC),
time constant 7, precision 1.000 us, tolerance 500 ppm,
続きは、また今晩書きたいと思います。
2015-07-02追記
次回の参考になるよう、slew モードで1秒が補正されるまでのデータを残しておきます。
まず、munin のグラフです。
次は、ntpq -np の出力を定期採取したデータです。
remote refid st t when poll reach delay offset jitter
==============================================================================
2015-07-01 04:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 11 64 377 19.788 -2.099 0.993
2015-07-01 04:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 32 128 377 19.714 -1.349 0.772
2015-07-01 05:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 118 128 377 20.725 -2.126 2.264
2015-07-01 05:32:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 76 128 377 20.475 -1.875 1.471
2015-07-01 06:02:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 27 128 377 20.205 -1.154 2.433
2015-07-01 06:32:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 122 128 377 21.338 -0.645 2.110
2015-07-01 07:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 202 256 377 20.592 -2.101 1.402
2015-07-01 07:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 143 256 377 20.653 -2.038 3.277
2015-07-01 08:02:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 111 256 377 20.023 -2.303 0.631
2015-07-01 08:32:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 60 256 377 19.803 -2.709 0.536
2015-07-01 09:02:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 9 256 377 21.023 -1.460 378.296
2015-07-01 09:32:14 x106.xxx.yy.zz 133.243.u.vvv 2 u 231 256 377 18.791 -1001.8 377.872
2015-07-01 10:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 187 256 377 18.732 -850.50 128.921
2015-07-01 10:32:14 x106.xxx.yy.zz 133.243.u.vvv 2 u 140 256 377 19.959 -338.47 202.357
2015-07-01 11:02:14 x106.xxx.yy.zz 133.243.u.vvv 2 u 108 256 377 19.959 -338.47 124.808
2015-07-01 11:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 94 256 377 18.902 -92.918 48.587
2015-07-01 12:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 46 256 377 19.725 -46.976 24.980
2015-07-01 12:32:14 -106.xxx.yy.zz 133.243.u.vvv 2 u 14 256 377 21.471 24.117 16.097
2015-07-01 13:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 247 256 377 21.222 33.890 23.763
2015-07-01 13:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 202 256 377 21.370 47.732 20.740
2015-07-01 14:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 160 256 377 20.123 66.180 31.655
2015-07-01 14:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 128 256 377 19.378 67.970 5.429
2015-07-01 15:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 99 256 377 19.839 71.999 0.685
2015-07-01 15:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 50 256 377 20.541 71.707 3.409
2015-07-01 16:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 10 256 377 20.986 73.016 1.333
2015-07-01 16:32:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 252 256 377 20.864 71.603 3.392
2015-07-01 17:02:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 215 256 377 21.057 72.781 3.576
2015-07-01 17:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 153 256 377 20.601 68.391 5.254
2015-07-01 18:02:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 108 256 377 21.467 66.549 2.707
2015-07-01 18:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 60 256 377 21.532 63.015 36.577
2015-07-01 19:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 7 256 377 21.525 58.468 1.322
2015-07-01 19:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 233 256 377 22.197 57.370 3.762
2015-07-01 20:02:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 184 256 377 19.177 58.782 30.390
2015-07-01 20:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 122 256 377 20.570 54.714 1.959
2015-07-01 21:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 79 256 377 20.570 54.714 5.023
2015-07-01 21:32:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 50 256 377 21.628 50.943 4.072
2015-07-01 22:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 3 256 377 36.953 41.933 4.676
2015-07-01 22:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 224 256 377 37.968 44.620 46.186
2015-07-01 23:02:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 181 256 377 36.238 41.819 16.091
2015-07-01 23:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 152 256 377 36.340 46.415 7.950
2015-07-02 00:02:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 89 256 377 39.487 42.372 11.150
2015-07-02 00:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 59 128 377 32.067 32.882 5.267
2015-07-02 01:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 21 64 377 21.239 13.838 6.248
2015-07-02 01:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 50 128 377 22.461 12.798 3.011
2015-07-02 02:02:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 11 256 377 21.303 11.877 16.779
2015-07-02 02:32:14 +106.xxx.yy.zz 133.243.u.vvv 2 u 249 256 377 21.504 16.263 6.163
2015-07-02 03:02:14 *106.xxx.yy.zz 133.243.u.vvv 2 u 61 128 377 20.093 16.886 1.101
2015-07-02 03:32:16 *106.xxx.yy.zz 133.243.u.vvv 2 u 24 64 377 20.018 5.750 2.548
2015-07-02 04:02:16 +106.xxx.yy.zz 133.243.u.vvv 2 u 48 64 377 21.012 2.840 0.944
2015-07-02 04:32:16 *106.xxx.yy.zz 133.243.u.vvv 2 u 63 128 377 19.750 3.482 0.846
2015-07-02 05:02:16 *106.xxx.yy.zz 133.243.u.vvv 2 u 12 64 377 19.643 4.361 26.509
2015-07-02 05:32:16 +106.xxx.yy.zz 133.243.u.vvv 2 u 41 64 377 21.850 1.910 2.910
2015-07-02 06:02:16 +106.xxx.yy.zz 133.243.u.vvv 2 u 12 64 377 20.327 1.325 7.538
2015-07-02 06:32:16 *106.xxx.yy.zz 133.243.u.vvv 2 u 49 64 377 19.247 1.809 3.580
2015-07-02 07:02:16 *106.xxx.yy.zz 133.243.u.vvv 2 u 77 128 377 20.714 -0.037 1.250
2015-07-02 07:32:16 *106.xxx.yy.zz 133.243.u.vvv 2 u 28 128 377 20.356 1.243 0.894
2015-07-02 08:02:16 +106.xxx.yy.zz 133.243.u.vvv 2 u 260 256 377 21.686 2.613 2.557
2015-07-02 08:32:16 +106.xxx.yy.zz 133.243.u.vvv 2 u 227 256 377 20.114 2.458 16.880
2015-07-02 09:02:16 +106.xxx.yy.zz 133.243.u.vvv 2 u 187 256 377 21.051 3.840 0.556
2015-07-02 09:32:16 *106.xxx.yy.zz 133.243.u.vvv 2 u 150 256 377 21.165 3.337 6.229
2015-07-02 10:02:16 *106.xxx.yy.zz 133.243.u.vvv 2 u 105 128 377 20.724 2.008 1.382
実際は、上位サーバは4つ指定してあり、そのうちの1つについて 30 分毎のデータです。
前回(2012-07-01)観測したマシンでは、offset が 10 ミリ秒より小さくなるまでに 27 時間かかりましたが、今回は maxpoll 8 を設定した効果が出たようで、18 時間半でした。
最後に、/var/log/messages 抜粋です。
[root@hoge ~]# who -b
system boot 2015-06-30 06:00
[root@hoge ~]# grep ntp /var/log/messages
※データ採取準備をして1度マシンを再起動した
Jun 30 06:01:04 hoge ntpd[12771]: ntpd 4.2.6p5@1.2349-o Mon Mar 16 14:53:03 UTC 2015 (1)
Jun 30 06:01:04 hoge ntpd[12778]: proto: precision = 0.048 usec
Jun 30 06:01:04 hoge ntpd[12778]: 0.0.0.0 c01d 0d kern kernel time sync enabled
Jun 30 06:01:04 hoge ntpd[12778]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
Jun 30 06:01:04 hoge ntpd[12778]: Listen and drop on 1 v6wildcard :: UDP 123
Jun 30 06:01:04 hoge ntpd[12778]: Listen normally on 2 lo 127.0.0.1 UDP 123
Jun 30 06:01:04 hoge ntpd[12778]: Listen normally on 3 lo ::1 UDP 123
Jun 30 06:01:04 hoge ntpd[12778]: peers refreshed
Jun 30 06:01:04 hoge ntpd[12778]: Listening on routing socket on fd #20 for interface updates
Jun 30 06:01:04 hoge ntpd[12778]: Deferring DNS for 0.centos.pool.ntp.org 1
Jun 30 06:01:04 hoge ntpd[12778]: Deferring DNS for 1.centos.pool.ntp.org 1
Jun 30 06:01:04 hoge ntpd[12778]: Deferring DNS for 2.centos.pool.ntp.org 1
Jun 30 06:01:04 hoge ntpd[12778]: Deferring DNS for 3.centos.pool.ntp.org 1
Jun 30 06:01:04 hoge ntpd[12778]: 0.0.0.0 c016 06 restart
Jun 30 06:01:04 hoge ntpd[12778]: 0.0.0.0 c012 02 freq_set ntpd 500.000 PPM
Jun 30 06:01:07 hoge ntpd[12778]: Listen normally on 4 virbr0 192.168.122.1 UDP 123
Jun 30 06:01:07 hoge ntpd[12778]: peers refreshed
Jun 30 06:01:09 hoge ntpd[12778]: Listen normally on 5 eth0 fe80::f2de:f1ff:fef9:52c5 UDP 123
Jun 30 06:01:09 hoge ntpd[12778]: peers refreshed
Jun 30 06:01:22 hoge ntpd[12778]: Listen normally on 6 wlan0 fe80::2677:3ff:fe8f:224 UDP 123
Jun 30 06:01:22 hoge ntpd[12778]: peers refreshed
Jun 30 06:01:24 hoge ntpd[12778]: Listen normally on 7 wlan0 192.168.1.4 UDP 123
Jun 30 06:01:24 hoge ntpd[12778]: peers refreshed
Jun 30 06:01:24 hoge ntpd_intres[12786]: DNS 0.centos.pool.ntp.org -> 122.215.240.52
Jun 30 06:01:24 hoge ntpd_intres[12786]: DNS 1.centos.pool.ntp.org -> 157.7.154.23
Jun 30 06:01:24 hoge ntpd_intres[12786]: DNS 2.centos.pool.ntp.org -> 202.234.64.222
Jun 30 06:01:25 hoge ntpd_intres[12786]: DNS 3.centos.pool.ntp.org -> 106.187.50.84
Jun 30 06:01:31 hoge ntpd[12778]: 0.0.0.0 c615 05 clock_sync
Jun 30 09:32:53 hoge ntpd[12778]: 0.0.0.0 461a 0a leap_disarmed
Jul 1 09:00:00 hoge ntpd[12778]: 0.0.0.0 061b 0b leap_event
Jul 1 09:17:18 hoge ntpd[12778]: 0.0.0.0 0618 08 no_sys_peer
※以後はntpdからメッセージは出なかった
というわけで、めでたし、めでたし。