[20200217]使用snapper探究DBMS_SHARED_POOL.MARKHOT標識熱物件的等待事件.txt
[20200217]使用snapper探究DBMS_SHARED_POOL.MARKHOT標識熱物件的等待事件.txt
--//snapper.sql是Tanel Poder探究會話相關等待事件的指令碼，參考連結：
--//上個星期使用我寫的wait.sql不是很好，僅僅看一個點,無法完整的分析。
--//反正現在上班沒什麼事情，重複上個星期的測試，探究DBMS_SHARED_POOL.MARKHOT標識熱物件的等待事件。
1.環境:
SYS@book> @ ver1
PORT_STRING VERSION BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx 11.2.0.4.0 Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
SYS@book> @ hide _kgl_hot_object_copies
NAME DESCRIPTION DEFAULT_VALUE SESSION_VALUE SYSTEM_VALUE ISSES ISSYS_MOD
---------------------- ----------------------------------- ------------- ------------- ------------ ----- ---------
_kgl_hot_object_copies Number of copies for the hot object TRUE 0 0 FALSE FALSE
$ alias zzdate
alias zzdate='date +'\''trunc(sysdate)+%H/24+%M/1440+%S/86400 == %Y/%m/%d %T'\'''
--//rename job_times to job_times_20200217;
create table job_times (sid number, sessionid number,time_ela number,method varchar2(20));
--//建立指令碼bb.txt:
$ cat bb.txt
SELECT owner
,name
,hash_value
,full_hash_value
,namespace
,child_latch
,property hot_flag
,executions
,invalidations
FROM v$db_object_cache
WHERE name = 'DBMS_APPLICATION_INFO' AND owner = 'SYS'
order by executions desc ;
--//建立測試指令碼m3.txt
set verify off
--//host sleep $(echo &&3/50 | bc -l )
insert into job_times values ( sys_context ('userenv', 'sid') ,sys_context ('userenv', 'sessionid'),dbms_utility.get_time ,'&&2') ;
commit ;
declare
v_id number;
v_d date;
begin
for i in 1 .. &&1 loop
execute immediate 'begin dbms_application_info.set_client_info(''mutex'');end;';
end loop;
end ;
/
update job_times set time_ela = dbms_utility.get_time - time_ela where sid=sys_context ('userenv', 'sid') and sessionid=sys_context ('userenv', 'sessionid') and method='&&2';
commit;
quit
2.測試1：
--//不使用DBMS_SHARED_POOL.MARKHOT的情況
$ sqlplus / as sysdba
SYS@book> @ tpt/snapper all 436 1 "select 1,sid from v$session where username='SCOTT' and program like 'sqlplus%'"
$ zzdate;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book @m3.txt 1e6 p=50 {} >/dev/null;zzdate
trunc(sysdate)+10/24+31/1440+30/86400 == 2020/02/17 10:31:30
trunc(sysdate)+10/24+38/1440+30/86400 == 2020/02/17 10:38:30
SYS@book> @ tpt/snapper all 436 1 "select 1,sid from gv$session where username='SCOTT' and program like 'sqlplus%'"
Sampling SID select 1,sid from gv$session where username='SCOTT' and program like 'sqlplus%' with interval 436 seconds, taking 1 snapshots...
-- Session Snapper v4.11 BETA - by Tanel Poder ( http://blog.tanelpoder.com ) - Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! :)
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SID, USERNAME , TYPE, STATISTIC , DELTA, HDELTA/SEC, %TIME, GRAPH , NUM_WAITS, WAITS/SEC, AVERAGES
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
--//這麼沒有資訊，取樣太長，還是別的原因，或者會話太多不允許...
----------------------------------------------------------------------------------------------------
Active% | INST | SQL_ID | SQL_CHILD | EVENT | WAIT_CLASS
----------------------------------------------------------------------------------------------------
2086% | 1 | 11c4s0a35j48v | 0 | library cache: mutex X | Concurrency
1196% | 1 | | | library cache: mutex X | Concurrency
932% | 1 | 11c4s0a35j48v | 0 | ON CPU | ON CPU
310% | 1 | 93sbqnyzaas4t | 0 | ON CPU | ON CPU
211% | 1 | | | ON CPU | ON CPU
23% | 1 | | | cursor: pin S | Concurrency
19% | 1 | 93sbqnyzaas4t | 0 | cursor: pin S | Concurrency
5% | 1 | 11c4s0a35j48v | 0 | cursor: pin S | Concurrency
3% | 1 | 11c4s0a35j48v | | ON CPU | ON CPU
1% | 1 | 3s8yd6xsr6fu6 | 0 | library cache: mutex X | Concurrency
-- End of ASH snap 1, end=2020-02-17 10:38:45, seconds=436, samples_taken=428
PL/SQL procedure successfully completed.
SYS@book> set verify off
SYS@book> @ tpt/ash/ash_wait_chains username||':'||program2||event2 username='SCOTT' trunc(sysdate)+10/24+31/1440+30/86400 trunc(sysdate)+10/24+38/1440+30/86400
-- Display ASH Wait Chain Signatures script v0.2 BETA by Tanel Poder ( http://blog.tanelpoder.com )
%This SECONDS AAS WAIT_CHAIN
------ ---------- ---------- --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
40% 8368 19.9 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) ON CPU
30% 6323 15.1 -> SCOTT:(sqlplus) ON CPU
19% 3883 9.2 -> SCOTT:(sqlplus) library cache: mutex X
5% 1041 2.5 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) ON CPU
4% 924 2.2 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X
1% 150 .4 -> SCOTT:(sqlplus) cursor: pin S
0% 56 .1 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) ON CPU
0% 38 .1 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X
0% 25 .1 -> SCOTT:(sqlplus) cursor: pin S -> SCOTT:(sqlplus) ON CPU
0% 12 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) cursor: pin S -> SCOTT:(sqlplus) ON CPU
0% 11 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) cursor: pin S
0% 8 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) ON CPU
0% 7 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X
0% 3 0 -> SCOTT:(sqlplus) latch free -> SCOTT:(sqlplus) ON CPU
0% 2 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X
0% 1 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library
cache: mutex X -> SCOTT:(sqlplus) ON CPU
16 rows selected.
--//主要是library cache: mutex X等待事件，並且形成一個鏈條。
3.測試2:
--//使用DBMS_SHARED_POOL.MARKHOT的情況,首先使用dbms_shared_pool.markhot設定，注意必須sys使用者執行：
SYS@book> @ bb.txt
OWNER NAME HASH_VALUE FULL_HASH_VALUE NAMESPACE CHILD_LATCH HOT_FLAG EXECUTIONS INVALIDATIONS
------ ---------------------------------------- ---------- -------------------------------- ---------------- ----------- ------------ ---------- -------------
SYS DBMS_APPLICATION_INFO 539807965 eab253aef59cd250bd8b8a13202cd0dd BODY 53469 52816131 0
SYS DBMS_APPLICATION_INFO 2876716960 5a81de0b29b19e757e67708dab7737a0 TABLE/PROCEDURE 79776 0 0
SYS@book> exec dbms_shared_pool.markhot('SYS','DBMS_APPLICATION_INFO',1);
PL/SQL procedure successfully completed.
SYS@book> exec dbms_shared_pool.markhot('SYS','DBMS_APPLICATION_INFO',2);
PL/SQL procedure successfully completed.
SYS@book> @ tpt/snapper ash 120 1 "select inst_id,sid from gv$session where username='SCOTT' and program like 'sqlplus%' and inst_id=1"
$ zzdate;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book @m3.txt 1e6 markhot_p=50 {} >/dev/null;zzdate
trunc(sysdate)+10/24+55/1440+18/86400 == 2020/02/17 10:55:18
trunc(sysdate)+10/24+57/1440+16/86400 == 2020/02/17 10:57:16
SYS@book> @ tpt/snapper ash 120 1 "select inst_id,sid from gv$session where username='SCOTT' and program like 'sqlplus%' and inst_id=1"
Sampling SID select inst_id,sid from gv$session where username='SCOTT' and program like 'sqlplus%' and inst_id=1 with interval 120 seconds, taking 1 snapshots...
-- Session Snapper v4.11 BETA - by Tanel Poder ( http://blog.tanelpoder.com ) - Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! :)
----------------------------------------------------------------------------------------------------
Active% | INST | SQL_ID | SQL_CHILD | EVENT | WAIT_CLASS
----------------------------------------------------------------------------------------------------
2311% | 1 | 11c4s0a35j48v | 0 | ON CPU | ON CPU
909% | 1 | 93sbqnyzaas4t | 0 | ON CPU | ON CPU
412% | 1 | 11c4s0a35j48v | 0 | library cache: mutex X | Concurrency
397% | 1 | | | ON CPU | ON CPU
246% | 1 | | | library cache: mutex X | Concurrency
214% | 1 | | | cursor: pin S | Concurrency
150% | 1 | 93sbqnyzaas4t | 0 | cursor: pin S | Concurrency
86% | 1 | 11c4s0a35j48v | 0 | cursor: pin S | Concurrency
26% | 1 | 11c4s0a35j48v | 0 | latch free | Other
8% | 1 | 11c4s0a35j48v | | ON CPU | ON CPU
-- End of ASH snap 1, end=2020-02-17 10:57:18, seconds=120, samples_taken=119
PL/SQL procedure successfully completed.
SYS@book> @ tpt/ash/ash_wait_chains username||':'||program2||event2 username='SCOTT' trunc(sysdate)+10/24+55/1440+18/86400 trunc(sysdate)+10/24+57/1440+16/86400
-- Display ASH Wait Chain Signatures script v0.2 BETA by Tanel Poder ( http://blog.tanelpoder.com )
%This SECONDS AAS WAIT_CHAIN
------ ---------- ---------- ------------------------------------------------------------------------------------
78% 4430 37.5 -> SCOTT:(sqlplus) ON CPU
7% 401 3.4 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) ON CPU
7% 398 3.4 -> SCOTT:(sqlplus) library cache: mutex X
6% 333 2.8 -> SCOTT:(sqlplus) cursor: pin S
2% 117 1 -> SCOTT:(sqlplus) cursor: pin S -> SCOTT:(sqlplus) ON CPU
0% 24 .2 -> SCOTT:(sqlplus) latch free -> SCOTT:(sqlplus) ON CPU
0% 9 .1 -> SCOTT:(sqlplus) latch free
0% 1 0 -> SCOTT:(sqlplus) cursor: pin S -> SCOTT:(sqlplus) cursor: pin S
0% 1 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X
9 rows selected.
4.對比:
SCOTT@book> Select method,count(*),round(avg(TIME_ELA),0),sum(TIME_ELA) from job_times group by method order by 3 ;
METHOD COUNT(*) ROUND(AVG(TIME_ELA),0) SUM(TIME_ELA)
-------------------- ---------- ---------------------- -------------
markhot_p=50 50 11445 572258
p=50 50 41783 2089136
--//明顯標識熱物件後，library cache: mutex X 等待事件大大減少,快了大約4倍.
--//標識熱物件後，依舊存在library cache: mutex X等待事件，但是因為分散開來，形成一個鏈條明顯變小。
--//另外看等待事件cursor: pin S，標識熱物件後佔 333 秒，並且SCOTT:(sqlplus) cursor: pin S -> SCOTT:(sqlplus) ON CPU佔117秒。
--//而沒有標識前佔 150 秒，這是因為減少library cache: mutex X了等待,大量重複的sql語句
--//begin dbms_application_info.set_client_info(''mutex'');end; 而導致在cursor: pin S上時間增加。
--//如果修改
begin dbms_application_info.set_client_info(''mutex'');end;
為
begin /*+ &&3 */ dbms_application_info.set_client_info(''mutex'');end;
--//這樣cursor: pin S會相應減少。
4.測試3:
--//修改測試指令碼m3.txt，加入註解看看。
set verify off
--//host sleep $(echo &&3/50 | bc -l )
insert into job_times values ( sys_context ('userenv', 'sid') ,sys_context ('userenv', 'sessionid'),dbms_utility.get_time ,'&&2') ;
commit ;
declare
v_id number;
v_d date;
begin
for i in 1 .. &&1 loop
execute immediate 'begin /*+ &&3 */ dbms_application_info.set_client_info(''mutex'');end;';
end loop;
end ;
/
update job_times set time_ela = dbms_utility.get_time - time_ela where sid=sys_context ('userenv', 'sid') and sessionid=sys_context ('userenv', 'sessionid') and method='&&2';
commit;
quit
--//使用DBMS_SHARED_POOL.MARKHOT的情況：
SYS@book> @ tpt/snapper ash 120 1 "select inst_id,sid from gv$session where username='SCOTT' and program like 'sqlplus%' and inst_id=1"
$ zzdate;seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book @m3.txt 1e6 markhotx_p=50 {} >/dev/null;zzdate
trunc(sysdate)+11/24+14/1440+52/86400 == 2020/02/17 11:14:52
trunc(sysdate)+11/24+16/1440+49/86400 == 2020/02/17 11:16:49
SYS@book> @ tpt/snapper ash 120 1 "select inst_id,sid from gv$session where username='SCOTT' and program like 'sqlplus%' and inst_id=1"
Sampling SID select inst_id,sid from gv$session where username='SCOTT' and program like 'sqlplus%' and inst_id=1 with interval 120 seconds, taking 1 snapshots...
-- Session Snapper v4.11 BETA - by Tanel Poder ( http://blog.tanelpoder.com ) - Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! :)
----------------------------------------------------------------------------------------------------
Active% | INST | SQL_ID | SQL_CHILD | EVENT | WAIT_CLASS
----------------------------------------------------------------------------------------------------
2335% | 1 | 11c4s0a35j48v | 0 | ON CPU | ON CPU
895% | 1 | 93sbqnyzaas4t | 0 | ON CPU | ON CPU
451% | 1 | | | ON CPU | ON CPU
376% | 1 | 11c4s0a35j48v | 0 | library cache: mutex X | Concurrency
227% | 1 | | | library cache: mutex X | Concurrency
214% | 1 | | | cursor: pin S | Concurrency
166% | 1 | 93sbqnyzaas4t | 0 | cursor: pin S | Concurrency
65% | 1 | 11c4s0a35j48v | 0 | cursor: pin S | Concurrency
13% | 1 | 11c4s0a35j48v | 0 | latch free | Other
6% | 1 | 11c4s0a35j48v | | ON CPU | ON CPU
-- End of ASH snap 1, end=2020-02-17 11:16:51, seconds=120, samples_taken=119
PL/SQL procedure successfully completed.
SYS@book> @ tpt/ash/ash_wait_chains username||':'||program2||event2 username='SCOTT' trunc(sysdate)+11/24+14/1440+52/86400 trunc(sysdate)+11/24+16/1440+49/86400
-- Display ASH Wait Chain Signatures script v0.2 BETA by Tanel Poder ( http://blog.tanelpoder.com )
%This SECONDS AAS WAIT_CHAIN
------ ---------- ---------- -------------------------------------------------------------------------------------------------------------------
78% 4473 38.2 -> SCOTT:(sqlplus) ON CPU
7% 407 3.5 -> SCOTT:(sqlplus) library cache: mutex X
6% 338 2.9 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) ON CPU
5% 262 2.2 -> SCOTT:(sqlplus) cursor: pin S
3% 171 1.5 -> SCOTT:(sqlplus) cursor: pin S -> SCOTT:(sqlplus) ON CPU
0% 28 .2 -> SCOTT:(sqlplus) latch free -> SCOTT:(sqlplus) ON CPU
0% 14 .1 -> SCOTT:(sqlplus) latch free
0% 2 0 -> SCOTT:(sqlplus) cursor: pin S -> SCOTT:(sqlplus) library cache: mutex X
0% 2 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X
0% 1 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) ON CPU
0% 1 0 -> SCOTT:(sqlplus) cursor: pin S -> SCOTT:(sqlplus) cursor: pin S
0% 1 0 -> SCOTT:(sqlplus) library cache: mutex X -> SCOTT:(sqlplus) cursor: pin S
12 rows selected.
SCOTT@book> Select method,count(*),round(avg(TIME_ELA),0),sum(TIME_ELA) from job_times group by method order by 3 ;
METHOD COUNT(*) ROUND(AVG(TIME_ELA),0) SUM(TIME_ELA)
-------------------- ---------- ---------------------- -------------
markhotx_p=50 50 11398 569916
markhot_p=50 50 11445 572258
p=50 50 41783 2089136
--//僅僅快一點點，不明顯。
--//cursor: pin S 佔 262，明顯較少。
來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/267265/viewspace-2675910/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- [20200212]使用DBMS_SHARED_POOL.MARKHOT標識熱物件.txt物件
- [20200213]使用DBMS_SHARED_POOL.MARKHOT標識熱物件2.txt物件
- [20191125]探究等待事件的本源.txt事件
- [20191127]探究等待事件的本源4.txt事件
- [20191126]探究等待事件的本源2.txt事件
- [20211031]18c row cache mutext等待事件探究.txtMutex事件
- [20160205]大量子游標引起的等待事件.txt事件
- [20150520]使用gdb檢視等待事件.txt事件
- 【等待事件】ORACLE常見等待事件事件Oracle
- 【等待事件】等待事件系列（5.1）--Enqueue(佇列等待)事件ENQ佇列
- Oracle的等待事件Oracle事件
- 等待事件事件
- [20210207]使用gdb檢視等待事件11g.txt事件
- [20191203]大量resmgrcpu quantum等待事件.txt事件
- [20130409]Data file init write等待事件.txt事件
- [20200213]使用DBMS_SHARED_POOL.MARKHOT的總結.txt
- Solidity事件，等待事件Solid事件
- 網路上的等待事件事件
- RAC中的等待事件事件
- ORACLE中的等待事件Oracle事件
- 【TUNE_ORACLE】等待事件之等待事件類別Oracle事件
- 【等待事件之二】log 相關的等待事件
- [20140506]使用ethtool標識網路卡.txt
- 等待事件分析事件
- oracle等待事件Oracle事件
- Oracle 等待事件Oracle事件
- px等待事件事件
- 等待事件 二事件
- [20220518]enq FU - contention等待事件.txtENQ事件
- [20161228]奇怪log file sync等待事件.txt事件
- [20130904]等待事件wait for a undo record.txt事件AI
- 【等待事件】等待事件系列（1）--User I/O型別事件型別
- 【效能調整】等待事件(三) 常見等待事件（一）事件
- 【效能調整】等待事件(四) 常見等待事件（二）事件
- javascript如何獲取事件目標物件JavaScript事件物件
- Oracle等待事件的種類Oracle事件
- 兩個重要的等待事件！事件
- 常見的oraclet等待事件Oracle事件