2008年5月4日日曜日

古いパソコン、FreeBSD 7.0Rにしたら、topのCPU states行が、全部「0.0%」

古いパソコンは、実家に持っていって、第二の人生を歩んでもらってます。



そのうちの1台、CPUはAMD Athlon 800MHz(たぶんThunderbirdコア)というものなんですけど、お正月すぎに6.3-STABLEにアップグレードインストールして、とくに問題なく使えていました(やや動作がもっさりしてる、ってのはおいといて)。



最近、もうFreeBSD7.0でいいや、という気分になってきているので、今週、えいやとアップグレードしてみたところ、なんかおかしい。



portupgradeなど、重い処理を実行中のとき、別端末でキーボードのキー入力が数秒間遅れてくるとか、かなり動きがおかしい。ちょうど、リナックスで、裏で重い処理が走っていると、シェルなどのインタラクティブな処理が影響うけまくりで、やってられない、みたいな、あんな感じ。あれよりひどいかも。



何がおきてるんだ?と思ってtopを実行すると・・・



20080503



上から3行目、CPU statesという行の表示が、いつも、全部、値が0.0%なんです。



ただ、おかしいと感じるのは、このCPU statesくらいだけ。load averageはそんなもんかな、ってかんじで、各プロセスのCPU使用率もそんなもんだろう、という感じ。



これまで、5台くらい、FreeBSD7系を使ってきて、こんな症状ははじめて見ました。





Errataをチェック



まずは、エラッタ(バグ情報)がでてないか、公式サイトで確認。

http://www.freebsd.org/releases/7.0R/errata.html
FreeBSD 7.0-RELEASE Errata

無いですね。





なんとなくスケジューラをSCHED_ULEにしてみた



反応が鈍くなる、といったプロセススケジューリングに関係していることなので、SCHED_BSDからSCHED_ULEに変更して、カーネル再構築してみました。



ほとんど変化なし。


topのバグかな?と思ってcvswebで確認



この辺でしょうか。



http://www.jp.freebsd.org/cgi/cvsweb.cgi/src/usr.bin/top/machine.c



commit logで、なんとなく関係しそうなところで変更が入ってますが、どうも「0.0%になってしまう不具合」とは違いそう。



ダメもとで、4月のsnapshot版のlive fsなISOファイルをダウンロードして、topだけ実行してみましたが、やっぱりダメでした。


いや待てよ、topだけの問題なのか?と思ってvmstat



vmstatの出力を比較してみました。



正常なFreeBSD7



% vmstat 5
procs      memory      page                    disks     faults      cpu
r b w     avm    fre   flt  re  pi  po    fr  sr ad0 ad2   in   sy   cs us sy id
1 1 0  318540  22264    57   0   0   0    49   3   0   0 1133  216  417  1  1 98
0 1 0  318540  22264     1   0   0   0     0   0   0   0 1131   41  378  0  0 99
0 1 0  318540  22260     3   0   0   0     1   0   2   0 1136  200  380  0  1 99



おかしなFreeBSD7



% vmstat 5
procs      memory      page                   disk   faults      cpu
r b w     avm    fre   flt  re  pi  po    fr  sr ad0   in   sy   cs us sy id
1 0 0  134200  52872  1340   1   0   0  1246  20   0  120 1485  348  1  1 98
0 0 0  134200  52872     1   0   0   0     0   0   0  101   30  250  0  0  0
0 0 0  134200  52872     0   0   0   0     0   0   0  101   28  249  0  0  0
0 0 0  134200  52872     0   0   0   0     0   0   0  101   28  249  0  0  0



最初の1発目は無視するとして、2発目以降に注目。
右端の3列、CPUが何をしているのかを、ユーザー、システム、アイドルで分類してるので、足したら大体100%になるはずです。
ところが、おかしなFreeBSD7では、全部ゼロのまま。なんじゃこりゃ。





「sysctl -a」を見比べてみた



CPUがIntel Celeron 900MHzという、似たようなスペックのFreeBSD 7.0Rは、とくに問題なく動いているので、これとsysctl -aの違いを比較



なんとなく気になったのはtimecounterの辺。



