[20241018]21c x$mutex_sleep_history记录的变化.txt

来源:这里教程网 时间:2026-03-03 20:44:10 作者:

[20241018]21c x$mutex_sleep_history记录的变化.txt --//mutex很少会成为主要等待事件,如果遇到多数情况非常特别,比如bug。mutex本身和保护对象是一体的,不像latch一样有单独的 --//latch,而且mutex本身占内存也更小,mutex没有等待和持有队列,所以没有排队机制,mutex具有共享和排它两种模式. --//正是mutex的特点,很分散,oracle使用x$mutex_sleep_history记录(某个内存区域),即使get数量很高,只要不进入sleep状态,就 --//不会记录。而且一旦进入sleep将其值,sleeps数量,gets数量一并,我以前自己写的脚本有问题,采用sum(gets),sum(sleeps)显 --//示,这样无形放大gets,sleeps的数量,换一句话讲以前记录更像是流水帐。 --//今天在使用tpt里面mutexprof.sql脚本时遇到的问题,我发现里面的SLEEPS不再是累积,而是实时修改,这样mutexprof.sql的脚本 --//执行存在问题。 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. 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 * from x$mutex_sleep_history where mutex_identifier=287837530; SCOTT@book01p> SELECT COUNT(*) FROM T WHERE ID = 1 ;   COUNT(*) ----------          1 SCOTT@book01p> @ 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  2024-10-18 16:14:38    19771968 --//记下sql=5mr67th8kh3au,hash_value=287837530,然后避开其他因素,我重启数据库测试。 3.测试:  $ \zzdate;seq 20 | xargs -IQ -P 20 sqlplus scott/book@book01p @ m1.txt 1e6 > /dev/null;\zzdate trunc(sysdate)+16/24+20/1440+47/86400 == 2024/10/18 16:20:47 === 2024-10-18 16:20:47== "timestamp'2024-10-18 16:20:47'" trunc(sysdate)+16/24+22/1440+07/86400 == 2024/10/18 16:22:07 === 2024-10-18 16:22:07== "timestamp'2024-10-18 16:22:07'" SYS@book> @ m3.txt ADDR             INDX INST_ID CON_ID MUTEX_ADDR       MUTEX_IDENTIFIER SLEEP_TIMESTAMP            MUTEX_TYPE MUTEX_TYPE_ID     GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION_ID LOCATION                       MUTEX_VALUE ---------------- ---- ------- ------ ---------------- ---------------- -------------------------- ---------- ------------- -------- ------ ------------------ ---------------- ----------- ------------------------------ ---------------- 00007FBA49A99B28    9       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.906324 Cursor Pin             7 39844604      1                151              281           9 kksLockDelete [KKSCHLPIN6]     0000011900000004 00007FBA49A99C60   10       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.871089 Cursor Pin             7 39828068      1                150               26           3 kksfbc [KKSCHLFSP2]            0000001A00000001 00007FBA49A99D98   11       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.973587 Cursor Pin             7 39876924      1                149              398           9 kksLockDelete [KKSCHLPIN6]     0000018E00000004 00007FBA49A99ED0   12       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:05.974210 Cursor Pin             7 39381458      1                148              398           9 kksLockDelete [KKSCHLPIN6]     0000018E00000008 00007FBA49A9A008   13       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.503297 Cursor Pin             7 39646099      1                147               29           9 kksLockDelete [KKSCHLPIN6]     0000001D00000006 00007FBA49A998B8   20       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:07.248338 Cursor Pin             7 39985982      1                281               26           3 kksfbc [KKSCHLFSP2]            0000001A00000001 00007FBA49A999F0   21       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:05.926493 Cursor Pin             7 39356946      1                280              148           9 kksLockDelete [KKSCHLPIN6]     000000940000000C 00007FBA49A99B28   22       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:05.974183 Cursor Pin             7 39381458      1                279              398           3 kksfbc [KKSCHLFSP2]            0000018E00000008 00007FBA49A99C60   23       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.659299 Cursor Pin             7 39723202      1                278               29           9 kksLockDelete [KKSCHLPIN6]     0000001D00000008 00007FBA49A99D98   24       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:07.278975 Cursor Pin             7 39992938      1                277               26           3 kksfbc [KKSCHLFSP2]            0000001A00000000 00007FBA49A99B28   33       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.906319 Cursor Pin             7 39844604      1                403              281           3 kksfbc [KKSCHLFSP2]            0000011900000004 00007FBA49A99C60   34       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:04.246499 Cursor Pin             7 38504224      2                402              150           9 kksLockDelete [KKSCHLPIN6]     000000960000000C 00007FBA49A99D98   35       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.472489 Cursor Pin             7 39631542      1                401               29           3 kksfbc [KKSCHLFSP2]            0000001D00000006 00007FBA49A99ED0   36       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:05.140514 Cursor Pin             7 38959831      1                399              149           9 kksLockDelete [KKSCHLPIN6]     000000950000000E 00007FBA49A9A008   37       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:07.056237 Cursor Pin             7 39917943      1                398              149           9 kksLockDelete [KKSCHLPIN6]     0000009500000004 00007FBA49A999F0   58       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.786873 Cursor Pin             7 39786415      1                 29                0           9 kksLockDelete [KKSCHLPIN6]     0000000000000005 00007FBA49A99B28   59       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.104102 Cursor Pin             7 39445671      1                 28               24           9 kksLockDelete [KKSCHLPIN6]     0000001800000009 00007FBA49A99C60   60       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:07.236079 Cursor Pin             7 39981963      1                 26              281           3 kksfbc [KKSCHLFSP2]            0000011900000002 00007FBA49A99D98   61       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:05.623212 Cursor Pin             7 39204684      1                 25                0           9 kksLockDelete [KKSCHLPIN6]     0000000000000010 00007FBA49A99ED0   62       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.755218 Cursor Pin             7 39771165      1                 24              277           3 kksfbc [KKSCHLFSP2]            0000011500000005 20 rows selected. --//正好20个行,感觉应该出现40行才对,估计运行时间不够。 --//注意看sleeps列,仅仅出现1,2数值,而只有gets列是累积增加的。我没有按照SLEEP_TIMESTAMP排序。 --//而且看SLEEP_TIMESTAMP时间,基本接近程序结束的时间2024/10/18 16:22:07。 --//换一句话将以前x$mutex_sleep_history记录的信息更像是流水账,而现在实时更新里面的信息。 --//顺便提一下我以前自己写的脚本有问题,采用sum(gets),sum(sleeps),这样无形放大了gets,sleeps的数量。 --//再次运行测试: $ \zzdate;seq 20 | xargs -IQ -P 20 sqlplus scott/book@book01p @ m1.txt 1e6 > /dev/null;\zzdate trunc(sysdate)+16/24+31/1440+31/86400 == 2024/10/18 16:31:31 === 2024-10-18 16:31:31== "timestamp'2024-10-18 16:31:31'" trunc(sysdate)+16/24+32/1440+51/86400 == 2024/10/18 16:32:51 === 2024-10-18 16:32:51== "timestamp'2024-10-18 16:32:51'" SYS@book> @ m3.txt ADDR             INDX INST_ID CON_ID MUTEX_ADDR       MUTEX_IDENTIFIER SLEEP_TIMESTAMP            MUTEX_TYPE MUTEX_TYPE_ID     GETS SLEEPS REQUESTING_SESSION BLOCKING_SESSION LOCATION_ID LOCATION                       MUTEX_VALUE ---------------- ---- ------- ------ ---------------- ---------------- -------------------------- ---------- ------------- -------- ------ ------------------ ---------------- ----------- ------------------------------ ---------------- 00007FBA49A999F0    9       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.272496 Cursor Pin             7 79622561      1                152              282           3 kksfbc [KKSCHLFSP2]            0000011A0000000A 00007FBA49A99B28   10       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.533450 Cursor Pin             7 79753891      1                151               29           3 kksfbc [KKSCHLFSP2]            0000001D00000006 00007FBA49A99C60   11       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:51.204528 Cursor Pin             7 80011129      1                150              280           3 kksfbc [KKSCHLFSP2]            0000011800000001 00007FBA49A99D98   12       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:06.973587 Cursor Pin             7 39876924      1                149              398           9 kksLockDelete [KKSCHLPIN6]     0000018E00000004 00007FBA49A99ED0   13       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.737053 Cursor Pin             7 79853824      1                148              280           9 kksLockDelete [KKSCHLPIN6]     0000011800000006 00007FBA49A9A008   14       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.419470 Cursor Pin             7 79697742      1                147              278           9 kksLockDelete [KKSCHLPIN6]     0000011600000009 00007FBA49A99780   21       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.674697 Cursor Pin             7 79824064      1                282              148           3 kksfbc [KKSCHLFSP2]            0000009400000007 00007FBA49A998B8   22       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:49.972562 Cursor Pin             7 79471290      2                281               29           9 kksLockDelete [KKSCHLPIN6]     0000001D0000000A 00007FBA49A999F0   23       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:51.140114 Cursor Pin             7 79995303      1                280              150           9 kksLockDelete [KKSCHLPIN6]     0000009600000002 00007FBA49A99B28   24       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.456973 Cursor Pin             7 79716120      1                279              282           9 kksLockDelete [KKSCHLPIN6]     0000011A00000006 00007FBA49A99C60   25       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.904891 Cursor Pin             7 79929552      1                278              280           3 kksfbc [KKSCHLFSP2]            0000011800000002 00007FBA49A99D98   26       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:07.278975 Cursor Pin             7 39992938      1                277               26           3 kksfbc [KKSCHLFSP2]            0000001A00000000 00007FBA49A999F0   35       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:49.545363 Cursor Pin             7 79259791      2                403               29           9 kksLockDelete [KKSCHLPIN6]     0000001D00000008 00007FBA49A99B28   36       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.065868 Cursor Pin             7 79517951      1                402              278           3 kksfbc [KKSCHLFSP2]            0000011600000009 00007FBA49A99C60   37       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.904885 Cursor Pin             7 79929552      1                401              280           9 kksLockDelete [KKSCHLPIN6]     0000011800000002 00007FBA49A99D98   38       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.815225 Cursor Pin             7 79891822      1                400              280           3 kksfbc [KKSCHLFSP2]            0000011800000004 00007FBA49A99ED0   39       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:49.844326 Cursor Pin             7 79407915      1                399              402           9 kksLockDelete [KKSCHLPIN6]     000001920000000B 00007FBA49A9A008   40       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:07.056237 Cursor Pin             7 39917943      1                398              149           9 kksLockDelete [KKSCHLPIN6]     0000009500000004 00007FBA49A998B8   62       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.491494 Cursor Pin             7 79732732      1                 29              152           9 kksLockDelete [KKSCHLPIN6]     0000009800000008 00007FBA49A999F0   63       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:49.545387 Cursor Pin             7 79259791      1                 28               29           9 kksLockDelete [KKSCHLPIN6]     0000001D00000008 00007FBA49A99B28   64       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:50.814495 Cursor Pin             7 79891456      1                 27                0           9 kksLockDelete [KKSCHLPIN6]     0000000000000004 00007FBA49A99C60   65       1      0 00000000649AD2B8        287837530 2024-10-18 16:22:07.236079 Cursor Pin             7 39981963      1                 26              281           3 kksfbc [KKSCHLFSP2]            0000011900000002 00007FBA49A99D98   66       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:49.413471 Cursor Pin             7 79194407      1                 25              279           3 kksfbc [KKSCHLFSP2]            0000011700000009 00007FBA49A99ED0   67       1      0 00000000649AD2B8        287837530 2024-10-18 16:32:48.393100 Cursor Pin             7 78680357      1                 24               28           3 kksfbc [KKSCHLFSP2]            0000001C0000000D 24 rows selected. --//看SLEEP_TIMESTAMP时间,正是接近结束的时间2024/10/18 16:32:51。 --//这样tpt的mutexprof.sql脚本有点不再适用。 SYS@book> @ mutexprof id,loc "id=287837530" -- MutexProf by Tanel Poder (http://www.tanelpoder.com) -- Showing profile of top 20 sleeps...     SLEEPS  SLEEPS MUTEX_TYPE              ID GET_LOCATION                      OBJECT_NAME ---------- ------- --------------- ---------- --------------------------------- --------------------------------------------          2       1 Cursor Pin       287837530 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1 --//看到sleeps仅仅2,1.我当时仅仅觉得奇怪,并没有怀疑,当我在更加1个gets字段时,发现问题。 SYS@book> @ mutexprof id,gets,loc "id=287837530" -- MutexProf by Tanel Poder (http://www.tanelpoder.com) -- Showing profile of top 20 sleeps...     SLEEPS  SLEEPS MUTEX_TYPE              ID       GETS GET_LOCATION                      OBJECT_NAME ---------- ------- --------------- ---------- ---------- --------------------------------- -------------------------------------          2         Cursor Pin       287837530   79471290 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          2       1 Cursor Pin       287837530   79259791 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79622561 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79753891 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   80011129 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   39876924 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79853824 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79697742 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79824064 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79995303 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79716120 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79929552 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   39992938 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79517951 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79929552 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79891822 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79407915 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   39917943 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79732732 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530   79891456 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1 20 rows selected. --//看到sleeps比前面的多,这才发现问题,21c的x$mutex_sleep_history视图记录的信息已经发生了变化,不能在使用max(sleeps)的 --//显示,这样看到也许永远时1,2,而是改写sum(sleeps),比较准确。 --//我做了修改,并且加入了mutex_addr地址显示,取消如下注解。 , decode(max(gets)-min(gets),0,to_number(null),max(gets)-min(gets)) mutexprof_gets -- may not be very accurate but give an idea SYS@book> @ mutexprof id,loc "id=287837530" -- MutexProf by Tanel Poder (http://www.tanelpoder.com) -- Showing profile of top 20 sleeps...     SLEEPS  SLEEPS MUTEX_TYPE              ID GET_LOCATION                      OBJECT_NAME ---------- ------- --------------- ---------- --------------------------------- ------------------------------------          2       1 Cursor Pin       287837530 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1         Cursor Pin       287837530 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1 SYS@book> @ mutexprofz id,loc "id=287837530" -- MutexProf by Tanel Poder (http://www.tanelpoder.com) -- Showing profile of top 20 sleeps... SUM_SLEEPS           GETS MUTEX_TYPE              ID GET_LOCATION                      OBJECT_NAME ---------- -------------- --------------- ---------- --------------------------------- -----------------------------------         15       40118379 Cursor Pin       287837530 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1         11       40029166 Cursor Pin       287837530 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1 --//这样看到sleeps也是仅仅作为参考,因为前面的记录已经不存在了。显示max(gets)-min(gets)也是作为参考。 --//注意看即使这样,看到的SUM_SLEEPS也是非常小,根据这个判断有可能存在问题。 SYS@book> @ mutexprofz id,gets,loc "id=287837530" -- MutexProf by Tanel Poder (http://www.tanelpoder.com) -- Showing profile of top 20 sleeps... SUM_SLEEPS           GETS MUTEX_TYPE              ID       GETS GET_LOCATION                      OBJECT_NAME ---------- -------------- --------------- ---------- ---------- --------------------------------- ------------------------------------          3                Cursor Pin       287837530   79259791 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          2                Cursor Pin       287837530   79471290 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79622561 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79753891 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   80011129 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   39876924 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~                  1                Cursor Pin       287837530   79853824 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79697742 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79824064 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79995303 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79716120 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79929552 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   39992938 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~                  1                Cursor Pin       287837530   79517951 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79929552 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79891822 kksfbc [KKSCHLFSP2]               SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79407915 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   39917943 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79732732 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1          1                Cursor Pin       287837530   79891456 kksLockDelete [KKSCHLPIN6]        SELECT COUNT(*) FROM T WHERE ID = 1 20 rows selected. --//第2列的gets显示为null实际是0,前面SUM_SLEEPS非常小。 --//是否可以以第2列desc排序显示,我发现也不行,看下划线行gets比其它小很多。 --//这样导致前面看到gets很多,如果没有下划线2行,第2列gets的数量会很小,也就是不能以gets的变化作为判断。 --//也许查询加入ts>= sysdate -1 /1440 之类的条件对于诊断有一定的帮助。 --//另外我加入mutex_addr列,能够具体知道mutex的位置。 SYS@book> @ mutexprofz id,maddr "id=287837530" -- MutexProf by Tanel Poder (http://www.tanelpoder.com) -- Showing profile of top 20 sleeps... SUM_SLEEPS           GETS MUTEX_TYPE              ID mutex_addr           OBJECT_NAME ---------- -------------- --------------- ---------- -------------------- --------------------------------------------------------------------------------         26       40134205 Cursor Pin       287837530 00000000649AD2B8     SELECT COUNT(*) FROM T WHERE ID = 1 SYS@book> @ fchaz 00000000649AD2B8 GET_LOCATION                      KSMCHPTR           KSMCHIDX   KSMCHDUR KSMCHCOM           KSMCHSIZ KSMCHCLS   KSMCHTYP KSMCHPAR         KSMCHPTR_BEGIN   KSMCHPTR_END+1 --------------------------------- ---------------- ---------- ---------- ---------------- ---------- -------- ---------- ---------------- ---------------- ----------------- SGA                               00000000649ACB08          1          1 KGLH0^11280d5a         4096 recr           4095 00000000649ADB78 00000000649ACB08 00000000649ADB08 SYS@book> @ sharepool/shp4 '' 287837530 HANDLE_TYPE            KGLHDADR         KGLHDPAR         C40                                        KGLHDLMD   KGLHDPMD   KGLHDIVC KGLOBHD0         KGLOBHD6           KGLOBHS0   KGLOBHS6   KGLOBT16   N0_6_16        N20   KGLNAHSH KGLOBT03        KGLOBT09 ---------------------- ---------------- ---------------- ---------------------------------------- ---------- ---------- ---------- ---------------- ---------------- ---------- ---------- ---------- --------- ---------- ---------- ------------- ---------- child handle address   00000000649AC5D8 00000000649ADD38 SELECT COUNT(*) FROM T WHERE ID = 1               0          0          0 00000000649AC418 00000000649AD360       8128      12128       3301     23557      23557  287837530 5mr67th8kh3au          0 parent handle address  00000000649ADD38 00000000649ADD38 SELECT COUNT(*) FROM T WHERE ID = 1               0          0          0 00000000649ADB78 00                     4064          0          0      4064       4064  287837530 5mr67th8kh3au      65535 SYS@book> @ ksmsp 00000000649ADB78 '' GET_LOCATION                      KSMCHPTR           KSMCHIDX   KSMCHDUR KSMCHCOM           KSMCHSIZ KSMCHCLS   KSMCHTYP KSMCHPAR         KSMCHPTR_BEGIN   KSMCHPTR_END+1    HEAP_DESC --------------------------------- ---------------- ---------- ---------- ---------------- ---------- -------- ---------- ---------------- ---------------- ----------------- ------------------------- SGA                               00000000649ADB08          1          1 KGLDA                   512 freeabl           0 00               00000000649ADB08 00000000649ADD08 SGA                               00000000649ACB08          1          1 KGLH0^11280d5a         4096 recr           4095 00000000649ADB78 00000000649ACB08 00000000649ADB08  KSMCHPAR=00000000649ADB78 --//可以发现mutex_addr=00000000649AD2B8在父堆0里面。 SYS@book> select max(gets) from x$mutex_sleep_history where MUTEX_IDENTIFIER =287837530; MAX(GETS) ----------   80011129 --//80011129 = 0x4c4df79 SYS@book> @ opeek 00000000649AD2B8 32 1 New tracefile_identifier = /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_4208_0001.trc Statement processed. [0649AD2B8, 0649AD2D8) = 00000000 00000000 04C55EAC 0000D2E8 11280D5A 00000000 00000000 00000000 --//而现在记录在mutex结构里面的明显是x04C55EAC = 80043692。不知道那个是sleep字段,以前的可以猜测出来。 --//而记录在x$mutex_sleep是汇总信息。 SYS@book> select * from x$mutex_sleep; ADDR                   INDX    INST_ID     CON_ID MUTEX_TYPE    MUTEX_TYPE_ID LOCATION_ID LOCATION                           SLEEPS  WAIT_TIME ---------------- ---------- ---------- ---------- ------------- ------------- ----------- ------------------------------ ---------- ---------- 00007FBA495BEF58          0          1          0 Row Cache                 3          19 [19] kqrpre                             1       2124 00007FBA495BEFF0          1          1          0 Row Cache                 3          14 [14] kqrScan                            1         10 00007FBA495BF088          2          1          0 Row Cache                 3          10 [10] kqreqd                             1          4 00007FBA495BED90          3          1          0 Library Cache             4         119 kglUpgradeLock 119                      1         27 00007FBA495BEE28          4          1          0 Library Cache             4         106 kglhdgn2 106                            1          8 00007FBA495BEEC0          5          1          0 Library Cache             4          90 kglpnal1  90                            1          6 00007FBA495BEF58          6          1          0 Library Cache             4          57 kgllkc1   57                            1         10 00007FBA495BEFF0          7          1          0 Library Cache             4           4 kglpin1   4                             1         10 00007FBA495BF088          8          1          0 Library Cache             4           2 kglget2   2                             1        695 00007FBA495BEF58          9          1          0 Cursor Pin                7           9 kksLockDelete [KKSCHLPIN6]          35250  524978637 00007FBA495BEFF0         10          1          0 Cursor Pin                7           5 kkslce [KKSCHLPIN2]                   191     543489 00007FBA495BF088         11          1          0 Cursor Pin                7           3 kksfbc [KKSCHLFSP2]                 18728  282584102 12 rows selected. --//D2E8 = 53992 --//35250+18728  = 317816 = 0x4d978,我记忆sleeps记录仅仅2个字节,前面的4溢出。 SYS@book>  oradebug poke 0x00000000649AD2B8 8 0x0000012700000127 ORA-32519: insufficient privileges to execute ORADEBUG command: execution of ORADEBUG commands is disabled for this instance SYS@book01p> @ ashtop event,sid,sql_id,p1hex,p2hex,p3hex "event like 'cursor%'"  trunc(sysdate)+16/24+31/1440+31/86400 trunc(sysdate)+16/24+32/1440+51/86400     Total                                                                                                                                                    Distinct Distinct    Distinct   Seconds     AAS %This   EVENT            SID SQL_ID        P1HEX             P2HEX             P3HEX             FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1 --------- ------- ------- ------------- ------ ------------- ----------------- ----------------- ----------------- ------------------- ------------------- ---------- -------- -----------         2      .0    0% | cursor: pin S     25                0000000011280D5A  0000011A0000000E  0000000900000000 2024-10-18 16:32:17 2024-10-18 16:32:31          1        2           2         2      .0    0% | cursor: pin S     25                0000000011280D5A  000001900000000F  0000000900000000 2024-10-18 16:32:23 2024-10-18 16:32:34          1        2           2         2      .0    0% | cursor: pin S    147 5mr67th8kh3au  0000000011280D5A  000001910000000D  0000000300000000 2024-10-18 16:32:23 2024-10-18 16:32:40          1        2           2         2      .0    0% | cursor: pin S    148 5mr67th8kh3au  0000000011280D5A  0000001D00000008  0000000300000000 2024-10-18 16:32:49 2024-10-18 16:32:50          1        2           2         2      .0    0% | cursor: pin S    151                0000000011280D5A  0000011A0000000E  0000000900000000 2024-10-18 16:32:17 2024-10-18 16:32:31          1        2           2         2      .0    0% | cursor: pin S    152                0000000011280D5A  0000011A0000000E  0000000900000000 2024-10-18 16:32:17 2024-10-18 16:32:31          1        2           2         2      .0    0% | cursor: pin S    278                0000000011280D5A  000000980000000F  0000000900000000 2024-10-18 16:31:34 2024-10-18 16:32:00          1        2           2         2      .0    0% | cursor: pin S    278                0000000011280D5A  0000011A0000000E  0000000900000000 2024-10-18 16:32:17 2024-10-18 16:32:31          1        2           2         2      .0    0% | cursor: pin S    279                0000000011280D5A  0000011A0000000E  0000000900000000 2024-10-18 16:32:17 2024-10-18 16:32:31          1        2           2         2      .0    0% | cursor: pin S    279                0000000011280D5A  000001900000000A  0000000900000000 2024-10-18 16:32:04 2024-10-18 16:32:16          1        2           2         2      .0    0% | cursor: pin S    400 5mr67th8kh3au  0000000011280D5A  0000011A0000000E  0000000300000000 2024-10-18 16:32:26 2024-10-18 16:32:31          1        2           2         2      .0    0% | cursor: pin S    400                0000000011280D5A  000000970000000C  0000000900000000 2024-10-18 16:32:39 2024-10-18 16:32:48          1        2           2         2      .0    0% | cursor: pin S    401                0000000011280D5A  000000930000000D  0000000900000000 2024-10-18 16:31:55 2024-10-18 16:32:27          1        2           2         2      .0    0% | cursor: pin S    401                0000000011280D5A  0000011600000010  0000000900000000 2024-10-18 16:32:15 2024-10-18 16:32:34          1        2           2         2      .0    0% | cursor: pin S    402                0000000011280D5A  000000000000000D  0000000900000000 2024-10-18 16:32:01 2024-10-18 16:32:25          1        2           2         2      .0    0% | cursor: pin S    402                0000000011280D5A  0000011A0000000E  0000000900000000 2024-10-18 16:32:17 2024-10-18 16:32:31          1        2           2         2      .0    0% | cursor: pin S    403 5mr67th8kh3au  0000000011280D5A  000000180000000D  0000000300000000 2024-10-18 16:31:50 2024-10-18 16:32:11          1        2           2         1      .0    0% | cursor: pin S     24 5mr67th8kh3au  0000000011280D5A  0000001B0000000B  0000000300000000 2024-10-18 16:32:20 2024-10-18 16:32:20          1        1           1         1      .0    0% | cursor: pin S     24 5mr67th8kh3au  0000000011280D5A  0000001C00000009  0000000300000000 2024-10-18 16:31:51 2024-10-18 16:31:51          1        1           1         1      .0    0% | cursor: pin S     24 5mr67th8kh3au  0000000011280D5A  0000001C0000000F  0000000300000000 2024-10-18 16:32:12 2024-10-18 16:32:12          1        1           1         1      .0    0% | cursor: pin S     24 5mr67th8kh3au  0000000011280D5A  000000940000000A  0000000300000000 2024-10-18 16:31:44 2024-10-18 16:31:44          1        1           1         1      .0    0% | cursor: pin S     24 5mr67th8kh3au  0000000011280D5A  000001180000000C  0000000300000000 2024-10-18 16:31:43 2024-10-18 16:31:43          1        1           1         1      .0    0% | cursor: pin S     24 5mr67th8kh3au  0000000011280D5A  0000011A0000000E  0000000300000000 2024-10-18 16:32:17 2024-10-18 16:32:17          1        1           1         1      .0    0% | cursor: pin S     24 5mr67th8kh3au  0000000011280D5A  0000011A0000000F  0000000300000000 2024-10-18 16:32:26 2024-10-18 16:32:26          1        1           1         1      .0    0% | cursor: pin S     24 5mr67th8kh3au  0000000011280D5A  000001910000000C  0000000300000000 2024-10-18 16:31:50 2024-10-18 16:31:50          1        1           1         1      .0    0% | cursor: pin S     24                0000000011280D5A  000000190000000D  0000000900000000 2024-10-18 16:32:27 2024-10-18 16:32:27          1        1           1         1      .0    0% | cursor: pin S     24                0000000011280D5A  0000001B0000000A  0000000900000000 2024-10-18 16:31:52 2024-10-18 16:31:52          1        1           1         1      .0    0% | cursor: pin S     24                0000000011280D5A  0000001C0000000D  0000000900000000 2024-10-18 16:32:14 2024-10-18 16:32:14          1        1           1         1      .0    0% | cursor: pin S     24                0000000011280D5A  0000001D00000012  0000000900000000 2024-10-18 16:31:54 2024-10-18 16:31:54          1        1           1         1      .0    0% | cursor: pin S     24                0000000011280D5A  000000940000000F  0000000900000000 2024-10-18 16:31:46 2024-10-18 16:31:46          1        1           1 30 rows selected. --//也许使用ashtop更好分析诊断。 SYS@book01p> @ ashtop event 1=1  trunc(sysdate)+16/24+31/1440+31/86400 trunc(sysdate)+16/24+32/1440+51/86400     Total                                                                                                      Distinct Distinct    Distinct   Seconds     AAS %This   EVENT                                      FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1 --------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------      1052    13.2   68% |                                            2024-10-18 16:31:31 2024-10-18 16:32:50        572       80         647       503     6.3   32% | cursor: pin S                              2024-10-18 16:31:33 2024-10-18 16:32:50          1       74          74         2      .0    0% | log file sync                              2024-10-18 16:31:31 2024-10-18 16:31:31          1        1           1         1      .0    0% | library cache lock                         2024-10-18 16:31:31 2024-10-18 16:31:31          1        1           1 4.附上我修改的脚本: $ cat 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 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... 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           , 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 /

相关推荐