2021年8月5日木曜日

time.sleep(0) ってどれくらいsleepするのか RaspberryPi4+Python3

 time.sleep(0)って0秒?本当?

0秒?
いや、0秒では無いでしょう。0.000000秒。
だって、プログラムとして動作しているのだから、0.1uSecぐらいはかかっているでしょう。

はい、事の発端はOLEDな1602ディスプレイを使った時の話です。

タイミングチャートで40nSecをカウントするのに、time.sleep(0)で代用できるのかどうか、time.sleep(0.00000004)って正確に測れるのか。
多分できそうだけど実際どうなのか。
例えば、ARMのマシン語で行って帰って来るだけのコードを書いたとしたら

    GOSUB time.sleep ;3cycle
time.sleep:
    RET                    ;3cycle

相当になります。それぞれの命令が各3cycle必要で計6cycle。1.5GHzで動作するARMなら4nSec。これが、Pythonならこれ以上のコードが必要なわけで。40nSecを計測して戻ってくるのは非常に困難を極めそうです。しかも、sleepならLinuxシステムへ制御を移して、他のプロセスやスレッドに制御を移して(コンテキストスイッチングして)から、こっちに戻ってくるわけで、あっちに行ってる間に時間が来てちゃんとこっちに戻ってこれるのか。リアルタイムOSではないのでそんなにすぐに戻ってこれないような。
Pythonでも呼び出しているであろう、nanosleep(2)のLinux Programmer's Manual を読むと、

int nanosleep(const struct timespec *req, struct timespec *rem);
     少なくとも *req で指定された時間の間、... 一時停止する。

【少なくとも】…ってどうなのよ?w

と、机上の空論も楽しいのですが…
まずは計測してみましょう。

計測用のプログラム
[sleep0.py]
import time
import datetime

dPrev = time.perf_counter() 
dNow =time.perf_counter() 
dNow =time.perf_counter() 
dNow =time.perf_counter() 
dNow =time.perf_counter() 
dNow =time.perf_counter() 
dNow =time.perf_counter() 
dNow =time.perf_counter() 
dNow =time.perf_counter() 
dNow =time.perf_counter() 
dNow =time.perf_counter() 


d_perfcounter = 0.0

for nnn in range(10):

    dPrev = time.perf_counter() 
    dNow =time.perf_counter() 
    dNow =time.perf_counter() 
    dNow =time.perf_counter() 
    dNow =time.perf_counter() 
    dNow =time.perf_counter() 
    dNow =time.perf_counter() 
    dNow =time.perf_counter() 
    dNow =time.perf_counter() 
    dNow =time.perf_counter() 
    dNow =time.perf_counter() 

    print(dPrev)
    print(dNow)
    print((dNow - dPrev))
    d_perfcounter += dNow - dPrev

    time.sleep(3)
next

d_perfcounter /= 100

print("time[perf_counter]:",end=" ")
print(d_perfcounter)

print()
print("sleep(0) 32 times....")

d_sleep0 = 0.0
for nnn in range(10):

    dPrev = time.perf_counter() 

    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)
    time.sleep(0)

    dNow =time.perf_counter() 

    print(dPrev)
    print(dNow)
    print((dNow - dPrev))
    sleep0 = dNow - dPrev - d_perfcounter
    d_sleep0 += sleep0 / 32
    print(sleep0 / 32)

    print()

    time.sleep(3)
next

print("time[time.sleep(0)]:",end="  ")
print(d_sleep0 / 10)



実行結果
@pi:/var/samba/sleep# python3 sleep0.py 
34270.738527
34270.738584
5.699999746866524e-05
34273.751956
34273.752057
0.00010099999781232327
34276.754022
34276.754086
6.399999983841553e-05
34279.756743
34279.756811
6.800000119255856e-05
34282.760176
34282.76027
9.399999544257298e-05
34285.761559
34285.761624
6.500000017695129e-05
34288.763212
34288.763283
7.100000220816582e-05
34291.766136
34291.766237
0.00010100000508828089
34294.76743
34294.767496
6.600000051548705e-05
34297.770177
34297.770245
6.800000119255856e-05
time[perf_counter]: 7.550000009359792e-06

sleep(0) 32 times....
34300.774029
34300.774392
0.00036299999919719994
1.1107812474620004e-05

34303.776494
34303.776823
0.00032900000223889947
1.0045312569673115e-05

34306.780181
34306.78058
0.0003989999968325719
1.2232812400725379e-05

34309.782258
34309.782607
0.00034900000173365697
1.0670312553884287e-05

34312.785442
34312.785868
0.0004259999986970797
1.3076562458991247e-05

34315.788325
34315.788681
0.00035599999682744965
1.0889062400565308e-05

34318.790176
34318.790573
0.0003969999961555004
1.2170312379566894e-05

34321.791633
34321.792072
0.00043899999582208693
1.3482812369147723e-05

34324.794228
34324.794555
0.00032700000156182796
9.98281254851463e-06

34327.796208
34327.796607
0.0003989999968325719
1.2232812400725379e-05

time[time.sleep(0)]:  1.1589062455641394e-05


結果

time.sleep(0) の実行時間は 11.5uSecでした。

ただ、この結果もRaspberryPiの動作状況に大きく依存するので、その時々でこの値は変わります。例えば、ローカルWifiに接続された状態で、Sambaへアクセスしている他のネットワークデバイスがあったりとか。実際に計測を繰り返すと計測値がまちまちです。

40nSecのようなごく短い時間だとtime.sleep(0.00000004)としても、11uSecも待たないといけないことがわかりました。
今回、40nSec待つのにtime.sleep(0)は、待てるのなら使えるという結果でした。