[20250207]21c library cache mutex的深入探究13.txt
[20250207]21c library cache mutex的深入探究13.txt
--//探究library cache mutex阻塞导致的相关等待事件,分析_mutex_wait_scheme=2的情况下修改mutext值的0-3字节。
--//关于mutex的结构,我的测试的结果如下:
--// 0- 7 字节是muext的值。
--// 8-11 字节是mutex gets的数量。
--//12-15 字节是mutex sleep的数量。
--//16-19 字节是Bucket桶号。
--//20-23 字节是转储看到的6.
--//我前面的测试仅仅修改mutex值的sid部分(4-7字节),也就是mutex结构里面0-7字节的4-7部分,没有尝试0-3字节的信息,该信息记
--//录的是持有该mutex的数量,尝试修改两部分信息看看会出现怎么情况。
1.环境:
SYS@book> @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.
SYS@book> @ hidez ^_mutex
NUM N_HEX NAME DESCRIPTION DEFAULT_VALUE SESSION_VALUE SYSTEM_VALUE ISSES ISSYS_MOD
---- ----- ------------------ ----------------- ------------- ------------- ------------ ----- ---------
3553 DE1 _mutex_wait_time Mutex wait time TRUE 1 1 FALSE IMMEDIATE
3554 DE2 _mutex_spin_count Mutex spin count TRUE 255 255 FALSE IMMEDIATE
3555 DE3 _mutex_wait_scheme Mutex wait scheme TRUE 2 2 FALSE IMMEDIATE
--//缺省_mutex_wait_time=1,时间单位与_mutex_wait_scheme相关,_mutex_wait_scheme=2时时间单位是厘秒,而
--//_mutex_wait_scheme=0,1时,单位时毫秒。
--//_mutex_wait_scheme =2时,_mutex_wait_time>1时sleeps的时间会出现指数回退.
--//缺省_mutex_wait_scheme =2.
--//网上找了一段资料:
* _mutex_spin_count (Integer)
- This sets the number of times to spin before yielding/waiting.
* _mutex_wait_scheme (Integer)
- In 11.2 this controls which wait scheme to use. It can be set to one of the three wait schemes described above thus:
_mutex_wait_scheme = 0 – Always YIELD
_mutex_wait_scheme = 1 & _mutex_wait_time = t – Always SLEEP for t milli-seconds
_mutex_wait_scheme = 2 & _mutex_wait_time = t – EXP BACKOFF with maximum sleep (default)
2.测试前准备:
SYS@book> oradebug setmypid
Statement processed.
SYS@book> oradebug dump library_cache 4
Statement processed.
$ grep "^Bucket:" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_10770.trc | head -4
Bucket: #=0 Mutex=0x6cfa1400(1125281431552, 9, 0, 6)
Bucket: #=5 Mutex=0x6cfa14f0(1125281431552, 4, 0, 6)
Bucket: #=17 Mutex=0x6cfa1730(1125281431552, 8, 0, 6)
Bucket: #=39 Mutex=0x6cfa1b50(1125281431552, 4, 0, 6)
--//以上是前面测试的结果,直接找Bucket: #=0 Mutex=0x6cfa1400的语句测试。
--//该sql语句select /*+ 9 */ count(*) from dept where deptno = 93834;的bucket=0.
--//Bucket: #=0 Mutex=0x6cfa1400
--//0x6cfa1400-0x10 = 0x6cfa13f0
3.测试:
--//节省篇幅,操作细节不再贴出,直接给出测试结果。
(gdb) x /8wx 0x6cfa1400
0x6cfa1400: 0x00000000 0x00000000 0x00000006 0x00000000
0x6cfa1410: 0x00000000 0x00000000 0x66a10bb8 0x00000000
(gdb) set *(int *)0x6cfa1404=0x9999
(gdb) set *(int *)0x6cfa1400=0x1
(gdb) x /8wx 0x6cfa1400
0x6cfa1400: 0x00000001 0x00009999 0x00000006 0x00000000
0x6cfa1410: 0x00000000 0x00000000 0x66a10bb8 0x00000000
(gdb) set *(int *)0x6cfa1404=0x0
(gdb) set *(int *)0x6cfa1400=0x0
(gdb) x /8wx 0x6cfa1400
0x6cfa1400: 0x00000000 0x00000000 0x00000007 0x00000d01
0x6cfa1410: 0x00000000 0x00000000 0x66a10bb8 0x00000000
--//sleeps=0x00000d01=3329,gets-> 0x6->0x7
SYS@book> @ ashtop event,p1,p1raw,p2raw,p3raw 1=1 "'2025/02/07 15:26:06'" "'2025/02/07 15:27:11'"
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1 P1RAW P2RAW P3RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ---------- ----------------- ----------------- ----------------- ------------------- ------------------- ---------- -------- -----------
54 .8 70% | library cache: bucket mutex X 0 0000000000000000 0000999900000001 000000000000003E 2025-02-07 15:26:07 2025-02-07 15:27:00 1 54 54
8 .1 10% | library cache: bucket mutex X 0 0000000000000000 0000000000000001 000000000000003E 2025-02-07 15:27:01 2025-02-07 15:27:09 1 8 8
4 .1 5% | 20 2025-02-07 15:26:07 2025-02-07 15:26:58 1 4 4
4 .1 5% | 100 2025-02-07 15:26:07 2025-02-07 15:26:46 1 4 4
2 .0 3% | LGWR all worker groups 0 0000000000000000 0000000000000000 0000000000000000 2025-02-07 15:26:07 2025-02-07 15:26:08 1 2 2
2 .0 3% | log file parallel write 1 0000000000000001 0000000000000001 0000000000000001 2025-02-07 15:26:07 2025-02-07 15:26:08 1 2 2
1 .0 1% | 0 2025-02-07 15:27:03 2025-02-07 15:27:03 1 1 1
1 .0 1% | 300 2025-02-07 15:26:17 2025-02-07 15:26:17 1 1 1
1 .0 1% | 1932464120 2025-02-07 15:26:31 2025-02-07 15:26:31 1 1 1
9 rows selected.
--//注意P2RAW的变化,开始0000999900000001,0000000000000001。
SYS@book> @ mutexprofz idn,hash,maddr,loc "ts>=trunc(sysdate)+15/24+26/1440+06/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 mutex_addr GET_LOCATION OBJECT_NAME
---------- -------------- --------------- ---------- ---------- -------------------- ------------ --------------------------------------------------------------------------------
3329 Library Cache 0 000000006CFA1400 kglhdgn1 62 (name not found)
3 Library Cache 2276283790 2276283790 00000000662B96A0 kglhdgn2 106 SELECT /*+ NO_STATEMENT_QUEUING RESULT_CACHE (SYSOBJ=TRUE) */
"OBJ#","CLASS_OID","JOB_FLAGS","RUN_TIME","PRIORITY","JOB_STATUS","RUNNING_INSTA
NCE","SCHEDULE_LIMIT","JOB_WEIGHT","INSTANCE_ID","AFFINITY","DATABASE_ROLE"
FROM "SYS"."SCHEDULER$_JOB_REFRESH" "SCHEDULER$_JOB_REFRESH" WHERE 1=1
--//3329 = 0xd01.
$ egrep "getrusage" 0207mutexb.txt
15:26:07.150476 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 347135}, ru_stime={0, 33692}, ...}) = 0 <0.000015>
15:26:07.150587 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 347177}, ru_stime={0, 33696}, ...}) = 0 <0.000012>
15:26:08.856385 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 348149}, ru_stime={0, 37665}, ...}) = 0 <0.000046>
15:26:10.911100 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 351302}, ru_stime={0, 39944}, ...}) = 0 <0.000124>
15:26:12.915692 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 354508}, ru_stime={0, 42252}, ...}) = 0 <0.000029>
15:26:14.912085 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 358084}, ru_stime={0, 44760}, ...}) = 0 <0.000228>
15:26:16.916171 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 361168}, ru_stime={0, 49060}, ...}) = 0 <0.000011>
15:26:18.915817 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 364606}, ru_stime={0, 52235}, ...}) = 0 <0.000238>
15:26:20.917717 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 366301}, ru_stime={0, 54421}, ...}) = 0 <0.000150>
15:26:22.920764 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 369432}, ru_stime={0, 57888}, ...}) = 0 <0.000018>
15:26:24.927205 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 373480}, ru_stime={0, 60677}, ...}) = 0 <0.000018>
15:26:26.942295 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 379902}, ru_stime={0, 62089}, ...}) = 0 <0.000009>
15:26:28.934122 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 381876}, ru_stime={0, 63469}, ...}) = 0 <0.000021>
15:26:30.936776 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 386159}, ru_stime={0, 65070}, ...}) = 0 <0.000096>
15:26:32.942150 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 393274}, ru_stime={0, 67326}, ...}) = 0 <0.000035>
15:26:34.952065 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 396936}, ru_stime={0, 71491}, ...}) = 0 <0.000029>
15:26:36.950711 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 403350}, ru_stime={0, 73140}, ...}) = 0 <0.000011>
15:26:38.949480 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 406376}, ru_stime={0, 75655}, ...}) = 0 <0.000029>
15:26:40.953517 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 411364}, ru_stime={0, 77738}, ...}) = 0 <0.000032>
15:26:42.953218 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 416651}, ru_stime={0, 79207}, ...}) = 0 <0.000014>
15:26:44.957684 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 421671}, ru_stime={0, 83023}, ...}) = 0 <0.000028>
15:26:46.973537 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 425903}, ru_stime={0, 86063}, ...}) = 0 <0.000037>
15:26:48.962069 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 428810}, ru_stime={0, 91730}, ...}) = 0 <0.000054>
15:26:50.966768 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 433422}, ru_stime={0, 96067}, ...}) = 0 <0.000015>
15:26:52.963272 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 436899}, ru_stime={0, 99959}, ...}) = 0 <0.000015>
15:26:54.971342 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 441843}, ru_stime={0, 100573}, ...}) = 0 <0.000070>
15:26:56.978882 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 446572}, ru_stime={0, 102529}, ...}) = 0 <0.000017>
15:26:58.981386 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 450588}, ru_stime={0, 107228}, ...}) = 0 <0.000026>
15:27:00.981732 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 452718}, ru_stime={0, 109749}, ...}) = 0 <0.000072>
--//以上基本2秒间隔。
--//2025-02-07 15:27:01,set *(int *)0x6cfa1404=0x0.
15:27:01.906844 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 455381}, ru_stime={0, 110117}, ...}) = 0 <0.000018>
15:27:02.507095 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 524171}, ru_stime={0, 145603}, ...}) = 0 <0.000032>
15:27:02.977242 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 613417}, ru_stime={0, 160914}, ...}) = 0 <0.000007>
15:27:03.020355 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 623319}, ru_stime={0, 161481}, ...}) = 0 <0.000006>
15:27:03.533703 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 700621}, ru_stime={0, 185209}, ...}) = 0 <0.000007>
15:27:04.045811 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 744292}, ru_stime={0, 209496}, ...}) = 0 <0.000008>
15:27:04.559666 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 811104}, ru_stime={0, 234625}, ...}) = 0 <0.000007>
15:27:04.980668 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 877326}, ru_stime={0, 267244}, ...}) = 0 <0.000007>
15:27:05.083171 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 889736}, ru_stime={0, 270556}, ...}) = 0 <0.000008>
15:27:05.596662 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 890103}, ru_stime={0, 274617}, ...}) = 0 <0.000028>
15:27:06.110036 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 975686}, ru_stime={0, 308338}, ...}) = 0 <0.000005>
15:27:06.622168 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 52302}, ru_stime={0, 337591}, ...}) = 0 <0.000013>
15:27:06.978185 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 99112}, ru_stime={0, 354831}, ...}) = 0 <0.000085>
15:27:07.135351 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 128844}, ru_stime={0, 360498}, ...}) = 0 <0.000006>
15:27:07.663219 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 220534}, ru_stime={0, 382071}, ...}) = 0 <0.000006>
15:27:08.175760 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 282472}, ru_stime={0, 410056}, ...}) = 0 <0.000024>
15:27:08.693119 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 296474}, ru_stime={0, 412372}, ...}) = 0 <0.000028>
15:27:08.985687 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 340967}, ru_stime={0, 420797}, ...}) = 0 <0.000016>
15:27:09.206344 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 371415}, ru_stime={0, 436874}, ...}) = 0 <0.000006>
15:27:09.723266 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 457950}, ru_stime={0, 450432}, ...}) = 0 <0.000006>
15:27:10.236054 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 515126}, ru_stime={0, 477863}, ...}) = 0 <0.000005>
15:27:10.750786 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 602139}, ru_stime={0, 499834}, ...}) = 0 <0.000006>
15:27:10.986176 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 635316}, ru_stime={0, 509629}, ...}) = 0 <0.000005>
15:27:11.008831 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 638633}, ru_stime={0, 511753}, ...}) = 0 <0.000006>
--//似乎后面2个都在继续调用getrusage。存在2个间隔都是2秒。
$ awk '{print $2}' 0207mutexb.txt |egrep "semtimedop|getrusage|sched_yield|select" | uniq -c | head -12
2 getrusage(0x1
2 sched_yield()
71 semtimedop(98304,
1 getrusage(0x1
92 semtimedop(98304,
1 getrusage(0x1
83 semtimedop(98304,
1 getrusage(0x1
117 semtimedop(98304,
1 getrusage(0x1
118 semtimedop(98304,
1 getrusage(0x1
--//开始调用1次sched_yield(),semtimedop多次,2秒之后调用getrusage。
$ awk '/^15.27./{print $2}' 0207mutexb.txt |egrep "semtimedop|getrusage|sched_yield|select" | uniq -c | head -14
57 semtimedop(98304,
1 getrusage(0x1
56 semtimedop(98304,
1 getrusage(0x1
99 sched_yield()
1 select(0,
99 sched_yield()
1 select(0,
99 sched_yield()
1 select(0,
99 sched_yield()
1 select(0,
99 sched_yield()
1 select(0,
--//99次sched_yield,1次select。遇到getrusage分开,相加次数还是99次,如此反复循环。
$ awk '{print $2}' 0207mutexb.txt |egrep "semtimedop|getrusage|sched_yield|select" | sort | uniq -c
53 getrusage(0x1
129989 sched_yield()
1313 select(0,
3099 semtimedop(98304,
--//sleeps = 129989+1313+3099 = 134401,远远大于3329,实际上单次sleeps最大的sleeps的保存是0xffff,
--//134401 = 0x20d01, 16进制后4位是0x0d01 = 3329,与opeek,mutexprofz的输出一致。
SYS@book> @opeek 0x6cfa13f0 48 0
[06CFA13F0, 06CFA1420) = 67DCBD20 00000000 67DCBD20 00000000 00000000 00000000 00000008 00000D01 00000000 00000000 66A10BB8 00000000
$ egrep "semtimedop" 0207mutexb.txt | head -4
15:26:07.150907 semtimedop(98304, {{46, -1, 0}}, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.010787>
15:26:07.161795 semtimedop(98304, {{46, -1, 0}}, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.030185>
15:26:07.192224 semtimedop(98304, {{46, -1, 0}}, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.020344>
15:26:07.212747 semtimedop(98304, {{46, -1, 0}}, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.010422>
--//{0, 10000000} 前面参数的时间单位是秒,后面参数的时间单位是纳秒。10000000/10^9 = .01,相当于10毫秒
$ egrep "select" 0207mutexb.txt | head -4
15:27:01.913128 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001389>
15:27:01.920727 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001606>
15:27:01.928416 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.004600>
15:27:01.939098 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001875>
--//休眠的时间单位微秒(1/10^6秒),1000微秒= 1000/10^6 = .001秒。
--//探究library cache mutex阻塞导致的相关等待事件,分析_mutex_wait_scheme=2的情况下修改mutext值的0-3字节。
--//关于mutex的结构,我的测试的结果如下:
--// 0- 7 字节是muext的值。
--// 8-11 字节是mutex gets的数量。
--//12-15 字节是mutex sleep的数量。
--//16-19 字节是Bucket桶号。
--//20-23 字节是转储看到的6.
--//我前面的测试仅仅修改mutex值的sid部分(4-7字节),也就是mutex结构里面0-7字节的4-7部分,没有尝试0-3字节的信息,该信息记
--//录的是持有该mutex的数量,尝试修改两部分信息看看会出现怎么情况。
1.环境:
SYS@book> @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.
SYS@book> @ hidez ^_mutex
NUM N_HEX NAME DESCRIPTION DEFAULT_VALUE SESSION_VALUE SYSTEM_VALUE ISSES ISSYS_MOD
---- ----- ------------------ ----------------- ------------- ------------- ------------ ----- ---------
3553 DE1 _mutex_wait_time Mutex wait time TRUE 1 1 FALSE IMMEDIATE
3554 DE2 _mutex_spin_count Mutex spin count TRUE 255 255 FALSE IMMEDIATE
3555 DE3 _mutex_wait_scheme Mutex wait scheme TRUE 2 2 FALSE IMMEDIATE
--//缺省_mutex_wait_time=1,时间单位与_mutex_wait_scheme相关,_mutex_wait_scheme=2时时间单位是厘秒,而
--//_mutex_wait_scheme=0,1时,单位时毫秒。
--//_mutex_wait_scheme =2时,_mutex_wait_time>1时sleeps的时间会出现指数回退.
--//缺省_mutex_wait_scheme =2.
--//网上找了一段资料:
* _mutex_spin_count (Integer)
- This sets the number of times to spin before yielding/waiting.
* _mutex_wait_scheme (Integer)
- In 11.2 this controls which wait scheme to use. It can be set to one of the three wait schemes described above thus:
_mutex_wait_scheme = 0 – Always YIELD
_mutex_wait_scheme = 1 & _mutex_wait_time = t – Always SLEEP for t milli-seconds
_mutex_wait_scheme = 2 & _mutex_wait_time = t – EXP BACKOFF with maximum sleep (default)
2.测试前准备:
SYS@book> oradebug setmypid
Statement processed.
SYS@book> oradebug dump library_cache 4
Statement processed.
$ grep "^Bucket:" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_10770.trc | head -4
Bucket: #=0 Mutex=0x6cfa1400(1125281431552, 9, 0, 6)
Bucket: #=5 Mutex=0x6cfa14f0(1125281431552, 4, 0, 6)
Bucket: #=17 Mutex=0x6cfa1730(1125281431552, 8, 0, 6)
Bucket: #=39 Mutex=0x6cfa1b50(1125281431552, 4, 0, 6)
--//以上是前面测试的结果,直接找Bucket: #=0 Mutex=0x6cfa1400的语句测试。
--//该sql语句select /*+ 9 */ count(*) from dept where deptno = 93834;的bucket=0.
--//Bucket: #=0 Mutex=0x6cfa1400
--//0x6cfa1400-0x10 = 0x6cfa13f0
3.测试:
--//节省篇幅,操作细节不再贴出,直接给出测试结果。
(gdb) x /8wx 0x6cfa1400
0x6cfa1400: 0x00000000 0x00000000 0x00000006 0x00000000
0x6cfa1410: 0x00000000 0x00000000 0x66a10bb8 0x00000000
(gdb) set *(int *)0x6cfa1404=0x9999
(gdb) set *(int *)0x6cfa1400=0x1
(gdb) x /8wx 0x6cfa1400
0x6cfa1400: 0x00000001 0x00009999 0x00000006 0x00000000
0x6cfa1410: 0x00000000 0x00000000 0x66a10bb8 0x00000000
(gdb) set *(int *)0x6cfa1404=0x0
(gdb) set *(int *)0x6cfa1400=0x0
(gdb) x /8wx 0x6cfa1400
0x6cfa1400: 0x00000000 0x00000000 0x00000007 0x00000d01
0x6cfa1410: 0x00000000 0x00000000 0x66a10bb8 0x00000000
--//sleeps=0x00000d01=3329,gets-> 0x6->0x7
SYS@book> @ ashtop event,p1,p1raw,p2raw,p3raw 1=1 "'2025/02/07 15:26:06'" "'2025/02/07 15:27:11'"
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1 P1RAW P2RAW P3RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ---------- ----------------- ----------------- ----------------- ------------------- ------------------- ---------- -------- -----------
54 .8 70% | library cache: bucket mutex X 0 0000000000000000 0000999900000001 000000000000003E 2025-02-07 15:26:07 2025-02-07 15:27:00 1 54 54
8 .1 10% | library cache: bucket mutex X 0 0000000000000000 0000000000000001 000000000000003E 2025-02-07 15:27:01 2025-02-07 15:27:09 1 8 8
4 .1 5% | 20 2025-02-07 15:26:07 2025-02-07 15:26:58 1 4 4
4 .1 5% | 100 2025-02-07 15:26:07 2025-02-07 15:26:46 1 4 4
2 .0 3% | LGWR all worker groups 0 0000000000000000 0000000000000000 0000000000000000 2025-02-07 15:26:07 2025-02-07 15:26:08 1 2 2
2 .0 3% | log file parallel write 1 0000000000000001 0000000000000001 0000000000000001 2025-02-07 15:26:07 2025-02-07 15:26:08 1 2 2
1 .0 1% | 0 2025-02-07 15:27:03 2025-02-07 15:27:03 1 1 1
1 .0 1% | 300 2025-02-07 15:26:17 2025-02-07 15:26:17 1 1 1
1 .0 1% | 1932464120 2025-02-07 15:26:31 2025-02-07 15:26:31 1 1 1
9 rows selected.
--//注意P2RAW的变化,开始0000999900000001,0000000000000001。
SYS@book> @ mutexprofz idn,hash,maddr,loc "ts>=trunc(sysdate)+15/24+26/1440+06/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 mutex_addr GET_LOCATION OBJECT_NAME
---------- -------------- --------------- ---------- ---------- -------------------- ------------ --------------------------------------------------------------------------------
3329 Library Cache 0 000000006CFA1400 kglhdgn1 62 (name not found)
3 Library Cache 2276283790 2276283790 00000000662B96A0 kglhdgn2 106 SELECT /*+ NO_STATEMENT_QUEUING RESULT_CACHE (SYSOBJ=TRUE) */
"OBJ#","CLASS_OID","JOB_FLAGS","RUN_TIME","PRIORITY","JOB_STATUS","RUNNING_INSTA
NCE","SCHEDULE_LIMIT","JOB_WEIGHT","INSTANCE_ID","AFFINITY","DATABASE_ROLE"
FROM "SYS"."SCHEDULER$_JOB_REFRESH" "SCHEDULER$_JOB_REFRESH" WHERE 1=1
--//3329 = 0xd01.
$ egrep "getrusage" 0207mutexb.txt
15:26:07.150476 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 347135}, ru_stime={0, 33692}, ...}) = 0 <0.000015>
15:26:07.150587 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 347177}, ru_stime={0, 33696}, ...}) = 0 <0.000012>
15:26:08.856385 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 348149}, ru_stime={0, 37665}, ...}) = 0 <0.000046>
15:26:10.911100 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 351302}, ru_stime={0, 39944}, ...}) = 0 <0.000124>
15:26:12.915692 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 354508}, ru_stime={0, 42252}, ...}) = 0 <0.000029>
15:26:14.912085 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 358084}, ru_stime={0, 44760}, ...}) = 0 <0.000228>
15:26:16.916171 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 361168}, ru_stime={0, 49060}, ...}) = 0 <0.000011>
15:26:18.915817 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 364606}, ru_stime={0, 52235}, ...}) = 0 <0.000238>
15:26:20.917717 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 366301}, ru_stime={0, 54421}, ...}) = 0 <0.000150>
15:26:22.920764 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 369432}, ru_stime={0, 57888}, ...}) = 0 <0.000018>
15:26:24.927205 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 373480}, ru_stime={0, 60677}, ...}) = 0 <0.000018>
15:26:26.942295 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 379902}, ru_stime={0, 62089}, ...}) = 0 <0.000009>
15:26:28.934122 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 381876}, ru_stime={0, 63469}, ...}) = 0 <0.000021>
15:26:30.936776 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 386159}, ru_stime={0, 65070}, ...}) = 0 <0.000096>
15:26:32.942150 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 393274}, ru_stime={0, 67326}, ...}) = 0 <0.000035>
15:26:34.952065 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 396936}, ru_stime={0, 71491}, ...}) = 0 <0.000029>
15:26:36.950711 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 403350}, ru_stime={0, 73140}, ...}) = 0 <0.000011>
15:26:38.949480 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 406376}, ru_stime={0, 75655}, ...}) = 0 <0.000029>
15:26:40.953517 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 411364}, ru_stime={0, 77738}, ...}) = 0 <0.000032>
15:26:42.953218 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 416651}, ru_stime={0, 79207}, ...}) = 0 <0.000014>
15:26:44.957684 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 421671}, ru_stime={0, 83023}, ...}) = 0 <0.000028>
15:26:46.973537 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 425903}, ru_stime={0, 86063}, ...}) = 0 <0.000037>
15:26:48.962069 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 428810}, ru_stime={0, 91730}, ...}) = 0 <0.000054>
15:26:50.966768 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 433422}, ru_stime={0, 96067}, ...}) = 0 <0.000015>
15:26:52.963272 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 436899}, ru_stime={0, 99959}, ...}) = 0 <0.000015>
15:26:54.971342 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 441843}, ru_stime={0, 100573}, ...}) = 0 <0.000070>
15:26:56.978882 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 446572}, ru_stime={0, 102529}, ...}) = 0 <0.000017>
15:26:58.981386 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 450588}, ru_stime={0, 107228}, ...}) = 0 <0.000026>
15:27:00.981732 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 452718}, ru_stime={0, 109749}, ...}) = 0 <0.000072>
--//以上基本2秒间隔。
--//2025-02-07 15:27:01,set *(int *)0x6cfa1404=0x0.
15:27:01.906844 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 455381}, ru_stime={0, 110117}, ...}) = 0 <0.000018>
15:27:02.507095 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 524171}, ru_stime={0, 145603}, ...}) = 0 <0.000032>
15:27:02.977242 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 613417}, ru_stime={0, 160914}, ...}) = 0 <0.000007>
15:27:03.020355 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 623319}, ru_stime={0, 161481}, ...}) = 0 <0.000006>
15:27:03.533703 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 700621}, ru_stime={0, 185209}, ...}) = 0 <0.000007>
15:27:04.045811 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 744292}, ru_stime={0, 209496}, ...}) = 0 <0.000008>
15:27:04.559666 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 811104}, ru_stime={0, 234625}, ...}) = 0 <0.000007>
15:27:04.980668 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 877326}, ru_stime={0, 267244}, ...}) = 0 <0.000007>
15:27:05.083171 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 889736}, ru_stime={0, 270556}, ...}) = 0 <0.000008>
15:27:05.596662 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 890103}, ru_stime={0, 274617}, ...}) = 0 <0.000028>
15:27:06.110036 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 975686}, ru_stime={0, 308338}, ...}) = 0 <0.000005>
15:27:06.622168 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 52302}, ru_stime={0, 337591}, ...}) = 0 <0.000013>
15:27:06.978185 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 99112}, ru_stime={0, 354831}, ...}) = 0 <0.000085>
15:27:07.135351 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 128844}, ru_stime={0, 360498}, ...}) = 0 <0.000006>
15:27:07.663219 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 220534}, ru_stime={0, 382071}, ...}) = 0 <0.000006>
15:27:08.175760 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 282472}, ru_stime={0, 410056}, ...}) = 0 <0.000024>
15:27:08.693119 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 296474}, ru_stime={0, 412372}, ...}) = 0 <0.000028>
15:27:08.985687 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 340967}, ru_stime={0, 420797}, ...}) = 0 <0.000016>
15:27:09.206344 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 371415}, ru_stime={0, 436874}, ...}) = 0 <0.000006>
15:27:09.723266 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 457950}, ru_stime={0, 450432}, ...}) = 0 <0.000006>
15:27:10.236054 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 515126}, ru_stime={0, 477863}, ...}) = 0 <0.000005>
15:27:10.750786 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 602139}, ru_stime={0, 499834}, ...}) = 0 <0.000006>
15:27:10.986176 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 635316}, ru_stime={0, 509629}, ...}) = 0 <0.000005>
15:27:11.008831 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 638633}, ru_stime={0, 511753}, ...}) = 0 <0.000006>
--//似乎后面2个都在继续调用getrusage。存在2个间隔都是2秒。
$ awk '{print $2}' 0207mutexb.txt |egrep "semtimedop|getrusage|sched_yield|select" | uniq -c | head -12
2 getrusage(0x1
2 sched_yield()
71 semtimedop(98304,
1 getrusage(0x1
92 semtimedop(98304,
1 getrusage(0x1
83 semtimedop(98304,
1 getrusage(0x1
117 semtimedop(98304,
1 getrusage(0x1
118 semtimedop(98304,
1 getrusage(0x1
--//开始调用1次sched_yield(),semtimedop多次,2秒之后调用getrusage。
$ awk '/^15.27./{print $2}' 0207mutexb.txt |egrep "semtimedop|getrusage|sched_yield|select" | uniq -c | head -14
57 semtimedop(98304,
1 getrusage(0x1
56 semtimedop(98304,
1 getrusage(0x1
99 sched_yield()
1 select(0,
99 sched_yield()
1 select(0,
99 sched_yield()
1 select(0,
99 sched_yield()
1 select(0,
99 sched_yield()
1 select(0,
--//99次sched_yield,1次select。遇到getrusage分开,相加次数还是99次,如此反复循环。
$ awk '{print $2}' 0207mutexb.txt |egrep "semtimedop|getrusage|sched_yield|select" | sort | uniq -c
53 getrusage(0x1
129989 sched_yield()
1313 select(0,
3099 semtimedop(98304,
--//sleeps = 129989+1313+3099 = 134401,远远大于3329,实际上单次sleeps最大的sleeps的保存是0xffff,
--//134401 = 0x20d01, 16进制后4位是0x0d01 = 3329,与opeek,mutexprofz的输出一致。
SYS@book> @opeek 0x6cfa13f0 48 0
[06CFA13F0, 06CFA1420) = 67DCBD20 00000000 67DCBD20 00000000 00000000 00000000 00000008 00000D01 00000000 00000000 66A10BB8 00000000
$ egrep "semtimedop" 0207mutexb.txt | head -4
15:26:07.150907 semtimedop(98304, {{46, -1, 0}}, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.010787>
15:26:07.161795 semtimedop(98304, {{46, -1, 0}}, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.030185>
15:26:07.192224 semtimedop(98304, {{46, -1, 0}}, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.020344>
15:26:07.212747 semtimedop(98304, {{46, -1, 0}}, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.010422>
--//{0, 10000000} 前面参数的时间单位是秒,后面参数的时间单位是纳秒。10000000/10^9 = .01,相当于10毫秒
$ egrep "select" 0207mutexb.txt | head -4
15:27:01.913128 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001389>
15:27:01.920727 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001606>
15:27:01.928416 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.004600>
15:27:01.939098 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001875>
--//休眠的时间单位微秒(1/10^6秒),1000微秒= 1000/10^6 = .001秒。
【推荐】编程新体验,更懂你的AI,立即体验豆包MarsCode编程助手
【推荐】凌霞软件回馈社区,博客园 & 1Panel & Halo 联合会员上线
【推荐】抖音旗下AI助手豆包,你的智能百科全书,全免费不限次数
【推荐】博客园社区专享云产品让利特惠,阿里云新客6.5折上折
【推荐】轻量又高性能的 SSH 工具 IShell:AI 加持,快人一步
· 一个费力不讨好的项目,让我损失了近一半的绩效!
· 清华大学推出第四讲使用 DeepSeek + DeepResearch 让科研像聊天一样简单!
· 实操Deepseek接入个人知识库
· CSnakes vs Python.NET:高效嵌入与灵活互通的跨语言方案对比
· Plotly.NET 一个为 .NET 打造的强大开源交互式图表库
2024-02-19 [20240219]建立完善sql_idx.sh脚本.txt
2019-02-19 [20190219]那个更快(11g).txt