[20250211]更正11g x$mutex_sleep_history记录的一些疑问.txt

[20250211]更正11g x$mutex_sleep_history记录的一些疑问.txt

--//在11g下测试遇到的问题,看了以前的链接:[20241018]21c x$mutex_sleep_history记录的变化.txt,实际上当时自己的理解也存在
--//错误,有必要在11g下重复验证自己以前混乱的概念。
--//实际上第一次学习就存在遇到这个问题,将自己写的脚本将gets,sleeps数量做sum汇总,当时就发生gets数量不对,想当然认为
--//sleeps数量也是类似情况,实际上gets数量理解是对的,但是sleeps的理解是错误的,还有一些理解不对的地方,通过真实的例子说
--//明问题。

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

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

$ cat m2.txt
DECLARE
   v_pad   VARCHAR2 (200);
   l_count PLS_INTEGER;
BEGIN
    FOR i IN 1..&&1
    LOOP
       --EXECUTE IMMEDIATE 'select pad from t where id = :j ' INTO v_pad USING i;
       --EXECUTE IMMEDIATE 'select count(distinct pad) from t where id = :j ' INTO l_count USING i;
       --EXECUTE IMMEDIATE 'select count(*) from t where id = :j ' INTO l_count USING i;
       SELECT COUNT(*) INTO L_COUNT FROM T WHERE ID = 1 ;
    END LOOP;
END;
/
--//PL SQL的里面sql语句自动转换成大写执行。

$ cat m3.txt
column p1 noprint
column p2 noprint
column p3 noprint
column p4 noprint
column p5 noprint
column p1raw noprint
column MUTEX_TYPE format a13
SELECT MUTEX_ADDR,MUTEX_IDENTIFIER,SLEEP_TIMESTAMP,MUTEX_TYPE,GETS,
       SLEEPS,REQUESTING_SESSION,BLOCKING_SESSION,LOCATION,MUTEX_VALUE
  FROM x$mutex_sleep_history
 WHERE mutex_identifier = 287837530
 ORDER BY SLEEP_TIMESTAMP;

--//注意设置按SLEEP_TIMESTAMP排序,便于后面观察。

SCOTT@book> SELECT COUNT(*) FROM T WHERE ID = 1 ;
  COUNT(*)
----------
         1

SCOTT@book> @ hash
HASH_VALUE SQL_ID        CHILD_NUMBER KGL_BUCKET PLAN_HASH_VALUE HASH_HEX   SQL_EXEC_START      SQL_EXEC_ID
---------- ------------- ------------ ---------- --------------- ---------- ------------------- -----------
 287837530 5mr67th8kh3au            1       3418       916843435  11280d5a  2025-02-11 09:09:58    19849416
--//记下sql=5mr67th8kh3au,hash_value=287837530,然后避开其他因素,重启数据库测试。

3.测试:
$ zzdate;seq 10 | xargs -IQ -P 10 sqlplus scott/book @ m2.txt 1e6 > /dev/null;zzdate
trunc(sysdate)+10/24+53/1440+35/86400 -1739242415.181859957
trunc(sysdate)+10/24+54/1440+14/86400 1739242454.048513370

--//在执行过程中执行m3.txt.
SYS@book> @ m3.txt
no rows selected

SYS@book> @ m3.txt
MUTEX_ADDR       MUTEX_IDENTIFIER SLEEP_TIMESTAMP            MUTEX_TYPE     GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION                   MUTEX_VALUE
---------------- ---------------- -------------------------- ---------- -------- ------ ------------------ ---------------- -------------------------- ----------------
00000000877906C8        287837530 2025-02-11 10:53:37.062648 Cursor Pin   760418     22                 12               10 kksLockDelete [KKSCHLPIN6] 0000000A00000004
00000000877906C8        287837530 2025-02-11 10:53:37.321700 Cursor Pin   898059     41                135              199 kksfbc [KKSCHLFSP2]        000000C700000004
00000000877906C8        287837530 2025-02-11 10:53:37.321706 Cursor Pin   898059     32                133              199 kksfbc [KKSCHLFSP2]        000000C700000004
00000000877906C8        287837530 2025-02-11 10:53:37.351523 Cursor Pin   913868     41                197              135 kksLockDelete [KKSCHLPIN6] 0000008700000006
00000000877906C8        287837530 2025-02-11 10:53:37.351534 Cursor Pin   913868     34                195              135 kksfbc [KKSCHLFSP2]        0000008700000006
00000000877906C8        287837530 2025-02-11 10:53:37.351541 Cursor Pin   913870     49                 69              135 kksfbc [KKSCHLFSP2]        0000000000000004
00000000877906C8        287837530 2025-02-11 10:53:37.360631 Cursor Pin   918601     17                 10              133 kksLockDelete [KKSCHLPIN6] 0000000000000005
00000000877906C8        287837530 2025-02-11 10:53:37.360633 Cursor Pin   918599     27                  8              133 kksfbc [KKSCHLFSP2]        0000008500000004
00000000877906C8        287837530 2025-02-11 10:53:37.360634 Cursor Pin   918599     35                199              133 kksfbc [KKSCHLFSP2]        0000008500000004
00000000877906C8        287837530 2025-02-11 10:53:37.360653 Cursor Pin   918600     55                 71              133 kksfbc [KKSCHLFSP2]        0000000000000004
10 rows selected.

