timeで複数のコマンドの実行時間を測る

bash のビルドインコマンドならブレースでグループ化できます。

#!/bin/bash

time -p {
  sleep 1
  sleep 2
}

output

real 3.00
user 0.00
sys 0.00

GNU time だとこんな書き方はできません。

#!/bin/bash

/usr/bin/time -p {
  sleep 1
  sleep 2
}

output

/usr/bin/time: cannot run {: No such file or directory
real 0.00
user 0.00
sys 0.00
a.sh: line 6: syntax error near unexpected token `}'
a.sh: line 6: `}'

GNU time でも bash -c でコマンドを記述すれば大丈夫です。

#!/bin/bash

/usr/bin/time -p /bin/bash -c 'sleep 1; sleep 2'

output

real 3.00
user 0.00
sys 0.00

これを応用して各コマンドの実行時間とトータルの実行時間を表示してみます。

#!/bin/bash

time -p {
  echo "sleep 1"
  time -p sleep 1
  echo

  echo "sleep 2"
  time -p sleep 2
  echo

  echo "total"
}

output

sleep 1
real 1.00
user 0.00
sys 0.00

sleep 2
real 2.00
user 0.00
sys 0.00

total
real 3.00
user 0.00
sys 0.00

さらに syslog に記録してみます。

#!/bin/bash

{
  time -p {
    echo "sleep 1"
    time -p sleep 1
    echo

    echo "sleep 2"
    time -p sleep 2
    echo

    echo "total"
  }
} 2>&1 | logger -i -s -t oreore -p user.info

output

oreore[3636]: sleep 1
oreore[3636]: real 1.00
oreore[3636]: user 0.00
oreore[3636]: sys 0.00
oreore[3636]:
oreore[3636]: sleep 2
oreore[3636]: real 2.00
oreore[3636]: user 0.00
oreore[3636]: sys 0.00
oreore[3636]:
oreore[3636]: total
oreore[3636]: real 3.00
oreore[3636]: user 0.00
oreore[3636]: sys 0.00

/var/log/messages

May 15 19:19:01 areserver oreore[3636]: sleep 1
May 15 19:19:02 areserver oreore[3636]: real 1.00
May 15 19:19:02 areserver oreore[3636]: user 0.00
May 15 19:19:02 areserver oreore[3636]: sys 0.00
May 15 19:19:02 areserver oreore[3636]:
May 15 19:19:02 areserver oreore[3636]: sleep 2
May 15 19:19:04 areserver oreore[3636]: real 2.00
May 15 19:19:04 areserver oreore[3636]: user 0.00
May 15 19:19:04 areserver oreore[3636]: sys 0.00
May 15 19:19:04 areserver oreore[3636]:
May 15 19:19:04 areserver oreore[3636]: total
May 15 19:19:04 areserver oreore[3636]: real 3.00
May 15 19:19:04 areserver oreore[3636]: user 0.00
May 15 19:19:04 areserver oreore[3636]: sys 0.00