ORACLEのCPU使用時間

ORACLEではシステム統計やセッション統計、SQL統計等から様々な単位でのCPU使用時間を確認することができますが、 通常プログラムがどの程度CPUを消費したのかはソース等から予測したり計算することはできません。 ではどのようにORACLEがCPU使用時間を取得しているかというと、システムコール(Linuxではgetrusageを利用しているようです)を利用してプロセスのCPU使用時間を取得し、 statspackのように特定のタイミングでの差分からSQLやセッション単位のCPU使用時間を求めているようです。

Linuxでの検証

Linuxではstraceコマンドによりシステムコールをトレースすることができますのでシステムコールの戻り値と実際にORACLEが表示するCPU使用時間とシステムコールの結果を比較してみます。 なお、aixやsolarisではtruss、HP-UXではtuscといったコマンドでシステムコールをトレースすることができます

・straceを仕掛けてsqlを実行する
以下のようにローカル接続のsqlplusに対してstraceを仕掛けます。 実際にCPU使用時間を取得しているのはsqlplusではなくsqlplusからforkしてできたサーバプロセスなのでfork等をしたプロセスも追跡できるように-f -Fオプションを付与しています。 Listener経由の接続の場合専用サーバプロセスがforkされるのはsqlplus等のクライアントからではなくリスナーからforkされるのでListener経由での接続をトレースする場合は-pオプションによりプロセス指定をしてトレースします。
strace -f -F -tt -o ./strace.log -e getrusage sqlplus test/test
続いて、CPUを使用するため以下のコマンドを何回か実行します。
select count(*) from dba_source;

・ORACLEのCPU使用時間を確認する
以下のコマンドによりセッション統計のCPU使用時間を確認してみます。 CPU used by this sessionが該当セッションが使用したCPU時間で単位はセンチ秒であるため以下の例では10.53秒のCPUを使用したことがわかります。
select name,value from v$sesstat a,v$statname b 
where sid=(select sid from v$session where username ='TEST') and upper(name) like '%CPU%';

NAME                              VALUE
---------------------------- ----------
recursive cpu usage                  54
CPU used when call started         1053
CPU used by this session           1053
parse time cpu                        1

・straceの結果確認
straceで出力したstrace.logを確認するとSQL実行回数が数十回程度だったのに対してgetrusageは数千回コールされている様子が確認できます。 恐らく、パースのCPU時間、SQLの使用時間、SQLの実行が終わった段階のCPU使用時間等、様々な単位でCPU時間を記録しているものと予想されます。 最終的には以下のような出力となっており、ユーザCPU使用時間が10.375422秒、システムCPU時間が0.180972秒使用されていることが確認でき、 ユーザ時間とシステム時間の合計がORACLEの表示である10.53秒と非常に近い値となっていることが確認できます。
3850  22:47:51.147588 getrusage(RUSAGE_SELF, {ru_utime={10, 375422}, ru_stime={0, 180972}, ...}) = 0

CPU使用時間に対する考察

・CPU使用時間自体は正しい値ですが、その他の時間関連の統計と同じように考えるとつじつまが合わなくなる可能性が考えられます。 例えば、一般的にはクエリ等はI/O時間とCPU使用時間の合計がほぼ処理時間のように考えられる場合がありますが、 データファイルへのI/OがOSのファイルキャッシュ上で処理されたような場合、ORACLE的にはOS側にI/Oを要求しているだけなのでこの処理時間はI/O時間として計上されると思われますが、 実際にはI/Oは発生せずファイルキャッシュ上のメモリからデータを読み込むとシステムCPU使用時間が増えると思われるためCPU使用時間+I/O時間が処理時間を超えるケースが発生しそうな気がします。(未確認)

・CPU使用時間はCPU使用率ではありません。CPU使用時間が10秒であることは10秒間1CPUを100%占有していたということではなく、 I/O時間等が発生すればその間CPUは未使用の状態になるためCPU使用率50%で20秒間かかっている可能性もあります。

・複数CPUコアを搭載しているサーバではCPU使用時間は1秒間に1秒以上増加する場合があります。 パラレルや並列でSQLを流すと1秒間にCPU時間は1秒以上増加する場合があります。

マニュアル

パフォーマンス・チューニング・ガイド10gリリース2(10.2)
★ORACLE案件承ります