正常なFreeBSD7
kern.timecounter.choice: TSC(800) ACPI-fast(1000) i8254(0) dummy(-1000000)
kern.timecounter.hardware: ACPI-fast
kern.timecounter.nsetclock: 4
kern.timecounter.ngetmicrotime: 49577785



異常なFreeBSD7
kern.timecounter.choice: TSC(800) ACPI-safe(850) i8254(0) dummy(-1000000)
kern.timecounter.hardware: ACPI-safe
kern.timecounter.nsetclock: 3
kern.timecounter.ngetmicrotime: 2358257



ACPI-fastとACPI-safeという、よくわかんないけど微妙な違い。



なんとなく、kern.timecounter.hardwareをTSCに変更したけど、直らない。





ACPIのせいかと疑ってsefe modeにしてみたら…



ACPIを切ろうと思って、sefe modeにしてみたら、ブート途中、ディスクad0を見つけられなくなって、ルートファイルシステムをマウントできず。終了。
はぁ?


kern.hz="100"にしてみた



古いパソコンだから、kern.hz="100"にしてみてもいいんじゃない?との思いつきで変更してみたけど、とくに変化なし。


vmstat -iで割り込みのチェック



正常なFreeBSD7



% vmstat -i
interrupt                          total       rate
irq0: clk                      522482022       1000
irq8: rtc                       66870937        127
irq9: fxp0 uhci0+                1483983          2
irq14: ata0                      1128495          2
irq15: ata1                          307          0
Total                          591965744       1133



異常なFreeBSD7



% vmstat -i
interrupt                          total       rate
irq0: clk                        1249889         99
irq1: atkbd0                           6          0
irq6: fdc0                             2          0
irq7: ppbus0 ppc0                      1          0
irq8: rtc                           1093          0
irq9: fxp0 acpi0                   44175          3
irq14: ata0                       185869         14
Total                            1481035        118


変な割り込みが大量発生、ということはない。
ただ、異常な方では、rtc(real time clockかな?)が、ほとんど発生していないのが、ちょっと変な気もします。



詳しくないので、よくわかんないです。



もう一度「sysctl -a」を見比べてみた。
kern.cp_timeが怪しい?



これ、CPUの働き具合を計測するカウンタらしいです。



% sysctl -d kern.cp_time
kern.cp_time: CPU time statistics



正常なFreeBSD7では、実行するたびに、カウントアップしていきます。



% sysctl kern.cp_time
kern.cp_time: 835065 1579 512065 137986 65329647
% sysctl kern.cp_time
kern.cp_time: 835066 1579 512066 137986 65330151
% sysctl kern.cp_time
kern.cp_time: 835066 1579 512068 137988 65331158



ところが、おかしいFreeBSD7では、ほとんど変化しません。



% sysctl kern.cp_time
kern.cp_time: 10 0 8 0 1074
% sysctl kern.cp_time
kern.cp_time: 10 0 8 0 1074
% sysctl kern.cp_time
kern.cp_time: 10 0 8 0 1074



これは怪しい!ということで、ソースコードをチェック。



cp_timeでgrepしたら、すぐに見つかりました。/sys/kern/kern_clock.c でしょうね。



http://www.jp.freebsd.org/cgi/cvsweb.cgi/src/sys/kern/kern_clock.c?rev=1.202&content-type=text/x-cvsweb-markup



この関数statclockで、カウントアップさせているように見えます。



/*
* Statistics clock.  Updates rusage information and calls the scheduler
* to adjust priorities of the active thread.
*
* This should be called by all active processors.
*/
void
statclock(int usermode)



7.0-RELEASEがrevision 1.202ですが、それ以降でcp_timeに大きな変更が入ってますが、どっちかっていうと、新機能の追加という感じで、不具合の修正ではないです。



だいたい、こんな中心部のところでバグってたら、topでの表示が0.0%になるFreeBSD7が、ほかにゴロゴロしてそうなものです。





というわけで、まだ問題解決できていません。



今、割り込みのrtcが怪しいかな?と思っているところです。



snapshot版をアップグレードインストールするか、または、あまりよくないけど、カーネルだけ7-STABLEにして、動作確認してみる、というのが、そんなに頭を使わず、手っ取りばやいかな…



カーネルのデバッグって、やったことないので、これをいい機会に勉強してみるというのも…




■ つづき







0 件のコメント:

コメントを投稿