SYS@book> @ m3.txt
MUTEX_ADDR       MUTEX_IDENTIFIER SLEEP_TIMESTAMP            MUTEX_TYPE     GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION                   MUTEX_VALUE
---------------- ---------------- -------------------------- ---------- -------- ------ ------------------ ---------------- -------------------------- ----------------
00000000877906C8        287837530 2025-02-11 10:54:02.083479 Cursor Pin 13950008    469                  8              195 kksLockDelete [KKSCHLPIN6] 0000000000000006
00000000877906C8        287837530 2025-02-11 10:54:02.184960 Cursor Pin 14003353    503                 69              199 kksLockDelete [KKSCHLPIN6] 000000C700000007
00000000877906C8        287837530 2025-02-11 10:54:02.260661 Cursor Pin 14043662    458                133                8 kksfbc [KKSCHLFSP2]        0000000800000005
00000000877906C8        287837530 2025-02-11 10:54:02.260662 Cursor Pin 14043662    436                 12                8 kksfbc [KKSCHLFSP2]        0000000800000005
00000000877906C8        287837530 2025-02-11 10:54:02.260663 Cursor Pin 14043663    450                197                8 kksLockDelete [KKSCHLPIN6] 0000000000000005
00000000877906C8        287837530 2025-02-11 10:54:02.314660 Cursor Pin 14072550    528                 71              135 kksLockDelete [KKSCHLPIN6] 0000008700000007
00000000877906C8        287837530 2025-02-11 10:54:02.346910 Cursor Pin 14089645    534                135               71 kksfbc [KKSCHLFSP2]        0000004700000008
00000000877906C8        287837530 2025-02-11 10:54:02.346916 Cursor Pin 14089645    436                195               71 kksLockDelete [KKSCHLPIN6] 0000004700000008
00000000877906C8        287837530 2025-02-11 10:54:02.346924 Cursor Pin 14089645    415                199               71 kksLockDelete [KKSCHLPIN6] 0000004700000008
00000000877906C8        287837530 2025-02-11 10:54:02.346924 Cursor Pin 14089647    452                 10               71 kksfbc [KKSCHLFSP2]        0000000000000007
10 rows selected.

--//全部结束后,执行如下:
SYS@book> @ m3.txt
MUTEX_ADDR       MUTEX_IDENTIFIER SLEEP_TIMESTAMP            MUTEX_TYPE     GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION                   MUTEX_VALUE
---------------- ---------------- -------------------------- ---------- -------- ------ ------------------ ---------------- -------------------------- ----------------
00000000877906C8        287837530 2025-02-11 10:54:11.936582 Cursor Pin 19142324    705                135               12 kksLockDelete [KKSCHLPIN6] 0000000000000006
00000000877906C8        287837530 2025-02-11 10:54:12.276535 Cursor Pin 19317941    595                197               69 kksfbc [KKSCHLFSP2]        0000004500000006
00000000877906C8        287837530 2025-02-11 10:54:12.569631 Cursor Pin 19471875    662                 69              195 kksfbc [KKSCHLFSP2]        0000000000000003
00000000877906C8        287837530 2025-02-11 10:54:12.703461 Cursor Pin 19541631    633                 12              133 kksfbc [KKSCHLFSP2]        0000000000000005
00000000877906C8        287837530 2025-02-11 10:54:12.709637 Cursor Pin 19544898    694                 71              195 kksLockDelete [KKSCHLPIN6] 0000000000000004
00000000877906C8        287837530 2025-02-11 10:54:13.054674 Cursor Pin 19724415    601                195               10 kksfbc [KKSCHLFSP2]        0000000A00000002
00000000877906C8        287837530 2025-02-11 10:54:13.141620 Cursor Pin 19770180    643                  8              195 kksfbc [KKSCHLFSP2]        000000C300000003
00000000877906C8        287837530 2025-02-11 10:54:13.575564 Cursor Pin 19931013    641                 10              199 kksfbc [KKSCHLFSP2]        000000C700000000
00000000877906C8        287837530 2025-02-11 10:54:13.575566 Cursor Pin 19931013    671                133              199 kksfbc [KKSCHLFSP2]        000000C700000000
00000000877906C8        287837530 2025-02-11 10:54:13.587096 Cursor Pin 19933718    607                199                0 kksfbc [KKSCHLFSP2]        00
--//Sum = 6452
10 rows selected.
--//gets记录的最大值是19933718。
--//仔细gets的变化顺着SLEEP_TIMESTAMP变化,不断累积的。

