[20190320]測試相同語句遇到導致cursor pin S的情況.txt--//前面測試鏈接:http://blog.itpub.net/267265/viewspace-2636342/--//各個會話執行語句相同的,很容易出現cursor: pin S等待事件.看看如果各個會話執行的語句不 ...
[20190320]測試相同語句遇到導致cursor pin S的情況.txt
--//前面測試鏈接:http://blog.itpub.net/267265/viewspace-2636342/
--//各個會話執行語句相同的,很容易出現cursor: pin S等待事件.看看如果各個會話執行的語句不同.
--//測試結果如何呢?
1.環境:
SCOTT@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
2.建立測試腳本:
create table job_times (sid number, time_ela number,method varchar2(20));
$ cat mutex.sql
set verify off
insert into job_times values ( sys_context ('userenv', 'sid') ,dbms_utility.get_time ,'&&2') ;
declare
v_id number;
v_d date;
begin
for i in 1 .. &&1 loop
select /*+ &&3 */ sysdate from into v_date dual;
--select sysdate from into v_date dual;
end loop;
end ;
/
update job_times set time_ela = dbms_utility.get_time - time_ela where sid=sys_context ('userenv', 'sid') and method='&&2';
commit;
quit
$ cat mutex1.sql
set verify off
insert into job_times values ( sys_context ('userenv', 'sid') ,dbms_utility.get_time ,'&&2') ;
declare
v_id number;
v_d date;
begin
for i in 1 .. &&1 loop
--select /*+ &&3 */ sysdate from into v_date dual;
select sysdate from into v_date dual;
end loop;
end ;
/
update job_times set time_ela = dbms_utility.get_time - time_ela where sid=sys_context ('userenv', 'sid') and method='&&2';
commit;
quit
--//通過加入註解&&3,產生每個會話執行語句不同,對比看看.
3.測試:
exec dbms_workload_repository.create_snapshot();
host seq 150 | xargs -I{} -P 150 bash -c "sqlplus -s -l scott/book @mutex.sql 1e6 test1 {} >/dev/null"
exec dbms_workload_repository.create_snapshot();
host seq 150 | xargs -I{} -P 150 bash -c "sqlplus -s -l scott/book @mutex1.sql 1e6 test2 {} >/dev/null"
exec dbms_workload_repository.create_snapshot();
--//測試1,執行時等待事件集中在latch: shared pool.
--//測試2,執行時等待事件集中在cursor: pin S.
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)
-------------------- ---------- ---------------------- -------------
test1 150 19897 2984502
test2 150 19380 2907006
--//奇怪的是,測試實際上測試1反而慢一點.從這個測試可以看出,如果如果應用真有大量語句出現cursor爭用,通過打散語句的執行,
--//可能未必能提高執行效率.
--//test1的awr報表:
Snap Id Snap Time Sessions Curs/Sess
--------- ------------------- -------- ---------
Begin Snap: 1681 20-Mar-19 09:53:01 27 1.2
End Snap: 1682 20-Mar-19 09:56:23 28 1.2
Elapsed: 3.37 (mins)
DB Time: 497.85 (mins)
...
Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Tota Wait % DB
Event Waits Time Avg(ms) time Wait Class
------------------------------ ------------ ---- ------- ------ ----------
latch: shared pool 233,755 18.6 79 62.2 Concurrenc
DB CPU 4751 15.9
library cache: mutex X 828 13.7 17 .0 Concurrenc
cursor: pin S wait on X 68 1.4 20 .0 Concurrenc
library cache load lock 94 1.1 12 .0 Concurrenc
log file sync 141 .5 4 .0 Commit
wait list latch free 50 .3 6 .0 Other
enq: SQ - contention 2 0 10 .0 Configurat
library cache lock 2 0 8 .0 Concurrenc
SQL*Net message to client 2,560 0 0 .0 Network
--//出現了latch: shared pool大量爭用.反而測試2使用mutex的效率更高.
--//test2的awr報表:
Snap Id Snap Time Sessions Curs/Sess
--------- ------------------- -------- ---------
Begin Snap: 1682 20-Mar-19 09:56:23 28 1.2
End Snap: 1683 20-Mar-19 09:59:40 28 1.2
Elapsed: 3.28 (mins)
DB Time: 484.76 (mins)
...
Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Tota Wait % DB
Event Waits Time Avg(ms) time Wait Class
------------------------------ ------------ ---- ------- ------ ----------
cursor: pin S 585,684 12.1 21 41.6 Concurrenc
DB CPU 4611 15.9
library cache: mutex X 525 8.6 16 .0 Concurrenc
latch: shared pool 117 1.5 13 .0 Concurrenc
latch free 45 1.3 28 .0 Other
log file sync 129 .5 4 .0 Commit
cursor: pin S wait on X 44 .4 9 .0 Concurrenc
library cache load lock 57 .3 6 .0 Concurrenc
row cache lock 18 .2 10 .0 Concurrenc
enq: SQ - contention 3 0 11 .0 Configurat
--//對比測試2的cursor: pin S使用12.1秒.而測試1的latch: shared pool使用18.6秒,差距並不大.
--//可以看出使用oracle使用mutex效率更高.
--//另外從一個側面說明,如果應用大量重覆語句執行出現cursor: pin S爭用,通過分散的方式也許更加並不是最佳的.
--//減少語句的執行次數才是比較正確的處理問題方式,或者找到為什麼執行次數這麼高的原因.
--//我又重覆測試1次.test1修改testa,test2修改testb.
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)
-------------------- ---------- ---------------------- -------------
test2 150 19380 2907006
testb 150 19648 2947223
testa 150 19884 2982666
test1 150 19897 2984502
--//結論依舊.
--//如果減少測試用戶連接數量呢?測試併發用戶50的情況:
$ cat aa3.txt
exec dbms_workload_repository.create_snapshot();
host seq 50 | xargs -I{} -P 50 bash -c "sqlplus -s -l scott/book @mutex.sql 1e6 test50a {} >/dev/null"
exec dbms_workload_repository.create_snapshot();
host seq 50 | xargs -I{} -P 50 bash -c "sqlplus -s -l scott/book @mutex1.sql 1e6 test50b {} >/dev/null"
exec dbms_workload_repository.create_snapshot();
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)
-------------------- ---------- ---------------------- -------------
test50b 50 6437 321825
test50a 50 6791 339554
test2 150 19380 2907006
testb 150 19648 2947223
testa 150 19884 2982666
test1 150 19897 2984502
6 rows selected.
--//你可以發現在併發用戶50的情況下,情況不變,結論依舊.改成併發用戶10的情況呢?
--//還可以發現現在同樣的工作量,50個併發的情況下,6X秒就可以完成.
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)
-------------------- ---------- ---------------------- -------------
testi10b 10 1872 18724
testi10a 10 2003 20028
test50b 50 6437 321825
test50a 50 6791 339554
test2 150 19380 2907006
testb 150 19648 2947223
testa 150 19884 2982666
test1 150 19897 2984502
8 rows selected.
--//有點奇怪為什麼測試1會出現大量的latch: shared pool.
--//這個測試有點像按下葫蘆起了瓢,也說明任何問題都給辯證的看.
總結:
--//在測試前我一直以為測試1會塊一些,實際情況正好相反.
--//不過為什麼這樣,我還不是很清楚....
