bash で処理時間を 10 ミリ秒単位で計測する方法

bash スクリプト中の特定部分の処理時間（経過時間）を、１秒より細かい粒度で計測したいため、その方法を考えてみました。

まず、秒単位で良ければ、次の場所にあれこれと書いてある方法で良いかと思います。

http://www.atmarkit.co.jp/bbs/phpBB/viewtopic.php?topic=22451&forum=10

ただ、bash には組み込み変数 SECONDS (シェルが起動されてからの経過秒数) があるので、次のように書いたほうがオーバーヘッドが少ないはずです。

#!/bin/bash
#
# Name: elaps.bash
#

sleep 1

START=$SECONDS  #bash's builtin
echo START=$START

echo -e "\n### sleep 2"
sleep 2
echo

END=$SECONDS
let ELAPS=$END-$START
echo END=$END
echo ELAPS=START-END=$ELAPS

# ./elaps.bash 
START=1

### sleep 2

END=3
ELAPS=START-END=2

さて、わたしが取り組んでいる内容に対して、秒では粗すぎます。ミリ秒程度まで取得したいのですが、標準では bash から直接 gettimeofday() を呼ぶことができません。builtin を作れば不可能ではありませんが、ターゲットがそこまで自由に出来る環境ではないので、別の方法を考えました。

目をつけたのは、/proc/uptime です。このファイルから、システム起動からの経過時間を 10 ミリ秒の粒度で読み取ることができます。man proc 参照。

# cat /proc/uptime 
4542.13 4528.56
# uptime
 11:42am  up  1:15,  2 users,  load average: 0.13, 0.07, 0.02

bash の組み込みコマンド read を利用すれば、オーバーヘッド少なく 10 ミリ秒の粒度で経過時間を計測できるはずです。次が、テストスクリプトです。

#!/bin/bash
#
# Name: elaps_ms.bash
#

set_START() {
        local dummy
        read START dummy < /proc/uptime
}

get_ELAPS() {
        local dummy
        read END dummy < /proc/uptime
        let ELAPS=${END/./}0-${START/./}0
}

echo SECONDS=$SECONDS   #bash's builtin
time {
        set_START
}
echo START=$START

echo -e "\n### sleep (50 x 10 x 1000) [us]  using usleep"
time {
        usleep 500000
}

time {
        get_ELAPS
}
echo END=$END
echo ELAPS=START-END=$ELAPS
echo
echo SECONDS=$SECONDS   #bash's builtin

# ./elaps_ms.bash 
SECONDS=0

real    0m0.001s
user    0m0.000s
sys     0m0.000s
START=5579.40

### sleep (50 x 10 x 1000) [us]  using usleep

real    0m0.520s
user    0m0.000s
sys     0m0.010s

real    0m0.001s
user    0m0.000s
sys     0m0.000s
END=5579.92
ELAPS=START-END=520

SECONDS=0

このように、500 ミリ秒の usleep 実行の経過時間を 52 x 10 ミリ秒 = 520 ミリ秒と計測することができました。bash 組み込みの time コマンドの計測結果とも一致しています。一方、SECONDS による計測では、0 秒となってしまっています。

さてここで、少しだけ気になる点があります、bash で扱える整数の範囲です。上述のテストスクリプトでは、/proc/uptime から読み取った小数（小数点以下 2 桁）を、単位ミリ秒の整数に変換しています。１日をミリ秒で表すと 24 x 60 x 60 x 1000 = 86400000 となりますが、

# getconf INT_MAX
2147483647
# bc -l
bc 1.06
Copyright 1991-1994, 1997, 1998, 2000 Free Software Foundation, Inc.
This is free software with ABSOLUTELY NO WARRANTY.
For details type `warranty'. 
2147483647 / (24 * 60 * 60 * 1000)
24.85513480324074074074

なので、システム起動から 25 日経過した時に大丈夫かな？と不安になりませんか？
しかし、過去に調べたとおり、最近は 32bit 環境の bash でも、64bit 幅までの整数を扱えるので、大丈夫なはずです。次の記事を参照してください。

bash で扱える整数の上限

2011-11-06追記
試しに bash のビルトインを自作して、もっと細かい粒度で経過時間を測定してみました。

ビルトインを自作して、bash で処理時間をミリ秒単位で計測