SYS@book> @ opeek 00000000877906C8 24 0
[0877906C8, 0877906E0) = 00000000 00000000 01312D00 00001934 11280D5A 00000000

--//0x11280D5A = 287837530,正好等于bucket桶号,也就是hash_value.

--//gets 0x01312D00 = 20000000,总共执行10*1000000 = 10000000,有2个LOCATION出现kksLockDelete [KKSCHLPIN6],kksfbc [KKSCHLFSP2] 。
--//这样gets=执行次数*2,完全能对上。而m3.txt脚本查询最大的gets=19933718,因为后面没有sleeps,就不做记录,与20000000非常接近。

--//sleeps =0x00001934 = 6452。将最后的输出sleeps结果累积
--//705+595+662+633+694+601+643+641+671+607 = 6452,正好等于opeek.sql脚本输出看到的结果。

--//另外注意输出的记录每次都是10行,说明10个会话在执行(我以前的理解存在错误),实际上相当于取样每个REQUESTING_SESSION,对于每个
--//REQUESTING_SESSION讲sleeps的次数是不断累积的,相当于snapshot当时的情况。最后sum(sleeps)就是实际sleeps的数量。
--//另外注意一个前提就是出现sleeps在x$mutex_sleep_history视图才会有记录。

--//另外注意一个细节最后一行MUTEX_VALUE=00,因为其他会话已经退出,无法抓取到MUTEX_VALUE值。

$ zzdate;seq 10 | xargs -IQ -P 10 sqlplus scott/book @ m2.txt 1e6 > /dev/null;zzdate
trunc(sysdate)+11/24+13/1440+41/86400 -1739243621.004123399
trunc(sysdate)+11/24+14/1440+22/86400 1739243662.918034260
--//注意这次执行修改m2.txt ,结尾加入host sleep 3再退出。

