[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"