arm gccが改めてすごいと感じたこと

サイクルカウンタを使ってみて気になったのはパフォーマンスカウンタを有効にしていると発熱や消費電力に影響があるのかないのか？気にはなりますが、おそらく数字に出てこないレベルなのではないかと思うのですが、とはいえ、使用が終わったらカウンタを止めておきたいと思ったときに、本当に止まっているのかテストをしてたところ、

    while((cnt<50000) && (((unsigned long)end - start)<150)){

        cnt++;
        end = pmon_read_cycle_counter();
    }
    if(isStart){
        pmon_stop_cycle_counter();
        dummy = pmon_read_cycle_counter();
        printf("stop\n");
        dummy2 = pmon_read_cycle_counter();

        printf("%ld, %ld\n", dummy, dummy2);
    }

まぁこんなことをやってみたわけです。

サイクルカウンタのテストプログラムでも、一定の回数を回している上記のループが終わった時のカウンタの値が150なのでたまたまかな？と思っていたんですが、これが上記の物でも150という数字を返してきました。

何がすごいかといえば、ループの終了条件判断の分岐とその後の条件文の分岐を無視して機械語レベルで1サイクルの中でサイクルカウンタが止められているということです。

armの特性として、実行条件が命令と結合しているので条件分岐がハマれば実行順序の乱れが無いというのは分っていたのですが、ここまで正確に数字に出てくると驚きの方が大きかったです。

試しに停止直前に

        dummy = pmon_read_cycle_counter();
        pmon_stop_cycle_counter();
        dummy = pmon_read_cycle_counter();

などと、やってみましたが、これで返される値は151という。

dummyに代入するところは直後に再度同じdummyに代入しているので、最適化で外されているとは思いますが、インラインアセンブラとは言え本当に1cycleしかかかっていないとか…

正直凄い以外の言葉が出ない。

ARMのサイクルカウンタ

先の投稿でARMなにがしの手順はあったのですが、結局Raspberry piで使えるのかどうか確認するのにえらい手間取りました。

そもそもARMでの開発をするためのバイブルなんて一切ないので。

昔は書店に行って「やっぱりない」と言うことがとても多く、無駄なお金を使っていましたが、今ならアマゾンとかあるので、、、

だからポチるのか？と言われれば、まずは下調べからしないと痛い目を見そうですし、そもそもARMの種類ってよくわかんないんですよねｗ気づけば64bitだとか。

とりあえずダイレクトで検索して見るとバイブルっぽいPDFがいくつかありました。

さらに、Raspberry pi 2bで採用されているARMv7の仕様書っぽい感じのものがありました。

https://static.docs.arm.com/ddi0406/c/DDI0406C_C_arm_architecture_reference_manual.pdf

英語なので細かい所はさっぱりですが、コードとその場のノリでなんとなく必要なことが見えてきました。

少なくてもRaspberry pi 2bなら ARM Coretex-A9と同じ手順で行けそうな気配がしてきました。

Raspberry pi 3bとかはARM Coretex-A53とかA72とか互換性はどんな風になってるのか想像できません…下位互換性なCPUでも結構維持されていなかったりするのであれなんですが、そもそもの拡張のされ方とか内容と型番を覚えるのが苦手なので正直つらいですｗ

パフォーマンスカウンタが複数設定できそうなところとかが良くわかってませんが、一つ一つ確認したところポイントは変わっていないのが確認できました。

まぁ最悪カーネルパニックになるだけなので、とっとと試したいと思います。

ARM LinuxのユーザプログラムからCortex-A9のサイクルカウンタを利用する

ソースファイルなどを準備して、まずは…権限付与ドライバからいきましょうかね。

pi@rasp4b4g:~/pmon $ ls
Makefile  pmon_ca9.h  pmuser.c  test.c
pi@rasp4b4g:~/pmon $ make
make -C /lib/modules/5.4.51-v7l+/build M=/home/pi/pmon modules
make[1]: ディレクトリ '/usr/src/linux-headers-5.4.51-v7l+' に入ります
  CC [M]  /home/pi/pmon/pmuser.o
  Building modules, stage 2.
  MODPOST 1 modules
  CC [M]  /home/pi/pmon/pmuser.mod.o
  LD [M]  /home/pi/pmon/pmuser.ko
make[1]: ディレクトリ '/usr/src/linux-headers-5.4.51-v7l+' から出ます
pi@rasp4b4g:~/pmon $ ls
Makefile        modules.order  pmuser.c   pmuser.mod    pmuser.mod.o  test.c
Module.symvers  pmon_ca9.h     pmuser.ko  pmuser.mod.c  pmuser.o

ドライバが作れる環境なのと、すこしmakeを調べたので手直しすべき部分はあっさりとクリアｗ

さて…

pi@rasp4b4g:~/pmon $ gcc -o test test.c
pi@rasp4b4g:~/pmon $ ./test
Illegal instruction

権限がないと、例外が発生するのも確認。

