懲りもせず今日も少し夜空を見上げてしまいました

今日の昼間は雨こそ降りませんでしたが、雷は激しく、思わず動画撮影したらいい音が取れました。手ごろな編集ソフトが無いのでyoutubeにアップして前後をカットしてコレクションにｗ

寝る前に窓の外を見てみると、北の空の雲がなさそうなので出てみると意外と涼しかったです。

そんな中さすがにラッキーなことは３度目は起こらず、結局１時間ぐらい外に居ました。

見えたものは…カシオペア座の下の方に上から下へ短く流れるものを見た気がするのと、飛行機か人工衛星の光が右へゆっくりと流れる光ぐらいでした。

ペルセウス流星群

 日付としては一昨日になりますが、１２日は天気が悪くなるとのことで前日の夜に少しベランダで夜空を眺めていました。youtubeでウェザーニュースなどでも幕張の夜空のライブ中継やっていましたが、私がちょうど一つ流星を見つけて満足して戻ったらライブは終わってました。時刻は23時20分ごろで北極星の下側に左から右へほぼ真横に流れました。見えた流星はかなり短め（手を伸ばして５～１０㎝程度）でしたがはっきりと見えました。

そして今日はふと外をみると星が見えたのですこしベランダに出て北側を少し眺めているとほぼ真上にカシオペア座が見え、その下に右から左へ流れる流星を見ることができました。長さはいい感じの長さ（腕を伸ばしたところで２０～３０㎝程度かな？）でした。時刻は２：３０過ぎかな…そのあと蚊取り線香に火をつけてスマホを構えてベランダで待機してみましたが、残念ながら写真に収めることはできませんでした。ベランダに出て２、３分もしないうちに見れたのがラッキーだっと思います。

昨日もyoutubeでライブが流れていましたが、北海道とどこかな。レーザー光線やら人工衛星やら色々と邪魔が入ってたようですが、ライブ中継で映ったのなら、どこかで編集して公開してくれると嬉しいですね。

実行時間の計測

全体でどのくらいの負荷がかかっているのか気になったのでどんな手段があるのか検索してみました。

Linuxでシェルレベルの時間計測は３つの方法がありそうです。

• timeコマンドを利用する
• dateコマンドを利用する
• bashで利用可能なSECONDS変数を利用する

timeコマンドは秒単位ですが小数点を表示しているのでミリ秒程度の精度はあるようです。dateコマンドとSECONDS変数は秒単位となります。

コマンドレベルで利用するのに便利なのはtimeで、シェルスクリプトで利用するなら表示形態によってdateコマンドかSECONDS変数を利用するか変わるのではないでしょうか。

試しに実行してみました

pi@rasp4b4g:~/gpioread $ time ./dht2 -h
未知のオプションが指定されました。

dht ver.0.1 debugコードコミコミ版

指定可能なオプション
--debug : デバッグ情報の表示
--gpio n : GPIOピン番号(デフォルトはGPIO5番).
--type x : DHT11かDHT22を指定する。(デフォルトはDHT11)大文字、小文字の判別はしない。
        指定された型の手順でセンサーから読込み、湿度、温度を出力するが、
        読込んだデータをもとに判定しできる限り出力する。
        ただし、その時のリターンコードはエラーとなる。
--oneread : 無指定時はセンサーから2回読込み、2回目に取得した値を出力する。
        このオプションが指定されるとセンサーからの読込を1回だけに限定する。
        センサーがスリープしていた場合はスリープ前の値が出力される。

real    0m0.010s
user    0m0.000s
sys     0m0.011s

最初からなんか数字がおかしい感じなので調べてみると

real > user + sys

という関係になると思いますが、0.001sずれている結果に。

気を取り直して、同じような状態になるようにオプションをつけてcで作成したものとpythonとで比較したいと思います。

pi@rasp4b4g:~/gpioread $ time ./dht2 --oneread
temperature : 35.6
humidity : 60.0

real    0m0.044s
user    0m0.001s
sys     0m0.043s
pi@rasp4b4g:~/gpioread $ time python3 ./dht.py --onetime --nodirect
DHT results.
Conversion  : DHT11V1.3
Temperature : 35.5 C
Humidity    : 60.0 %

real    0m0.257s
user    0m0.136s
sys     0m0.052s

実行時間で比較すると0.2s程度python側の方が時間がかかっているようです。実行時間が長いpythonでは確実に割り込みによって実行時間が伸びている感じがします。

この差の大小を考えるには運用方法とそれぞれの利点と欠点を比較する必要がありますね。
個人レベルとしては、

