SQL TRACE TKProfレポート
19519 ワード
SQL TRACE TKProfレポート
2013/08/25 BY
MACLEAN LIU
1つのコメント
「MacleanがOracle 10046 SQL TRACEの読み取りを教えてくれます」では、10046 TRACEの読み取りとフィールドの意味について説明し、10046 sql traceのパートナーツールTKPROFについて説明します.
TKPROFは実行可能ファイルであり、追加のインストールを必要とせずにOracleServerソフトウェアに付属しています.このツールファイルは、ORACLEのSQL TRACE(10046)を解析して、より読み取り可能なコンテンツを生成するために使用することができる.実際にtkprofは10046 SQL traceの内容をまとめたもので、例えば1つの文で出会ったwait event、PARSE、Execute、Fetchの3段階での消費時間、CPU_TIMEなど.
tkprofは10046 SQL TRACEの要約であるため、tkprofの情報は完全に10046から得ることができ、10046の問題は巨細が失われているためTRACEの内容が多すぎる可能性があり、内容が多ければ迅速に分析することが難しく、TKPROFは10046 traceを解析した後、最適者の閲覧に適している.
TKPROFの構文は次のとおりです.
tkprof tracefile outfile [explain=user/password] [options...]
いくつかのオプション
print=integerは、前のSQL文のみをリストします.integerは、print=10などの指定された数のSQL文をリストします.
Sys=no SYSユーザーで実行される文はリストされません
sort=optionソートオプション、オプションリストは次のとおりです.
prscnt number of times parse was called
prscpu cpu time parsing
prsela elapsed time parsing
prsdsk number of disk reads during parse
prsqry number of buffers for consistent read during parse
prscu number of buffers for current read during parse
prsmis number of misses in library cache during parse
execnt number of execute was called
execpu cpu time spent executing
exeela elapsed time executing
exedsk number of disk reads during execute
exeqry number of buffers for consistent read during execute
execu number of buffers for current read during execute
exerow number of rows processed during execute
exemis number of library cache misses during execute
fchcnt number of times fetch was called
fchcpu cpu time spent fetching
fchela elapsed time fetching
fchdsk number of disk reads during fetch
fchqry number of buffers for consistent read during fetch
fchcu number of buffers for current read during fetch
fchrow number of rows fetched
userid userid of user that parsed the cursor
次に、最も簡単なTKPROFの例を見てみましょう.
上記の例では、TKPROFが1つのSQL Statementの実行をいくつかの部分に分割していることを示します.
1.SQL文のparse、execute、fetchフェーズの所要時間:
call:各カーソルの動作は3つのステップに分けられます.
Parse:カーソルを解析し、実行計画の統計を生成するExecute:このカーソルフェーズを実行する統計Fetch:Fetch取得データ行段階の統計情報
countとは、parse count:2、すなわち、カーソルが2回を解析するカーソルに関する操作の回数を指す.
CPU:関連欄で消費するCPU時間、単位はs Elapsed:関連欄で消費される時間、単位はs disk:関連欄で消費される物理読みQuery:関連欄で消費されるコンシステンシ論理読みconsistent logical read=>SELECTクエリではqueryのみcurrent はありません
current:関連欄現在の論理読みcurrent logical read rowsこのステップで取り戻す行数==本例ではcount(*)であるため1行しかない.
Misses in library cache during parse:1解析段階でlibrary cacheにmissが発生した場合、今回の解析は硬解析であることを示します.
疑問点:
1、PL/SQLの場合、匿名ブロック/ストレージプロセスとその中に含まれるSQL文は同時にTKPROFに現れ、つまり重複がある.SQLは再帰的なSQLとして表示されます.
PARSING IN CURSOR #4 len=56 dep=1 uid=0 oct=6 lid=0 tim=1345130672819745 hv=3509762282 ad=’a7525f30′ UPDATE FULLSCAN SET OWNER=’MACLEAN’ WHERE OBJECT_ID=:B1
COMMITもそうです.
PARSING IN CURSOR #2 len=6 dep=1 uid=0 oct=44 lid=0 tim=1345130672822889 hv=255718823 ad=’0′ COMMIT
実際の例を見てみましょう
以上、匿名ブロックループにより10000回実行された「update fullscan set owner='MACLEAN'where object_id=i;およびcommitの合計実行Elapsed:00:00:04.00.
この匿名ブロックの総消費時間は0.68 s、10000サイクルupdate fullscanは2.69 s、10000回commitの総消費時間は0.52 s、0.68+0.52+2.69=3.89 sであり、また少量の再帰SQLの消費時間もこの4.0 sに計算される.
2、以上の例では、PL/SQL匿名ブロック、update、commitにはfetchフェーズではなくexecuteフェーズがあり、fetchの回数は0である.SELECT文にはexecuteフェーズがあるが,executeフェーズのdisk,query,currentは一般にゼロであり,すべてFetchフェーズとする.
3、実際に10046において上記匿名ブロックが実際に反映された実行時間は3907489であるμs=3.9 sおよびその合計cr=20037 cu=28928(updateの19364+commitの9564)であるが、TKPROFでは匿名ブロックなどPL/SQLオブジェクトに表示される情報が全面的ではなく、ユーザの誤解を避けるためである可能性がある.
TKPROFでは、さまざまなソート方法が用意されています
Sort options: default
******************************************************************************** count = number of times OCI procedure was executed cpu = cpu time in seconds executing elapsed = elapsed time in seconds executing disk = number of physical reads of buffers from disk query = number of buffers gotten for consistent read current = number of buffers gotten in current mode (usually for update) rows = number of rows processed by the fetch or execute call
一般に,クエリのチューニングによく用いられる組合せはSYS=NO fchelaであり,fchelaはfetch段階のelapsed timeに従って大きくから小さく配列される.
上記のようにSort options:fchelaの後、trace中の情報はfetch elapsed timeに従って長さから短さに並べられます.
計画の実行
TKPROFの実行計画は現実的なcard、costなどのCBO指標ではなく、提供される各ステップのRows、CR、PR情報は、実行計画がどのステップより遅いかを診断するのに役立つが、そのtimeの時間消費情報は正確ではない.
イベントの待機
TKPROFでは、この待機イベント(Times Waited)が何回発生したか、最大待機時間がどのくらいMax.Waitなのか、合計待機時間Total Waited、単位がSであることを含む文関連の待機イベントを簡単に説明しています.
10046での待ち時間の記述はあまりにも簡単で、読者に待ち問題を簡単に把握させるためだけに、待ち時間のチューニングに対してAWRでのwait histogramとASHに基づいて分析することを強く提案し、彼らと比較してTKPROFは明らかに時代遅れである.
サンプルの解析
(a)この文の総消費時間21.45 s を説明する.
(b)この文の解析にかかる時間20.12 s を説明する.
(c)文の解析にかかるCPU時間が20.02 s であることを示す.
文解析待ち時間=文解析時間–文解析CPU時間=20.12–20.02=0.10 s
以上の分析では、この文の実行にかかる時間のほとんどが解析に費やされていることを示していますが、解析にかかる時間の多くはCPU演算であり、一般的には多くのCPU演算を引き起こす可能性があります.
文が複雑すぎて、parse解析とoptimize最適化に多くのCPU を消費する.
ホストCPUは忙しくて、プロセスは十分なCPUタイムスライスを割り当てられない.
resource manager制限実装CPU に遭遇する可能性がある
実情に即して,具体的な分析が必要である.
2013/08/25 BY
MACLEAN LIU
1つのコメント
「MacleanがOracle 10046 SQL TRACEの読み取りを教えてくれます」では、10046 TRACEの読み取りとフィールドの意味について説明し、10046 sql traceのパートナーツールTKPROFについて説明します.
TKPROFは実行可能ファイルであり、追加のインストールを必要とせずにOracleServerソフトウェアに付属しています.このツールファイルは、ORACLEのSQL TRACE(10046)を解析して、より読み取り可能なコンテンツを生成するために使用することができる.実際にtkprofは10046 SQL traceの内容をまとめたもので、例えば1つの文で出会ったwait event、PARSE、Execute、Fetchの3段階での消費時間、CPU_TIMEなど.
tkprofは10046 SQL TRACEの要約であるため、tkprofの情報は完全に10046から得ることができ、10046の問題は巨細が失われているためTRACEの内容が多すぎる可能性があり、内容が多ければ迅速に分析することが難しく、TKPROFは10046 traceを解析した後、最適者の閲覧に適している.
TKPROFの構文は次のとおりです.
tkprof tracefile outfile [explain=user/password] [options...]
いくつかのオプション
print=integerは、前のSQL文のみをリストします.integerは、print=10などの指定された数のSQL文をリストします.
Sys=no SYSユーザーで実行される文はリストされません
sort=optionソートオプション、オプションリストは次のとおりです.
prscnt number of times parse was called
prscpu cpu time parsing
prsela elapsed time parsing
prsdsk number of disk reads during parse
prsqry number of buffers for consistent read during parse
prscu number of buffers for current read during parse
prsmis number of misses in library cache during parse
execnt number of execute was called
execpu cpu time spent executing
exeela elapsed time executing
exedsk number of disk reads during execute
exeqry number of buffers for consistent read during execute
execu number of buffers for current read during execute
exerow number of rows processed during execute
exemis number of library cache misses during execute
fchcnt number of times fetch was called
fchcpu cpu time spent fetching
fchela elapsed time fetching
fchdsk number of disk reads during fetch
fchqry number of buffers for consistent read during fetch
fchcu number of buffers for current read during fetch
fchrow number of rows fetched
userid userid of user that parsed the cursor
次に、最も簡単なTKPROFの例を見てみましょう.
drop table fullscan;
create table fullscan as select * from dba_objects;
exec dbms_stats.gather_table_stats(user,'FULLSCAN');
alter system flush shared_pool;
alter system flush buffer_cache;
alter session set events '10046 trace name context forever,level 12';
select count(*) from fullscan;
oradebug setmypid
oradebug tracefile_name;
/s01/admin/G10R25/udump/g10r25_ora_30334.trc
[oracle@vrh8 udump]$ tkprof /s01/admin/G10R25/udump/g10r25_ora_30334.trc 30334.tkf
TKPROF: Release 10.2.0.5.0 - Production on Sun Aug 25 02:21:27 2013 askmaclean.com
Copyright (c) 1982, 2007, Oracle. All rights reserved.
vi 30334.tkf
Trace file: /s01/admin/G10R25/udump/g10r25_ora_30334.trc
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
select obj#,type#,ctime,mtime,stime,status,dataobj#,flags,oid$, spare1,
spare2
from
obj$ where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null
and linkname is null and subname is null
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 2 4 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 2 4 0 1
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=4 pr=2 pw=0 time=133 us)
1 INDEX RANGE SCAN I_OBJ2 (cr=3 pr=1 pw=0 time=74 us)(object id 37)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.01 0.01
db file sequential read 2 0.00 0.00
********************************************************************************
select count(*)
from
fullscan
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 4 15 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.01 0.01 1139 1143 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.02 0.02 1143 1158 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=1143 pr=1139 pw=0 time=15759 us)
77268 TABLE ACCESS FULL FULLSCAN (cr=1143 pr=1139 pw=0 time=463719 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
db file sequential read 1 0.00 0.00
db file scattered read 80 0.00 0.00
SQL*Net message from client 2 0.00 0.00上記の例では、TKPROFが1つのSQL Statementの実行をいくつかの部分に分割していることを示します.
1.SQL文のparse、execute、fetchフェーズの所要時間:
select count(*)
from
fullscan
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 4 15 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.01 0.01 1139 1143 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.02 0.02 1143 1158 0 1call:各カーソルの動作は3つのステップに分けられます.
Parse:カーソルを解析し、実行計画の統計を生成するExecute:このカーソルフェーズを実行する統計Fetch:Fetch取得データ行段階の統計情報
countとは、parse count:2、すなわち、カーソルが2回を解析するカーソルに関する操作の回数を指す.
CPU:関連欄で消費するCPU時間、単位はs Elapsed:関連欄で消費される時間、単位はs disk:関連欄で消費される物理読みQuery:関連欄で消費されるコンシステンシ論理読みconsistent logical read=>SELECTクエリではqueryのみcurrent はありません
current:関連欄現在の論理読みcurrent logical read rowsこのステップで取り戻す行数==本例ではcount(*)であるため1行しかない.
Misses in library cache during parse:1解析段階でlibrary cacheにmissが発生した場合、今回の解析は硬解析であることを示します.
疑問点:
1、PL/SQLの場合、匿名ブロック/ストレージプロセスとその中に含まれるSQL文は同時にTKPROFに現れ、つまり重複がある.SQLは再帰的なSQLとして表示されます.
PARSING IN CURSOR #4 len=56 dep=1 uid=0 oct=6 lid=0 tim=1345130672819745 hv=3509762282 ad=’a7525f30′ UPDATE FULLSCAN SET OWNER=’MACLEAN’ WHERE OBJECT_ID=:B1
COMMITもそうです.
PARSING IN CURSOR #2 len=6 dep=1 uid=0 oct=44 lid=0 tim=1345130672822889 hv=255718823 ad=’0′ COMMIT
実際の例を見てみましょう
alter system flush shared_pool;
alter system flush buffer_cache;
set timing on;
alter session set events '10046 trace name context forever,level 12';
create index ind_objd on fullscan(object_id);
begin
for i in 1..10000 loop
update fullscan set owner='MACLEAN' where object_id=i;
commit;
end loop;
end;
/
PL/SQL procedure successfully completed.
Elapsed: 00:00:04.00
begin
for i in 1..10000 loop
update fullscan set owner='MACLEAN' where object_id=i;
commit;
end loop;
end;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.62 0.68 178 20037 0 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.62 0.68 178 20037 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
log file sync 1 0.00 0.00
SQL*Net message to client 1 0.00 0.00
********************************************************************************
UPDATE FULLSCAN SET OWNER='MACLEAN'
WHERE
OBJECT_ID=:B1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 10000 2.90 2.69 178 20037 19364 9564
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10001 2.90 2.69 178 20037 19364 9564
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS (recursive depth: 1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 177 0.00 0.00
COMMIT
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 10000 0.43 0.52 0 0 9564 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10001 0.43 0.52 0 0 9564 0
Misses in library cache during parse: 0
Parsing user id: SYS (recursive depth: 1)以上、匿名ブロックループにより10000回実行された「update fullscan set owner='MACLEAN'where object_id=i;およびcommitの合計実行Elapsed:00:00:04.00.
この匿名ブロックの総消費時間は0.68 s、10000サイクルupdate fullscanは2.69 s、10000回commitの総消費時間は0.52 s、0.68+0.52+2.69=3.89 sであり、また少量の再帰SQLの消費時間もこの4.0 sに計算される.
2、以上の例では、PL/SQL匿名ブロック、update、commitにはfetchフェーズではなくexecuteフェーズがあり、fetchの回数は0である.SELECT文にはexecuteフェーズがあるが,executeフェーズのdisk,query,currentは一般にゼロであり,すべてFetchフェーズとする.
begin
for i in 1..10000 loop
update fullscan set owner='MACLEAN' where object_id=i;
commit;
end loop;
end;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.62 0.68 178 20037 0 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.62 0.68 178 20037 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
log file sync 1 0.00 0.00
SQL*Net message to client 1 0.00 0.00
PARSING IN CURSOR #5 len=106 dep=0 uid=0 oct=47 lid=0 tim=1345130672819492 hv=3631473533 ad='a750b960'
begin
for i in 1..10000 loop
update fullscan set owner='MACLEAN' where object_id=i;
commit;
end loop;
end;
END OF STMT
PARSE #5:c=1000,e=891,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=1345130672819487
BINDS #5:
EXEC #5:c=3968396,e=3907489,p=178,cr=20037,cu=28928,mis=0,r=1,dep=0,og=1,tim=1345130676727033
WAIT #5: nam='log file sync' ela= 162 buffer#=8084 sync scn=14950441 p3=0 obj#=96606 tim=1345130676727293
WAIT #5: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=96606 tim=1345130676727343
*** 2013-08-25 03:00:52.748
WAIT #5: nam='SQL*Net message from client' ela= 234159641 driver id=1650815232 #bytes=1 p3=0 obj#=96606 tim=13451309108870163、実際に10046において上記匿名ブロックが実際に反映された実行時間は3907489であるμs=3.9 sおよびその合計cr=20037 cu=28928(updateの19364+commitの9564)であるが、TKPROFでは匿名ブロックなどPL/SQLオブジェクトに表示される情報が全面的ではなく、ユーザの誤解を避けるためである可能性がある.
TKPROFでは、さまざまなソート方法が用意されています
Sort options: default
******************************************************************************** count = number of times OCI procedure was executed cpu = cpu time in seconds executing elapsed = elapsed time in seconds executing disk = number of physical reads of buffers from disk query = number of buffers gotten for consistent read current = number of buffers gotten in current mode (usually for update) rows = number of rows processed by the fetch or execute call
一般に,クエリのチューニングによく用いられる組合せはSYS=NO fchelaであり,fchelaはfetch段階のelapsed timeに従って大きくから小さく配列される.
[oracle@vrh8 udump]$ tkprof g10r25_ora_30731.trc 30731.tkf sys=no sort=fchela
TKPROF: Release 10.2.0.5.0 - Production on Sun Aug 25 03:39:46 2013
Copyright (c) 1982, 2007, Oracle. All rights reserved.
Sort options: fchela
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
select count(*)
from
fullscan
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.01 0.01 1140 1144 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.01 0.01 1140 1144 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 64
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=1144 pr=1140 pw=0 time=14476 us)
77270 TABLE ACCESS FULL FULLSCAN (cr=1144 pr=1140 pw=0 time=386457 us)上記のようにSort options:fchelaの後、trace中の情報はfetch elapsed timeに従って長さから短さに並べられます.
計画の実行
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=1144 pr=1140 pw=0 time=14476 us)
77270 TABLE ACCESS FULL FULLSCAN (cr=1144 pr=1140 pw=0 time=386457 us)TKPROFの実行計画は現実的なcard、costなどのCBO指標ではなく、提供される各ステップのRows、CR、PR情報は、実行計画がどのステップより遅いかを診断するのに役立つが、そのtimeの時間消費情報は正確ではない.
イベントの待機
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
db file sequential read 1 0.00 0.00
db file scattered read 81 0.00 0.00
SQL*Net message from client 2 0.00 0.00TKPROFでは、この待機イベント(Times Waited)が何回発生したか、最大待機時間がどのくらいMax.Waitなのか、合計待機時間Total Waited、単位がSであることを含む文関連の待機イベントを簡単に説明しています.
10046での待ち時間の記述はあまりにも簡単で、読者に待ち問題を簡単に把握させるためだけに、待ち時間のチューニングに対してAWRでのwait histogramとASHに基づいて分析することを強く提案し、彼らと比較してTKPROFは明らかに時代遅れである.
サンプルの解析
select count(1) from big1
where object_id between 10 and 100000
and data_object_id between 1 and 1000
and status like 'VALI%'
and object_type IN ('TABLE', 'INDEX')
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 20.02 (c) 20.12 (b) 0 1 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 1.13 1.33 0 9087 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 21.15 21.45 (a) 0 9088 0 1
Misses in library cache during parse: 1 <==
Optimizer mode: ALL_ROWS
Parsing user id: 54(a)この文の総消費時間21.45 s を説明する.
(b)この文の解析にかかる時間20.12 s を説明する.
(c)文の解析にかかるCPU時間が20.02 s であることを示す.
文解析待ち時間=文解析時間–文解析CPU時間=20.12–20.02=0.10 s
以上の分析では、この文の実行にかかる時間のほとんどが解析に費やされていることを示していますが、解析にかかる時間の多くはCPU演算であり、一般的には多くのCPU演算を引き起こす可能性があります.
文が複雑すぎて、parse解析とoptimize最適化に多くのCPU を消費する.
ホストCPUは忙しくて、プロセスは十分なCPUタイムスライスを割り当てられない.
resource manager制限実装CPU に遭遇する可能性がある
実情に即して,具体的な分析が必要である.