[20241121]测试软软解析遇到的疑惑.txt

[20241121]测试软软解析遇到的疑惑.txt

--//测试软软解析遇到的疑惑,就是大量软软解析以及分散执行两者的执行时间差别并不是很大,有点疑惑,展开分析看看。

1.环境:
SCOTT@book01p> @ver2
==============================
PORT_STRING                   : x86_64/Linux 2.4.xx
VERSION                       : 21.0.0.0.0
BANNER                        : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
BANNER_FULL                   : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
Version 21.3.0.0.0
BANNER_LEGACY                 : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
CON_ID                        : 0
PL/SQL procedure successfully completed.

2.建立测试环境:
create table job_times (sid number, time_ela number,method varchar2(20));

drop table t purge ;
create table t as select rownum id ,'test' pad from dual connect by level<=5e5;
create unique index pk_t on t(id);
exec dbms_stats.gather_table_stats(user, 't', method_opt=>'for all columns size 1');

$ cat m9.txt
set verify off
insert into job_times values ( sys_context ('userenv', 'sid') ,dbms_utility.get_time ,'&&2') ;
commit ;
DECLARE
   l_count PLS_INTEGER;
BEGIN
    FOR i IN 1..&&1
    LOOP
       EXECUTE IMMEDIATE 'Select /*+ &2 */ count(*) from t where id = :j ' INTO l_count USING i;
    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.测试:
$ zzdate;seq 20 | xargs -P 20 -IQ sqlplus -s -l scott/book@book01p @m9.txt 5e5 test > /dev/null;zzdate
trunc(sysdate)+10/24+11/1440+58/86400
trunc(sysdate)+10/24+12/1440+49/86400
--//等待测试完成。需要1*60+49-58 = 51秒。

SYS@book> @ ashtop event,p1raw,p1 1=1 trunc(sysdate)+10/24+11/1440+58/86400 trunc(sysdate)+10/24+12/1440+49/86400
    Total                                                                                                                                   Distinct Distinct    Distinct
  Seconds     AAS %This   EVENT                                      P1RAW                     P1 FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ----------------- ---------- ------------------- ------------------- ---------- -------- -----------
      751    14.7   78% |                                                               752002402 2024-11-21 10:12:01 2024-11-21 10:12:48        397       48         443
      191     3.7   20% | cursor: pin S                              000000002CD2A562   752002402 2024-11-21 10:12:01 2024-11-21 10:12:47          1       34          34
        9      .2    1% |                                                              1413697536 2024-11-21 10:11:59 2024-11-21 10:12:00          8        2           8
        2      .0    0% | log file parallel write                    0000000000000001           1 2024-11-21 10:12:00 2024-11-21 10:12:48          1        2           2
        1      .0    0% | log file sync                              000000000000065B        1627 2024-11-21 10:11:59 2024-11-21 10:11:59          1        1           1
        1      .0    0% | log file sync                              000000000000067D        1661 2024-11-21 10:12:00 2024-11-21 10:12:00          1        1           1
        1      .0    0% | log file sync                              00000000000006A6        1702 2024-11-21 10:12:48 2024-11-21 10:12:48          1        1           1
        1      .0    0% |                                                                     100 2024-11-21 10:12:23 2024-11-21 10:12:23          1        1           1
        1      .0    0% |                                                                     300 2024-11-21 10:12:25 2024-11-21 10:12:25          1        1           1
        1      .0    0% |                                                                   65536 2024-11-21 10:12:00 2024-11-21 10:12:00          1        1           1
        1      .0    0% |                                                              2020423704 2024-11-21 10:12:48 2024-11-21 10:12:48          1        1           1
11 rows selected.

$ zzdate;seq 20 | xargs -P 20 -IQ sqlplus -s -l scott/book@book01p @m9.txt 5e5 Q > /dev/null;zzdate
trunc(sysdate)+10/24+14/1440+24/86400
trunc(sysdate)+10/24+15/1440+15/86400
--//参数2不同导致每个执行sql语句的都不相同,这样相当于分散开来。
--//等待测试完成。需要1*60+15-24 = 51秒。

