[20190401]那个更快的疑问.txt

--//前一阵子,做了11g于10g下,单表单条记录唯一索引扫描的测试,摘要如下:

--//参考链接:

http://blog.itpub.net/267265/viewspace-2636321/

http://blog.itpub.net/267265/viewspace-2636342/

1.环境:

--//当时的测试,在11g下测试结果如下:

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)

-------------------- ---------- ---------------------- -------------

result_cache                 50                   8611        430536

id=1_unique_index            50                   9494        474714

null                         50                  10664        533197

id=1_index                   50                  28160       1407987

notnull                      50                  29279       1463928

--//在10g下测试结果如下:

SCOTT@test> 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)

-------------------- ---------- ---------------------- -------------

id=1_unique_index            50                   4864        243192

notnull                      50                  34134       1706713

id=1_index                   50                  34703       1735173

null                         50                  37234       1861717

--//我的测试环境服务器硬件相同,os版本一样,对比可以发现id=1_unique_index的情况下,10g比11g快了1倍(指id=1_unique_index的情况).

--//而其他方式下11g都明显快于10g,而10g下除了id=1_unique_index下其他执行方式都可以看到大量cbc latch等待事件.

--//而11g仅仅在id=1_index,notnull下看到大量cbc latch等待时间,null方式下(全表扫描)的情况下反而看不到cbc 

--//latch等待事件.

--//我一直再想,我是不是测试方法存在什么问题,或者11g做了什么改进?重复测试唯一索引的情况看看:

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

create table t as select rownum id from dual ;

create unique index pk_t on t(id);

create table job_times (sid number, time_ela number,method varchar2(20));

--//分析表略.

$ cat m1.txt

set verify off

host sleep $(echo &&3/50 | bc -l )

insert into job_times values ( sys_context ('userenv', 'sid') ,dbms_utility.get_time ,'&&2') ;

commit ;

declare

v_id number;

v_d date;

begin

    for i in 1 .. &&1 loop

        select /*+ &&3 */ count (*) into v_id from t where id=1;

        --//select /*+ &&3 */ count (*) into v_id from t ;

        --//select /*+ &&3 */ 1 into v_id from dual ;

        --//select /*+ &&3 */ sysdate into v_d from 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

$ sqlplus -s -l scott/book @m1.txt 1e6 id=1_unique_index 0 >/dev/null

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)

-------------------- ---------- ---------------------- -------------

id=1_unique_index             1                   2615          2615

--//在10g环境下重复上面的步骤略.环境:

SCOTT@test> @ &r/ver1

PORT_STRING                    VERSION        BANNER

------------------------------ -------------- ----------------------------------------------------------------

x86_64/Linux 2.4.xx            10.2.0.4.0     Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bi

$ sqlplus -s -l scott/btbtms @m1.txt 1e6 id=1_unique_index 0 >/dev/null

SCOTT@test> 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)

-------------------- ---------- ---------------------- -------------

id=1_unique_index             1                   1535          1535

--//可以看出即使我单个用户执行相似的sql语句情况下,唯一索引查询10g下明显快于11g.

2.使用strace跟踪看看:

--//执行1e6次有点慢,改成1e5看看.

--//11g的测试:

$ strace -f -c sqlplus -s -l scott/book @m1.txt 1e5 id=1_unique_index 0 >/dev/null

...

% time     seconds  usecs/call     calls    errors syscall

------ ----------- ----------- --------- --------- ----------------

 72.78    0.043919           0    700708           getrusage

 19.80    0.011947           0    200179           times

  6.67    0.004024         671         6         3 wait4

  0.24    0.000147          29         5           clone

  0.18    0.000106           0       375         2 read

  0.16    0.000096           0       264       106 open

...

------ ----------- ----------- --------- --------- ----------------

100.00    0.060341                902967       206 total

--//10g的测试:

$ strace -f -c sqlplus -s -l scott/btbtms @m1.txt 1e5 id=1_unique_index 0 >/dev/null

% time     seconds  usecs/call     calls    errors syscall

------ ----------- ----------- --------- --------- ----------------

 72.00    0.056425           0    700486           getrusage

 24.98    0.019573        2796         7         2 wait4

  0.91    0.000714           3       236           read

  0.74    0.000582          97         6           clone

  0.73    0.000572         286         2           shmdt

  0.23    0.000177           1       302       189 open

  0.16    0.000122           1       145       108 stat

  0.05    0.000042           1        65           write

..

  0.03    0.000025           0       116           times

------ ----------- ----------- --------- --------- ----------------

100.00    0.097352                702291       347 total

--//差异在于10g很少做times的系统调用上.10g下仅仅116次.而11g高达200179.

--//如果再次执行跟踪如下,11g: 

$ strace -f  -p 57003

times({tms_utime=1948, tms_stime=328, tms_cutime=0, tms_cstime=0}) = 10865304314

times({tms_utime=1948, tms_stime=328, tms_cutime=0, tms_cstime=0}) = 10865304314

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

times({tms_utime=1948, tms_stime=328, tms_cutime=0, tms_cstime=0}) = 10865304314

times({tms_utime=1948, tms_stime=328, tms_cutime=0, tms_cstime=0}) = 10865304314

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={19, 483038}, ru_stime={3, 285500}, ...}) = 0

times({tms_utime=1948, tms_stime=328, tms_cutime=0, tms_cstime=0}) = 10865304314

times({tms_utime=1948, tms_stime=328, tms_cutime=0, tms_cstime=0}) = 10865304314

--//调用7次getrusage,调用2次times.

--//对比前面的调用比例也可以看出getrusage调用700708,times调用times200179.非常接近7:2

--//而10g下仅仅看到:

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

getrusage(RUSAGE_SELF, {ru_utime={13, 203992}, ru_stime={1, 700741}, ...}) = 0

--//正是这样的差异导致10g下明显快于11g.