pi@rasp4b4g:~/pmon $ sudo insmod ./pmuser.ko
pi@rasp4b4g:~/pmon $ ./test
time = 94, x = 500500
pi@rasp4b4g:~/pmon $ ./test
time = 105, x = 500500
pi@rasp4b4g:~/pmon $ ./test
time = 94, x = 500500

無事動作確認が取れました！

ARM Cortex-A72の4bで行けたから2b以降なら大丈夫でしょう(ただし32bit環境)…ということで。

これで…150サイクルが実現できて、ドライバ内で処理が完結しやすくなります。

pi@rasp4b4g:~/pmon $ sudo rmmod pmuser

で削除するか再起動をお忘れなく…

湿度が下がってかなり楽にはなったけど、温度が上がってくるときになることは…

昨日から関東上空に停滞続けていた梅雨前線の中央が消滅したと同時に湿度が下がりようやく梅雨明けしました。

昨日の午前中はまだ若干部屋の中の湿度が高めだったのですが、午後からはようやく夏の気候になりました。それでも日本の夏は湿度高めですが…

気温が低くても湿度が高いと体感温度はかなり上がってしまうので、正直２週間ほど前の状態よりは体感温度は低く感じますが、温度計を見ると結構上がってました。

そこで気になるのは…そうですRaspberry piの本体温度ですｗ

サイクルカウントのヒント？

全然関係のないことを調べていたら検索結果にタイムリーな記事が。

Zynq Cortex-A9 ARMでお手軽にサイクル計測する手法を調査する(1)

サイクルカウントできそうな話題！

正直なところ、モード切替の150サイクルを待機する部分がお手上げだったのでソースを探して…まではしたんですけど、いままでまったく興味が無かった部分でソースや断片がどこにあるのかとか明るくないのでそちらもお手上げでしたｗ

で、いきなり「コプロセッサとアクセス…」ドライバ側で何もしないでアクセスできるのかどうか不安になりつつも、少し見ていくとそれの元ネタのページへのリンク。

2010年08月10日 Cortex-A9のサイクルカウンタを利用した簡単な実行時間の計測方法

なんとなく行けそうなタイトルです。「このソースは特権モードで使用することを想定しています。」ど、ドライバ内で使えるのかな？

早速組み込んで遊んでみようかな。

見てみると色々と捉え方が変わりますね。まずドライバをinsmodすると初期化処理が動いてrmmodするまでそのままの状態であるということ。確かにそうですが、こんな感じに利用するのが本来の使い方なのかな？。確かに権限付与とかやりやすそうな実装に見えます。

気になる部分を書き換え中に気付いたこと

今日はraspberry pi 4bで動かしていますが、気になったこと。

python側もサンプリング時のループ回数を表示させてみたところ、cで試していた時とは違った違いが出てきました。dhtセンサーの値を2連続で取得しているのですが、１回目と2回目の差が出てきています。

array('I', [11, 82, 88, 53, 25, 54, 70, 54, 24, 54, 24, 54, 24, 54, 24, 54, 25, 53, 72, 54, 24, 54, 24, 54, 24, 54, 24, 54, 24, 54, 24, 54, 24, 54, 26, 53, 25, 54, 24, 54, 70, 54, 24, 54, 24, 54, 24, 54, 24, 54, 25, 54, 25, 54, 24, 54, 24, 54, 24, 54, 24, 54, 70, 54, 71, 54, 25, 54, 24, 54, 70, 54, 71, 54, 24, 54, 24, 54, 70, 54, 70, 54, 72, 54])
array('I', [104, 805, 852, 526, 236, 527, 687, 526, 235, 526, 236, 526, 236, 526, 236, 527, 236, 526, 697, 526, 236, 526, 236, 526, 236, 526, 236, 526, 236, 526, 236, 526, 236, 526, 246, 526, 236, 526, 236, 526, 695, 526, 236, 526, 236, 526, 236, 526, 236, 526, 245, 527, 235, 527, 236, 526, 236, 526, 236, 526, 238, 527, 687, 526, 688, 526, 246, 526, 236, 526, 687, 526, 688, 526, 235, 527, 235, 526, 688, 526, 687, 527, 694, 526])

2nd read.
array('I', [8, 82, 87, 55, 24, 54, 70, 54, 24, 54, 24, 54, 24, 54, 24, 54, 24, 54, 72, 54, 24, 54, 24, 54, 24, 54, 24, 54, 24, 54, 24, 54, 24, 54, 25, 54, 25, 53, 25, 54, 70, 54, 24, 54, 24, 54, 24, 54, 24, 54, 25, 54, 25, 53, 25, 53, 25, 54, 24, 54, 24, 54, 70, 54, 71, 53, 72, 54, 24, 54, 70, 54, 71, 54, 24, 54, 70, 54, 24, 54, 24, 54, 25, 54])
array('I', [29, 328, 347, 215, 96, 214, 280, 214, 96, 215, 96, 214, 96, 215, 96, 214, 96, 214, 284, 215, 96, 214, 96, 215, 96, 214, 96, 214, 96, 215, 96, 214, 96, 214, 100, 215, 96, 214, 96, 215, 280, 214, 96, 214, 96, 214, 96, 215, 96, 214, 100, 215, 96, 214, 96, 214, 96, 215, 96, 214, 96, 215, 280, 214, 280, 214, 284, 215, 96, 214, 280, 214, 280, 215, 96, 214, 280, 215, 96, 214, 96, 214, 100, 214])

