Temp落ち #1 - "Temp落ち" って？ Tweet
ぐるぐる系に並び、一部で人気？w のある俗称、
この、”Temp落ち”とはなんなのでしょうか？（ご存知の方も多いと思いますが）
こんなイメージです。
ざっくり、言ってしまうと、
Hash JoinやSort処理などを”メモリー上”で行おうとします。その際、利用可能なメモリー不足が発生すると一時表領域（HDDやSSDなど）を作業域としてして処理を行います。
この一時表領域も利用しながらHash JoinやSort処理などを行う動きが、"Temp落ち" の正体です。
なぜ可能な限りメモリー上で完結させようとするのか？
たとえば、HDDを利用したソートとメモリー内のみで同量のソート行ったらどちらが早く終わると思いますか？
ということを考えれば、理由はわかりますよね。
ただ、最近はメモリーも安くなり、大容量のメモリーのサーバーもあり、ぜーんぶオンメモリーでできるじゃん？
と思わなくも無いのですが、
無限にメモリーを利用できるわけでもないく（仕様などにもよる）、データ量の爆発とともに、"Temp落ち”と戦わなければならない場面も多くなってきているような気はします。
また、"Temp落ち"の辛さが認識されていない場合は、大人の事情も絡まって予想以上にめんどくさい状況になることもしばしば。。。
そういえば、某性能問題専門チームへ本格的に参画しはじめたころの最初の戦いが、
”性能試験でTemp落ちして試験にならないというプロジェクトをなんとかする”というやつでしたw （もう７年ぐらい前ですがw）
その時期に調べていた内容をまとめていたのがエントリーが以下のシリーズでした。
pga_aggregate_targetでPGA?、_pga_max_sizeでPGA? Season2 #8
https://discus-hamburg.cocolog-nifty.com/mac_de_oracle/2010/09/pga_aggregate-7.html
以下、津島博士のパフォーマンス講座も読んでおくとよいと思います。：）
参考）
津島博士のパフォーマンス講座 - 第36回 遅くなるSQLについて
http://www.oracle.com/technetwork/jp/database/articles/tsushima/tsushima-hakushi-36-2184118-ja.html
津島博士のパフォーマンス講座 - 第45回 Temp領域について
http://www.oracle.com/technetwork/jp/database/articles/tsushima/tsushima-hakushi-45-2491038-ja.html
ちなみに、AWRレポートやstatpackレポートなど、一時表領域が利用された"Temp落ち"の有無を確認する方法はいろいろあるのですが、代表的なものをいくつか載せておきますね。
ここで紹介する機能で利用したdatabase versionは以下の通り
BANNER CON_ID
-------------------------------------------------------------------------------- ----------
Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production 0
PL/SQL Release 12.2.0.1.0 - Production 0
CORE 12.2.0.1.0 Production 0
TNS for Linux: Version 12.2.0.1.0 - Production 0
NLSRTL Version 12.2.0.1.0 - Production 0
12cR2のAWRレポートのTop 10 Foreground Eventsセクションより
インスタンス全体の状態を確認できます。
上位の待機イベントから、一時表領域が多く利用されていたことを知ることができます。
direct path write temp / direct path read tempという待機イベントが上位にきています。この2つの待機イベントは一時表領域への書き込みと読み込みを示す待機イベントです。
一時表領域に書き込まれたデータは、”どのようなタイプのデータ”であるか、この情報からでは判断できませんが、一時表領域を利用する操作が全体の6割近くを占めていることは確認できます。
Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Total Wait Avg % DB Wait
Event Waits Time (sec) Wait time Class
------------------------------ ----------- ---------- --------- ------ --------
direct path write temp 8,688 36.9 4.24ms 50.3 User I/O
DB CPU 26 35.4
direct path read temp 8,403 6.2 738.19us 8.5 User I/O
direct path read 400 4.1 10.36ms 5.6 User I/O
db file sequential read 1,082 1.8 1.66ms 2.4 User I/O
control file sequential read 456 1.3 2.80ms 1.7 System I
SQL*Net message to client 66,674 .2 2.30us .2 Network
PGA memory operation 4,944 .1 25.30us .2 Other
log file sync 8 .1 10.55ms .1 Commit
db file scattered read 33 .1 1.69ms .1 User I/O
おなじく、12cR2のAWRレポートのPGA Aggr Target Histogramセクションより
インスタンス全体の状態を確認できます。1-Pass/M-Passの部分で一時表領域の利用した操作があったことが確認できます。
GB単位の1-Pass操作（一時表領域を利用した操作）があったことが確認できます。
PGA Aggr Target Histogram DB/Inst: ORCL12C/orcl12c Snaps: 214-216
-> Optimal Executions are purely in-memory operations
Low High
Optimal Optimal Total Execs Optimal Execs 1-Pass Execs M-Pass Execs
------- ------- -------------- -------------- ------------ ------------
2K 4K 879 879 0 0
64K 128K 12 12 0 0
128K 256K 14 14 0 0
256K 512K 8 8 0 0
512K 1024K 60 60 0 0
1M 2M 40 40 0 0
2M 4M 1 1 0 0
32M 64M 1 1 0 0
1G 2G 1 0 1 0
------------------------------------------------------
おなくじ、12cR2のAWRレポートのTop SQL with Top Row Sourcesより
以下の例では、SQLID=g95385r59bm47というSQL文の実行時間の内、50%以上がHash join操作でのdirect path write temp待機イベント（一時表領域への書き込み）であることがレポートされています。
このSQL文のHash Joinでメモリー内では処理しきれないほどの結合操作が行われたことがわかります。
Top SQL with Top Row Sources DB/Inst: ORCL12C/orcl12c Snaps: 214-216
-> Top SQL statements by DB Time along with the top row sources by DB Time
for those SQLs.
-> % Activity is the percentage of DB Time due to the SQL.
-> % Row Source is the percentage of DB Time spent on the row source by
that SQL.
-> % Event is the percentage of DB Time spent on the event by the
SQL executing the row source.
-> Executions is the number of executions of the SQL that were sampled in ASH.
SQL ID Plan Hash Executions % Activity
----------------------- -------------------- -------------------- --------------
% Row
Row Source Source Top Event % Event
---------------------------------------- ------- ----------------------- -------
Container Name
-------------------------------------------
g95385r59bm47 1822065247 1 100.00
HASH JOIN 66.67 direct path write temp 50.00
SELECT /*+ MONITOR LEADING(m1 m2) USE_HASH(m1 m2)
*/ * FROM m1 INNER JOIN m2 ON m1.id = m2.id AN
D m1.rev# = m2.rev#
AWRレポート以外では、
v$tempseg_usageを問い合わせることで一時表領域の利用状況をセッション、SQL毎に確認することもできます。
この例では、ブロックサイズは、8KBとしているので、Hash一時セグメントで、3GB程の一時表領域が利用されたことがわかります。
orcl12c@SYS> select con_id,session_num,username,sql_id,segtype,contents,blocks from v$Tempseg_usage order by session_num;
CON_ID SESSION_NUM USERNAME SQL_ID SEGTYPE CONTENTS BLOCKS
---------- ----------- ------------------------------ ------------- --------- --------- ----------
3 26123 SCOTT g95385r59bm47 HASH TEMPORARY 427520
SQLモニターのMem(Max)/Temp(Max)列でHash joinやSort処理で利用された最大メモリーサイズと最大一時表領域のサイズを確認することができます。
この例ではId=1のHash JoinでTemp(Max) = 3GB より、一時表領域がHash Join操作の作業領域として3GB利用されたことを確認できます。
また、Activity Details列で、direct path write temp / direct path read temp待機イベントの割合も高いため一時表領域へのI/O量をどうするかが性能改善へのポイントであることも確認できます。
SQL Plan Monitoring Details (Plan Hash Value=1822065247)
=======================================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read | Write | Write | Mem | Temp | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | Reqs | Bytes | (Max) | (Max) | (%) | (# samples) |
=======================================================================================================================================================================================
| 0 | SELECT STATEMENT | | | | 86 | +2 | 1 | 1M | | | | | . | . | 9.52 | Cpu (6) |
| 1 | HASH JOIN | | 1M | 382K | 86 | +2 | 1 | 1M | 13302 | 3GB | 13302 | 3GB | 1GB | 3GB | 76.19 | Cpu (10) |
| | | | | | | | | | | | | | | | | direct path read temp (4) |
| | | | | | | | | | | | | | | | | direct path write temp (34) |
| 2 | TABLE ACCESS FULL | M1 | 1M | 90575 | 45 | +2 | 1 | 1M | 2619 | 3GB | | | . | . | 6.35 | Cpu (3) |
| | | | | | | | | | | | | | | | | direct path read (1) |
| 3 | TABLE ACCESS FULL | M2 | 1M | 90574 | 24 | +46 | 1 | 1M | 2619 | 3GB | | | . | . | 7.94 | Cpu (1) |
| | | | | | | | | | | | | | | | | direct path read (4) |
=======================================================================================================================================================================================
最後に、SQLモニターはTuning pack と Diagnostic packの両方が必要なのですが、追加パックなしで利用できる機能として、DBMS_XPLAN.DISPLAY_CURSORでActual Planを取得して確認する方法もあります。
DBMS_XPLAN.DISPLAY_CURSOR(format=>'ALL ALLSTATS LAST')でActual Planで確認することもできます。
Used-Mem/Used-Tmpから利用されたメモリーサイズと一時表領域のサイズが確認できます。
ただ、User_Tmpのサイズ単位は、KじゃなくてMなんじゃないか？（バグ？ 誰か調べてw）
前述したv$tempseg_usageとSQLモニターで実行したSQL文なのですが....ほかにも単位が変なところがあるみたい。。。まあいいか。（いいわけ無い！w）
Plan hash value: 1822065247
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes|E-Temp | Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | Reads | Writes | OMem | 1Mem | Used-Mem | Used-Tmp|
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | | 382K(100)| | 1000K|00:00:56.65 | 727K| 1079K| 412K| | | | |
|* 1 | HASH JOIN | | 1 | 1000K| 4038M| 2126M| 382K (1)| 00:00:15 | 1000K|00:00:56.65 | 727K| 1079K| 412K| 2047M| 28M| 1049M (1)| 3340K|
| 2 | TABLE ACCESS FULL| M1 | 1 | 1000K| 2115M| | 90575 (1)| 00:00:04 | 1000K|00:00:06.79 | 374K| 333K| 0 | | | | |
| 3 | TABLE ACCESS FULL| M2 | 1 | 1000K| 1923M| | 90574 (1)| 00:00:04 | 1000K|00:00:01.68 | 352K| 333K| 0 | | | | |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQLモニター関連と、Actual Planを取得するサンプルスクリプト（私がよく利用してるやっつけスクリプト）
どちらを利用するかは、必要としている情報次第なのですが、利用できる環境であれば（主にライセンス）、SQLモニターとActual Planを併用することが多いです。（経験上）
SQLモニターは5秒以上の処理時間やパラレル処理を自動的にモニターできるので、利用可能な環境であれば、本番環境で今まさに終わらないSQLとなっているようなSQL文を分析するには便利です。
SQLIDは判明していても、終わらないSQL文の場合は、DBMS_XPLAN.DISPLAY_CORSORでActual Planを取得することは難しい(Actual Planの場合、SQLが正常終了しないと実行統計が取得できない）
ツール毎に、取得できる内容に多少違いがあるので、複数のツールを組み合わせて使うことが多い（ここ重要）
なお、SQLモニターは、対象とするSQL文に MONITORヒント付加することで強制的にモニタリングすることを前提にしてあります。
（自動的にSQLモニターの対象となる条件は、5秒以上実行されているか、パラレル実行されている場合のみ）
MONITORヒント付加を前提としており、パラメータを空で渡した場合は、直前に実行されたSQLモニター対象のSQLのモニター結果をテキスト形式でレポートします。(sql_idをパラメータとして渡した場合には対象のSQL文がSQLモニターの対象となっている必要があります）
SQLモニタースクリプト
[oracle@localhost ˜]$ cat show_realmon.sql
set linesize 1000
set long 1000000
set longchunksize 1000000
select dbms_sqltune.report_sql_monitor(sql_id=>'&1', type=>'text') from dual;
SQLモニタースクリプトの実行例
ORCL@SCOTT> select /*+ monitor */ * from dual;
D
-
X
Elapsed: 00:00:00.00
ORCL@SCOTT> @show_realmon ''
old 1: select dbms_sqltune.report_sql_monitor(sql_id=>'&1', type=>'text') from dual
new 1: select dbms_sqltune.report_sql_monitor(sql_id=>'', type=¥>'text') from dual
DBMS_SQLTUNE.REPORT_SQL_MONITOR(SQL_ID=>'',TYPE=>'TEXT')
------------------------------------------------------------------------------------------------------------------------
SQL Monitoring Report
SQL Text
------------------------------
select /*+ monitor */ * from dual
Global Information
------------------------------
Status : DONE (ALL ROWS)
Instance ID : 1
Session : SCOTT (123:34510)
SQL ID : 2w4nk70tv7w1d
SQL Execution ID : 16777216
・・・中略・・・
Fetch Calls : 1
Global Stats
=======================================
| Elapsed | Other | Fetch | Buffer |
| Time(s) | Waits(s) | Calls | Gets |
=======================================
| 0.00 | 0.00 | 1 | 3 |
=======================================
SQL Plan Monitoring Details (Plan Hash Value=272002086)
=========================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | (%) | (# samples) |
=========================================================================================================================
| 0 | SELECT STATEMENT | | | | 1 | +0 | 1 | 1 | | |
| 1 | TABLE ACCESS FULL | DUAL | 1 | 2 | 1 | +0 | 1 | 1 | | |
=========================================================================================================================
Actual Plan取得スクリプト
ORCL@SCOTT> !cat show_actualplan.sql
set linesize 1000
set long 1000000
set longchunksize 1000000
select * from table(dbms_xplan.display_cursor(format=>'ALL ALLSTATS LAST'));
Actual Plan取得スクリプトの実行例
ORCL@SCOTT> alter session set statistics_level=all;
Session altered.
Elapsed: 00:00:00.01
ORCL@SCOTT> select * from dual;
D
-
X
Elapsed: 00:00:00.01
ORCL@SCOTT> @show_actualplan
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------------------------------
SQL_ID a5ks9fhw2v9s1, child number 0
-------------------------------------
select * from dual
Plan hash value: 272002086
--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 2 (100)| | 1 |00:00:00.01 | 3 |
| 1 | TABLE ACCESS FULL| DUAL | 1 | 1 | 2 | 2 (0)| 00:00:01 | 1 |00:00:00.01 | 3 |
--------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / DUAL@SEL$1
Column Projection Information (identified by operation id):
-----------------------------------------------------------
1 - "DUAL"."DUMMY"[VARCHAR2,1]
23 rows selected.
では、つづく。（どういうながれにするかまだ、考えてないけど、ブログ書かないとw）
| 固定リンク | 0
コメント