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

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