SYS@book> @ m3.txt
MUTEX_ADDR       MUTEX_IDENTIFIER SLEEP_TIMESTAMP            MUTEX_TYPE     GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION                   MUTEX_VALUE
---------------- ---------------- -------------------------- ---------- -------- ------ ------------------ ---------------- -------------------------- ----------------
00000000877906C8        287837530 2025-02-11 10:54:11.936582 Cursor Pin 19142324    705                135               12 kksLockDelete [KKSCHLPIN6] 0000000000000006
00000000877906C8        287837530 2025-02-11 10:54:12.276535 Cursor Pin 19317941    595                197               69 kksfbc [KKSCHLFSP2]        0000004500000006
00000000877906C8        287837530 2025-02-11 10:54:12.569631 Cursor Pin 19471875    662                 69              195 kksfbc [KKSCHLFSP2]        0000000000000003
00000000877906C8        287837530 2025-02-11 10:54:12.709637 Cursor Pin 19544898    694                 71              195 kksLockDelete [KKSCHLPIN6] 0000000000000004
00000000877906C8        287837530 2025-02-11 10:54:13.141620 Cursor Pin 19770180    643                  8              195 kksfbc [KKSCHLFSP2]        000000C300000003
00000000877906C8        287837530 2025-02-11 10:54:13.575564 Cursor Pin 19931013    641                 10              199 kksfbc [KKSCHLFSP2]        000000C700000000
00000000877906C8        287837530 2025-02-11 10:54:13.587096 Cursor Pin 19933718    607                199                0 kksfbc [KKSCHLFSP2]        00
00000000877906C8        287837530 2025-02-11 11:14:16.431549 Cursor Pin 38381754    569                 73              195 kksfbc [KKSCHLFSP2]        000000C300000007
00000000877906C8        287837530 2025-02-11 11:14:16.912629 Cursor Pin 38636326    612                136              195 kksfbc [KKSCHLFSP2]        0000000000000004
00000000877906C8        287837530 2025-02-11 11:14:18.354618 Cursor Pin 39388791    658                200               12 kksLockDelete [KKSCHLPIN6] 0000000C00000008
00000000877906C8        287837530 2025-02-11 11:14:18.772595 Cursor Pin 39608095   1147                 12               11 kksLockDelete [KKSCHLPIN6] 0000000000000005
00000000877906C8        287837530 2025-02-11 11:14:18.878636 Cursor Pin 39664305    642                134               12 kksLockDelete [KKSCHLPIN6] 0000000000000005
00000000877906C8        287837530 2025-02-11 11:14:19.019570 Cursor Pin 39738675    643                 11               70 kksLockDelete [KKSCHLPIN6] 0000004600000003
00000000877906C8        287837530 2025-02-11 11:14:19.141432 Cursor Pin 39801441   1267                195                0 kksLockDelete [KKSCHLPIN6] 0000000000000003
00000000877906C8        287837530 2025-02-11 11:14:19.426140 Cursor Pin 39913625    657                198              133 kksfbc [KKSCHLFSP2]        0000008500000001
00000000877906C8        287837530 2025-02-11 11:14:19.522707 Cursor Pin 39937671   1334                133               70 kksfbc [KKSCHLFSP2]        0000004600000001
00000000877906C8        287837530 2025-02-11 11:14:19.554008 Cursor Pin 39945620    619                 70              133 kksLockDelete [KKSCHLPIN6] 0000000000000002
--//Sum = 12695
17 rows selected.
--//这次看到不是10行正常的,因为sid发生了变化,前面SLEEP_TIMESTAMP=2025-02-11 10:54占7行。第2次执行仅仅3个会话的sid与前
--//面相同,可以发现3条记录的sleep大于1000。

SYS@book> @ opeek 00000000877906C8 24 0
[0877906C8, 0877906E0) = 00000000 00000000 02625A02 00003197 11280D5A 00000000

--//0x02625A02  = 40000002
--//0x00003197 = 12695,与记录的完全一致,两者相减就是这次sleeps的数量12695-6452 = 6243。

--//我不知道x$mutex_sleep_history占用的内存区域多大,这些信息保存多久,如果记录不全,sum(sleeps)会存在误差。
--//注意这次的最后的MUTEX_VALUE不再是00.

--//再次执行:
$ zzdate;seq 10 | xargs -IQ -P 10 sqlplus scott/book @ m2.txt 1e6 > /dev/null;zzdate
trunc(sysdate)+11/24+30/1440+57/86400 -1739244657.163923990
trunc(sysdate)+11/24+31/1440+38/86400 1739244698.618742061