順番にサンプリングのデータ、サンプリング時のウェイトループのループ回数とありますが、サンプリングのデータはほぼ同じような数字となっていますが、ループ回数が大きく違います。

ドライバを呼び出さない場合も比べてみると、

array('I', [6, 82, 88, 52, 23, 55, 69, 54, 23, 54, 23, 54, 23, 54, 23, 54, 69, 54, 23, 54, 23, 54, 23, 54, 23, 54, 23, 53, 25, 53, 25, 51, 26, 51, 25, 54, 23, 54, 23, 54, 71, 54, 23, 53, 25, 51, 25, 53, 23, 53, 25, 54, 23, 52, 25, 53, 23, 54, 23, 54, 23, 55, 69, 53, 25, 51, 72, 54, 23, 53, 69, 54, 70, 55, 23, 54, 23, 53, 70, 55, 71, 52, 72, 54])

array('I', [1, 24, 33, 19, 8, 20, 26, 20, 8, 20, 8, 20, 8, 20, 8, 20, 26, 20, 8, 20, 8, 20, 8, 20, 8, 20, 8, 20, 9, 20, 9, 19, 9, 19, 9, 20, 8, 20, 8, 20, 27, 20, 8, 20, 9, 19, 9, 20, 8, 20, 9, 20, 8, 19, 9, 20, 8, 20, 8, 20, 8, 21, 26, 20, 9, 19, 19, 20, 8, 20, 26, 20, 26, 20, 8, 20, 8, 19, 26, 20, 26, 19, 27, 20])

2nd read.

array('I', [0, 81, 87, 53, 26, 52, 72, 51, 27, 51, 25, 51, 25, 51, 26, 52, 70, 58, 19, 58, 25, 51, 25, 51, 25, 50, 25, 52, 25, 51, 25, 52, 26, 51, 26, 57, 19, 59, 18, 59, 64, 58, 19, 52, 25, 57, 19, 59, 20, 52, 26, 58, 19, 58, 19, 57, 25, 51, 25, 51, 26, 51, 71, 51, 26, 52, 72, 57, 18, 58, 70, 51, 72, 51, 26, 53, 25, 52, 70, 51, 71, 52, 72, 52])

array('I', [0, 8, 12, 7, 3, 7, 10, 7, 3, 7, 3, 7, 3, 7, 3, 7, 10, 8, 2, 8, 3, 7, 3, 7, 3, 7, 3, 7, 3, 7, 3, 7, 3, 7, 3, 8, 2, 8, 2, 8, 9, 8, 2, 7, 3, 8, 2, 8, 2, 7, 3, 8, 2, 8, 2, 8, 3, 7, 3, 7, 3, 7, 10, 7, 3, 7, 10, 8, 2, 8, 10, 7, 10, 7, 3, 7, 3, 7, 10, 7, 10, 7, 10, 7])

サンプリングのブレ幅はありますが、こちらもループ回数が半減していました。

それぞれの４番目のデータを見てみます。

ドライバで求めた値 53 562 / 55 215

python内で求めた値 52 19 / 53 7

562 ÷ 215 ≒ 2.6

19 ÷ 7 ≒ 2.7

もうちょい正確にいってみましょうかｗ

1μ秒単位のループ回数比で計算してみると

562÷53≒10.60

215÷55≒3.909

10.6÷3.9≒2.711

19÷52≒0.3653

7÷55≒0.1272

0.3653÷0.1272≒2.871

それぞれ回数の低い方基準の数字ですが、こんな感じに。0.16の差は何かというのは気になりますね。レジスタアクセスでキャッシュが効いてないアクセスがあるのが原因か、pythonの実行処理がキャッシュ前提の効率化がうまく行っているのかはわかりません。

このぐらいの数字で心当たりがあるとすれば、CPUクロックの変動ぐらいしかなさそうなので、確認してみます。

pi@rasp4b4g:~/gpioread $ cpufreq-info -p
600000 1500000 ondemand
pi@rasp4b4g:~/gpioread $ cpufreq-info -f
600000

1500000÷600000＝2.5

原因はおそらくこれかな…cではそのまま実行されるので、クロック変動しないままサンプリング処理を終えていましたが、pythonはおそらくオーバーヘッドの処理が重たいのでクロックアップ状態のままサンプリングを行って、２秒の待ち時間があることでクロックダウンしたのではないかと推測。記憶を辿ると、3bでcで連続で試したときもリトライ時の方が処理速度が落ちていたときがあったような気がします。