Makefile上の個々の操作の実行時間をファイルに出力したかったところからの諸々

memo time bash make

Makefile上の操作に対して、実行時間を計測したい。ただしコンソール上に出力するのではなくファイルに出力したい（というところから始まった）。

ファイルを分けたいので呼び出し側でリダイレクトでは無理

例えば以下の様なタスクがある。それぞれの操作の実行時間を個別にファイルに出力したい。

default:
    # 本来sleep 1の部分は何らかのコマンドの記述になっている
    time sleep 1  # aaaに出力したい
    time sleep 1  # bbbに出力したい

タスク内の操作で出力するファイルを分けたいので以下のように呼び出す側でリダイレクトでは無理。これでは全ての出力結果が１つのファイルに出力されてしまう。

# ちなみに make > xxx 2>&1 と同じ意味
$ make &> xxx

ただmakeのタスク内にリダイレクトを書けば良いわけでもない

試しにそれっぽい感じのものを書いてみる。気持ちとしてはaaa,bbbにそれぞれの出力結果が含まれて欲しい

default: clean
  time sleep 1 &> aaa
  time sleep 1 &> bbb

clean:
  rm -f aaa bbb

実行結果

$ make
rm -f aaa bbb
time sleep 1 &> aaa

real    0m1.003s
user    0m0.003s
sys 0m0.000s
time sleep 1 &> bbb

real    0m1.002s
user    0m0.001s
sys 0m0.000s

上手く動いてくれない。これは通常の環境ではtimeはコマンドではなくshellの組み込みの操作として実装されているため。

$ which: no time in ( ....)
# /usr/bin/time にgnuのtimeコマンドが入っている環境もあるかもしれない

内部でshellが動いてくれれば良さそう

内部でshellが動いてくれれば良さそう。()で囲む。ただしこれはbashでだけの話かもしれない(他のshellでは試していない)

default: clean
  (time sleep 1) &> aaa
  (time sleep 1) &> bbb

clean:
  rm -f aaa bbb

実行結果

$ make
rm -f aaa bbb
(time sleep 1) &> aaa
(time sleep 1) &> bbb

$ cat aaa
real    0m1.003s
user    0m0.002s
sys 0m0.000s

上手くいっていそう。

本来の目的は達成されたけれど、もう少しバリエーションを試してみる。

追記したい場合

&> を &>> にすれば良い。

default:
  (time sleep 1) &>> aaa
  (time sleep 1) &>> bbb

clean:
  rm -f aaa bbb

コンソールにも出力したい場合

teeを使うように書き換えれば、ファイル出力とコンソール出力を兼ねられる。ただし&>の代わりに|&を使う。具体的には以下のように。

default: clean
  (time sleep 1) |& tee aaa
  (time sleep 1) |& tee bbb

clean:
  rm -f aaa bbb

とはいえ、全部書き換えて回るのはめんどくさい。間に結合する演算子的なものを定義しておくとオプションで切り替えられるようにはなる。

TRACE ?=
ifeq ($(TRACE),)
    outOP := &>
else
    outOP := |& tee
endif

default: clean
  (time sleep 1) ${outOP} aaa
  (time sleep 1) ${outOP} bbb

clean:
  rm -f aaa bbb

ただしちょっとMakefile上でのプログラミングに足を踏み入れてしまっている感じがある。

一応期待通りに動きはする。

$ make -n
rm -f aaa bbb
(time sleep 1) &> aaa
(time sleep 1) &> bbb
$ make -n TRACE=1
rm -f aaa bbb
(time sleep 1) |& tee aaa
(time sleep 1) |& tee bbb

並行して

makeに任せればさっきの２つを並行して呼び出すことも出来はする。

TRACE ?=
ifeq ($(TRACE),)
    outOP := &>
else
    outOP := |& tee
endif

default: clean
  $(MAKE) aaa bbb

aaa:
  (time sleep 1) ${outOP} aaa
bbb:
  (time sleep 1) ${outOP} bbb

clean:
  rm -f aaa bbb
.PHONY: aaa bbb

(この例だと気にする必要がないことではあるけれど)cleanが終了しきった後にそれぞれのタスクが実行されて欲しいのでdefaultタスクの依存にaaa,bbbを書いていない。

$ time make >/dev/null

real    0m2.044s
user    0m0.033s
sys 0m0.010s
$ time make -j >/dev/null

real    0m1.031s
user    0m0.031s
sys 0m0.011s

２つのタスクが同時に動いているので時間は半分になっている。とはいえこのあたりになってくるともう色々頑張り過ぎなような気がする。