[20190320]測試相同語句遇到導致cursor pin S的情況.txt

--//前面測試連結:http://blog.itpub.net/267265/viewspace-2636342/

--//各個會話執行語句相同的,很容易出現cursor: pin S等待事件.看看如果各個會話執行的語句不同.

--//測試結果如何呢?

- -//後記:補充說明測試不嚴謹,請參考連結:http://blog.itpub.net/267265/viewspace-2639097/

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會塊一些,實際情況正好相反.

--//不過為什麼這樣,我還不是很清楚....

[20190320]測試相同語句遇到導致cursor pin S的情況.txt

相關文章