[20250210]21c library cache mutex的深入探究12(补充).txt

[20250210]21c library cache mutex的深入探究12(补充).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的数量，尝试修改这部分信息看看会出现怎么情况。 --//前次测试忘记关闭resmgr cpu quantum,补充完善关闭resmgr cpu quantum下做的测试。 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      0x00000007      0x00000000 0x6cfa1410:     0x00000000      0x00000000      0x63e8bc78      0x00000000 (gdb) set *(int *)0x6cfa1400=0x6 (gdb) x /8wx 0x6cfa1400 0x6cfa1400:     0x00000006      0x00000000      0x00000007      0x00000000 0x6cfa1410:     0x00000000      0x00000000      0x63e8bc78      0x00000000 --//select /*+ 9 */ count(*) from dept where deptno = 93834; 等3X秒，执行如下。 (gdb) set *(int *)0x6cfa1400=0x0 (gdb) x /8wx 0x6cfa1400 0x6cfa1400:     0x00000000      0x00000000      0x00000008      0x0000ef38 0x6cfa1410:     0x00000000      0x00000000      0x63e8bc78      0x00000000 --//gets次数0x7->0x8 ,sleeps次数0x0->0x0000ef38 = 61240. SYS@book> @ ashtop event,p1,p1raw,p2raw,p3raw 1=1 trunc(sysdate)+09/24+03/1440+47/86400 trunc(sysdate)+09/24+04/1440+36/86400     Total                                                                                                                                                                       Distinct Distinct    Distinct   Seconds     AAS %This   EVENT                                              P1 P1RAW             P2RAW             P3RAW             FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1 --------- ------- ------- ------------------------------------------ ---------- ----------------- ----------------- ----------------- ------------------- ------------------- ---------- -------- -----------        37      .8   67% | library cache: bucket mutex X                       0 0000000000000000  0000000000000006  000000000000003E  2025-02-10 09:03:48 2025-02-10 09:04:35          1       37          37        11      .2   20% |                                                     0                                                       2025-02-10 09:04:00 2025-02-10 09:04:33          1       11          11         6      .1   11% |                                                   100                                                       2025-02-10 09:03:48 2025-02-10 09:04:21          1        6           6         1      .0    2% |                                                     3                                                       2025-02-10 09:04:17 2025-02-10 09:04:17          1        1           1 $ egrep "getrusage" 0210mutexa.txt 09:03:48.172624 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 303099}, ru_stime={0, 38442}, ...}) = 0 <0.000019> 09:03:49.380082 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 456255}, ru_stime={0, 99773}, ...}) = 0 <0.000010> 09:03:51.381719 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 735628}, ru_stime={0, 236915}, ...}) = 0 <0.000011> 09:03:53.382038 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 10436}, ru_stime={0, 307752}, ...}) = 0 <0.000007> 09:03:55.383268 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 288414}, ru_stime={0, 387664}, ...}) = 0 <0.000013> 09:03:57.384009 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 479131}, ru_stime={0, 445793}, ...}) = 0 <0.000007> 09:03:59.384298 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={1, 753466}, ru_stime={0, 569824}, ...}) = 0 <0.000006> 09:04:01.385257 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={2, 77129}, ru_stime={0, 671155}, ...}) = 0 <0.000012> 09:04:03.389199 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={2, 350130}, ru_stime={0, 771763}, ...}) = 0 <0.000006> 09:04:05.389855 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={2, 622499}, ru_stime={0, 846137}, ...}) = 0 <0.000006> 09:04:07.391404 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={2, 866029}, ru_stime={0, 948938}, ...}) = 0 <0.000008> 09:04:09.393450 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={3, 151839}, ru_stime={1, 40751}, ...}) = 0 <0.000006> 09:04:11.395003 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={3, 462951}, ru_stime={1, 146327}, ...}) = 0 <0.000007> 09:04:13.398522 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={3, 719526}, ru_stime={1, 245038}, ...}) = 0 <0.000026> 09:04:15.399019 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={4, 36260}, ru_stime={1, 338502}, ...}) = 0 <0.000007> 09:04:17.400348 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={4, 374888}, ru_stime={1, 409892}, ...}) = 0 <0.000033> 09:04:19.422586 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={4, 597359}, ru_stime={1, 507211}, ...}) = 0 <0.000054> 09:04:21.436519 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={4, 797668}, ru_stime={1, 570634}, ...}) = 0 <0.000015> 09:04:23.437964 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={4, 981486}, ru_stime={1, 629400}, ...}) = 0 <0.000017> 09:04:25.440397 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={5, 186811}, ru_stime={1, 684002}, ...}) = 0 <0.000007> 09:04:27.440161 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={5, 401148}, ru_stime={1, 743441}, ...}) = 0 <0.000018> 09:04:29.442450 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={5, 656631}, ru_stime={1, 856503}, ...}) = 0 <0.000040> 09:04:31.442938 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={5, 873049}, ru_stime={1, 914698}, ...}) = 0 <0.000016> 09:04:33.444659 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={6, 133743}, ru_stime={2, 19798}, ...}) = 0 <0.000007> 09:04:35.445343 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={6, 422594}, ru_stime={2, 140179}, ...}) = 0 <0.000013> 09:04:35.821465 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={6, 476067}, ru_stime={2, 169657}, ...}) = 0 <0.000006> 09:04:35.822626 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={6, 476342}, ru_stime={2, 169749}, ...}) = 0 <0.000008> --//调用getrusage是2秒间隔。 $ awk '{print $2}' 0210mutexa.txt |egrep "semtimedop|getrusage|sched_yield|select" | uniq -c | head -20       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(0,      99 sched_yield()       1 select(0,      99 sched_yield()       1 select(0,      99 sched_yield()       1 select(0,      99 sched_yield() --//如果单独抽取sched_yield，select函数，99次sched_yield()，1次select(0。可以发现就是_mutex_wait_scheme=0模式。 $ awk '{print $2}' 0210mutexa.txt |egrep "semtimedop|getrusage|sched_yield|select" | uniq -c | grep sched_yield| uniq -c| head -20     182      99 sched_yield()       1      43 sched_yield()       1      56 sched_yield()     334      99 sched_yield()       1      60 sched_yield()       1      39 sched_yield()     293      99 sched_yield()       1      45 sched_yield()       1      54 sched_yield()     321      99 sched_yield()       1      76 sched_yield()       1      23 sched_yield()     542      99 sched_yield()       1      33 sched_yield()       1      66 sched_yield()     395      99 sched_yield()       1      89 sched_yield()       1      10 sched_yield()     623      99 sched_yield()       1      40 sched_yield() --//遇到getrusage分开，sched_yield相加次数还是99次,如此反复循环。 $ egrep "select" 0210mutexa.txt | head -6 09:03:48.178734 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001815> 09:03:48.186904 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001444> 09:03:48.194249 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.006749> 09:03:48.207123 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.001742> 09:03:48.214762 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.016548> 09:03:48.237299 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.023285> --//休眠的时间单位微秒（1/10^6秒），1000微秒= 1000/10^6  = .001秒。select休眠的时间很短1毫秒。 SYS@book> @ mutexprofz idn,hash,loc,maddr "ts>=trunc(sysdate)+09/24+03/1440+47/86400 and ts<=trunc(sysdate)+09/24+04/1440+36/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 ---------- -------------- --------------- ---------- ---------- --------------------------------- -------------------- ----------------      61240                Library Cache            0            kglhdgn1  62                      000000006CFA1400     (name not found) --//可以发现与前面的查询一致。 (gdb) x /8wx 0x6cfa1400 0x6cfa1400:     0x00000000      0x00000000      0x00000008      0x0000ef38 0x6cfa1410:     0x00000000      0x00000000      0x63e8bc78      0x00000000 --//gets次数0x7->0x8 ,sleeps次数0x0->0x0000ef38 = 61240. $ awk '{print $2}' 0210mutexa.txt |egrep "semtimedop|getrusage|sched_yield|select" | sort | uniq -c      27 getrusage(0x1  709434 sched_yield()    7166 select(0, --//实际记录的sleeps 次数 709434+7166 = 716600,远远大于61240，实际上单次sleeps最大的sleeps的保存是0xffff， --//716600 = 0xaef38, 16进制后4位是0xef38  = 61240,与opeek，mutexprofz的输出一致。 4.小结： --//可以发现采用sleep模式并非一成不变，oracle根据mutex的位置采用不同的模式，当前是_mutex_wait_scheme=2， --//在这里采用sched_yield 99+select模式,相当于_mutex_wait_scheme=0，估计持有数量的释放更快。