[20250521]生产系统表没有分析统计信息出现的问题(21c).txt
[20250521]生产系统表没有分析统计信息出现的问题(21c).txt
--//oracle 19c的生产系统有几个表没有分析统计信息遇到的问题,实际上最主要的原因是涉及到的sql语句没有使用绑定变量,导致大
--//量sql语句动态分析取样出现的情况,在测试环境21c做一个测试说明问题。
1.环境:
SCOTT@book01p> @ ver2
==============================
PORT_STRING : x86_64/Linux 2.4.xx
VERSION : 21.0.0.0.0
BANNER : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
BANNER_FULL : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
Version 21.3.0.0.0
BANNER_LEGACY : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
CON_ID : 0
PL/SQL procedure successfully completed.
2.测试环境建立:
SCOTT@book01p> create table t1 as select mod(rownum,1e4) id ,'test' vc from dual connect by level<=1e6;
Table created.
SCOTT@book01p> create index i_t1_id on t1(id);
Index created.
--//注意不要分析表,建立索引不能唯一,否则不会执行动态取样。
--//注意21c支持这类插入自动分析表,受参数_optimizer_gather_stats_on_load=TRUE的影响。
--//执行如下可以删除表统计信息。
SCOTT@book01p> execute sys.dbms_stats.delete_table_stats ('SCOTT', 'T1',cascade_columns=> false,cascade_indexes=>false,cascade_parts=>false,no_invalidate=> false);
PL/SQL procedure successfully completed.
--//注:我仅仅删除表信息,其他索引,字段的统计信息保留,这样比较符合生产系统看到的情况.
--//没有表统计信息,主要原因是禁止了晚上auto optimizer stats collection.
SCOTT@book01p> @ sosiz scott t1
**********************************
Table Level 参数 schema tablename
**********************************
Table Number Empty Average Chain Average Global User Sample
Name of Rows Blocks Blocks Space Count Row Len Stats Stats Size LAST_ANALYZED
--------------- -------------- ------------ ------------ -------- -------- -------- ------ ------ -------------- -------------------
T1 NO NO
Column Column Distinct Number Number Global User Sample
Name Details Values Density Buckets Nulls Stats Stats Size LAST_ANALYZED HISTOGRAM
------------------------- ------------------------ ------------ ----------- ------- ---------- ------ ------ -------------- ------------------- ---------------
ID NUMBER(22) 1,000,000 0.00000100 1 0 YES NO 1,000,000 2025-05-21 15:46:05 NONE
VC CHAR(4) 1 1.00000000 1 0 YES NO 1,000,000 2025-05-21 15:46:05 NONE
B Average Average
Index Tree Leaf Distinct Number Leaf Blocks Data Blocks Cluster Global User Sample
Name Unique Level Blks Keys of Rows Per Key Per Key Factor Stats Stats Size LAST_ANALYZED
------------------------- --------- ----- ------ -------------- -------------- ----------- ----------- ------------ ------ ------ -------------- -------------------
I_T1_ID NONUNIQUE 2 2226 1,000,000 1,000,000 1 1 2,074 YES NO 1,000,000 2025-05-21 15:49:46
Index Column Col Column
Name Name Pos Details
------------------------- ------------------------- ---- ------------------------
I_T1_ID ID 1 NUMBER(22)
***************
Partition Level
***************
***************
SubPartition Level
***************
$ cat loope.txt
set verify off
DECLARE
l_count PLS_INTEGER;
BEGIN
FOR i IN 1..&&1
LOOP
EXECUTE IMMEDIATE 'Select /*+ &2 */ count(*) from t1 where id = ' || i INTO l_count ;
END LOOP;
END;
/
--//注:执行的SQL语句使用文字变量,如果参数2在不相同,这样每个会话不同执行的sql语句都是硬解析。
--//create table job_times (sid number, time_ela number,method varchar2(20));
$ cat record.txt
--// arg1 = loop counts , arg2 = method , arg3= test scirpt
set verify off
variable v_method varchar2(20)
exec :v_method := (case when '&2' >= '1' and '&2'<='9999' then 'QQQQ' else '&2' end);
define t=&&1;
column 3 new_value 3;
select decode('&3',null,'loop.txt','&&3') "3" from dual;
@@ &&3 5 &&2
--//insert into job_times values ( sys_context ('userenv', 'sid') ,dbms_utility.get_time ,:v_method) ;
--//commit ;
@@ &&3 &&t &&2
--//update job_times set time_ela = dbms_utility.get_time - time_ela where sid=sys_context ('userenv', 'sid') and method= :v_method;
--//commit;
quit
3.测试:
$ zzdate ; seq 5 | xargs -IQ -P 5 sqlplus -s -l scott/book@book01p @record.txt 1e6 Q loope.txt > /dev/null ; zzdate
trunc(sysdate)+15/24+51/1440+30/86400 1747813890.819470149
--//参数2使用Q代替,这样每个会话执行的sql语句都不同,相当于产生大量的文字变量的sql语句。
4.不等执行完成开始分析:
SYS@book> host sleep 300
SYS@book> @ ashtop event 1=1 trunc(sysdate)+15/24+51/1440+30/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
2527 2.2 43% | 2025-05-21 15:51:31 2025-05-21 16:10:50 18 1158 1174
2095 1.8 36% | enq: RC - Result Cache: Contention 2025-05-21 15:51:31 2025-05-21 16:10:50 1 868 868
1040 .9 18% | latch: shared pool 2025-05-21 15:51:35 2025-05-21 16:10:50 3 517 423
104 .1 2% | latch free 2025-05-21 15:52:17 2025-05-21 16:10:49 1 75 75
28 .0 0% | library cache: bucket mutex X 2025-05-21 15:52:04 2025-05-21 16:09:23 3 11 12
12 .0 0% | library cache: mutex X 2025-05-21 15:57:17 2025-05-21 16:10:33 2 12 12
7 .0 0% | latch: enqueue hash chains 2025-05-21 15:56:36 2025-05-21 16:06:17 1 4 4
3 .0 0% | control file parallel write 2025-05-21 16:04:33 2025-05-21 16:05:47 1 3 3
3 .0 0% | db file sequential read 2025-05-21 15:57:43 2025-05-21 16:03:52 3 3 3
3 .0 0% | row cache mutex 2025-05-21 15:51:34 2025-05-21 15:51:58 1 2 2
1 .0 0% | cursor: pin S 2025-05-21 15:57:28 2025-05-21 15:57:28 1 1 1
1 .0 0% | log file parallel write 2025-05-21 16:03:52 2025-05-21 16:03:52 1 1 1
12 rows selected.
--//可以发现开始等待事件并不是latch: shared pool排在第一,而是enq: RC - Result Cache: Contention.
SYS@book> @ ashtop sql_id,p1raw "event='enq: RC - Result Cache: Contention'" trunc(sysdate)+15/24+51/1440+30/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID P1RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ----------------- ------------------- ------------------- ---------- -------- -----------
1 .0 0% | 008zvgdw25qs9 0000000052430004 2025-05-21 15:53:37 2025-05-21 15:53:37 1 1 1
1 .0 0% | 01ab447knd8tm 0000000052430004 2025-05-21 15:53:12 2025-05-21 15:53:12 1 1 1
1 .0 0% | 02mt2ux61664y 0000000052430004 2025-05-21 15:52:04 2025-05-21 15:52:04 1 1 1
1 .0 0% | 03uf8zd6kkasy 0000000052430004 2025-05-21 15:54:23 2025-05-21 15:54:23 1 1 1
1 .0 0% | 040an7spr2pac 0000000052430004 2025-05-21 15:51:40 2025-05-21 15:51:40 1 1 1
1 .0 0% | 04tw3f4xnzwva 0000000052430004 2025-05-21 15:54:02 2025-05-21 15:54:02 1 1 1
...
--//查询sql_id已经不在共享池.基本都是执行1次的语句,如果扫描共享池按照执行次数倒排序,可以发现大量执行语句如下:
SYS@book> @ sql_id fbmkq644v60zw
-- SQL_ID = fbmkq644v60zw come from shared pool
SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE RESULT_CACHE(SNAPSHOT=3600) opt_param('parallel_execution_enabled', 'false') NO_PARALLEL(SAMPLESUB) NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1") FROM (SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL("T1") FULL("T1") NO_PARALLEL_INDEX("T1") */ :"SYS_B_2" AS C1, CASE WHEN "T1"."ID"=:"SYS_B_3" THEN :"SYS_B_4" ELSE :"SYS_B_5" END AS C2 FROM "SCOTT"."T1" SAMPLE BLOCK (:"SYS_B_6" , :"SYS_B_7") SEED (:"SYS_B_8") "T1") SAMPLESUB;
SYS@book> @ sql_id 4bm5p8sahp9js
-- SQL_ID = 4bm5p8sahp9js come from shared pool
SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS RESULT_CACHE(SNAPSHOT=3600) opt_param('parallel_execution_enabled', 'false') NO_PARALLEL(SAMPLESUB) NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1"), NVL(SUM(C3),:"SYS_B_2") FROM (SELECT /*+ NO_PARALLEL("T1") INDEX("T1" I_T1_ID) NO_PARALLEL_INDEX("T1") */ :"SYS_B_3" AS C1, :"SYS_B_4" AS C2, :"SYS_B_5" AS C3 FROM "SCOTT"."T1" "T1" WHERE "T1"."ID"=:"SYS_B_6" AND ROWNUM <= :"SYS_B_7") SAMPLESUB;
--//也就是每次执行取样都是执行以上sql语句,而注意提示加入RESULT_CACHE(SNAPSHOT=3600),这样的结果导致Result Cache Contention.
--//出现latch: shared pool是很自然的,上面执行的sql语句每次执行都是硬解析.
--//继续看latch free 等待事件.
SYS@book> @ ashtop p1raw,p2raw,p3raw "event='latch free'" trunc(sysdate)+15/24+51/1440+30/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This P1RAW P2RAW P3RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ----------------- ----------------- ----------------- ------------------- ------------------- ---------- -------- -----------
83 .1 100% | 000000006CF72120 000000000000034E 0000000000000001 2025-05-21 15:52:17 2025-05-21 16:06:41 1 61 61
SYS@book> @ la 000000006CF72120
ADDR LATCH# CHLD NAME GETS IGETS MISSES IMISSES SPINGETS SLEEPS WAIT_TIME
---------------- ---------- ------ --------------------------------------------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
000000006CF72120 846 1 Result Cache: RC Latch 5955359 0 575464 0 406981 170445 80482658
--//还是关联Result Cache,也就是在释放时也存在小量阻塞的情况.
--//继续看library cache: bucket mutex X等待事件.
SYS@book> @ ashtop event,p1raw "event like 'library cache:%'" trunc(sysdate)+15/24+51/1440+30/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ----------------- ------------------- ------------------- ---------- -------- -----------
26 .0 35% | library cache: bucket mutex X 0000000000011BA3 2025-05-21 15:52:04 2025-05-21 16:20:37 1 10 10
22 .0 29% | library cache: mutex X 00000000CA14AC19 2025-05-21 15:57:17 2025-05-21 16:20:58 1 16 16
15 .0 20% | library cache: bucket mutex X 00000000000119C7 2025-05-21 15:53:12 2025-05-21 16:19:04 3 6 7
5 .0 7% | library cache: mutex X 00000000A6411BA3 2025-05-21 16:04:37 2025-05-21 16:20:37 2 4 4
3 .0 4% | library cache: mutex X 000000001C1D19C7 2025-05-21 16:02:14 2025-05-21 16:18:06 3 3 3
1 .0 1% | library cache: bucket mutex X 000000000000EC2A 2025-05-21 16:12:01 2025-05-21 16:12:01 1 1 1
1 .0 1% | library cache: bucket mutex X 000000000001A8D3 2025-05-21 15:57:51 2025-05-21 15:57:51 1 1 1
1 .0 1% | library cache: mutex X 000000003726D9E7 2025-05-21 16:17:37 2025-05-21 16:17:37 1 1 1
1 .0 1% | library cache: mutex X 00000000ABDD8C76 2025-05-21 16:18:30 2025-05-21 16:18:30 1 1 1
9 rows selected.
--//因为每次都是硬解析,这样每次都要反复一些对象,导致出现library cache: bucket mutex X.很容易猜测集中在表,owner,实例
--//等对象上.因为enq: RC - Result Cache: Contention排在第一,反而访问这些对象的等待事件不是很明显.
--//注:如果在11g测试,不会出现enq: RC - Result Cache: Contention等待事件,library cache: bucket mutex X在oracle不存在,实
--//际上11g标识为library cache: mutex X,出现这样的情况注意看P1的值是否小于2^17 = 131072时,有可能是在library cache: bucket
--//mutex.
--//注意看p1raw 对于 library cache: mutex X 对于的hash值,对于library cache: bucket mutex X 取的是对象的hash值 取模2^17.
--//比如 0000000000011BA3 00000000A6411BA3 后面的4位相同.看看是那些对象.
SYS@book> @ kglob '' 00000000CA14AC19 '' ''
==============================
INST_ID : 1
OWNER : SCOTT
NAME : T1
DB_LINK :
NAMESPACE : TABLE/PROCEDURE
TYPE : TABLE
NAMESPACE_NUM : 1
NAMESPACE_HEX : 1
SHARABLE_MEM : 4064
PERSISTENT_MEM : 0
RUNTIME_MEM : 0
LOADS : 3
EXECUTIONS : 0
LOCKS : 5
PINS : 0
KEPT : NO
CHILD_LATCH : 44057
INVALIDATIONS : 0
HASH_VALUE : 3390352409
HASH_HEX : ca14ac19
LOCK_MODE : SHARED
PIN_MODE : SHARED
STATUS : VALID
TIMESTAMP : 2025-05-21/15:41:11
PREVIOUS_TIMESTAMP :
LOCKED_TOTAL : 2844128
PINNED_TOTAL : 2844118
PROPERTY :
FULL_HASH_VALUE : 3a7f3c628eea956aa98d1395ca14ac19
CON_ID : 3
CON_NAME : BOOK01P
ADDR : 0000000063BAE4D8
PAR_ADDR : 0000000063BAE4D8
HANDLE_TYPE : parent handle address
KGLOBHD0 : 00000000618CB830
KGLOBHD6 : 00
EDITION :
SQL_ID :
OBJECT_STR : T1.SCOTT.BOOK01P\x1\0\0\0
PL/SQL procedure successfully completed.
--//表T1.
SYS@book> @ kglob '' 000000001C1D19C7 '' ''
==============================
INST_ID : 1
OWNER : SYS
NAME : 1073777561
DB_LINK :
NAMESPACE : DBINSTANCE
TYPE : CURSOR
NAMESPACE_NUM : 74
NAMESPACE_HEX : 4a
SHARABLE_MEM : 0
PERSISTENT_MEM : 0
RUNTIME_MEM : 0
LOADS : 0
EXECUTIONS : 0
LOCKS : 4
PINS : 0
KEPT : NO
CHILD_LATCH : 72135
INVALIDATIONS : 0
HASH_VALUE : 471669191
HASH_HEX : 1c1d19c7
LOCK_MODE : SHARED
PIN_MODE : NONE
STATUS : UNKOWN
TIMESTAMP :
PREVIOUS_TIMESTAMP :
LOCKED_TOTAL : 8705557
PINNED_TOTAL : 0
PROPERTY :
FULL_HASH_VALUE : 25d8c2e2a1f8d5e74176b9b61c1d19c7
CON_ID : 1
CON_NAME : CDB$ROOT
ADDR : 000000006CF7FC50
PAR_ADDR : 000000006CF7FC50
HANDLE_TYPE : parent handle address
KGLOBHD0 : 00
KGLOBHD6 : 00
EDITION :
SQL_ID :
OBJECT_STR : 1073777561.SYS.CDB$ROOT\x4a\0\0\0
PL/SQL procedure successfully completed.
--//pdb=book01 的dbid。
SYS@book> select con_id,dbid,name from v$pdbs;
CON_ID DBID NAME
---------- ---------- ------------------------------
2 2763294012 PDB$SEED
3 1073777561 BOOK01P
SYS@book> @ kglob '' 00000000A6411BA3 '' ''
==============================
INST_ID : 1
OWNER : SYS
NAME : book
DB_LINK :
NAMESPACE : DBINSTANCE
TYPE : CURSOR
NAMESPACE_NUM : 74
NAMESPACE_HEX : 4a
SHARABLE_MEM : 0
PERSISTENT_MEM : 0
RUNTIME_MEM : 0
LOADS : 0
EXECUTIONS : 0
LOCKS : 5
PINS : 0
KEPT : NO
CHILD_LATCH : 72611
INVALIDATIONS : 0
HASH_VALUE : 2789284771
HASH_HEX : a6411ba3
LOCK_MODE : SHARED
PIN_MODE : NONE
STATUS : UNKOWN
TIMESTAMP :
PREVIOUS_TIMESTAMP :
LOCKED_TOTAL : 9046637
PINNED_TOTAL : 0
PROPERTY :
FULL_HASH_VALUE : b885bb910059a4d2fdbfc245a6411ba3
CON_ID : 1
CON_NAME : CDB$ROOT
ADDR : 0000000072550A58
PAR_ADDR : 0000000072550A58
HANDLE_TYPE : parent handle address
KGLOBHD0 : 00
KGLOBHD6 : 00
EDITION :
SQL_ID :
OBJECT_STR : book.SYS.CDB$ROOT\x4a\0\0\0
PL/SQL procedure successfully completed.
--//实例book.
SYS@book> @ kglob '' 000000003726D9E7 '' ''
==============================
INST_ID : 1
OWNER :
NAME : SCOTT
DB_LINK :
NAMESPACE : SCHEMA
TYPE : NONE
NAMESPACE_NUM : 73
NAMESPACE_HEX : 49
SHARABLE_MEM : 0
PERSISTENT_MEM : 0
RUNTIME_MEM : 0
LOADS : 0
EXECUTIONS : 0
LOCKS : 11
PINS : 0
KEPT : NO
CHILD_LATCH : 55783
INVALIDATIONS : 0
HASH_VALUE : 925293031
HASH_HEX : 3726d9e7
LOCK_MODE : SHARED
PIN_MODE : NONE
STATUS : UNKOWN
TIMESTAMP :
PREVIOUS_TIMESTAMP :
LOCKED_TOTAL : 3195263
PINNED_TOTAL : 0
PROPERTY :
FULL_HASH_VALUE : 46bd45166adbb098d6fef7ce3726d9e7
CON_ID : 3
CON_NAME : BOOK01P
ADDR : 0000000063CA42D8
PAR_ADDR : 0000000063CA42D8
HANDLE_TYPE : parent handle address
KGLOBHD0 : 00
KGLOBHD6 : 00
EDITION :
SQL_ID :
OBJECT_STR : SCOTT
PL/SQL procedure successfully completed.
--//schema或者owner.
--//可以想象如果生产系统,一般使用几个schema,正好涉及到的这些表没有统计分析,而语句存在大量文字变量,出现上面的情况正常不过.
--//注:我开启的会话仅仅5个,如果相关library cache: bucket mutex X,library cache: mutex X没有出现,增加会话数量.
--//才想起前一段时间遇到的问题,第三方安装的数据库设置result_cache_max_size=0.测试看看.
SYS@book> show parameter result_cache_max_size
PARAMETER_NAME TYPE VALUE
--------------------- ----------- ------
result_cache_max_size big integer 5M
SYS@book> alter system set result_cache_max_size=0 scope=spfile;
System altered.
5.测试result_cache_max_size=0的情况.
--//重启数据库略.
SYS@book> show parameter result_cache_max_size
PARAMETER_NAME TYPE VALUE
--------------------- ----------- -----
result_cache_max_size big integer 0
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @record.txt 1e6 Q loope.txt > /dev/null ; zzdate
trunc(sysdate)+16/24+38/1440+19/86400 1747816699.970865672
--//增加会话数量,不然library cache相关事件不容易抓取到.
SYS@book> @ ashtop event 1=1 trunc(sysdate)+16/24+38/1440+19/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
935 11.5 59% | latch: shared pool 2025-05-21 16:38:22 2025-05-21 16:39:39 6 77 82
565 7.0 36% | 2025-05-21 16:38:20 2025-05-21 16:39:39 9 79 87
42 .5 3% | library cache: mutex X 2025-05-21 16:38:23 2025-05-21 16:39:35 2 9 10
25 .3 2% | library cache: bucket mutex X 2025-05-21 16:38:32 2025-05-21 16:39:35 5 3 7
4 .0 0% | latch: call allocation 2025-05-21 16:38:33 2025-05-21 16:38:33 1 1 1
4 .0 0% | library cache load lock 2025-05-21 16:38:20 2025-05-21 16:38:20 1 1 1
3 .0 0% | row cache mutex 2025-05-21 16:38:30 2025-05-21 16:39:28 1 3 3
7 rows selected.
--//因为设置result_cache_max_size=0,相当于关闭result cache,导致latch: shared pool排在第一.
SYS@book> @ ashtop event,p1raw "event like 'library cache:%'" trunc(sysdate)+16/24+38/1440+19/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ----------------- ------------------- ------------------- ---------- -------- -----------
49 .1 29% | library cache: bucket mutex X 00000000000119C7 2025-05-21 16:38:32 2025-05-21 16:43:33 5 7 9
42 .1 25% | library cache: mutex X 00000000CA14AC19 2025-05-21 16:38:23 2025-05-21 16:43:35 1 16 16
31 .1 18% | library cache: bucket mutex X 0000000000011BA3 2025-05-21 16:41:07 2025-05-21 16:42:43 1 4 4
19 .1 11% | library cache: mutex X 000000001C1D19C7 2025-05-21 16:39:35 2025-05-21 16:43:33 3 4 6
14 .0 8% | library cache: mutex X 00000000A6411BA3 2025-05-21 16:38:29 2025-05-21 16:43:07 2 6 7
7 .0 4% | library cache: mutex X 00000000ABDD8C76 2025-05-21 16:38:54 2025-05-21 16:43:23 1 5 5
5 .0 3% | library cache: mutex X 000000003726D9E7 2025-05-21 16:39:42 2025-05-21 16:43:08 1 3 3
1 .0 1% | library cache: mutex X 00000000ED7864C9 2025-05-21 16:43:15 2025-05-21 16:43:15 1 1 1
8 rows selected.
--//涉及到的对象看上面的查询,不再赘述。
--//其实这个问题很好解决,我觉得第三方解决方式也有点太武断,估计都没有认真分析问题的本质,而简单化设置
--//result_cache_max_size=0.而实际上12c开始后台大量的语句使用result_cache提示.
SYS@book> select count(*) from v$sqlarea where lower(sql_text) like '%result_cache%';
COUNT(*)
----------
29
--//人为设置result_cache_max_size=0明显不合适,我个人认为。
6.继续:
SYS@book> alter system reset result_cache_max_size;
System altered.
--//重启数据库.
--//分析表,再次重复测试:
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @record.txt 1e6 Q loope.txt > /dev/null ; zzdate
trunc(sysdate)+16/24+56/1440+13/86400 1747817773.794634318
SYS@book> @ ashtop event 1=1 trunc(sysdate)+16/24+56/1440+13/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
1448 16.1 81% | latch: shared pool 2025-05-21 16:56:15 2025-05-21 16:57:42 4 87 90
255 2.8 14% | 2025-05-21 16:56:13 2025-05-21 16:57:42 6 88 93
48 .5 3% | library cache: bucket mutex X 2025-05-21 16:57:00 2025-05-21 16:57:42 2 3 4
20 .2 1% | row cache mutex 2025-05-21 16:56:20 2025-05-21 16:57:19 1 6 6
6 .1 0% | library cache: mutex X 2025-05-21 16:56:28 2025-05-21 16:57:41 2 6 6
3 .0 0% | log file parallel write 2025-05-21 16:57:38 2025-05-21 16:57:39 1 2 2
1 .0 0% | LGWR all worker groups 2025-05-21 16:57:39 2025-05-21 16:57:39 1 1 1
7 rows selected.
--//这样靠前的等待事件没有enq: RC - Result Cache: Contention,实际上问题还是在于开发没有使用绑定变量.
--//在执行脚本record.txt 开头加入 alter session set cursor_sharing=force;
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @record.txt 1e6 AAAA loope.txt > /dev/null ; zzdate
trunc(sysdate)+17/24+03/1440+30/86400 -1747818210.797655564
trunc(sysdate)+17/24+08/1440+20/86400 1747818500.644827098
--//Sum = 289.847171534
--//参数2使用AAAA,这样每个会话执行的sql语句都一样在cursor_sharing=force的情况下相同的.
--//我前面的测试基本都没有完成就重启数据库了,修改为cursor_sharing=force的情况下.
SYS@book> @ ashtop event,p1raw 1=1 trunc(sysdate)+17/24+03/1440+30/86400 trunc(sysdate)+17/24+08/1440+20/86400
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ----------------------------- ----------------- ------------------- ------------------- ---------- -------- -----------
2984 10.3 52% | 2025-05-21 17:03:31 2025-05-21 17:08:19 917 289 1193
2266 7.8 40% | library cache: mutex X 000000000A548BA4 2025-05-21 17:03:32 2025-05-21 17:08:17 21 284 296
241 .8 4% | library cache: bucket mutex X 0000000000008BA4 2025-05-21 17:03:33 2025-05-21 17:08:11 20 95 20
114 .4 2% | cursor: pin S 000000000A548BA4 2025-05-21 17:03:38 2025-05-21 17:08:12 1 56 56
50 .2 1% | cursor: mutex S 0000000000000000 2025-05-21 17:03:53 2025-05-21 17:08:10 1 20 20
38 .1 1% | cursor: mutex S 000000000A548BA4 2025-05-21 17:03:53 2025-05-21 17:07:59 1 18 18
2 .0 0% | log file parallel write 0000000000000001 2025-05-21 17:03:31 2025-05-21 17:06:41 1 2 2
1 .0 0% | db file sequential read 0000000000000003 2025-05-21 17:05:43 2025-05-21 17:05:43 1 1 1
1 .0 0% | library cache: bucket mutex X 00000000000003C8 2025-05-21 17:04:02 2025-05-21 17:04:02 1 1 1
1 .0 0% | library cache: bucket mutex X 0000000000001F0B 2025-05-21 17:08:12 2025-05-21 17:08:12 1 1 1
1 .0 0% | library cache: bucket mutex X 000000000001D625 2025-05-21 17:04:28 2025-05-21 17:04:28 1 1 1
11 rows selected.
--//library cache: mutex X P1raw=000000000A548BA4,library cache: bucket mutex X P1RAW=0000000000008BA4,后4位相同。
--//000000000A548BA4 = 173312932
SYS@book> @ sharepool/shp4 '' 173312932
HANDLE_TYPE KGLHDADR KGLHDPAR C40 KGLHDLMD KGLHDPMD KGLHDIVC KGLOBHD0 KGLOBHD6 KGLOBHS0 KGLOBHS6 KGLOBT16 N0_6_16 N20 KGLNAHSH KGLOBT03 KGLOBT09
---------------------- ---------------- ---------------- ---------------------------------------- ---------- ---------- ---------- ---------------- ---------------- ---------- ---------- ---------- --------- ---------- ---------- ------------- ----------
child handle address 0000000064D3E2D0 0000000070A4D378 Select /*+ AAAA */ count(*) from t1 wher 1 2 0 000000006F533F30 0000000064CF2828 8128 16176 3346 27650 27650 173312932 1frgawc5592x4 0
parent handle address 0000000070A4D378 0000000070A4D378 Select /*+ AAAA */ count(*) from t1 wher 1 0 0 0000000066A089B0 00 4064 0 0 4064 4064 173312932 1frgawc5592x4 65535
--//这是我以前没有测试的情况,在cursor_sharing=force的情况下,靠前的等待事件竟然是library cache: mutex X,以前如果使用绑定
--//变量的情况是cursor: pin S.为什么?另外写一篇分析.
7.总结:
--//1.在19c后如果表没有分析统计信息遇大量sql语句动态分析取样出现的情况,可能首先遇到的等待事件enq: RC - Result Cache:
--//Contention,实际上即使禁用auto optimizer stats collection,只要定期查看awr报表,这个问题还是可以发现的。
--//注:生产系统确实不明显,混杂在其中,不过对比以前的awr报表还是可以发现端倪,有时候不明白为什么开发写的sql语句要以非常
--//密集的方式执行,感觉程序的算法存在某种问题,要么就是所谓的刷新语句,非常的不理解。
--//2.再次提醒oltp使用绑定变量很重要,即使设置cursor_sharing=force也就是不得以而为之,也就是仅仅有所改善。
--//oracle 19c的生产系统有几个表没有分析统计信息遇到的问题,实际上最主要的原因是涉及到的sql语句没有使用绑定变量,导致大
--//量sql语句动态分析取样出现的情况,在测试环境21c做一个测试说明问题。
1.环境:
SCOTT@book01p> @ ver2
==============================
PORT_STRING : x86_64/Linux 2.4.xx
VERSION : 21.0.0.0.0
BANNER : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
BANNER_FULL : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
Version 21.3.0.0.0
BANNER_LEGACY : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
CON_ID : 0
PL/SQL procedure successfully completed.
2.测试环境建立:
SCOTT@book01p> create table t1 as select mod(rownum,1e4) id ,'test' vc from dual connect by level<=1e6;
Table created.
SCOTT@book01p> create index i_t1_id on t1(id);
Index created.
--//注意不要分析表,建立索引不能唯一,否则不会执行动态取样。
--//注意21c支持这类插入自动分析表,受参数_optimizer_gather_stats_on_load=TRUE的影响。
--//执行如下可以删除表统计信息。
SCOTT@book01p> execute sys.dbms_stats.delete_table_stats ('SCOTT', 'T1',cascade_columns=> false,cascade_indexes=>false,cascade_parts=>false,no_invalidate=> false);
PL/SQL procedure successfully completed.
--//注:我仅仅删除表信息,其他索引,字段的统计信息保留,这样比较符合生产系统看到的情况.
--//没有表统计信息,主要原因是禁止了晚上auto optimizer stats collection.
SCOTT@book01p> @ sosiz scott t1
**********************************
Table Level 参数 schema tablename
**********************************
Table Number Empty Average Chain Average Global User Sample
Name of Rows Blocks Blocks Space Count Row Len Stats Stats Size LAST_ANALYZED
--------------- -------------- ------------ ------------ -------- -------- -------- ------ ------ -------------- -------------------
T1 NO NO
Column Column Distinct Number Number Global User Sample
Name Details Values Density Buckets Nulls Stats Stats Size LAST_ANALYZED HISTOGRAM
------------------------- ------------------------ ------------ ----------- ------- ---------- ------ ------ -------------- ------------------- ---------------
ID NUMBER(22) 1,000,000 0.00000100 1 0 YES NO 1,000,000 2025-05-21 15:46:05 NONE
VC CHAR(4) 1 1.00000000 1 0 YES NO 1,000,000 2025-05-21 15:46:05 NONE
B Average Average
Index Tree Leaf Distinct Number Leaf Blocks Data Blocks Cluster Global User Sample
Name Unique Level Blks Keys of Rows Per Key Per Key Factor Stats Stats Size LAST_ANALYZED
------------------------- --------- ----- ------ -------------- -------------- ----------- ----------- ------------ ------ ------ -------------- -------------------
I_T1_ID NONUNIQUE 2 2226 1,000,000 1,000,000 1 1 2,074 YES NO 1,000,000 2025-05-21 15:49:46
Index Column Col Column
Name Name Pos Details
------------------------- ------------------------- ---- ------------------------
I_T1_ID ID 1 NUMBER(22)
***************
Partition Level
***************
***************
SubPartition Level
***************
$ cat loope.txt
set verify off
DECLARE
l_count PLS_INTEGER;
BEGIN
FOR i IN 1..&&1
LOOP
EXECUTE IMMEDIATE 'Select /*+ &2 */ count(*) from t1 where id = ' || i INTO l_count ;
END LOOP;
END;
/
--//注:执行的SQL语句使用文字变量,如果参数2在不相同,这样每个会话不同执行的sql语句都是硬解析。
--//create table job_times (sid number, time_ela number,method varchar2(20));
$ cat record.txt
--// arg1 = loop counts , arg2 = method , arg3= test scirpt
set verify off
variable v_method varchar2(20)
exec :v_method := (case when '&2' >= '1' and '&2'<='9999' then 'QQQQ' else '&2' end);
define t=&&1;
column 3 new_value 3;
select decode('&3',null,'loop.txt','&&3') "3" from dual;
@@ &&3 5 &&2
--//insert into job_times values ( sys_context ('userenv', 'sid') ,dbms_utility.get_time ,:v_method) ;
--//commit ;
@@ &&3 &&t &&2
--//update job_times set time_ela = dbms_utility.get_time - time_ela where sid=sys_context ('userenv', 'sid') and method= :v_method;
--//commit;
quit
3.测试:
$ zzdate ; seq 5 | xargs -IQ -P 5 sqlplus -s -l scott/book@book01p @record.txt 1e6 Q loope.txt > /dev/null ; zzdate
trunc(sysdate)+15/24+51/1440+30/86400 1747813890.819470149
--//参数2使用Q代替,这样每个会话执行的sql语句都不同,相当于产生大量的文字变量的sql语句。
4.不等执行完成开始分析:
SYS@book> host sleep 300
SYS@book> @ ashtop event 1=1 trunc(sysdate)+15/24+51/1440+30/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
2527 2.2 43% | 2025-05-21 15:51:31 2025-05-21 16:10:50 18 1158 1174
2095 1.8 36% | enq: RC - Result Cache: Contention 2025-05-21 15:51:31 2025-05-21 16:10:50 1 868 868
1040 .9 18% | latch: shared pool 2025-05-21 15:51:35 2025-05-21 16:10:50 3 517 423
104 .1 2% | latch free 2025-05-21 15:52:17 2025-05-21 16:10:49 1 75 75
28 .0 0% | library cache: bucket mutex X 2025-05-21 15:52:04 2025-05-21 16:09:23 3 11 12
12 .0 0% | library cache: mutex X 2025-05-21 15:57:17 2025-05-21 16:10:33 2 12 12
7 .0 0% | latch: enqueue hash chains 2025-05-21 15:56:36 2025-05-21 16:06:17 1 4 4
3 .0 0% | control file parallel write 2025-05-21 16:04:33 2025-05-21 16:05:47 1 3 3
3 .0 0% | db file sequential read 2025-05-21 15:57:43 2025-05-21 16:03:52 3 3 3
3 .0 0% | row cache mutex 2025-05-21 15:51:34 2025-05-21 15:51:58 1 2 2
1 .0 0% | cursor: pin S 2025-05-21 15:57:28 2025-05-21 15:57:28 1 1 1
1 .0 0% | log file parallel write 2025-05-21 16:03:52 2025-05-21 16:03:52 1 1 1
12 rows selected.
--//可以发现开始等待事件并不是latch: shared pool排在第一,而是enq: RC - Result Cache: Contention.
SYS@book> @ ashtop sql_id,p1raw "event='enq: RC - Result Cache: Contention'" trunc(sysdate)+15/24+51/1440+30/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID P1RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ----------------- ------------------- ------------------- ---------- -------- -----------
1 .0 0% | 008zvgdw25qs9 0000000052430004 2025-05-21 15:53:37 2025-05-21 15:53:37 1 1 1
1 .0 0% | 01ab447knd8tm 0000000052430004 2025-05-21 15:53:12 2025-05-21 15:53:12 1 1 1
1 .0 0% | 02mt2ux61664y 0000000052430004 2025-05-21 15:52:04 2025-05-21 15:52:04 1 1 1
1 .0 0% | 03uf8zd6kkasy 0000000052430004 2025-05-21 15:54:23 2025-05-21 15:54:23 1 1 1
1 .0 0% | 040an7spr2pac 0000000052430004 2025-05-21 15:51:40 2025-05-21 15:51:40 1 1 1
1 .0 0% | 04tw3f4xnzwva 0000000052430004 2025-05-21 15:54:02 2025-05-21 15:54:02 1 1 1
...
--//查询sql_id已经不在共享池.基本都是执行1次的语句,如果扫描共享池按照执行次数倒排序,可以发现大量执行语句如下:
SYS@book> @ sql_id fbmkq644v60zw
-- SQL_ID = fbmkq644v60zw come from shared pool
SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE RESULT_CACHE(SNAPSHOT=3600) opt_param('parallel_execution_enabled', 'false') NO_PARALLEL(SAMPLESUB) NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1") FROM (SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL("T1") FULL("T1") NO_PARALLEL_INDEX("T1") */ :"SYS_B_2" AS C1, CASE WHEN "T1"."ID"=:"SYS_B_3" THEN :"SYS_B_4" ELSE :"SYS_B_5" END AS C2 FROM "SCOTT"."T1" SAMPLE BLOCK (:"SYS_B_6" , :"SYS_B_7") SEED (:"SYS_B_8") "T1") SAMPLESUB;
SYS@book> @ sql_id 4bm5p8sahp9js
-- SQL_ID = 4bm5p8sahp9js come from shared pool
SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS RESULT_CACHE(SNAPSHOT=3600) opt_param('parallel_execution_enabled', 'false') NO_PARALLEL(SAMPLESUB) NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1"), NVL(SUM(C3),:"SYS_B_2") FROM (SELECT /*+ NO_PARALLEL("T1") INDEX("T1" I_T1_ID) NO_PARALLEL_INDEX("T1") */ :"SYS_B_3" AS C1, :"SYS_B_4" AS C2, :"SYS_B_5" AS C3 FROM "SCOTT"."T1" "T1" WHERE "T1"."ID"=:"SYS_B_6" AND ROWNUM <= :"SYS_B_7") SAMPLESUB;
--//也就是每次执行取样都是执行以上sql语句,而注意提示加入RESULT_CACHE(SNAPSHOT=3600),这样的结果导致Result Cache Contention.
--//出现latch: shared pool是很自然的,上面执行的sql语句每次执行都是硬解析.
--//继续看latch free 等待事件.
SYS@book> @ ashtop p1raw,p2raw,p3raw "event='latch free'" trunc(sysdate)+15/24+51/1440+30/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This P1RAW P2RAW P3RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ----------------- ----------------- ----------------- ------------------- ------------------- ---------- -------- -----------
83 .1 100% | 000000006CF72120 000000000000034E 0000000000000001 2025-05-21 15:52:17 2025-05-21 16:06:41 1 61 61
SYS@book> @ la 000000006CF72120
ADDR LATCH# CHLD NAME GETS IGETS MISSES IMISSES SPINGETS SLEEPS WAIT_TIME
---------------- ---------- ------ --------------------------------------------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
000000006CF72120 846 1 Result Cache: RC Latch 5955359 0 575464 0 406981 170445 80482658
--//还是关联Result Cache,也就是在释放时也存在小量阻塞的情况.
--//继续看library cache: bucket mutex X等待事件.
SYS@book> @ ashtop event,p1raw "event like 'library cache:%'" trunc(sysdate)+15/24+51/1440+30/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ----------------- ------------------- ------------------- ---------- -------- -----------
26 .0 35% | library cache: bucket mutex X 0000000000011BA3 2025-05-21 15:52:04 2025-05-21 16:20:37 1 10 10
22 .0 29% | library cache: mutex X 00000000CA14AC19 2025-05-21 15:57:17 2025-05-21 16:20:58 1 16 16
15 .0 20% | library cache: bucket mutex X 00000000000119C7 2025-05-21 15:53:12 2025-05-21 16:19:04 3 6 7
5 .0 7% | library cache: mutex X 00000000A6411BA3 2025-05-21 16:04:37 2025-05-21 16:20:37 2 4 4
3 .0 4% | library cache: mutex X 000000001C1D19C7 2025-05-21 16:02:14 2025-05-21 16:18:06 3 3 3
1 .0 1% | library cache: bucket mutex X 000000000000EC2A 2025-05-21 16:12:01 2025-05-21 16:12:01 1 1 1
1 .0 1% | library cache: bucket mutex X 000000000001A8D3 2025-05-21 15:57:51 2025-05-21 15:57:51 1 1 1
1 .0 1% | library cache: mutex X 000000003726D9E7 2025-05-21 16:17:37 2025-05-21 16:17:37 1 1 1
1 .0 1% | library cache: mutex X 00000000ABDD8C76 2025-05-21 16:18:30 2025-05-21 16:18:30 1 1 1
9 rows selected.
--//因为每次都是硬解析,这样每次都要反复一些对象,导致出现library cache: bucket mutex X.很容易猜测集中在表,owner,实例
--//等对象上.因为enq: RC - Result Cache: Contention排在第一,反而访问这些对象的等待事件不是很明显.
--//注:如果在11g测试,不会出现enq: RC - Result Cache: Contention等待事件,library cache: bucket mutex X在oracle不存在,实
--//际上11g标识为library cache: mutex X,出现这样的情况注意看P1的值是否小于2^17 = 131072时,有可能是在library cache: bucket
--//mutex.
--//注意看p1raw 对于 library cache: mutex X 对于的hash值,对于library cache: bucket mutex X 取的是对象的hash值 取模2^17.
--//比如 0000000000011BA3 00000000A6411BA3 后面的4位相同.看看是那些对象.
SYS@book> @ kglob '' 00000000CA14AC19 '' ''
==============================
INST_ID : 1
OWNER : SCOTT
NAME : T1
DB_LINK :
NAMESPACE : TABLE/PROCEDURE
TYPE : TABLE
NAMESPACE_NUM : 1
NAMESPACE_HEX : 1
SHARABLE_MEM : 4064
PERSISTENT_MEM : 0
RUNTIME_MEM : 0
LOADS : 3
EXECUTIONS : 0
LOCKS : 5
PINS : 0
KEPT : NO
CHILD_LATCH : 44057
INVALIDATIONS : 0
HASH_VALUE : 3390352409
HASH_HEX : ca14ac19
LOCK_MODE : SHARED
PIN_MODE : SHARED
STATUS : VALID
TIMESTAMP : 2025-05-21/15:41:11
PREVIOUS_TIMESTAMP :
LOCKED_TOTAL : 2844128
PINNED_TOTAL : 2844118
PROPERTY :
FULL_HASH_VALUE : 3a7f3c628eea956aa98d1395ca14ac19
CON_ID : 3
CON_NAME : BOOK01P
ADDR : 0000000063BAE4D8
PAR_ADDR : 0000000063BAE4D8
HANDLE_TYPE : parent handle address
KGLOBHD0 : 00000000618CB830
KGLOBHD6 : 00
EDITION :
SQL_ID :
OBJECT_STR : T1.SCOTT.BOOK01P\x1\0\0\0
PL/SQL procedure successfully completed.
--//表T1.
SYS@book> @ kglob '' 000000001C1D19C7 '' ''
==============================
INST_ID : 1
OWNER : SYS
NAME : 1073777561
DB_LINK :
NAMESPACE : DBINSTANCE
TYPE : CURSOR
NAMESPACE_NUM : 74
NAMESPACE_HEX : 4a
SHARABLE_MEM : 0
PERSISTENT_MEM : 0
RUNTIME_MEM : 0
LOADS : 0
EXECUTIONS : 0
LOCKS : 4
PINS : 0
KEPT : NO
CHILD_LATCH : 72135
INVALIDATIONS : 0
HASH_VALUE : 471669191
HASH_HEX : 1c1d19c7
LOCK_MODE : SHARED
PIN_MODE : NONE
STATUS : UNKOWN
TIMESTAMP :
PREVIOUS_TIMESTAMP :
LOCKED_TOTAL : 8705557
PINNED_TOTAL : 0
PROPERTY :
FULL_HASH_VALUE : 25d8c2e2a1f8d5e74176b9b61c1d19c7
CON_ID : 1
CON_NAME : CDB$ROOT
ADDR : 000000006CF7FC50
PAR_ADDR : 000000006CF7FC50
HANDLE_TYPE : parent handle address
KGLOBHD0 : 00
KGLOBHD6 : 00
EDITION :
SQL_ID :
OBJECT_STR : 1073777561.SYS.CDB$ROOT\x4a\0\0\0
PL/SQL procedure successfully completed.
--//pdb=book01 的dbid。
SYS@book> select con_id,dbid,name from v$pdbs;
CON_ID DBID NAME
---------- ---------- ------------------------------
2 2763294012 PDB$SEED
3 1073777561 BOOK01P
SYS@book> @ kglob '' 00000000A6411BA3 '' ''
==============================
INST_ID : 1
OWNER : SYS
NAME : book
DB_LINK :
NAMESPACE : DBINSTANCE
TYPE : CURSOR
NAMESPACE_NUM : 74
NAMESPACE_HEX : 4a
SHARABLE_MEM : 0
PERSISTENT_MEM : 0
RUNTIME_MEM : 0
LOADS : 0
EXECUTIONS : 0
LOCKS : 5
PINS : 0
KEPT : NO
CHILD_LATCH : 72611
INVALIDATIONS : 0
HASH_VALUE : 2789284771
HASH_HEX : a6411ba3
LOCK_MODE : SHARED
PIN_MODE : NONE
STATUS : UNKOWN
TIMESTAMP :
PREVIOUS_TIMESTAMP :
LOCKED_TOTAL : 9046637
PINNED_TOTAL : 0
PROPERTY :
FULL_HASH_VALUE : b885bb910059a4d2fdbfc245a6411ba3
CON_ID : 1
CON_NAME : CDB$ROOT
ADDR : 0000000072550A58
PAR_ADDR : 0000000072550A58
HANDLE_TYPE : parent handle address
KGLOBHD0 : 00
KGLOBHD6 : 00
EDITION :
SQL_ID :
OBJECT_STR : book.SYS.CDB$ROOT\x4a\0\0\0
PL/SQL procedure successfully completed.
--//实例book.
SYS@book> @ kglob '' 000000003726D9E7 '' ''
==============================
INST_ID : 1
OWNER :
NAME : SCOTT
DB_LINK :
NAMESPACE : SCHEMA
TYPE : NONE
NAMESPACE_NUM : 73
NAMESPACE_HEX : 49
SHARABLE_MEM : 0
PERSISTENT_MEM : 0
RUNTIME_MEM : 0
LOADS : 0
EXECUTIONS : 0
LOCKS : 11
PINS : 0
KEPT : NO
CHILD_LATCH : 55783
INVALIDATIONS : 0
HASH_VALUE : 925293031
HASH_HEX : 3726d9e7
LOCK_MODE : SHARED
PIN_MODE : NONE
STATUS : UNKOWN
TIMESTAMP :
PREVIOUS_TIMESTAMP :
LOCKED_TOTAL : 3195263
PINNED_TOTAL : 0
PROPERTY :
FULL_HASH_VALUE : 46bd45166adbb098d6fef7ce3726d9e7
CON_ID : 3
CON_NAME : BOOK01P
ADDR : 0000000063CA42D8
PAR_ADDR : 0000000063CA42D8
HANDLE_TYPE : parent handle address
KGLOBHD0 : 00
KGLOBHD6 : 00
EDITION :
SQL_ID :
OBJECT_STR : SCOTT
PL/SQL procedure successfully completed.
--//schema或者owner.
--//可以想象如果生产系统,一般使用几个schema,正好涉及到的这些表没有统计分析,而语句存在大量文字变量,出现上面的情况正常不过.
--//注:我开启的会话仅仅5个,如果相关library cache: bucket mutex X,library cache: mutex X没有出现,增加会话数量.
--//才想起前一段时间遇到的问题,第三方安装的数据库设置result_cache_max_size=0.测试看看.
SYS@book> show parameter result_cache_max_size
PARAMETER_NAME TYPE VALUE
--------------------- ----------- ------
result_cache_max_size big integer 5M
SYS@book> alter system set result_cache_max_size=0 scope=spfile;
System altered.
5.测试result_cache_max_size=0的情况.
--//重启数据库略.
SYS@book> show parameter result_cache_max_size
PARAMETER_NAME TYPE VALUE
--------------------- ----------- -----
result_cache_max_size big integer 0
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @record.txt 1e6 Q loope.txt > /dev/null ; zzdate
trunc(sysdate)+16/24+38/1440+19/86400 1747816699.970865672
--//增加会话数量,不然library cache相关事件不容易抓取到.
SYS@book> @ ashtop event 1=1 trunc(sysdate)+16/24+38/1440+19/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
935 11.5 59% | latch: shared pool 2025-05-21 16:38:22 2025-05-21 16:39:39 6 77 82
565 7.0 36% | 2025-05-21 16:38:20 2025-05-21 16:39:39 9 79 87
42 .5 3% | library cache: mutex X 2025-05-21 16:38:23 2025-05-21 16:39:35 2 9 10
25 .3 2% | library cache: bucket mutex X 2025-05-21 16:38:32 2025-05-21 16:39:35 5 3 7
4 .0 0% | latch: call allocation 2025-05-21 16:38:33 2025-05-21 16:38:33 1 1 1
4 .0 0% | library cache load lock 2025-05-21 16:38:20 2025-05-21 16:38:20 1 1 1
3 .0 0% | row cache mutex 2025-05-21 16:38:30 2025-05-21 16:39:28 1 3 3
7 rows selected.
--//因为设置result_cache_max_size=0,相当于关闭result cache,导致latch: shared pool排在第一.
SYS@book> @ ashtop event,p1raw "event like 'library cache:%'" trunc(sysdate)+16/24+38/1440+19/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ----------------- ------------------- ------------------- ---------- -------- -----------
49 .1 29% | library cache: bucket mutex X 00000000000119C7 2025-05-21 16:38:32 2025-05-21 16:43:33 5 7 9
42 .1 25% | library cache: mutex X 00000000CA14AC19 2025-05-21 16:38:23 2025-05-21 16:43:35 1 16 16
31 .1 18% | library cache: bucket mutex X 0000000000011BA3 2025-05-21 16:41:07 2025-05-21 16:42:43 1 4 4
19 .1 11% | library cache: mutex X 000000001C1D19C7 2025-05-21 16:39:35 2025-05-21 16:43:33 3 4 6
14 .0 8% | library cache: mutex X 00000000A6411BA3 2025-05-21 16:38:29 2025-05-21 16:43:07 2 6 7
7 .0 4% | library cache: mutex X 00000000ABDD8C76 2025-05-21 16:38:54 2025-05-21 16:43:23 1 5 5
5 .0 3% | library cache: mutex X 000000003726D9E7 2025-05-21 16:39:42 2025-05-21 16:43:08 1 3 3
1 .0 1% | library cache: mutex X 00000000ED7864C9 2025-05-21 16:43:15 2025-05-21 16:43:15 1 1 1
8 rows selected.
--//涉及到的对象看上面的查询,不再赘述。
--//其实这个问题很好解决,我觉得第三方解决方式也有点太武断,估计都没有认真分析问题的本质,而简单化设置
--//result_cache_max_size=0.而实际上12c开始后台大量的语句使用result_cache提示.
SYS@book> select count(*) from v$sqlarea where lower(sql_text) like '%result_cache%';
COUNT(*)
----------
29
--//人为设置result_cache_max_size=0明显不合适,我个人认为。
6.继续:
SYS@book> alter system reset result_cache_max_size;
System altered.
--//重启数据库.
--//分析表,再次重复测试:
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @record.txt 1e6 Q loope.txt > /dev/null ; zzdate
trunc(sysdate)+16/24+56/1440+13/86400 1747817773.794634318
SYS@book> @ ashtop event 1=1 trunc(sysdate)+16/24+56/1440+13/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
1448 16.1 81% | latch: shared pool 2025-05-21 16:56:15 2025-05-21 16:57:42 4 87 90
255 2.8 14% | 2025-05-21 16:56:13 2025-05-21 16:57:42 6 88 93
48 .5 3% | library cache: bucket mutex X 2025-05-21 16:57:00 2025-05-21 16:57:42 2 3 4
20 .2 1% | row cache mutex 2025-05-21 16:56:20 2025-05-21 16:57:19 1 6 6
6 .1 0% | library cache: mutex X 2025-05-21 16:56:28 2025-05-21 16:57:41 2 6 6
3 .0 0% | log file parallel write 2025-05-21 16:57:38 2025-05-21 16:57:39 1 2 2
1 .0 0% | LGWR all worker groups 2025-05-21 16:57:39 2025-05-21 16:57:39 1 1 1
7 rows selected.
--//这样靠前的等待事件没有enq: RC - Result Cache: Contention,实际上问题还是在于开发没有使用绑定变量.
--//在执行脚本record.txt 开头加入 alter session set cursor_sharing=force;
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @record.txt 1e6 AAAA loope.txt > /dev/null ; zzdate
trunc(sysdate)+17/24+03/1440+30/86400 -1747818210.797655564
trunc(sysdate)+17/24+08/1440+20/86400 1747818500.644827098
--//Sum = 289.847171534
--//参数2使用AAAA,这样每个会话执行的sql语句都一样在cursor_sharing=force的情况下相同的.
--//我前面的测试基本都没有完成就重启数据库了,修改为cursor_sharing=force的情况下.
SYS@book> @ ashtop event,p1raw 1=1 trunc(sysdate)+17/24+03/1440+30/86400 trunc(sysdate)+17/24+08/1440+20/86400
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1RAW FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ----------------------------- ----------------- ------------------- ------------------- ---------- -------- -----------
2984 10.3 52% | 2025-05-21 17:03:31 2025-05-21 17:08:19 917 289 1193
2266 7.8 40% | library cache: mutex X 000000000A548BA4 2025-05-21 17:03:32 2025-05-21 17:08:17 21 284 296
241 .8 4% | library cache: bucket mutex X 0000000000008BA4 2025-05-21 17:03:33 2025-05-21 17:08:11 20 95 20
114 .4 2% | cursor: pin S 000000000A548BA4 2025-05-21 17:03:38 2025-05-21 17:08:12 1 56 56
50 .2 1% | cursor: mutex S 0000000000000000 2025-05-21 17:03:53 2025-05-21 17:08:10 1 20 20
38 .1 1% | cursor: mutex S 000000000A548BA4 2025-05-21 17:03:53 2025-05-21 17:07:59 1 18 18
2 .0 0% | log file parallel write 0000000000000001 2025-05-21 17:03:31 2025-05-21 17:06:41 1 2 2
1 .0 0% | db file sequential read 0000000000000003 2025-05-21 17:05:43 2025-05-21 17:05:43 1 1 1
1 .0 0% | library cache: bucket mutex X 00000000000003C8 2025-05-21 17:04:02 2025-05-21 17:04:02 1 1 1
1 .0 0% | library cache: bucket mutex X 0000000000001F0B 2025-05-21 17:08:12 2025-05-21 17:08:12 1 1 1
1 .0 0% | library cache: bucket mutex X 000000000001D625 2025-05-21 17:04:28 2025-05-21 17:04:28 1 1 1
11 rows selected.
--//library cache: mutex X P1raw=000000000A548BA4,library cache: bucket mutex X P1RAW=0000000000008BA4,后4位相同。
--//000000000A548BA4 = 173312932
SYS@book> @ sharepool/shp4 '' 173312932
HANDLE_TYPE KGLHDADR KGLHDPAR C40 KGLHDLMD KGLHDPMD KGLHDIVC KGLOBHD0 KGLOBHD6 KGLOBHS0 KGLOBHS6 KGLOBT16 N0_6_16 N20 KGLNAHSH KGLOBT03 KGLOBT09
---------------------- ---------------- ---------------- ---------------------------------------- ---------- ---------- ---------- ---------------- ---------------- ---------- ---------- ---------- --------- ---------- ---------- ------------- ----------
child handle address 0000000064D3E2D0 0000000070A4D378 Select /*+ AAAA */ count(*) from t1 wher 1 2 0 000000006F533F30 0000000064CF2828 8128 16176 3346 27650 27650 173312932 1frgawc5592x4 0
parent handle address 0000000070A4D378 0000000070A4D378 Select /*+ AAAA */ count(*) from t1 wher 1 0 0 0000000066A089B0 00 4064 0 0 4064 4064 173312932 1frgawc5592x4 65535
--//这是我以前没有测试的情况,在cursor_sharing=force的情况下,靠前的等待事件竟然是library cache: mutex X,以前如果使用绑定
--//变量的情况是cursor: pin S.为什么?另外写一篇分析.
7.总结:
--//1.在19c后如果表没有分析统计信息遇大量sql语句动态分析取样出现的情况,可能首先遇到的等待事件enq: RC - Result Cache:
--//Contention,实际上即使禁用auto optimizer stats collection,只要定期查看awr报表,这个问题还是可以发现的。
--//注:生产系统确实不明显,混杂在其中,不过对比以前的awr报表还是可以发现端倪,有时候不明白为什么开发写的sql语句要以非常
--//密集的方式执行,感觉程序的算法存在某种问题,要么就是所谓的刷新语句,非常的不理解。
--//2.再次提醒oltp使用绑定变量很重要,即使设置cursor_sharing=force也就是不得以而为之,也就是仅仅有所改善。
[20250521]生产系统表没有分析统计信息出现的问题(21c).txt[20250521]生产系统表没有分析统计信息出现的问题(21c).txt[20250521]生产系统表没有分析统计信息出现的问题(21c).txt[20250521]生产系统表没有分析统计信息出现的问题(21c).txt[20250521]生产系统表没有分析统计信息出现的问题(21c).txt[20250521]生产系统表没有分析统计信息出现的问题(21c).txt[20250521]生产系统表没有分析统计信息出现的问题(21c).txt[20250521]生产系统表没有分析统计信息出现的问题(21c).txt[20250521]生产系统表没有分析统计信息出现的问题(21c).txt