• ソースファイルと実行ファイルが分かれていないので、管理コストがかなり低い。
• ほとんどのことがpythonだけで完結する。
• ライブラリなども動的にリンクさせて実行できる。

といったpythonの利点がかなり有利なのでpython以外の選択肢はない気がしていますが、それでも常駐させるような形のものをpythonで書くのはどうかという部分も引っかかっています。

この数字はその時の判断材料となりそうです。 

c側のコマンドがサンプリングバッファを利用しない形に対応していないので --nodirectとして実行していますが、先日書き換えた結果どのくらい効果があったのか見てみたいと思います。

pi@rasp4b4g:~/gpioread $ time python3 ./dht.py --onetime
DHT results.
Conversion  : DHT11V1.3
Temperature : 35.6 C
Humidity    : 60.0 %

real    0m0.246s
user    0m0.134s
sys     0m0.042s 

時間にして0.257s - 0.246s = 0.011s まぁこんなものでしょうｗメモリー操作なら数メガ単位の操作にならなければ、個人レベルのデータ量であればそこまで気にする必要はなさそうです。

無駄にpython側でもダイレクトにdataformatへ格納する処理を作ってみた

スクリプト的に流れが気に入らなかったので、結局pythonでもドライバで実装したサンプリング配列を作らないで直接dataformatを作成する処理を実装することに。

ついでに異常値に色付けなども行ってみました。

ドライバを介さないと途端に割り込み処理による取りこぼしが発生していました。

pi@rasp4b4g:~/gpioread $ python3 ./dht.py --debug --nodriver
Output for debugging.
gpio_no : 5
No driver is used.
OSError : 1 IsNoDriver
Sampling is performed without using a driver.
respons low  : 82
respons high : 87
data low     : 51 ～ 55
data high '0': 23 ～ 26
data high '1': 69 ～ 72
data format : 3F 00 23 06 68
2nd read.
OSError : 1 IsNoDriver
Sampling is performed without using a driver.
respons low  : 85
respons high : 89
data low     : 43 ～ 113
data high '0': 21 ～ 29
data high '1': 66 ～ 73
data format : 2F 00 23 06 68
CRC Error.
ErrorCode :  2  retry.
OSError : 1 IsNoDriver
Sampling is performed without using a driver.
respons low  : 82
respons high : 87
data low     : 48 ～ 133
data high '0': 21 ～ 29
data high '1': 65 ～ 72
data format : 3F 00 23 06 D0
CRC Error.
ErrorCode :  2  retry.
OSError : 1 IsNoDriver
Sampling is performed without using a driver.
respons low  : 88
respons high : 87
data low     : 48 ～ 58
data high '0': 21 ～ 29
data high '1': 65 ～ 72
data format : 3F 00 23 06 68
DHT results.
Retry count : 2 time(s)
Conversion  : DHT11V1.3
Temperature : 35.6 C
Humidity    : 63.0 %

不完全とはいえ、こうなると割り込み停止させるためにメモリマップドレジスタに展開されている割り込み停止処理も入れておきたくはなります。個人的にはそれよりドライバをちゃんと登録して、再起動時にも読み込まれるようにするのが先の様な気がしますｗ

サンプリングせずにダイレクトにビットを格納してみると…

作業としてはあまり大変そうではなかったので、コピペして切り張りして試してみました。

最初、ちょっと間違えてLOW信号の長さを見てしまったため、FFFFFFFFFFになってしまいましたが、見直してすぐに正しい処理が流れてよかったｗ

インターバルのデバッグもそのままコピーしたのでログから実行時間を比べてみました。

サイクルカウントのウェイトを作成してGPIOのPull Up/Downを実装してみました。

150Cycleのウェイトループが作れるようになったのでドライバ側でpull up/downの実装も行ってみました。これで一歩踏み込んだ形になります。

ただし、データシート上に記載してありましたが、pull up/downの設定値はcpuから見えなくなるため、設定値はソフト側で管理する必要があるとのこと。なので、これを行うとRpi.gpioの内部バッファと実際値のズレが生じてRpi.gpoiでうまく機能しなくなる可能性があります。

実装中に色々と新たな発見というか記載を見かけて色々な部分を書き換えながら実装していましたが、一番気になったのがioremapでアクセスできるようになったメモリーに対してアクセスするためにioread/iowriteといった関数を通す必要があるらしいという点。

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で連続で試したときもリトライ時の方が処理速度が落ちていたときがあったような気がします。