gauche.time - 時間の計測 ¶Schemeコードの実行時間を測る3つの方法を提供します。
インタラクティブな使用に便利なtimeマクロ、
ベンチマークのための手続きのセット、
プログラム中に埋め込んで使える<time-counter>オブジェクトです。
註: timeマクロはgauche.timeモジュールをオートロードする
ようにあらかじめ定義されているので、timeマクロを使うだけなら
(use gauche.time)としておく必要はありません。
{gauche.time}
式expr expr2 … を順に評価し、最後の式の結果を返します。
結果が返される前に、全ての式の評価にかかった実(経過)時間および
ユーザースペース、カーネルスペースで費されたCPU時間がカレントエラーポートに
報告されます。
現在の実装は、経過時間に対してはsys-gettimeofday
(時間参照)を、CPU時間に対してはsys-times
(システムへの問い合わせ参照)を用いています。従って、
それぞれの数値の分解能はこれらの手続きが用いているシステムコールに依存します。
CPU時間は10ms単位で、経過時間はそれより細かいことが多いです。
但しgettimeofday(2)コールをサポートしていないOSでは経過時間が最悪の場合
秒単位になります。
gosh> (time (length (sort (call-with-input-file "/usr/share/dict/words"
port->string-list))))
;(time (length (sort (call-with-input-file "/usr/share/dict/words" port- ...
; real 0.357
; user 0.350
; sys 0.000
45427
計測したいルーチンの一回の実行が一瞬で終わるために、 何度も繰り返して実行してより正確に時間を測りたいということはよくあります。 また、複数の実装を計測して比べてみたいということもよくあります。 ここに挙げるのは、そのために便利な手続きです。
これらベンチマーク手続きの名前と振る舞いは、PerlのBenchmarkモジュールを 参考にしています。
{gauche.time}
thunkを何度も呼び出し、実行時間を測ります。
howには次の形が指定できます。
integer指定された回数だけ、thunkを呼びます。
(metric real)時間の合計が指定された数値(秒)を越えるまでthunkを繰り返し呼びます。
metricはシンボルcpu、user、sys、realの
いずれかで、どの時間で測るかを指定します。
このルーチンはまた、thunkを実行するのと同じ回数だけ 空のループを実行して、その時間を結果から引くので、 結果にはthunkの実行時間のみが反映されます。
戻り値は後述する<time-result>レコードです。先に例を示しておきます。
;; Run the thunk 1,000,000 times (time-this 1000000 (lambda () (expt 100 30))) ⇒ #<time-result 1000000 times/ 1.030 real/ 1.040 user/ 0.000 sys> ;; Run the thunk at least 5.0 cpu seconds (time-this '(cpu 5.0) (lambda () (expt 100 30))) ⇒ #<time-result 4903854 times/ 5.090 real/ 5.050 user/ 0.010 sys>
{gauche.time}
ベンチマーク結果を保持するレコードです。以下のスロットがあります。
<time-result>: count ¶thunkが実行された回数です。
このスロットはアクセサ手続きtime-result-countでもアクセスできます。
<time-result>: real ¶thunkの実行にかかった実経過時間の合計です。
このスロットはアクセサ手続きtime-result-realでもアクセスできます。
<time-result>: user ¶thunkの実行にかかったユーザCPU時間の合計です。
このスロットはアクセサ手続きtime-result-userでもアクセスできます。
<time-result>: sys ¶thunkの実行にかかったシステムCPU時間の合計です。
このスロットはアクセサ手続きtime-result-sysでもアクセスできます。
{gauche.time}
<time-result>レコードのコンストラクタです。
{gauche.time}
<time-result>レコードかどうかを判定します。
{gauche.time}
ふたつの<time-result>レコードの和と差を求め、新しいレコードを返します。
with-countが偽なら、 real, user, sysの各スロットのみが計算対象となり、 結果のcountスロットはt1のcountスロットの値がそのまま引き継がれます。 これは、部分ごとに別々に計測された結果を対象に計算する場合を意図しています。
with-countが真なら、 countスロットも同様に計算対象となります。 これは、何度か走らせたベンチマーク結果を対象に計算する場合を意図しています。
{gauche.time}
複数のコード片をベンチマークして比較する手続きです。
alistは((key . thunk) …)という形でなければなりません。
ここで、keyはシンボル、thunkは引数を取らない手続きです。
how引数はtime-thisと同じです。すなわち、
実行の繰り返し回数を指定する整数か、
使うCPU時間をxとして(cpu x)の形のリストか、です。
time-theseはalist中のthunkそれぞれを走らせて計測し、
結果を
(how (key1 . result1) (key2 . result2) …)
の形で返します。ここでresultは<time-result>オブジェクトです。
time-these/reportはベンチマーク結果を、人間が読みやすい
形式にして表示します。
gosh> (time-these/report '(cpu 3.0)
`((real1 . ,(cut expt 100 20))
(real2 . ,(cut %expt 100 20))
(imag . ,(cut expt +100i 20))))
Benchmark: ran real1, real2, imag, each for at least 3.0 cpu seconds.
real1: 3.312 real, 3.320 cpu (3.320 user + 0.000 sys)@ 1694277.11/s n=5625000
real2: 2.996 real, 3.010 cpu (3.010 user + 0.000 sys)@35595634.55/s n=107142860
imag: 3.213 real, 3.190 cpu (3.190 user + 0.000 sys)@ 862068.97/s n=2750000
Rate real1 real2 imag
real1 1694277/s -- 0.048 1.965
real2 35595635/s 21.009 -- 41.291
imag 862069/s 0.509 0.024 --
レポートの最初の部分は、各thunkについて、 実経過時間、CPU時間(およびその内訳としてのuser時間とsystem時間)、 一秒あたりの繰り返し回数、そしてトータルの繰り返し回数です。
次の部分は、ベンチマーク間の比較です。
例えば最初の行は、real1はreal2の0.048倍、
imagの1.965倍の速度で実行されたことを示しています。
metric引数は、速度計算および比較マトリクスにどの時間を使うかを指定します。
渡す値は#fか、シンボルcpu、real、
user、sysのいずれかでなければなりません。
デフォルトは#fで、その場合はhowに渡したメトリックが使われます
(howが回数を指定する整数の場合は、cpuが使われます)。
{gauche.time}
これはtime-theseの結果を見やすいレポートとして表示する
ユーティリティ手続きです。time-these/reportは
time-theseとこの手続きを組み合わせているだけです。
省略可能なmetric引数の意味は、
time-these/reportのmetricキーワード引数と同じです。
(define (time-these/report how samples :key metric) (report-time-results (time-these how samples) metric))
{gauche.time}
時間カウンタの抽象クラスです。時間カウンタは
時間の経過と共にその値が増加してゆく一種のタイマーです。
何度でもカウントを止めたり開始したりできます。
カウンタの値はカウントが止まっている時に読み出すことができます。
複数の時間カウンタを使えば、
例えばループ中の二つの部分について費される時間を別々に計測することもできます。
具体的なサブクラスが、どの時間をカウントするかを決定します。 時間カウンタを使うには、下に挙げるサブクラスのいずれかを インスタンシエイトしなければなりません。
{gauche.time}
それぞれ、実経過時間、ユーザースペースCPU時間、カーネルスペースCPU時間、
総CPU時間 (ユーザー+カーネル)を計測する時間カウンタのクラスです。
{gauche.time}
時間カウンタcounterを開始/停止します。カウンタが走っている間の時間が、
カウンタが停止した時点でカウンタの値に加算されます。
開始/停止の対はネストすることができます。その場合は、一番外側の対のみが
有効です。
つまり、既に走っているカウンタに対しtime-counter-start!を呼んでも
何も起こりませんが、一度余分にtime-counter-stop!を呼ばないと
カウンタは止まりません。
これは、内部に既に開始/停止の対を含んでいるかもしれない大きなコードブロックの
全体の時間を計測したいというような場合に便利です。
既に停止しているカウンタに対してtime-counter-stop!を呼んでも
何も起こりません。
{gauche.time}
カウンタcounterの値をリセットします。既にcounterが走っている
場合は、リセットの前にカウンタは停止させられます。
{gauche.time}
カウンタcounterの現在の値(秒数)を実数で返します。
分解能はそれぞれのカウンタが用いているシステムコールに依存します。
{gauche.time}
式expr …が評価される間だけcounterを走らせる、
便利なマクロです。最後の式の結果を返します。このマクロは次のように
定義されます。
(define-syntax with-time-counter
(syntax-rules ()
((_ counter . exprs)
(dynamic-wind
(lambda () (time-counter-start! counter))
(lambda () . exprs)
(lambda () (time-counter-stop! counter))))
))
下の例では、ループ内でのprocess-Aとprocess-Bにて費された 概略の時間をそれぞれ計測します。
(let ((ta (make <real-time-counter>))
(tb (make <real-time-counter>)))
(dotimes (i 100000)
(with-time-counter ta
(process-A))
(with-time-counter tb
(process-B)))
(format #t "Time spent in process-A: ~s\n" (time-counter-value ta))
(format #t "Time spent in process-B: ~s\n" (time-counter-value tb))
)