Linuxで実行時間を測る time には、Bashの予約語と /usr/bin/time などの外部プログラムがあります。まず type -a time で実体を確認します。Bashの time はパイプライン全体を計測でき、表示形式は TIMEFORMAT で指定します。GNU /usr/bin/time は -f や -v で経過時間、CPU、最大常駐メモリなどを出せますが、オプションは他OSのtimeと同じではありません。realは壁時計時間、userはユーザーモードCPU時間、sysはカーネルモードCPU時間です。比較では同じ入力を複数回測り、ウォームキャッシュ、同時負荷、周波数変動などのノイズを記録します。 確認ポイント：Bash keywordのtimeと外部GNU timeを識別し、計測結果が通常stderrへ出る点も固定します。
Bash keywordとGNU timeを識別する
type -a time
help time
/usr/bin/time --versionBashでは time is a shell keyword と表示されるのが典型です。さらに外部の /usr/bin/time が列挙される場合があります。help time はBash予約語の構文、/usr/bin/time --version は外部プログラムの実装確認です。後者が存在しない、または --version を受け付けない環境では、GNU固有オプションを使わずそのOSのmanページを読みます。
単に time と入力したとき、シェルは通常予約語として解析します。command time や絶対パスで外部プログラムを選ぶ方法はありますが、手順書では曖昧さを避けて /usr/bin/time と明記します。エイリアス、関数、PATH上の別バイナリがある環境も type -a で判別できます。
Bashのtimeでreal・user・sysを読む
time sleep 0.2典型的な出力は real 0m0.20s、user 0m0.00s、sys 0m0.00s です。sleepはCPUをほとんど使わず待つので、realだけが約0.2秒になりやすい例です。スケジューリングやタイマー精度のため厳密に0.200秒とは限りません。
- real：開始から完了までに壁時計で経過した時間。I/O待ち、sleep、他プロセスにCPUを譲った時間も含む。
- user：対象プロセス群がユーザーモードで使ったCPU時間。
- sys：対象プロセス群がシステムコールなどカーネルモードで使ったCPU時間。
マルチスレッドまたは複数プロセスが複数CPUコアを並行利用すると、userとsysの合計がrealを超えることがあります。逆にI/O待ちが長い処理ではrealに比べてCPU時間が小さくなります。realだけを見てCPUが遅いと断定せず、CPU時間、I/O、待ち、同時負荷を分けます。
TIMEFORMATを現在の計測だけに適用する
( TIMEFORMAT=$'real=%3R user=%3U sys=%3S cpu=%P'; time sleep 0.2 )Bashの TIMEFORMAT では %R がreal秒、%U がuser秒、%S がsys秒、%P がCPU使用率を表します。%3R の3は小数点以下の桁数です。括弧でサブシェルにしたため、計測後に親シェルのTIMEFORMATを変更しません。期待例は real=0.202 user=0.001 sys=0.000 cpu=0.49% のようになりますが、数値は負荷で変わります。
TIMEFORMATはBash予約語timeの表示に関係するシェル変数で、GNU /usr/bin/time -f の書式ではありません。二つの書式記号を混ぜると意味が変わります。計測ログには、使用したtimeの実体と書式文字列を一緒に残します。
パイプライン全体を測る
time printf "%s\n" alpha beta gamma | grep -F beta | wc -l
printf "pipeline exit=%s\n" "$?"Bashのtime予約語はパイプラインの前に置けるため、printf、grep、wcを含む全体を測ります。コマンド出力の期待値は 1 です。timeの統計は通常標準エラー側に表示され、次行は既定のパイプライン終了値を表示します。既定では最後のwcが成功すれば0なので、前段の失敗も評価したい場合はサブシェル内で set -o pipefail を有効にします。
外部の /usr/bin/time A | B では、シェル構文上timeが直接起動するのはAであり、パイプライン全体を測るとは限りません。全体を外部timeで測る必要があるなら /usr/bin/time sh -c "A | B" とできますが、引用、対象シェル、pipefailの有無が一段増えます。Bash予約語timeを使えるなら、その方がパイプライン構文を自然に扱えます。
終了ステータスを失わずに測る
time bash -c "exit 7"
rc=$?
printf "measured exit=%s\n" "$rc"期待出力の最後は measured exit=7 です。timeの統計が表示されても、測定対象の失敗が成功へ変わるわけではありません。$? はtime対象の終了ステータスを反映するので、直後に保存します。タイムアウト、シグナル終了、コマンドを開始できない場合は別の値になり、GNU timeは自身の起動失敗について特別な値を使います。
コマンド出力と計測結果を分離する
time grep -F -- "ERROR" ./app.log >./matches.txt
printf "grep exit=%s\n" "$?"この位置の >matches.txt はgrepの標準出力をファイルへ送り、Bash timeの統計は通常端末の標準エラーへ残ります。grep自身のエラーも標準エラーなのでtime表示と同じ端末に混ざります。Bash timeの出力だけを別ファイルへ捕捉するには、予約語を含むグループ全体の標準エラーをリダイレクトしますが、対象コマンドの標準エラーも同じファイルへ入る点を明記します。
{ time grep -F -- "ERROR" ./app.log >./matches.txt; } 2>./timing-and-errors.txtGNU timeなら -o で計測情報の出力先を指定できます。次の例はコマンドの通常出力、コマンドの標準エラー、time統計を3ファイルへ分けます。既存ファイルを上書きしない検証用ディレクトリで実行します。
/usr/bin/time -f "elapsed=%e user=%U sys=%S maxrss_kb=%M exit=%x" -o ./timing.txt -- grep -F -- "ERROR" ./app.log >./matches.txt 2>./command-errors.txt%e は経過秒、%U と %S はCPU秒、%M は最大常駐サイズ、%x はコマンド終了値です。単位と実装をログに付け、GNU timeの書式だと明記します。grepで一致なしの1と読み取りエラーの2を区別し、timeが出たことだけで計測成功としません。
GNU time -vを使う条件
/usr/bin/time -v -- sha256sum ./sample.bin >/dev/null-v はGNU timeの詳細表示で、経過時間、CPU使用率、最大常駐セットサイズ、ページフォールト、コンテキストスイッチ、ファイルシステムI/O、終了ステータスなどを表示します。フィールドの利用可否や値はOSが提供する資源情報に依存し、0が必ず「処理がなかった」とは限りません。
BSD系timeなどでは -v の意味が違う、または未対応です。移植するスクリプトでは /usr/bin/time --version とmanページでGNU実装を確認するか、対象OSごとのオプションを分けます。GNUの最大常駐サイズ %M はKiBとして扱われますが、他実装の単位を同じと仮定しません。
繰り返し計測とウォームキャッシュ
for run in 1 2 3 4 5; do
/usr/bin/time -f "run=$run elapsed=%e user=%U sys=%S" -- grep -F -- "ERROR" ./app.log >/dev/null
done5回の値を保存し、最小値だけでなく中央値、ばらつき、実行順を見ます。最初の実行はページキャッシュ、DNSキャッシュ、JIT、接続確立などのため遅く、その後は温まった条件になる場合があります。逆にバックグラウンド負荷やサーマル制御で後半が遅くなることもあります。ウォームアップを捨てるなら、その規則を結果を見る前に決めます。
比較対象AとBでは入力ファイル、出力検証、作業ディレクトリ、環境変数、CPU割り当て、同時実行数を揃えます。キャッシュを強制消去する操作はシステム全体へ影響するため通常の比較では行わず、「通常利用の温かいキャッシュ」か「新規プロセスの初回」かを測定条件として分けます。仮想マシンや共有ホストでは隣接負荷もノイズになります。
結果を解釈する確認手順
- 対象コマンドの出力件数またはハッシュが各回で同じか確認する。
- realだけ増えCPU時間が同程度なら、I/O待ち、ロック、スケジューリングを調べる。
- user/sysが増えたなら、処理量、アルゴリズム、システムコールの変化を調べる。
- 終了ステータスが異なる回は性能比較へ混ぜず、失敗原因を先に解決する。
- time実装、コマンド版、入力サイズ、実行順、同時負荷を結果と一緒に記録する。
TIMEFORMATと出力fileを片付ける
sleepや読み取りコマンドを端末へ表示するだけなら永続変更はありません。リダイレクト例は matches.txt、timing-and-errors.txt、timing.txt、command-errors.txt を作成または上書きします。既存名を避けた検証用ディレクトリで実行し、完了後に内容と正確なパスを照合して、その計測で作ったファイルだけを片付けます。副作用のある本番コマンドを性能測定のため何度も実行せず、読み取り専用入力や隔離されたテストへ置き換えます。
time計測値を比較可能にする
type -a timeでBash予約語と外部timeを区別した。- real、user、sysを壁時計時間とCPU時間として解釈した。
- TIMEFORMATはBash、
-f/-vはGNU timeの機能として分けた。 - リダイレクト位置を確認し、コマンド出力・エラー・計測値を意図どおり分離した。
- 同じ入力を複数回測り、終了値、ウォームキャッシュ、同時負荷、ばらつきを記録した。
コメント