2010年07月15日

KZM-CA9-01ボードのandroid用カーネルを2.6.32にアップデートしてみた(その2)

前回の続き。

KZM-CA9-01ボード(Cortex-A9 Quad core)で新しいカーネルが起動するようになったものの、動作が20倍以上遅い。

いったい何が起こっていて、その原因は?



三日目の午前

デバッグは探偵推理小説に似ている。」

この前そんな話題がありました。鋭い観察力で証拠を集めて、全体像を把握し、犯人をつきとめる。

動作は正しそうなのに実行速度が数十倍遅いという現象には今までも何度か遭遇したことがあります。いろいろな原因がありました。

  • CPUのキャッシュがオンになっていなかった。
  • 割り込みが異常な頻度で発生していた。
  • インターバルタイマの設定を間違えた。(そのときはミリ秒とマイクロ秒を取り違えていた orz)

などなど。

今回の場合はどうでしょうか。

まず、起動ログの中のBogoMIPSの値に注目。

Calibrating delay loop... 797.90 BogoMIPS (lpj=3989504)

この値は前のカーネルで正常に動いていたときと同じ値です。なのでCPU自体は正しい速度で動いていそうです。

(この記事の最後の/proc/cpuinfo を参照。)

次に割り込みの頻度。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でこけます。でも3つのCPUを殺してひとつのCPUで動かすとUSBメモリからも起動できました。

よく調べてませんがSMPに関して何か足りないところがあるのかもしれません。でもそれを調べるより先にARMのLinuxサイトにある2.6.33のカーネルをこのボードに対応させてみようと思います。

カーネルのアップデート作業は実質3日でここまで動かすことができました。(ブログを書いている時間を除く。)

  • 一日目 ... 7月9日(金)
  • 二日目 ... 7月10日(土)
  • 三日目 ... 7月12日(月)

PARTNER-Jetを使っています。いわゆる「printfデバッグ」は一切してません。2.6.33への対応はもっと短い時間でできるのではないかと思います。



トラックバックURL

トラックバック一覧

1. KZM-CA9-01ボードのリンク集  [ KMC Staff Blog ]   2010年09月16日 10:38
4コアのCortex-A9のKZM-CA9-01ボードを使って実験したことを書いたページをまとめてみました。

コメントする

名前
URL
 
  絵文字
 
 
記事検索
最新コメント
アクセスカウンター
  • 今日:
  • 昨日:
  • 累計:

QRコード
QRコード