SYS@book> @ m3.txt
MUTEX_ADDR       MUTEX_IDENTIFIER SLEEP_TIMESTAMP            MUTEX_TYPE     GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION                   MUTEX_VALUE
---------------- ---------------- -------------------------- ---------- -------- ------ ------------------ ---------------- -------------------------- ----------------
00000000877906C8        287837530 2025-02-11 10:54:11.936582 Cursor Pin 19142324    705                135               12 kksLockDelete [KKSCHLPIN6] 0000000000000006
00000000877906C8        287837530 2025-02-11 10:54:12.276535 Cursor Pin 19317941    595                197               69 kksfbc [KKSCHLFSP2]        0000004500000006
00000000877906C8        287837530 2025-02-11 10:54:12.569631 Cursor Pin 19471875    662                 69              195 kksfbc [KKSCHLFSP2]        0000000000000003
00000000877906C8        287837530 2025-02-11 10:54:12.709637 Cursor Pin 19544898    694                 71              195 kksLockDelete [KKSCHLPIN6] 0000000000000004
00000000877906C8        287837530 2025-02-11 10:54:13.587096 Cursor Pin 19933718    607                199                0 kksfbc [KKSCHLFSP2]        00
00000000877906C8        287837530 2025-02-11 11:14:18.354618 Cursor Pin 39388791    658                200               12 kksLockDelete [KKSCHLPIN6] 0000000C00000008
00000000877906C8        287837530 2025-02-11 11:14:19.019570 Cursor Pin 39738675    643                 11               70 kksLockDelete [KKSCHLPIN6] 0000004600000003
00000000877906C8        287837530 2025-02-11 11:31:34.098471 Cursor Pin 59257937   1894                133              198 kksLockDelete [KKSCHLPIN6] 0000000000000007
00000000877906C8        287837530 2025-02-11 11:31:34.906244 Cursor Pin 59679684   1723                 12              134 kksfbc [KKSCHLFSP2]        0000008600000005
00000000877906C8        287837530 2025-02-11 11:31:35.113291 Cursor Pin 59788336   1250                134               73 kksLockDelete [KKSCHLPIN6] 0000004900000003
00000000877906C8        287837530 2025-02-11 11:31:35.113304 Cursor Pin 59788337   1194                136               73 kksfbc [KKSCHLFSP2]        0000000000000003
00000000877906C8        287837530 2025-02-11 11:31:35.133611 Cursor Pin 59798956   1321                198              134 kksfbc [KKSCHLFSP2]        0000008600000005
00000000877906C8        287837530 2025-02-11 11:31:35.133612 Cursor Pin 59798956   1919                195              134 kksLockDelete [KKSCHLPIN6] 0000008600000005
00000000877906C8        287837530 2025-02-11 11:31:35.338611 Cursor Pin 59906303   1253                  8              198 kksfbc [KKSCHLFSP2]        000000C600000002
00000000877906C8        287837530 2025-02-11 11:31:35.443080 Cursor Pin 59960673   1279                 70               73 kksLockDelete [KKSCHLPIN6] 0000004900000003
00000000877906C8        287837530 2025-02-11 11:31:35.513651 Cursor Pin 59986883   1076                 73                8 kksfbc [KKSCHLFSP2]        0000000000000001
00000000877906C8        287837530 2025-02-11 11:31:35.517620 Cursor Pin 59988393   1169                 10                8 kksfbc [KKSCHLFSP2]        0000000800000002
--//Sum = 18642
17 rows selected.

SYS@book> @ opeek 00000000877906C8 24 0
[0877906C8, 0877906E0) = 00000000 00000000 03938702 000048D2 11280D5A 00000000

--//03938702 = 60000002
--//000048D2 = 18642
--//与opeek脚本的输出完全一致。

SYS@book> @ mutexprofz idn,hash,loc,maddr "idn=287837530"

-- 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
---------- -------------- --------------- ---------- ---------- --------------------------------- -------------------- -----------------------------------
      9600       40670452 Cursor Pin       287837530  287837530 kksfbc [KKSCHLFSP2]               00000000877906C8     SELECT COUNT(*) FROM T WHERE ID = 1
      9042       40818349 Cursor Pin       287837530  287837530 kksLockDelete [KKSCHLPIN6]        00000000877906C8     SELECT COUNT(*) FROM T WHERE ID = 1

SYS@book> @ mutexprofz idn,hash "idn=287837530"

-- 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 OBJECT_NAME
---------- -------------- --------------- ---------- ---------- -----------------------------------
     18642       40846069 Cursor Pin       287837530  287837530 SELECT COUNT(*) FROM T WHERE ID = 1

4.补充21c的情况:
--//在21c情况就不同了,记录sleeps很小,就是当时sleeps的实际数量。
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.

--//直接贴出测试结果:
$ zzdate;seq 10 | xargs -IQ -P 10 sqlplus scott/book@book01p @ m2.txt 1e6 > /dev/null;zzdate
trunc(sysdate)+15/24+30/1440+35/86400 1739259035.666690247
trunc(sysdate)+15/24+31/1440+16/86400 1739259076.844448490