SYS@book> @ ashtop event,p1raw,p1 1=1 trunc(sysdate)+10/24+14/1440+24/86400 trunc(sysdate)+10/24+15/1440+15/86400
    Total                                                                                                                                   Distinct Distinct    Distinct
  Seconds     AAS %This   EVENT                                      P1RAW                     P1 FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ----------------- ---------- ------------------- ------------------- ---------- -------- -----------
      900    17.6   94% |                                                                   65536 2024-11-21 10:14:26 2024-11-21 10:15:14        446       49         493
       48      .9    5% |                                                              1614620816 2024-11-21 10:14:27 2024-11-21 10:15:14         26       48          42
        6      .1    1% |                                                              2020423704 2024-11-21 10:15:13 2024-11-21 10:15:14          6        2           6
        2      .0    0% |                                                                       8 2024-11-21 10:14:26 2024-11-21 10:14:27          2        2           2
        2      .0    0% |                                                                     100 2024-11-21 10:14:24 2024-11-21 10:14:25          1        2           2
        1      .0    0% |                                                                  131072 2024-11-21 10:14:25 2024-11-21 10:14:25          1        1           1
6 rows selected.
--//看不见cursor: pin S等待时间。
--//但是前面cursor: pin S 占用191秒,相当于每个会话占用191/20 = 9.55秒,至少应该有9秒的差距。

SCOTT@book01p> Select decode(method,'test','test','Q'),count(*),round(avg(TIME_ELA),0),sum(TIME_ELA) from job_times group by decode(method,'test','test','Q') order by 3 ;
DECO   COUNT(*) ROUND(AVG(TIME_ELA),0) SUM(TIME_ELA)
---- ---------- ---------------------- -------------
Q            20                   4802         96036
test         20                   4822         96449

--//可以发现两者几乎同时完成,根本不存在这么大的差距,为什么呢?总的快了仅仅4秒。
--//实际上ash的取样放大了cursor: pin S等待事件,原来1次sleeps可能1毫秒或者1厘秒,而取样放大1秒,这样相当于一下子放大1000
--//或者100倍。

