2010年07月15日
KZM-CA9-01ボードのandroid用カーネルを2.6.32にアップデートしてみた(その2)
三日目の午前
「デバッグは探偵推理小説に似ている。」
この前そんな話題がありました。鋭い観察力で証拠を集めて、全体像を把握し、犯人をつきとめる。
動作は正しそうなのに実行速度が数十倍遅いという現象には今までも何度か遭遇したことがあります。いろいろな原因がありました。
- CPUのキャッシュがオンになっていなかった。
- 割り込みが異常な頻度で発生していた。
- インターバルタイマの設定を間違えた。(そのときはミリ秒とマイクロ秒を取り違えていた orz）
などなど。
今回の場合はどうでしょうか。
まず、起動ログの中のBogoMIPSの値に注目。
Calibrating delay loop... 797.90 BogoMIPS (lpj=3989504)
この値は前のカーネルで正常に動いていたときと同じ値です。なのでCPU自体は正しい速度で動いていそうです。
次に割り込みの頻度。vmstatの結果から簡単に見ることができます。
# vmstat procs memory system cpu r b free mapped anon slab in cs flt us ni sy id wa ir 0 1 375676 1316 1108 2504 0 88 2 0 0 2 99 99 0 0 2 375428 1360 1160 2528 26 85 1 0 0 2 99 99 0 0 1 375428 1368 1168 2524 8 70 0 0 0 1 99 99 0 0 3 375296 1408 1192 2532 8 78 4 0 0 2 99 99 0 0 1 375040 1416 1192 2532 8 59 1 0 0 1 0 99 0 0 0 375040 1468 1216 2532 8 78 0 2 0 2 99 49 0
inのカラムが割り込みの発生回数です。一秒間に8回というのは多いというよりはむしろ少ないという印象。
ここで興味深いのがwaのカラムです。これはI/O待ちのパーセントですが、99%になっています。こんなの初めて見ました。
起動ログでは
smsc911x: Driver version 2008-10-21. irq 66: nobody cared (try booting with the "irqpoll" option) (unwind_backtrace+0x0/0xd8) from (__report_bad_irq+0x30/0x8c) (__report_bad_irq+0x30/0x8c) from (note_interrupt+0x148/0x1d0) (note_interrupt+0x148/0x1d0) from (handle_level_irq+0xe8/0x14c) (handle_level_irq+0xe8/0x14c) from (asm_do_IRQ+0x80/0xb8) (asm_do_IRQ+0x80/0xb8) from (__irq_svc+0x38/0xc0) ... Disabling IRQ #66 ... net eth0: SMSC911x/921x identified at 0xd8840000, IRQ: 66
イーサネットのデバイスsmsc911xで何か変なことが起こっていて、このデバイスの使う割り込み IRQ #66がDisableにされてしまっています。
「ルートファイルシステムをNFSにしているところに、ネットワークドライバが不調でよたよた動いているために全体的にI/O待ちになってしまってすごく遅い。」
ということのようです。
ついでにインターバルタイマの設定がだいたいあっているかを簡単に調べる方法。
shellのプロンプトで
# sleep 10
これでプロンプトが返ってくるまでの時間をストップウオッチで計ります。10秒で返ってくればOK。厳密ではありませんが、クロックの分周比の設定の誤りは見つけることができます。ちなみにクロックの分周比を間違って時計の進み方が2倍遅い状態でベンチマークテストをやると2倍よい結果がでますが、それはぬか喜びです。(実話に基づく。）
さて、とにかくこのIRQ 66をなんとかしなくてはなりません。
"irq 66: nobody cared" のメッセージを出しているところのまわりのソースを調べましたが、なかなか何が悪いのかわかりません。
ただし、この割り込みがエッジでなくレベルで検出する割り込みだということはわかりました。レベルの割り込みの場合はその割り込みが放置されると割り込みがかかりっぱなしになって通常処理が全く動けなくなりシステム全体が固まります。それを防ぐためにカーネルはこの割り込みをDisableにしているのでしょう。
やはり今回自分で書いている部分が怪しいということでこのデバイスの初期設定の部分を入念に見直しました。
すると ...
.irq_polarity = SMSC911X_IRQ_POLARITY_ACTIVE_LOW,
となるべきところが
.irq_polarity = SMSC911X_IRQ_POLARITY_ACTIVE_HIGH,
になってました！ ははっ
割り込みの極性が逆でした。なるほど、それで初期化したとたんに割り込みが入りっぱなしと認識されてしまったわけです。
似た構成のrealviewボードの設定からきっと同じだろうと思ってこのデバイスの初期化のコードをコピペしたのが誤りの原因でした。
この一行を修正することで速度の問題は見事に解消されました。
三日目の午後
普通の速度で動作するようになったものの、液晶画面の表示のちらつきが気になります。これはなんとかしたい。
Androidのグラフィックスはフレームバッファを2面持ってそれを交互に切り替えて使うようになっています。(ダブルバッファリング)
このちらつきはフレームバッファの切り替えがうまくできていないためのようです。この機能はオプショナルなので標準のLCDドライバには入ってなくて後から追加したものです。この部分がカーネルのバージョンアップでうまく動かなくなったようです。
適当にそのまわりを変更して試してみたのですが、なかなかうまくいきません。これは本腰を入れてLCDドライバのソースを読まなきゃだめかな？と思ったちょうどそのときに、本当に偶然にある方からメイルでARM社のLinuxのサイトの存在を教えてもらいました。
そこをのぞくと2.6.33用のamba-lcd.cのAndroid用のパッチがあると書いてあります。まさに今欲しい情報。
それを参考にしてamba-lcdを修正することで画面のちらつきは改善されました。
次は？
SDメモリカードの読み書きもOK。
USBメモリも読み書きOK。
ただし、USBメモリをルートファイルシステムとして起動するとinitでこけます。でも３つのCPUを殺してひとつのCPUで動かすとUSBメモリからも起動できました。
よく調べてませんがSMPに関して何か足りないところがあるのかもしれません。でもそれを調べるより先にARMのLinuxサイトにある2.6.33のカーネルをこのボードに対応させてみようと思います。
カーネルのアップデート作業は実質3日でここまで動かすことができました。(ブログを書いている時間を除く。）
- 一日目 ... 7月9日(金)
- 二日目 ... 7月10日(土)
- 三日目 ... 7月12日(月)
PARTNER-Jetを使っています。いわゆる「printfデバッグ」は一切してません。2.6.33への対応はもっと短い時間でできるのではないかと思います。
関連するページ
KZM-CA9-01ボードの android用カーネルを2.6.32にアップデートしてみた(その1)
