うるう秒をテストしたら仮想インタフェースが落ちた話

今月末はうるう秒が予定されていますね。
http://jjy.nict.go.jp/news/leaps2015.html

これについては様々なところで「何が影響を受ける？」「どう対応する？」などが書かれています。

今回はその中でも、「事前に試験環境でうるう秒を入れてみる」ことについてRedHatの記事が書かれていたので、そのお話。
How to clear the Leap Second Insertion flag after it has been received?

この記事の中では leap-a-day.c というコードが公開されていて、簡単に言うと

• ntpdにうるう秒の通知を行う (adjtimex)
• うるう秒の直前まで時刻を進める (settimeofday)

ということをやってくれます。

これを試験環境で実行したところ、仮想ネットワークインタフェース(IP alias)が落ちたので、再現条件を記録しておきます。
なお、この問題にうるう秒は本質的に関係ありません。

OS

CentOS 6.4 2.6.32-358.23.2.el6.x86_64 on VirtualBox

ネットワーク設定

eth0 → DHCP (staticにしない)
/etc/sysconfig/network-scripts/ifcfg-eth0

DEVICE=eth0
HWADDR=08:00:27:B8:4B:7E
TYPE=Ethernet
UUID=0402e253-5c54-44cc-9611-141c5b00c5f0
ONBOOT=yes
#NM_CONTROLLED=no
BOOTPROTO=dhcp
DNS1=192.168.60.100
IPV6INIT=no

eth0:0 → static
/etc/sysconfig/network-scripts/ifcfg-eth0:0

DEVICE=eth0:0
ONBOOT=yes
IPADDR=192.168.60.144
NETMASK=255.255.255.0
BOOTPROTO=static
ONBOOT=yes
USERCTL=no

準備

• VMの外からIP alias (192.168.60.144) にpingを打ちっぱなしにしておく
• leap-a-day.c をコンパイルしておく
• tail -f /var/log/messages しておく

再現実験

./leap-a-day -s

しばらく処理が進んでから^Cで止める

syslogが以下のように出力された。

Jun 20 08:59:59 ku0001 kernel: Clock: inserting leap second 23:59:60 UTC
Jun 21 09:00:00 ku0001 kernel: Clock: deleting leap second 23:59:59 UTC
Jun 22 08:59:59 ku0001 kernel: Clock: inserting leap second 23:59:60 UTC
Jun 23 09:00:00 ku0001 kernel: Clock: deleting leap second 23:59:59 UTC
Jun 24 09:01:14 ku0001 dhclient[1977]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 6 (xid=0x59ff7945)
Jun 24 09:01:15 ku0001 dhclient[1977]: DHCPOFFER from 192.168.60.100
Jun 24 09:01:15 ku0001 dhclient[1977]: DHCPREQUEST on eth0 to 255.255.255.255 port 67 (xid=0x59ff7945)
Jun 24 09:01:15 ku0001 dhclient[1977]: DHCPACK from 192.168.60.100 (xid=0x59ff7945)
Jun 24 09:01:16 ku0001 ntpd[1274]: Deleting interface #10 eth0, 192.168.60.10#123, interface stats: received=9, sent=9, dropped=0, active_time=179 secs
Jun 24 09:01:16 ku0001 ntpd[1274]: Deleting interface #11 eth0:0, 192.168.60.144#123, interface stats: received=0, sent=0, dropped=0, active_time=176 secs
Jun 24 09:01:18 ku0001 NET[2173]: /sbin/dhclient-script : updated /etc/resolv.conf
Jun 24 09:01:18 ku0001 dhclient[1977]: bound to 192.168.60.10 -- renewal in 298 seconds.
Jun 24 09:01:19 ku0001 ntpd[1274]: Listening on interface #13 eth0, 192.168.60.10#123 Enabled
Jun 24 09:06:16 ku0001 dhclient[1977]: DHCPREQUEST on eth0 to 192.168.60.100 port 67 (xid=0x59ff7945)
Jun 24 09:06:16 ku0001 dhclient[1977]: DHCPACK from 192.168.60.100 (xid=0x59ff7945)
Jun 24 09:06:17 ku0001 dhclient[1977]: bound to 192.168.60.10 -- renewal in 240 seconds.

eth0:0が落ちている

$ ifconfig | eth0
eth0      Link encap:Ethernet  HWaddr 08:00:27:B8:4B:7E

pingも疎通しなくなっている

64 bytes from 192.168.60.144: icmp_seq=96 ttl=64 time=0.234 ms
64 bytes from 192.168.60.144: icmp_seq=97 ttl=64 time=0.219 ms
64 bytes from 192.168.60.144: icmp_seq=98 ttl=64 time=0.186 ms
From 192.168.60.144 icmp_seq=137 Destination Host Unreachable
From 192.168.60.144 icmp_seq=138 Destination Host Unreachable
From 192.168.60.144 icmp_seq=139 Destination Host Unreachable

何が起きているのか

どうやらleap-a-dayによって日付が進み、dhclientがDHCPのリース時間を大幅超過したとみなし、そのときのeth0およびaliasを一度全て落としてしまっているようです。
その後DHCPでeth0は再設定されますが、eth0:0は元に戻らないようです。
syslogにはntpdがinterfaceを削除したようなログが出ますが、ntpdが消すはずはもちろんなく、これはbindしているインタフェースが落とされたことを検知しているだけみたいです。

順番としてはsyslogからもわかるとおり以下のように動いています。

1. dhclientが起動する
2. リース期限が切れているのでインタフェースが全部(eth0, eth0:0)落ちる
3. これにhookしてntpdがbindしているインタフェースを全部(eth0, eth0:0)外す
4. dhclientがDHCPでIPアドレスを(eth0だけ)設定しなおす
5. ntpdがeth0のみにbindする

元に戻す

ntpdateで時刻を元に戻し、service network restartで元通りになります。
それにしてもこの挙動は不便…
時計を進めるときは気をつけましょう。