SYS@book> @ mutexprofz idn,hash,loc,maddr "ts>=trunc(sysdate)+10/24+11/1440+58/86400 and ts<=trunc(sysdate)+10/24+12/1440+49/86400"
-- MutexProf by Tanel Poder (http://www.tanelpoder.com)
-- Showing profile of top 20 sleeps...
-- column info : id idn hash hash_value=>hash_value ts=>sleep_timestamp
--               req=>requesting_session blk=>blocking_session val=>mutex_value maddr=>mutex_addr

SUM_SLEEPS      GETS_DIFF MUTEX_TYPE             IDN       HASH GET_LOCATION                      mutex_addr           OBJECT_NAME
---------- -------------- --------------- ---------- ---------- --------------------------------- -------------------- --------------------------------------------------------------------------------
        17         813649 Cursor Pin       752002402  752002402 kksLockDelete [KKSCHLPIN6]        0000000065F1A090     Select /*+ test */ count(*) from t where id = :j
         6         249929 Cursor Pin       752002402  752002402 kksfbc [KKSCHLFSP2]               0000000065F1A090     Select /*+ test */ count(*) from t where id = :j

SYS@book> @ mutexprofz idn,hash,loc,maddr "ts>=trunc(sysdate)+10/24+14/1440+24/86400 and ts<=trunc(sysdate)+10/24+15/1440+15/86400"
-- MutexProf by Tanel Poder (http://www.tanelpoder.com)
-- Showing profile of top 20 sleeps...
-- column info : id idn hash hash_value=>hash_value ts=>sleep_timestamp
--               req=>requesting_session blk=>blocking_session val=>mutex_value maddr=>mutex_addr
no rows selected
--//第2次执行根本没有输出。

4.深入分析:
--//session 1:
SCOTT@book01p> @ spid
==============================
SID                           : 158
SERIAL#                       : 47699
PROCESS                       : 3997
SERVER                        : DEDICATED
SPID                          : 3999
PID                           : 45
P_SERIAL#                     : 8
KILL_COMMAND                  : alter system kill session '158,47699' immediate;
PL/SQL procedure successfully completed.

--//session 2:
SYS@book> @ opeek 0000000065F1A090 40 0
[065F1A090, 065F1A0B8) = 00000000 00000000 01312D28 000029F5 2CD2A562 00000000 00000000 00000000 00000000 00000000
--//sleeps = 0x000029F5 = 10741次。
--//2CD2A562  = 752002402对应hash_value,与前面ashtop的P1raw输出一致。

--//window 1:
$ mod_addr.sh 0000000065F1A094 0 1
0x65f1a094:     0x00000001

--//session 2:
SYS@book> @ opeek 0000000065F1A090 40 0
[065F1A090, 065F1A0B8) = 00000000 00000001 01312D28 000029F5 2CD2A562 00000000 00000000 00000000 00000000 00000000
--//人为设置sid=1阻塞其他会话执行。

--//window 2:
$ strace -f -p 3999  -y -Ttt 2>&1 | tee /tmp/test.txt

--//session 1:
SCOTT@book01p> @ m9.txt 1 test
--//执行1次,挂起。

--//window 1:
$ sleep 30
$ mod_addr.sh 0000000065F1A094 0 0
0x65f1a094:     0x00000000

--//session 1,执行完成。

$ egrep "getrusage" /tmp/test.txt
10:41:03.594664 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 155251}, ru_stime={0, 26042}, ...}) = 0 <0.000014>
10:41:03.595953 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 155274}, ru_stime={0, 26874}, ...}) = 0 <0.000007>
10:41:03.597621 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 155459}, ru_stime={0, 26906}, ...}) = 0 <0.000033>
10:41:03.597718 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 155469}, ru_stime={0, 26908}, ...}) = 0 <0.000036>
10:41:03.598342 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 155524}, ru_stime={0, 26917}, ...}) = 0 <0.000078>
10:41:03.598487 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 155545}, ru_stime={0, 26921}, ...}) = 0 <0.000030>
10:41:05.286856 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 185189}, ru_stime={0, 38160}, ...}) = 0 <0.000020> --//开始
10:41:07.289493 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 199727}, ru_stime={0, 51653}, ...}) = 0 <0.000016>
10:41:09.296674 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 220614}, ru_stime={0, 58830}, ...}) = 0 <0.000027>
10:41:11.298284 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 244750}, ru_stime={0, 74489}, ...}) = 0 <0.000011>
10:41:13.299803 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 258506}, ru_stime={0, 89377}, ...}) = 0 <0.000023>
10:41:15.301216 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 276349}, ru_stime={0, 109685}, ...}) = 0 <0.000014>
10:41:17.303491 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 291781}, ru_stime={0, 119890}, ...}) = 0 <0.000013>
10:41:19.306078 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 316665}, ru_stime={0, 136150}, ...}) = 0 <0.000008>
10:41:21.306500 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 334213}, ru_stime={0, 144566}, ...}) = 0 <0.000053>
10:41:23.307949 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 349695}, ru_stime={0, 151694}, ...}) = 0 <0.000014>
10:41:25.310481 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 361525}, ru_stime={0, 173467}, ...}) = 0 <0.000010>
10:41:27.328359 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 366235}, ru_stime={0, 187187}, ...}) = 0 <0.000015>
10:41:29.330023 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 374466}, ru_stime={0, 202904}, ...}) = 0 <0.000009>
10:41:31.332351 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 386455}, ru_stime={0, 209885}, ...}) = 0 <0.000027>
10:41:33.332952 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 411865}, ru_stime={0, 228429}, ...}) = 0 <0.000035>
10:41:35.334616 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 418807}, ru_stime={0, 249539}, ...}) = 0 <0.000014>
10:41:36.453755 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 423399}, ru_stime={0, 258256}, ...}) = 0 <0.000053>
10:41:36.906525 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 550256}, ru_stime={0, 258256}, ...}) = 0 <0.000020>
10:41:37.335758 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 550256}, ru_stime={0, 258256}, ...}) = 0 <0.000021>
10:41:39.338048 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 575565}, ru_stime={0, 267048}, ...}) = 0 <0.000029>
10:41:41.359361 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 584471}, ru_stime={0, 274751}, ...}) = 0 <0.000120>
10:41:43.362103 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 594111}, ru_stime={0, 285503}, ...}) = 0 <0.000008>
10:41:45.373997 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 604310}, ru_stime={0, 298852}, ...}) = 0 <0.000008>
10:41:47.375294 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 611920}, ru_stime={0, 325030}, ...}) = 0 <0.000060>
10:41:47.946923 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 618978}, ru_stime={0, 329564}, ...}) = 0 <0.000025>
10:41:47.948071 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 619977}, ru_stime={0, 329564}, ...}) = 0 <0.000028>
10:41:47.949953 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 619977}, ru_stime={0, 329564}, ...}) = 0 <0.000018>
10:41:47.953368 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 619977}, ru_stime={0, 329564}, ...}) = 0 <0.000029>
10:41:47.954803 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 619977}, ru_stime={0, 330810}, ...}) = 0 <0.000024>
--//基本间隔2秒出现getrusage。

 $ egrep "getrusage|select" /tmp/test.txt | awk '{print $2}' | uniq -c | head -10
      6 getrusage(0x1
    855 select(0,
      1 getrusage(0x1
    678 select(0,
      1 getrusage(0x1
    546 select(0,
      1 getrusage(0x1
    844 select(0,
      1 getrusage(0x1
    575 select(0,

--//中间执行多次select。测试环境是虚拟机器,感觉性能不太稳定,如果真实的服务器我记忆里在11g下同样的参数环境下,没有其他
--//业务的情况下,select次数非常稳定基本都是18X次,感觉这次很多,仔细看以前笔记,发现休眠的时间发生了变化,11g下每次
--//select调用1厘秒(10毫秒),在getrusage调用2秒的间隔内出现181次.
--//我猜测在21c下如果是真实服务器,没有其他业务的情况下,select次数估计可以达到17XX,18XX次。

$ egrep "select" /tmp/test.txt | head -10
10:41:03.599064 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001461>
10:41:03.600622 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001835>
10:41:03.602569 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001885>
10:41:03.604577 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.002752>
10:41:03.607499 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001795>
10:41:03.609419 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001731>
10:41:03.611348 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001845>
10:41:03.613303 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001874>
10:41:03.615272 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001856>
10:41:03.617224 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001858>
--//每次select相当于sleep {0, 1000}里面的1000单位是微秒,相当于1毫秒。
--//21c下select仅仅1毫秒

--//sleeps = 0x000029F5 = 10741次。这个测试我重复几次基本在0x27XX-0x29XX之间。
--//10741*0.001050 = 11.27805秒 占11.3秒.
--//10741*0.001100 = 11.8151    占11.8秒.
--//我估计上select调用+加上其他消耗总共占用11.3-11.8秒。
--//说明:我每次调用select没有选择0.0018(最后显示的时间),我感觉使用strace跟踪大大影响调用select次数。
--//我仅仅大致估计select调用完成需要0.001050-0.001100秒之间。

SCOTT@book01p> Select decode(method,'test','test','Q'),count(*),round(avg(TIME_ELA),0),sum(TIME_ELA) from job_times group by decode(method,'test','test','Q') order by 3 ;
DECO   COUNT(*) ROUND(AVG(TIME_ELA),0) SUM(TIME_ELA)
---- ---------- ---------------------- -------------
Q            20                   4802         96036
test         20                   4822         96449
--//这里的时间单位是厘秒,总的执行时间集中模式比分散模式慢了(96449-96036)/100 = 4.13/100秒,存在
--//11.3-4.13 = 7.17, 11.8-4.13 = 7.67 差不多7秒的差距。

--//集中模式存在2次硬解析(1次存储过程1次sql语句),而分散模式存在40次硬解析(20次存储过程29次sql语句).
SCOTT@book01p> delete from JOB_TIMES ;
62 rows deleted.

SCOTT@book01p> commit ;
Commit complete.

$ zzdate;seq 20 | xargs -P 20 -IQ sqlplus -s -l scott/book@book01p @m9.txt 1 TEST > /dev/null;zzdate
trunc(sysdate)+16/24+25/1440+25/86400
trunc(sysdate)+16/24+25/1440+26/86400

$ zzdate;seq 20 | xargs -P 20 -IQ sqlplus -s -l scott/book@book01p @m9.txt 1 Q > /dev/null;zzdate
trunc(sysdate)+16/24+25/1440+33/86400
trunc(sysdate)+16/24+25/1440+34/86400
--//相当于仅仅执行1次。

COTT@book01p> Select decode(method,'TEST','TEST','Q'),count(*),round(avg(TIME_ELA),2),sum(TIME_ELA) from job_times group by decode(method,'TEST','TEST','Q') order by 3 ;
DECO   COUNT(*) ROUND(AVG(TIME_ELA),2) SUM(TIME_ELA)
---- ---------- ---------------------- -------------
Q            20                    2.3            46
TEST         20                   3.15            63

--//仅仅相差 (63-46)/100 = 0.17秒。还有7秒的误差不知道问题在哪里。

--//重复测试
--//delete from JOB_TIMES ;
--//commit ;

$ zzdate;seq 20 | xargs -P 20 -IQ sqlplus -s -l scott/book@book01p @m9.txt 5e5 TEST > /dev/null;zzdate
trunc(sysdate)+16/24+34/1440+59/86400
trunc(sysdate)+16/24+35/1440+50/86400

$ zzdate;seq 20 | xargs -P 20 -IQ sqlplus -s -l scott/book@book01p @m9.txt 5e5 Q > /dev/null;zzdate
trunc(sysdate)+16/24+35/1440+59/86400
trunc(sysdate)+16/24+36/1440+49/86400

SYS@book> @ ashtop event,p1raw,p1,p3raw 1=1 trunc(sysdate)+16/24+34/1440+59/86400 trunc(sysdate)+16/24+35/1440+50/86400
    Total                                                                                                                        Distinct Distinct    Distinct
  Seconds     AAS %This   EVENT         P1RAW                     P1 P3RAW             FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1
--------- ------- ------- ------------- ----------------- ---------- ----------------- ------------------- ------------------- ---------- -------- -----------
      748    14.7   77% |                                 3173923829                   2024-11-22 16:35:01 2024-11-22 16:35:49        407       49         455
      118     2.3   12% | cursor: pin S 00000000BD2E3BF5  3173923829 0000000900000000  2024-11-22 16:35:01 2024-11-22 16:35:49          1       33          33
       70     1.4    7% | cursor: pin S 00000000BD2E3BF5  3173923829 0000000300000000  2024-11-22 16:35:04 2024-11-22 16:35:45          1       30          30
       32      .6    3% |                                         12                   2024-11-22 16:35:01 2024-11-22 16:35:47         15       31          26
        2      .0    0% |                                 1413697536                   2024-11-22 16:35:01 2024-11-22 16:35:01          2        1           2
        1      .0    0% |                                     131072                   2024-11-22 16:35:00 2024-11-22 16:35:00          1        1           1
6 rows selected.

SYS@book> @ mutexprofz idn,hash,loc,maddr "ts>=trunc(sysdate)+16/24+34/1440+59/86400 and ts<=trunc(sysdate)+16/24+35/1440+50/86400"
-- MutexProf by Tanel Poder (http://www.tanelpoder.com)
-- Showing profile of top 20 sleeps...
-- column info : id idn hash hash_value=>hash_value ts=>sleep_timestamp
--               req=>requesting_session blk=>blocking_session val=>mutex_value maddr=>mutex_addr

SUM_SLEEPS      GETS_DIFF MUTEX_TYPE             IDN       HASH GET_LOCATION                      mutex_addr           OBJECT_NAME
---------- -------------- --------------- ---------- ---------- --------------------------------- -------------------- --------------------------------------------------------------------------------
         7         297757 Cursor Pin      3173923829 3173923829 kksLockDelete [KKSCHLPIN6]        0000000067EA8210     Select /*+ TEST */ count(*) from t where id = :j
         3         810203 Cursor Pin      3173923829 3173923829 kksfbc [KKSCHLFSP2]               0000000067EA8210     Select /*+ TEST */ count(*) from t where id = :j

SYS@book> @ opeek 0000000067EA8210 40 0
[067EA8210, 067EA8238) = 00000000 00000000 01312D20 00002789 BD2E3BF5 00000000 00000000 00000000 00000000 00000000
--//0x00002789 = 10121
--//10121*0.00105 = 10.62705

SCOTT@book01p> Select decode(method,'TEST','TEST','Q'),count(*),round(avg(TIME_ELA),2),sum(TIME_ELA) from job_times group by decode(method,'TEST','TEST','Q') order by 3 ;
DECO   COUNT(*) ROUND(AVG(TIME_ELA),2) SUM(TIME_ELA)
---- ---------- ---------------------- -------------
Q            20                4819.35         96387
TEST         20                 4867.4         97348
--//(97348-96387)/100 = 9.61
--//这次算是比较接近的1次。
--//总之大量相同sql语句软软解析密集执行ash记录cursor: pin S的时间由于1秒取样的原因被放大了,在我的测试里相当于仅仅看到1/20.
--//192/20 = 9.6

--//我不知道真实的环境是否到达这样的执行强度,我估计连接的会话数更多,但我总觉得分散带来的好处很小。
--//感觉虚拟机器太不稳定了,今天的测试
SYS@book> @ ashtop event,p1raw 1=1 trunc(sysdate)+16/24+24/1440+25/86400 trunc(sysdate)+16/24+25/1440+15/86400
    Total                                                                                                                        Distinct Distinct    Distinct
  Seconds     AAS %This   EVENT                                      P1RAW             FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ----------------- ------------------- ------------------- ---------- -------- -----------
      421     8.4   44% | resmgr:cpu quantum                         0000000000000002  2024-11-24 16:24:26 2024-11-24 16:25:14          1       49          49
      297     5.9   31% |                                                              2024-11-24 16:24:26 2024-11-24 16:25:14        170       49         210
      198     4.0   21% | resmgr:cpu quantum                         0000000000000003  2024-11-24 16:24:27 2024-11-24 16:25:13         21       40          21
       39      .8    4% | cursor: pin S                              00000000132C35C0  2024-11-24 16:24:27 2024-11-24 16:25:14          1       22          22
--//测试cursor: pin S 占39秒,不知道为什么今天的测试cursor: pin S占用偏小。
--//不知道是否与出现resmgr:cpu quantum事件有关。

--//有机会在11g下重复测试看看。

5.mod_addr.sh 代码如下:

$ cat mod_addr.sh
#/bin/bash
# modify address value
# arg1=address arg2=offset (default 0) arg3=value (default 0)

offset=${2:-0}
value=${3:-0}
gdb -q -batch -p $(pgrep -f ora_mmon_${ORACLE_SID}) -ex "set *(  int *)(0x${1}+0x${offset})=0x${value}"  -ex "x /wx 0x${1}+0x${offset}"  -ex "quit" |  grep "^0x" | grep -v "^0x0"
作者:lfree原文地址:https://www.cnblogs.com/lfree/p/18566377

%s 个评论

要回复文章请先登录注册