2011年12月29日

sched_clock() overflow after 208.5 days in Linux Kernel

えーっと、久しぶりに Linux Kernel にダメダメなバグが発見されて、よりにもよってうちの製品も影響を受けたので、ここに詳細を書くことにした。
つーか。新しい Kernel を使うなら皆で使おうよ。なんだよその「1つだけ」影響を受けて残りは「影響も受けないぐらい古い」ってのは…


概要
大雑把に 208.5日連続運転した Linux Kernel が突如として reboot する。

実機でなおかつ Time Stamp Counter を内包している必要があるので、Pentium4以降のプロセッサ(が、それはようするに今ある Intel 系CPU全部)か、その互換CPUである必要がある。32bit モード、64bit モードの区別はない。
逆に VMware や Xen など、仮想マシン上で動いている kernel に影響はない。これはそもそもバグを内包したルーチンを、仮想マシンで動いていると検出した Linux Kernel は使わなくなるからだ。

一切の予防的挙動は取られていないので、file systemなども含めて、non-volatile メディアに対する影響は甚大かつ破壊的。回避策はパッチの当たった Kernel をインストールしてrebootするか、200日以内に計画的に reboot する事のみ。


影響範囲
Linux Kernel 2.6.28 で導入されたパッチにバグがあり、3.1.5 で修正された。この間にリリースされた distribution は多分全部影響を受ける。

なお、具体的には
2.6系列:  2.6.32.50でfix
3.0系列:   3.0.13でfix
3.1系列:   3.1.5でfix
らしい。

商用 distribution で影響を受けているもの。

まずは SuSE11 SP1。fix パッチはこうなっている:
http://kernel.opensuse.org/cgit/kernel-source/commit/?id=413af9e6f17a1a1519cae0bfd1c1fe4409bb42a3

RHEL6も 2.6.32 base らいいのでこれも影響を受ける。
(2012/02/14追記: RHEL6 は kernel-2.6.32-220.4.2.el6 で修正が入ったらしい。http://rhn.redhat.com/errata/RHBA-2012-0124.html
ただし、ひどい事に「2012年1月24日に登録され、fix ができたのは2012-02-13という事になっている。3ヶ月近く何をしていたのか…)

多分Fedoraとかも影響をうけるはずだが、マシンを上げていないので判らない(何その手抜き)。
Fedora マシンを上げたら
「3.1.1→3.16 に kernel を更新」
という update が出ていた。 Fedora16使いは速攻で上げることをお勧めする。
また、Fedora15使いは速攻で Fedora16 にして、update を最新に持っていくことをおすすめする。


3.1.5のバグ修正後のコードはこう:
http://lxr.linux.no/linux+v3.1.5/arch/x86/include/asm/timer.h#L58
(LXRとか、こうやってソースコード丸ごと指定できるからありがたい)



なお、VMware とかの仮想環境では、このバグっているルーチンはそもそも利用されない。なのでこれは実機上で動かしている Linux Kernel でのみ、発生する。なので、VMで実験を…とかは一切効かない。


技術的詳細
最近の Intel processor やその互換CPUには Time Stamp Counter (TSC) という 64bit レジスタがある。

こいつは Intel の場合だと CPU 駆動クロックでカウントアップしていて、1tick ごとに+1していく。例えば 2GHz のCPUの場合、1秒で2Gづつ増えていくのだ。

また、AMDの場合だとCPUに投入されるクロックで 1tickごとに+1していく。大抵の場合は 800MHz なので1秒で800Mづつ増える。

判ると思うが、ほぼ nano 秒オーダーの時計として使えるので、リアルタイム制御をしたい場合、TSCはとてもありがたい。しかし、最近の電力消費量制御機構は、CPU駆動クロック周波数を変更してしまう。すると TSC の値は何がなんだか判らなくなる…
そこで、Linux Kernel 内部には cycles_2_ns() という関数があって、TSCの値をナノ秒に修正してくれる事になっている。

しかし、不幸はここに内包されていた


すごく簡単に言うと、TSCの値を必要な Scale Factor 倍すれば nano sec になる。しかし、TSCの値は nano sec に近い。当然 Scale Factor は 1.0 に近い、微妙な浮動小数点になってしまう。

そうだ! Scale Factor を分数で表そう!!
SC/1024 で表現して、
SCを整数にしておけば、
SCを掛け算した後、
右に10bit シフトすれば済むよっ!!!

…この段階で何か嫌な予感がしなかったんだろうか、こいつらは…


とにかく、元の式は、TSCの値を 64bit 変数に代入し、それに 32bit のSC ( コード上は per_cpu() という関数の戻り値) を掛けて、10bit 右にシフトする、というものになった。


さて。ちょっとここで視点を変えてほしい。
「TSCに SC を掛けて、その後 1024 で割ると nano sec になる」
って事は、

TSCにSCを掛けると
大雑把に pico sec の精度の数字ができる

って事だ。
210 = 1024 ≒ 1000 = 103

なので、メートル法の縮尺単位が1つ変化する度に10bit消費される。
(ここは試験に出ます)

すると、pico sec レベルでの数字を扱うと、1秒を扱うには 40bit 必要、ということだ。しかるに、この値は 64bit の変数に代入されいてる。って事は「1秒以上」の表現には 24bit しか有効桁数がないって事だ。

224 / ( 24 * 60 * 60 ) = 194.180741日

実際には、1024の方が若干大きいので、その端数が載る。具体的には 64bit変数を最後に 10bit 右にシフトするので、有効桁数は 54bitになる。これが nano sec で表された時刻なのだから、

254 / ( 24 * 60 * 60 * 1000 * 1000 * 1000 ) 
= 208.499983日

めでたく、今回 overflow を起こした日数そのものが出てくる。64bitは、無限にでかいに等しい桁数ではないのだ。

かくして、cycles_2_ns() は、208.5日経つと、桁あふれを起こして 0 に近い値を出力する。sched_clock() はこの値を利用しているため、ここもぶち飛ぶ。

スケジューラーはここの値に強く依存しているので、突如として 54bit の数字が 0 になると、カーネルのあちこちがぶっ飛んでしまい、reboot に至る。


感想
497日問題の反省
全く活かされておらずっっ!!!


------

あれから2年…どうやら新しい 208.5日問題が発見されたらしい…

今回は私なんぞよりよほどわかりやすく説明してくれる人が現れた。お陰でリンクを貼るだけで済む。ありがたや、ありがたや… (-人-)

今度のは CPU のバグとペアになっていて、reboot すると freeze する、という実に悪質な…実運用に入っているサーバのメンテナンスとかで再起動しようとしたら freeze した…なんて事、その場に立ち会ったら心臓がショックで止まりかねないだろう…。

2011年12月11日

lunar eclipse

On year 2011, Dec. 10th around 21:30 - 00:00, we had Lunar Eclipse here at Japan.

Here's some of the photos I took.

Camera: RICOH CX1
Mode: ... ah .. I kept on changing it in the dark. So I'm not sure.
























And .. Battery run out ..... gosh ...