[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会块一些,实际情况正好相反.
–//不过为什么这样,我还不是很清楚….