SYS@book> @ m3.txt
MUTEX_ADDR       MUTEX_IDENTIFIER SLEEP_TIMESTAMP            MUTEX_TYPE     GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION                   MUTEX_VALUE
---------------- ---------------- -------------------------- ---------- -------- ------ ------------------ ---------------- -------------------------- ----------------
000000006353C498        287837530 2025-02-11 15:30:45.611297 Cursor Pin  5069176      1                141               22 kksLockDelete [KKSCHLPIN6] 0000001600000006
000000006353C498        287837530 2025-02-11 15:30:45.611310 Cursor Pin  5069176      1                 20               22 kksLockDelete [KKSCHLPIN6] 0000001600000006
000000006353C498        287837530 2025-02-11 15:30:45.619614 Cursor Pin  5073068      1                273                0 kksfbc [KKSCHLFSP2]        0000000000000008
000000006353C498        287837530 2025-02-11 15:30:45.651220 Cursor Pin  5088852      1                142               20 kksLockDelete [KKSCHLPIN6] 0000001400000005
000000006353C498        287837530 2025-02-11 15:30:45.651231 Cursor Pin  5088852      1                276               20 kksfbc [KKSCHLFSP2]        0000001400000005
000000006353C498        287837530 2025-02-11 15:30:45.704251 Cursor Pin  5117720      1                274              397 kksLockDelete [KKSCHLPIN6] 0000018D00000008
000000006353C498        287837530 2025-02-11 15:30:45.774112 Cursor Pin  5156081      1                397              274 kksfbc [KKSCHLFSP2]        0000011200000005
000000006353C498        287837530 2025-02-11 15:30:45.812144 Cursor Pin  5176762      1                 22              397 kksLockDelete [KKSCHLPIN6] 0000018D00000005
000000006353C498        287837530 2025-02-11 15:30:45.836287 Cursor Pin  5189902      1                146              273 kksfbc [KKSCHLFSP2]        0000011100000007
000000006353C498        287837530 2025-02-11 15:30:45.836292 Cursor Pin  5189902      1                399              273 kksLockDelete [KKSCHLPIN6] 0000011100000007
10 rows selected.
--//看到gets是逐步累积,而sleeps很小,仅仅1.

--//执行脚本结束后执行:
SYS@book> @ m3.txt
MUTEX_ADDR       MUTEX_IDENTIFIER SLEEP_TIMESTAMP            MUTEX_TYPE     GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION                   MUTEX_VALUE
---------------- ---------------- -------------------------- ---------- -------- ------ ------------------ ---------------- -------------------------- ----------------
000000006353C498        287837530 2025-02-11 15:31:12.394131 Cursor Pin 19376968      3                276              397 kksLockDelete [KKSCHLPIN6] 0000018D00000009
000000006353C498        287837530 2025-02-11 15:31:12.841261 Cursor Pin 19616716      1                 20              142 kksLockDelete [KKSCHLPIN6] 0000008E00000006
000000006353C498        287837530 2025-02-11 15:31:13.011625 Cursor Pin 19708179      3                146              399 kksfbc [KKSCHLFSP2]        0000018F00000006
000000006353C498        287837530 2025-02-11 15:31:13.126153 Cursor Pin 19770339      1                 22              273 kksfbc [KKSCHLFSP2]        0000011100000005
000000006353C498        287837530 2025-02-11 15:31:13.126154 Cursor Pin 19770339      1                397              273 kksLockDelete [KKSCHLPIN6] 0000011100000005
000000006353C498        287837530 2025-02-11 15:31:13.153332 Cursor Pin 19785004      1                142              399 kksfbc [KKSCHLFSP2]        0000018F00000006
000000006353C498        287837530 2025-02-11 15:31:13.182297 Cursor Pin 19800904      1                141              397 kksfbc [KKSCHLFSP2]        0000018D00000007
000000006353C498        287837530 2025-02-11 15:31:13.346246 Cursor Pin 19882900      1                273              399 kksfbc [KKSCHLFSP2]        0000018F00000000
000000006353C498        287837530 2025-02-11 15:31:13.507455 Cursor Pin 19944940      1                274              273 kksLockDelete [KKSCHLPIN6] 0000011100000002
000000006353C498        287837530 2025-02-11 15:31:13.507458 Cursor Pin 19944940      1                399              273 kksLockDelete [KKSCHLPIN6] 0000011100000002
10 rows selected.

SYS@book> @ opeek 000000006353C498 24 0
[06353C498, 06353C4B0) = 00000000 00000000 01312D00 00001547 11280D5A 00000000
--//0x11280D5A = 287837530 bucket桶号。
--//gets = 0x01312D00 = 20000000
--//sleeps = 0x00001547 = 5447,从x$mutex_sleep_history的输出看就无法判断sleeps的数量。

