670
簡單幾招捕獲Oracle遞歸SQL調用源頭
作者介紹
蔣健，雲趣網絡科技聯合創始人，11g OCM，多年Oracle設計、管理及實施經驗，精通數據庫優化，Oracle CBO及並行原理，曾為多個行業的客戶的 Oracle 係統實施小型機到 X86跨平台遷移和數據庫優化服務。雲趣鷹眼監控核心設計和開發者，資深Python Web開發者。
一、概述
通常，DBA 確定通過 Oracle 的頂級活動會話圖確定 Top SQL，有了 SQL 的執行會話信息和 SQL 文本，可以和開發人員確定 Top SQL 來自哪些應用模塊的。有時候，Oracle DBA 需要自己確認 SQL 的來源，本文將演示如何使用 Oracle 提供豐富的跟蹤功能，來確認遞歸 SQL 的調用者來源。
二、問題描述
通過頂級會話頁麵，DBA 發現一個異常的 Top SQL，SQL ID 為c7452agj0s0t6，消耗了9%的數據庫時間。
通過 SQL 詳情頁麵，可以確定 SQL c7452agj0s0t6 的用戶名和模塊，但是沒有確定 SQL c7452agj0s0t6 是哪個客戶機器造成的。
從 SQL 的文本中，這是一個針對係統視圖 V$ACTIVE_SESSION_HISTORY 的查詢。
SELECT GROUP_TYPE, BUCKET_START, BUCKET_END, TM_GROUP_TYPE, TM_BUCKET_START,
TM_BUCKET_END, SUM(TM_CPU_FIRST_BUCKET_VALUE) TM_CPU_FIRST_BUCKET_VALUE,
SUM(TM_CPU_MIDDLE_BUCKETS_VALUE) TM_CPU_MIDDLE_BUCKETS_VALUE,
... 省略大量 SQL 文本
FROM TABLE(SYS.GV$(CURSOR(
... 省略大量 SQL 文本
SELECT ASH0.*
FROM V$ACTIVE_SESSION_HISTORY ASH0
... 省略大量 SQL 文本
通過 SQL 的活動會話信息，可以確定執行該 SQL 的進程為後台 PZ 進程，這些會話的 QC（query coordinator）不為空，也就是這是針對視圖 V$ACTIVE_SESSION_HISTORY 的並行查詢造成的。因為執行時間很短，並且執行此 SQL 的會話為短連接，無法查詢到 QC 會話的來源。
三、SQL ID 級別的跟蹤分析
為了確定 SQL c7452agj0s0t6 的來源，我們使用 Oracle 11g 中的新功能，對單個 SQL ID 打開10046事件跟蹤，命令如下：
alter system set events 'sql_trace [sql:c7452agj0s0t6] wait=true,bind=true,plan_stat=all_executions,level=12';
通過以下查詢確定 trace 文件的產生目錄：
select value from v$diag_info where name='Default Trace File';
對最新生成的 PRDDB_oraxxx.trc 執行 grep c7452agj0s0t6，找到跟蹤文件如下，可以確定該的客戶端為 testapp。通過 dep=2，知道 SQL c7452agj0s0t6 為深度二級的遞歸 SQL，並不是用戶直接提交的 SQL。我們依然不知道這個遞歸 SQL 具體由什麼 SQL 調用的。
*** 2016-10-14 09:34:13.921
*** SESSION ID:(329.41269) 2016-10-14 09:34:13.921
*** CLIENT ID:() 2016-10-14 09:34:13.921
*** SERVICE NAME:(PRDDB) 2016-10-14 09:34:13.921
*** MODULE NAME:(python@testapp (TNS V1-V3)) 2016-10-14 09:34:13.921
*** ACTION NAME:() 2016-10-14 09:34:13.921
... 省略大量文本
=====================
PARSING IN CURSOR #139987897061528 len=11079 dep=2 uid=87 oct=3 lid=87 tim=1476408854404253 hv=3792438054 ad='21b01ba960' sqlid='c7452agj0s0t6'
關閉 SQL ID 跟蹤的命令如下：
alter system set events 'sql_trace [sql:c7452agj0s0t6] off';
四、會話級別的跟蹤分析
為了確認什麼 SQL 調用了 c7452agj0s0t6，我們需要在會話級別打開10046跟蹤，因為執行 SQL c7452agj0s0t6 的會話是短連接，我們創建一個針對用戶 APPUSER 的 logon 觸發器，下次這個用戶登錄時會啟動10046跟蹤。
create or replace trigger sys.set_trace
after logon on database
when (user in ('APPUSER')）
declare
begin
execute immediate 'alter session set statistics_level=all';
execute immediate 'alter session set max_dump_file_size=unlimited';
execute immediate 'alter session set events ''10046 trace name context forever, level 12''';
end set_trace;
/
接著，在跟蹤文件目錄中找到最新生成的跟蹤文件 PRDDB1_ora_10452.trc 包含 SQL ID c7452agj0s0t6。接著我們使用 orasrp 這個工具分析10046跟蹤文件. orasrp 為 Oracle Session Resource Profiler，出自一位俄羅斯 DBA 的強大的10046分析工具，網址為：https://oracledba.ru/orasrp/
orasrp PRDDB1_ora_10452.trc PRDDB1_ora_10452.html
orasrp相對於 Oracle 自帶的 tkprof，功能更加強大，其中一大優勢是會生成會話的遞歸調用樹。遞歸調用樹(Session Call Graph)部分如下圖，SQL hash value=3792438054 為 SQL c7452agj0s0t6，深度為2，頂級的 SQL hash value = 2036392974。
頂級 SQL 文本如下，原來 SQL c7452agj0s0t6 是由 dbms_sqltune.report_sql_monitor 這個生成 SQL Monitor 報告的函數遞歸調用的。確定是前幾天新部署的監控 job，在後台定時抓取和保存新生成的 SQL monitor 報告，但是執行過於頻繁。解決的方法為降低後台 job 的執行頻率，對每次抓取 SQL monitor 的執行時間提高限製。
select dbms_sqltune.report_sql_monitor(type=>:1, sql_id=>:2, sql_exec_id=>:3, report_level=>'ALL') monitor_report from dual;
確定問題來源之後，刪除 logon 觸發器，避免過多的跟蹤文件產生：
drop trigger sys.set_trace;
五、總結
本文演示了如果在 Oracle 中分別使用 SQL ID 和會話級別的10046跟蹤，以確定遞歸 SQL 的調用源頭來自 PL/SQL 函數 dbms_sqltune.report_sql_monitor。現實工作中，使用類似的方法，可以對 PL/SQL 代碼性能，Oracle 解析時間過長等疑難雜症進行分析。對於 DBA 來說，使用 orasrp 對10046跟蹤文件生成的遞歸調用樹，也是研究應用負載特征的一個好手段。
原文發布時間為：2016-11-28
本文來自雲棲社區合作夥伴DBAplus
最後更新：2017-05-11 12:02:08