SYS@book> @ mutexprofz idn,hash,loc,maddr "idn=287837530"
-- 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    174721 Cursor Pin  287837530  287837530 kksfbc [KKSCHLFSP2]        000000006353C498 SELECT COUNT(*) FROM T WHERE ID = 1
         7    567972 Cursor Pin  287837530  287837530 kksLockDelete [KKSCHLPIN6] 000000006353C498 SELECT COUNT(*) FROM T WHERE ID = 1
--//最后sum_sleeps仅仅是7,两者相加也就是14.
--//gets的数量是累积的,但是sleeps就是当时sleeps的实际数量,总之该值不是累积的,感觉21c这样改进存在问题。
--//换一句讲11g看到sleeps高可能是之前的记录就很高,要比较就先后执行2次看看两者的差值。而21c下直接看SUM_SLEEPS值,而且只
--//能作为参考,包括GETS_DIFF值。不过多数情况mutex不会成为主要等待事件。

--//原始的tpt版本,sleeps取的是最大值,实际上感觉还是使用自己改写的版本更加科学一些。

5.附上opeek.sql脚本:
$ cat opeek.sql
-- Copyright 2023 lfree. All rights reserved.
-- Licensed under the Apache License, Version 2.0. See LICENSE.txt for terms and conditions.
--------------------------------------------------------------------------------
--
-- Name:        opeek.sql
-- Purpose:     oradebug peek
-- Author:      lfree
-- Usage:
--     @ opeek <addr> <length> <1|0>
-- argv3 : 1 -- write tracename and display 0 -- display
--------------------------------------------------------------------------------

set term off

col 1 new_value 1
select replace(lower('&&1'),'x','') "1" from dual;

column tt new_value var
select decode(&&3,1,'ti','zero') tt  from dual;

oradebug setmypid
set term on

@ &var.
--@ ti
oradebug peek 0x&1 &2 &3
prompt

$ cat tpt/mutexprofz.sql
--------------------------------------------------------------------------------
--
-- File name:   mutexprof.sql ( Mutex sleep Profiler )
--
-- Purpose:     Display KGX mutex sleep history from v$mutex_sleep_history
--              along library cache object names protected by these mutexes.
--              Only top 20 rows are shown by default
--
-- Author:      Tanel Poder
-- Copyright:   (c) http://www.tanelpoder.com
--
-- Usage:       @mutexprof <grouping columns> <filter condition>
--
--              The main grouping (and filtering) columns are:
--
--                  id  - mutex ID (which is the object hash value for library
--                                  cache object mutexes)
--                  ts  - timestamp of mutex sleep beginning
--                  loc - code location where the waiter slept for the mutex
--                  val - mutex value (shows whether mutex was held in exclusive or
--                                     shared mode)
--                  req - requesting session SID
--                  blk - blocking session SID
--
--              The filter condition allows filtering mutex sleep rows based on certain
--              criteria, such:
--
--                  1=1      - show all mutex sleeps (which are still in memory)
--                  blk=123  - show only these mutex sleeps where blocking sid was 123
--                  hash=2741853041 - show only these sleeps where mutex ID (KGL object hash value)
--                                    was 2741853041
--
--
--                  Its also possible to have multiple "AND" filter conditions, as long as you keep
--                  them in double quotes so that sqlplus would recognize them as one parameter
--
--                  For example: "name like '%DUAL%' and blk in (115,98)"
--
-- Examples:
--
--              @mutexprof loc 1=1
--              @mutexprof id,loc,req,blk "lower(name) like 'select%from dual%'"
--              @mutexprof loc,val blk=98
--              @mutexprof id,loc,req,blk "blk in (select sid from v$session where username = 'SYS')"
--
-- Other:       When the relevant object is aged out you will see (name not found)
--              as object_name.
--
--              On 10.2.0.1 the V$mutex_sleep_history does not have mutex_identifier
--              column externalized. In this case use X$mutex_sleep_history instead
--
--------------------------------------------------------------------------------

col msh_obj_name   head OBJECT_NAME for  a80 word_wrap
col msh_mutex_type head MUTEX_TYPE for a15 truncate
col loc   head GET_LOCATION for a33 truncate

col mutexprof_gets   head GETS_DIFF for 9999999999999
col mutexprof_sleeps head SLEEPS for 999999

col mutexprof_p2 head P2 for a16 wrap
col mutexprof_p3 head P3 for a16 wrap
col mutexprof_p4 head P4 for a16 wrap
col mutexprof_p5 head P5 for a20 wrap

col maddr head mutex_addr for a20 wrap

def MSH_NUMROWS=20

prompt
prompt -- MutexProf by Tanel Poder (http://www.tanelpoder.com)
prompt -- Showing profile of top &MSH_NUMROWS sleeps...
prompt -- column info : id idn hash hash_value=>hash_value ts=>sleep_timestamp
prompt --               req=>requesting_session blk=>blocking_session val=>mutex_value maddr=>mutex_addr

select * from (
    select /*+ ORDERED USE_NL(o) */
      -- TODO the sleep/get counting needs fixing!
      --MAX(sleeps)               sleeps
      sum(sleeps)               sum_sleeps
      --count(*)                sleeps
      --, decode(max(sleeps)-min(sleeps),0,to_number(null),max(sleeps)-min(sleeps)) mutexprof_sleeps -- may not be very accurate but give an idea
      , decode(max(gets)-min(gets),0,to_number(null),max(gets)-min(gets)) mutexprof_gets -- may not be very accurate but give an idea
      --  avg(sleeps)         sleeps
      --, avg(gets)           gets
      , mutex_type          msh_mutex_type
      , &1
      , replace(nvl(decode(kglnaown, null, kglnaobj, kglnaown||'.'||kglnaobj), '(name not found)'),chr(13),'')   msh_obj_name
      --, nvl(decode(kglnaown, null, kglnaobj, kglnaown||'.'||kglnaobj), '(name not found)')   msh_obj_name
      --, p1raw
      --, CASE WHEN p2 < 536870912 THEN TO_CHAR(p2) ELSE TRIM(TO_CHAR(p2, 'XXXXXXXXXXXXXXXX')) END mutexprof_p2
      --, CASE WHEN p3 < 536870912 THEN TO_CHAR(p3) ELSE TRIM(TO_CHAR(p3, 'XXXXXXXXXXXXXXXX')) END mutexprof_p3
      --, CASE WHEN p4 < 536870912 THEN TO_CHAR(p4) ELSE TRIM(TO_CHAR(p4, 'XXXXXXXXXXXXXXXX')) END mutexprof_p4
      --, p5 mutexprof_p5
    from
        (select
            mutex_identifier   id
          , mutex_identifier   idn
          , sleep_timestamp    ts
          , mutex_type
          , gets
          , sleeps
          , requesting_session req
          , blocking_session   blk
          , location           loc
          , mutex_value        val
          , mutex_addr         maddr
          , p1
          , p1raw
          , p2
          , p3
          , p4
          , p5
         from x$mutex_sleep_history) m
      , (select kglnahsh, kglnahsh hash_value, kglnahsh hash,
                kglhdpar, kglhdadr, kglnaown, kglnaobj,
                decode(kglnaown, null, kglnaobj, kglnaown||'.'||kglnaobj) object_name,
                decode(kglnaown, null, kglnaobj, kglnaown||'.'||kglnaobj) name
         from x$kglob) o
    where
        m.id = o.kglnahsh (+)
    and (o.kglhdadr = o.kglhdpar or (o.kglhdpar is null)) -- only parent KGL objects if still in cache
    and &2
    group by
        mutex_type
      , &1
      , kglnaown
      , kglnaobj
      , p1raw
      , CASE WHEN p2 < 536870912 THEN TO_CHAR(p2) ELSE TRIM(TO_CHAR(p2, 'XXXXXXXXXXXXXXXX')) END
      , CASE WHEN p3 < 536870912 THEN TO_CHAR(p3) ELSE TRIM(TO_CHAR(p3, 'XXXXXXXXXXXXXXXX')) END
      , CASE WHEN p4 < 536870912 THEN TO_CHAR(p4) ELSE TRIM(TO_CHAR(p4, 'XXXXXXXXXXXXXXXX')) END
      --, p5
    order by
        1 desc
       -- sleeps desc
)
where rownum <= &MSH_NUMROWS
/

posted @   lfree  阅读(1)  评论(0编辑  收藏  举报
相关博文:
阅读排行:
· 一个费力不讨好的项目,让我损失了近一半的绩效!
· 清华大学推出第四讲使用 DeepSeek + DeepResearch 让科研像聊天一样简单!
· 实操Deepseek接入个人知识库
· CSnakes vs Python.NET:高效嵌入与灵活互通的跨语言方案对比
· Plotly.NET 一个为 .NET 打造的强大开源交互式图表库
历史上的今天:
2021-02-18 [20210218]shared latch spin count 5.txt
点击右上角即可分享
微信分享提示