[20251107]latch cache buffers chains等待事件.txt
[20251107]latch cache buffers chains等待事件.txt
--//前一段时间测试oracle目前的版本在读读的情况很少出现latch cache buffers chains情况。
--//我以前的测试基本是单表，拿别人的例子验证看看。
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.建立测试环境：
--//参考链接：https://www.cnblogs.com/www-htz-pw/p/19014106
create table cbc1 as select * from dba_objects where owner='SYS' and rownum<201;
create table cbc2 as select * from dba_objects;
--//分析表略。
SCOTT@book01p> set timing on
SCOTT@book01p> SELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
COUNT(*)
----------
10883400
Elapsed: 00:00:00.65
SCOTT@book01p> @ sl all
alter session set statistics_level = all;
Session altered.
SCOTT@book01p> SELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
COUNT(*)
----------
10883400
SCOTT@book01p> @ dpc '' '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID 418781rd1m5kr, child number 1
-------------------------------------
SELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner =
b.owner
Plan hash value: 4079546673
----------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
----------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 87289 (100)| | 1 |00:00:04.95 | 315K|
| 1 | SORT AGGREGATE | | 1 | 1 | 9 | | | 1 |00:00:04.95 | 315K|
| 2 | NESTED LOOPS | | 1 | 602K| 5296K| 87289 (1)| 00:00:04 | 10M|00:00:03.91 | 315K|
| 3 | TABLE ACCESS FULL| CBC1 | 1 | 200 | 800 | 4 (0)| 00:00:01 | 200 |00:00:00.01 | 5 |
|* 4 | TABLE ACCESS FULL| CBC2 | 200 | 3013 | 15065 | 436 (1)| 00:00:01 | 10M|00:00:01.80 | 315K|
----------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1
3 - SEL$1 / "A"@"SEL$1"
4 - SEL$1 / "B"@"SEL$1"
Predicate Information (identified by operation id):
---------------------------------------------------
4 - filter("A"."OWNER"="B"."OWNER")
Hint Report (identified by operation id / Query Block Name / Object Alias):
Total hints for statement: 2 (U - Unused (1))
---------------------------------------------------------------------------
3 - SEL$1 / "A"@"SEL$1"
U - use_nl(a b)
4 - SEL$1 / "B"@"SEL$1"
- use_nl(a b)
39 rows selected.
--//看了执行计划，才发现实际上还是单表的情况，cbc1仅仅控制循环次数，看id=4，starts=200次。
--//在打开statistics_level = all测试需要4秒，如果不打开不到1秒完成。
--//建立测试脚本:
$ cat loop7.txt
set verify off
DECLARE
l_count number;
BEGIN
FOR i IN 1..&&1
LOOP
SELECT /*+ use_nl(a b)*/ COUNT (*) INTO l_count FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
END LOOP;
END;
/
--quit
3.测试：
--//在测试前猜测应该存在少量cbc，因为上面的2个表涉及许多数据块，无法保证每个cbc链条上不存在写的数据块。
--//发现密集执行还是很慢的(20个并发的情况，循环测试1e4的情况下)，在不打开的statistics_level = all的情况下需要接近2秒完成。
SCOTT@book01p> sELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
COUNT(*)
----------
10883400
Elapsed: 00:00:01.98
--//感觉虚拟机CPU数量不足...
--//这样不能测试时间太长，如果测试6个并发，执行100次。需要6*100*2/60/4 = 5(注：CPU_count=4)。
drop table cbc1 purge ;
create table cbc1 as select * from dba_objects where owner='SYS' and rownum<101;
--//分析略。
$ zzdate ; seq 6 | xargs -IQ -P 6 sqlplus -s -l scott/book@book01p @loop7.txt 100 > /dev/null ;zzdate
trunc(sysdate)+09/24+46/1440+34/86400 -1762479994.191368391
trunc(sysdate)+09/24+47/1440+25/86400 1762480045.920942321
--//Sum = 51.72957393
--//并发没有这么多还是不需要这么多时间完成。
--//51.72957393 /6/100 = .08621595655.
SYS@book> @ ashtop sql_id,p1raw,p1,event 1=1 trunc(sysdate)+09/24+46/1440+34/86400 trunc(sysdate)+09/24+47/1440+25/86400
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID P1RAW P1 EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ----------------- ---------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
210 4.1 70% | bjw5n8xcqpq8f 65536 2025-11-07 09:46:35 2025-11-07 09:47:24 210 50 210
43 .8 14% | bjw5n8xcqpq8f 1611704768 2025-11-07 09:46:42 2025-11-07 09:47:24 43 43 43
32 .6 11% | bjw5n8xcqpq8f 1413697536 2025-11-07 09:46:35 2025-11-07 09:46:43 32 9 32
7 .1 2% | bjw5n8xcqpq8f 740869104 2025-11-07 09:46:35 2025-11-07 09:46:41 7 7 7
4 .1 1% | 100 2025-11-07 09:46:34 2025-11-07 09:47:13 1 3 3
1 .0 0% | 3g08183h1fph7 8 2025-11-07 09:46:37 2025-11-07 09:46:37 1 1 1
1 .0 0% | 0000000000000002 2 control file parallel write 2025-11-07 09:46:38 2025-11-07 09:46:38 1 1 1
1 .0 0% | 0 2025-11-07 09:46:34 2025-11-07 09:46:34 1 1 1
8 rows selected.
--//在我的测试环境根本不存在dml操作，ashtop根本没有抓取到latch cache buffers chains等待事件，再次验证现在oracle版本在读
--//读模式下不需要持有cbc latch，或者讲不再存在阻塞，以一种共享的方式持有。
SYS@book> @ sql_id bjw5n8xcqpq8f
-- SQL_ID = bjw5n8xcqpq8f come from shared pool
SELECT /*+ use_nl(a b)*/ COUNT (*) FROM CBC1 A, CBC2 B WHERE A.OWNER = B.OWNER;
--//PL/sql将语句转换为大写。
--//你可能觉得ashtop的输出有点奇怪P1有值，而P1raw没有，实际上tpt的ashtop.sql脚本的执行p1raw的输出有条件：
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p1 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p1hex
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p2 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p2hex
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p3 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p3hex
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p1 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p1raw
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p2 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p2raw
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p3 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p3raw
SYS@book> @ s2h bjw5n8xcqpq8f
SQL_ID HASH_VALUE KGL_BUCKET
------------- ----------- ----------
bjw5n8xcqpq8f 1500174606 55566
--//明显与sql_id=bjw5n8xcqpq8f无关。
SYS@book> @ sharepool/shp4 '' 740869104
HANDLE_TYPE KGLHDADR KGLHDPAR C40 KGLHDLMD KGLHDPMD KGLHDIVC KGLOBHD0 KGLOBHD6 KGLOBHS0 KGLOBHS6 KGLOBT16 N0_6_16 N20 KGLNAHSH KGLOBT03 KGLHDBID KGLOBT09
---------------------- ---------------- ---------------- ---------------------------------------- ---------- ---------- ---------- ---------------- ---------------- ---------- ---------- ---------- --------- ---------- ---------- ------------- ---------- ----------
child handle address 0000000065A9E0A0 00000000659A0660 DECLARE l_count number; BEGIN FOR 0 0 0 0000000068A2BF90 00000000681D3E68 16256 16464 3448 36168 36168 740869104 8cqcbynq2jhzh 50160 0
parent handle address 00000000659A0660 00000000659A0660 DECLARE l_count number; BEGIN FOR 0 0 0 0000000068A4E980 00 4064 0 0 4064 4064 740869104 8cqcbynq2jhzh 50160 65535
--//P1=740869104对应匿名PLsql语句。
SYS@book> @ sharepool/shp4 '' 1413697536
no rows selected
SYS@book> @ sharepool/shp4 '' 1611704768
no rows selected
4.尝试使用latchprofx.sql看看
--//并发20个用户同时执行。
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @loop7.txt 100 > /dev/null ;zzdate
trunc(sysdate)+10/24+11/1440+15/86400 -1762481475.053176431
trunc(sysdate)+10/24+14/1440+06/86400 1762481646.062249438
--//Sum = 171.009073007
--//测试中间执行如下：
SCOTT@book01p> sELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
COUNT(*)
----------
5441700
Elapsed: 00:00:01.87
--//确实基本需要2秒完成。
SYS@book> @ tpt/latchprofx.sql laddr % cache 10000
-- LatchProfX 2.11 by Tanel Poder ( https://tanelpoder.com )
LADDR Held Gets Held % Held ms Avg hold ms
---------------- ---------- ---------- ------- ----------- -----------
000000007A763D38 506 32 5.06 153.824 4.807
000000007A767AA8 477 103 4.77 145.008 1.408
000000007A77C748 453 53 4.53 137.712 2.598
000000007A780FA8 420 42 4.20 127.680 3.040
000000007A771928 362 78 3.62 110.048 1.411
000000007A770560 360 42 3.60 109.440 2.606
000000007A760E60 348 21 3.48 105.792 5.038
000000007A7660A0 348 22 3.48 105.792 4.809
000000007A760C08 344 44 3.44 104.576 2.377
000000007A768CE0 340 20 3.40 103.360 5.168
000000007A77B020 289 34 2.89 87.856 2.584
000000007A75CF60 239 26 2.39 72.656 2.794
000000007A776C30 237 31 2.37 72.048 2.324
000000007A76D9A8 231 36 2.31 70.224 1.951
000000007A774A18 224 41 2.24 68.096 1.661
000000007A783840 217 31 2.17 65.968 2.128
000000007A770308 210 29 2.10 63.840 2.201
000000007A7778B0 201 35 2.01 61.104 1.746
000000007A7879D8 200 28 2.00 60.800 2.171
000000007A7771A8 197 25 1.97 59.888 2.396
000000007A78A938 196 15 1.96 59.584 3.972
000000007A78D0C8 194 32 1.94 58.976 1.843
000000007A788A40 190 14 1.90 57.760 4.126
000000007A76F3B0 188 12 1.88 57.152 4.763
000000007A7791F0 183 25 1.83 55.632 2.225
000000007A763BA8 182 22 1.82 55.328 2.515
000000007A75EE18 181 23 1.81 55.024 2.392
000000007A7849B0 178 13 1.78 54.112 4.162
000000007A773D58 172 18 1.72 52.288 2.905
000000007A76B000 172 23 1.72 52.288 2.273
000000007A760CD0 170 10 1.70 51.680 5.168
000000007A760B40 169 32 1.69 51.376 1.606
000000007A78D000 169 16 1.69 51.376 3.211
000000007A766400 165 13 1.65 50.160 3.858
000000007A76F928 152 31 1.52 46.208 1.491
000000007A776B68 151 16 1.51 45.904 2.869
000000007A7672D8 143 25 1.43 43.472 1.739
000000007A7676C0 133 9 1.33 40.432 4.492
000000007A7869F8 130 17 1.30 39.520 2.325
000000007A786B88 129 13 1.29 39.216 3.017
40 rows selected.
SYS@book> @ ashtop sql_id,p1raw,p1,event,session_state 1=1 trunc(sysdate)+10/24+11/1440+15/86400 trunc(sysdate)+10/24+14/1440+06/86400
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID P1RAW P1 EVENT SESSION FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ----------------- ---------- ------------------------------------------ ------- ------------------- ------------------- ---------- -------- -----------
2707 15.8 80% | bjw5n8xcqpq8f 65536 ON CPU 2025-11-07 10:11:19 2025-11-07 10:14:05 1620 166 1620
635 3.7 19% | bjw5n8xcqpq8f 1413697536 ON CPU 2025-11-07 10:11:15 2025-11-07 10:14:00 377 165 377
9 .1 0% | 758j92j7f1yhz 65536 ON CPU 2025-11-07 10:11:29 2025-11-07 10:11:37 1 9 1
9 .1 0% | d7ntu3r83d91t 65536 ON CPU 2025-11-07 10:11:44 2025-11-07 10:12:53 3 9 3
6 .0 0% | 100 ON CPU 2025-11-07 10:12:03 2025-11-07 10:13:45 1 6 6
4 .0 0% | 758j92j7f1yhz 131072 ON CPU 2025-11-07 10:11:38 2025-11-07 10:11:41 1 4 1
4 .0 0% | 0000000000000002 2 control file parallel write WAITING 2025-11-07 10:12:30 2025-11-07 10:13:15 1 4 4
3 .0 0% | 0000000000000001 1 log file parallel write WAITING 2025-11-07 10:12:34 2025-11-07 10:13:44 1 3 3
2 .0 0% | 3q9xacy69bumn 1413697536 ON CPU 2025-11-07 10:13:50 2025-11-07 10:13:51 1 2 1
1 .0 0% | 0jbnyaz07kjcq 65536 ON CPU 2025-11-07 10:12:15 2025-11-07 10:12:15 1 1 1
1 .0 0% | 1d25xwrbnv4ub 0 ON CPU 2025-11-07 10:12:14 2025-11-07 10:12:14 1 1 1
1 .0 0% | 3cdnf24kj3j68 524288 ON CPU 2025-11-07 10:12:20 2025-11-07 10:12:20 1 1 1
1 .0 0% | 3mk07wzbs6uc3 524288 ON CPU 2025-11-07 10:12:23 2025-11-07 10:12:23 1 1 1
1 .0 0% | 3p7m6kzdrkpp0 262144 ON CPU 2025-11-07 10:12:18 2025-11-07 10:12:18 1 1 1
1 .0 0% | 60vsw0fx68rvn 524288 ON CPU 2025-11-07 10:12:22 2025-11-07 10:12:22 1 1 1
1 .0 0% | 6v6k1dtjz3aq2 262144 ON CPU 2025-11-07 10:12:16 2025-11-07 10:12:16 1 1 1
1 .0 0% | 8tsfarqa5qm5x 65536 ON CPU 2025-11-07 10:12:44 2025-11-07 10:12:44 1 1 1
1 .0 0% | 9wncfacx0nj9h 0000000000000003 3 db file sequential read WAITING 2025-11-07 10:13:19 2025-11-07 10:13:19 1 1 1
1 .0 0% | abbh56uvstv2p 524288 ON CPU 2025-11-07 10:12:21 2025-11-07 10:12:21 1 1 1
1 .0 0% | c6j08t1chw12a 131072 ON CPU 2025-11-07 10:12:19 2025-11-07 10:12:19 1 1 1
1 .0 0% | f5x2rxssufdmh 262144 ON CPU 2025-11-07 10:12:17 2025-11-07 10:12:17 1 1 1
1 .0 0% | 300 ON CPU 2025-11-07 10:12:16 2025-11-07 10:12:16 1 1 1
1 .0 0% | 1413697536 ON CPU 2025-11-07 10:11:37 2025-11-07 10:11:37 1 1 1
23 rows selected.
--//一样看不到latch: cache buffers chains。
--//查询LADDR对应那些对象，注意要在pdb下查询，因为tpt的bhla.sql脚本里面使用dba_objects.查询靠前的2个。
--//laddr=000000007A763D38,000000007A767AA8
SYS@book01p> col state format 99999999
SYS@book01p> @ tpt/bhla 000000007A763D38
OBJ OBJECT_TYPE object CLASS TCH DBA STATE MODE_HELD DQ FLG_LRUFLG
------ --------------- ---------------------------- ---------- --- -------- ----- --------- --- -----------
168020 TABLE SCOTT.CBC2 data block 116 12 1355 1 0 0 80000:8
2 CLUSTER SYS.C_OBJ# data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.ICOL$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.COL$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.TAB$ data block 2 9 6088 1 0 0 0:4
18 TABLE SYS.OBJ$ data block 2 9 23038 1 0 0 80000:8
2 TABLE SYS.IND$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.CLU$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.TYPE_MISC$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.ATTRCOL$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.ASSEMBLY$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.LIBRARY$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.LOB$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.COLTYPE$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.SUBCOLTYPE$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.NTAB$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.REFCON$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.OPQTYPE$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.ICOLDEP$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.VIEWTRCOL$ data block 2 9 6088 1 0 0 0:4
438 TABLE SYS.SMON_SCN_TIME data block 1 10 52000 1 0 0 80000:8
438 CLUSTER SYS.SMON_SCN_TO_TIME_AUX data block 1 10 52000 1 0 0 80000:8
168024 INDEX PARTITION SYS.SYS_IL0000016021C00016$$ data block 1 10 5515 1 0 0 200000:4
64 TABLE SYS.HISTGRM$ data block 1 9 35725 1 0 0 0:4
64 CLUSTER SYS.C_OBJ#_INTCOL# data block 1 9 35725 1 0 0 0:4
25 rows selected.
SYS@book01p> @ tpt/bhla 000000007A767AA8
OBJ OBJECT_TYPE object CLASS TCH DBA STATE MODE_HELD DQ FLG_LRUFLG
------ ----------- --------------------- ---------- ---- --------- ----- --------- --- ----------
168020 TABLE SCOTT.CBC2 data block 116 12 1639 1 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 116 12 354 1 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 116 12 252 1 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 116 12 1741 1 0 0 80000:8
--//4个不同dba的数据块在同一个laddr下。
18 TABLE SYS.OBJ$ data block 3 9 23322 1 0 0 80000:8
18 TABLE SYS.OBJ$ data block 3 9 28972 1 0 0 80000:8
274 TABLE SYS.RECYCLEBIN$ data block 3 9 36009 1 0 0 80000:8
795 TABLE SYS.KOTAD$ data block 1 9 5087 1 0 0 0:4
70 INDEX SYS.I_HH_OBJ#_INTCOL# data block 1 9 19059 1 0 0 0:8
64 TABLE SYS.HISTGRM$ data block 1 9 824 1 0 0 0:4
64 CLUSTER SYS.C_OBJ#_INTCOL# data block 1 9 824 1 0 0 0:4
386 TABLE SYS.IDL_UB2$ data block 1 9 10635 1 0 0 0:4
12 rows selected.
--//可以发现touch高的对象都是SCOTT.CBC2。
--//换一句讲，如果出现latch cache buffers chains，也许涉及dml语句。
--//优化sql的重点还是要减少逻辑读，以及执行次数(有一些开发以一种变态的方式频繁调用sql语句，类似死循环)。
5.继续测试：
SCOTT@book01p> update cbc2 set object_name=lower(object_name) where mod(object_id,10)=0;
7562 rows updated.
Elapsed: 00:00:00.11
--//不提交。
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @loop7.txt 100 > /dev/null ;zzdate
trunc(sysdate)+10/24+50/1440+02/86400 1762483802.989724861
SYS@book01p> @ ashtop sql_id,p1raw,p1,event,session_state 1=1 trunc(sysdate)+10/24+50/1440+02/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID P1RAW P1 EVENT SESSION FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ----------------- ---------- ------------------------------------------ ------- ------------------- ------------------- ---------- -------- -----------
26 .3 1% | bjw5n8xcqpq8f 000000007A776780 2054645632 latch: cache buffers chains WAITING 2025-11-07 10:50:49 2025-11-07 10:51:31 26 2 26
19 .2 1% | bjw5n8xcqpq8f 000000007A77C810 2054670352 latch: cache buffers chains WAITING 2025-11-07 10:50:57 2025-11-07 10:51:00 19 2 19
18 .2 1% | bjw5n8xcqpq8f 000000007A785F08 2054709000 latch: cache buffers chains WAITING 2025-11-07 10:50:14 2025-11-07 10:51:27 18 5 18
17 .2 1% | bjw5n8xcqpq8f 000000007A78B210 2054730256 latch: cache buffers chains WAITING 2025-11-07 10:50:27 2025-11-07 10:50:48 17 2 17
16 .2 1% | bjw5n8xcqpq8f 000000000000000C 12 buffer busy waits WAITING 2025-11-07 10:50:07 2025-11-07 10:50:49 16 5 16
16 .2 1% | bjw5n8xcqpq8f 000000007A783F48 2054700872 latch: cache buffers chains WAITING 2025-11-07 10:50:40 2025-11-07 10:50:40 16 1 16
15 .2 1% | bjw5n8xcqpq8f 000000007A7821E0 2054693344 latch: cache buffers chains WAITING 2025-11-07 10:51:15 2025-11-07 10:51:20 15 3 15
15 .2 1% | bjw5n8xcqpq8f 12 ON CPU 2025-11-07 10:50:11 2025-11-07 10:51:33 15 11 15
15 .2 1% | bjw5n8xcqpq8f 2054720864 ON CPU 2025-11-07 10:50:13 2025-11-07 10:50:28 15 3 15
14 .2 1% | bjw5n8xcqpq8f 000000007A784CD0 2054704336 latch: cache buffers chains WAITING 2025-11-07 10:50:43 2025-11-07 10:50:43 14 1 14
13 .1 1% | bjw5n8xcqpq8f 000000007A75DA50 2054543952 latch: cache buffers chains WAITING 2025-11-07 10:50:18 2025-11-07 10:50:18 13 1 13
13 .1 1% | bjw5n8xcqpq8f 000000007A766978 2054580600 latch: cache buffers chains WAITING 2025-11-07 10:50:38 2025-11-07 10:50:38 13 1 13
13 .1 1% | bjw5n8xcqpq8f 000000007A76B000 2054598656 latch: cache buffers chains WAITING 2025-11-07 10:51:12 2025-11-07 10:51:12 13 1 13
13 .1 1% | bjw5n8xcqpq8f 000000007A76D9A8 2054609320 latch: cache buffers chains WAITING 2025-11-07 10:50:42 2025-11-07 10:51:07 13 2 13
13 .1 1% | bjw5n8xcqpq8f 000000007A783390 2054697872 latch: cache buffers chains WAITING 2025-11-07 10:51:21 2025-11-07 10:51:21 13 1 13
13 .1 1% | bjw5n8xcqpq8f 000000007A786EA8 2054713000 latch: cache buffers chains WAITING 2025-11-07 10:50:09 2025-11-07 10:51:22 13 2 13
13 .1 1% | bjw5n8xcqpq8f 2054635840 ON CPU 2025-11-07 10:50:08 2025-11-07 10:51:29 13 4 13
12 .1 1% | bjw5n8xcqpq8f 000000007A764378 2054570872 latch: cache buffers chains WAITING 2025-11-07 10:51:25 2025-11-07 10:51:25 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A765290 2054574736 latch: cache buffers chains WAITING 2025-11-07 10:50:23 2025-11-07 10:50:23 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A7685D8 2054587864 latch: cache buffers chains WAITING 2025-11-07 10:51:28 2025-11-07 10:51:28 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A76F090 2054615184 latch: cache buffers chains WAITING 2025-11-07 10:51:08 2025-11-07 10:51:08 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A776DC0 2054647232 latch: cache buffers chains WAITING 2025-11-07 10:50:44 2025-11-07 10:50:44 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A7770E0 2054648032 latch: cache buffers chains WAITING 2025-11-07 10:51:04 2025-11-07 10:51:04 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A77E858 2054678616 latch: cache buffers chains WAITING 2025-11-07 10:50:32 2025-11-07 10:51:12 12 2 12
12 .1 1% | bjw5n8xcqpq8f 000000007A782758 2054694744 latch: cache buffers chains WAITING 2025-11-07 10:51:06 2025-11-07 10:51:06 12 1 12
12 .1 1% | bjw5n8xcqpq8f 2054598656 ON CPU 2025-11-07 10:50:23 2025-11-07 10:51:14 11 4 11
12 .1 1% | bjw5n8xcqpq8f 2054625576 ON CPU 2025-11-07 10:50:05 2025-11-07 10:51:19 12 3 12
12 .1 1% | bjw5n8xcqpq8f 2054683880 ON CPU 2025-11-07 10:50:16 2025-11-07 10:50:16 12 1 12
12 .1 1% | bjw5n8xcqpq8f 2054693344 ON CPU 2025-11-07 10:51:15 2025-11-07 10:51:20 12 2 12
11 .1 1% | bjw5n8xcqpq8f 000000007A76A278 2054595192 latch: cache buffers chains WAITING 2025-11-07 10:51:13 2025-11-07 10:51:13 11 1 11
30 rows selected.
--//查询大量的latch: cache buffers chains等待事件。
--//测试中间提交事务。
SCOTT@book01p> update cbc2 set object_name=lower(object_name) where mod(object_id,10)=0;
7562 rows updated.
Elapsed: 00:00:00.11
SCOTT@book01p> commit ;
Commit complete.
Elapsed: 00:00:00.00
--//等待测试结束。
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @loop7.txt 100 > /dev/null ;zzdate
trunc(sysdate)+10/24+50/1440+02/86400 -1762483802.989724861
trunc(sysdate)+10/24+54/1440+08/86400 1762484048.657759817
--//Sum = 245.668034956
SYS@book01p> @ ashtop sql_id,event 1=1 trunc(sysdate)+10/24+50/1440+02/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
3657 13.4 76% | bjw5n8xcqpq8f 2025-11-07 10:50:03 2025-11-07 10:54:08 1885 245 1885
1159 4.3 24% | bjw5n8xcqpq8f latch: cache buffers chains 2025-11-07 10:50:04 2025-11-07 10:52:08 737 120 737
16 .1 0% | bjw5n8xcqpq8f buffer busy waits 2025-11-07 10:50:07 2025-11-07 10:50:49 16 5 16
2 .0 0% | bjw5n8xcqpq8f latch: undo global data 2025-11-07 10:51:10 2025-11-07 10:51:35 2 2 2
1 .0 0% | dkqaz3vwf51g0 2025-11-07 10:50:25 2025-11-07 10:50:25 1 1 1
1 .0 0% | g55rj8y228yhm 2025-11-07 10:53:23 2025-11-07 10:53:23 1 1 1
6 rows selected.
--//latch: cache buffers chains出现的时间范围在2025-11-07 10:50:04 -- 2025-11-07 10:52:08之间，而整个测试结束时间是
--//trunc(sysdate)+10/24+54/1440+08/86400。
--//可以看出问题现在如果出现latch: cache buffers chains可能涉及dml的对象。
SYS@book01p> @ tpt/bhla 000000007A776780
OBJ OBJECT_TYPE object CLASS TCH DBA STATE MODE_HELD DQ FLG_LRUFLG
------- ----------- ------------------------ ---------- ---- -------- ----- ---------- --- -----------
168020 TABLE SCOTT.CBC2 data block 201 12 552 1 0 0 200000:8
168020 TABLE SCOTT.CBC2 data block 201 12 654 1 0 0 200000:8
168020 TABLE SCOTT.CBC2 data block 2 12 654 3 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 2 12 552 3 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 2 12 552 3 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 2 12 552 3 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 1 12 654 3 0 0 0:6
736 TABLE SYS.OPTSTAT_SNAPSHOT$ data block 1 9 37696 1 0 0 80000:8
438 CLUSTER SYS.SMON_SCN_TO_TIME_AUX data block 1 10 58234 1 0 0 80000:8
438 TABLE SYS.SMON_SCN_TIME data block 1 10 58234 1 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 1 12 552 3 0 0 80000:8
790 INDEX SYS.SYS_C00937 data block 0 9 33433 1 0 0 0:0
836 INDEX SYS.I_TABPART_BOPART$ data block 0 9 5387 1 0 0 200000:4
168020 TABLE SCOTT.CBC2 data block 0 12 654 3 0 0 0:8
168020 TABLE SCOTT.CBC2 data block 0 12 654 3 0 0 0:8
15 rows selected.
--//注意看dba列，对象SCOTT.CBC2上的数据块dba是相同的，dba=12 552 ,12 654.
--//后面的FLG_LRUFLG表示的细节不知道。
SYS@book> @ hidez _db_block_max_cr_dba
SYS@book> @ pr
==============================
NUM : 1984
N_HEX : 7C0
CON_ID : 0
NAME : _db_block_max_cr_dba
DESCRIPTION : Maximum Allowed Number of CR buffers per dba
DEFAULT_VALUE : TRUE
SESSION_VALUE : 6
SYSTEM_VALUE : 6
ISSES_MODIFIABLE : FALSE
ISSYS_MODIFIABLE : FALSE
PL/SQL procedure successfully completed.
--//可以发现1个数据块最大的允许的CR数量是6.每次执行sql访问数据块，因为对应数据块的修改没有提交，oracle要重构数据块，这样
--//每次读取要反复持有该latch。如果该链表的其他对象的数据块dml问题就没有这么严重，除非是反复dml操作。
--//理论讲12c以上的oracle数据库应该很少latch: cache buffers chains等待事件，优化的重点并没有变化减少逻辑读以及执行次数，
--//提高响应时间。
--//大家自己可以想象什么情况下会出现latch: cache buffers chains等待事件。
--//前一段时间测试oracle目前的版本在读读的情况很少出现latch cache buffers chains情况。
--//我以前的测试基本是单表，拿别人的例子验证看看。
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.建立测试环境：
--//参考链接：https://www.cnblogs.com/www-htz-pw/p/19014106
create table cbc1 as select * from dba_objects where owner='SYS' and rownum<201;
create table cbc2 as select * from dba_objects;
--//分析表略。
SCOTT@book01p> set timing on
SCOTT@book01p> SELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
COUNT(*)
----------
10883400
Elapsed: 00:00:00.65
SCOTT@book01p> @ sl all
alter session set statistics_level = all;
Session altered.
SCOTT@book01p> SELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
COUNT(*)
----------
10883400
SCOTT@book01p> @ dpc '' '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID 418781rd1m5kr, child number 1
-------------------------------------
SELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner =
b.owner
Plan hash value: 4079546673
----------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
----------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 87289 (100)| | 1 |00:00:04.95 | 315K|
| 1 | SORT AGGREGATE | | 1 | 1 | 9 | | | 1 |00:00:04.95 | 315K|
| 2 | NESTED LOOPS | | 1 | 602K| 5296K| 87289 (1)| 00:00:04 | 10M|00:00:03.91 | 315K|
| 3 | TABLE ACCESS FULL| CBC1 | 1 | 200 | 800 | 4 (0)| 00:00:01 | 200 |00:00:00.01 | 5 |
|* 4 | TABLE ACCESS FULL| CBC2 | 200 | 3013 | 15065 | 436 (1)| 00:00:01 | 10M|00:00:01.80 | 315K|
----------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1
3 - SEL$1 / "A"@"SEL$1"
4 - SEL$1 / "B"@"SEL$1"
Predicate Information (identified by operation id):
---------------------------------------------------
4 - filter("A"."OWNER"="B"."OWNER")
Hint Report (identified by operation id / Query Block Name / Object Alias):
Total hints for statement: 2 (U - Unused (1))
---------------------------------------------------------------------------
3 - SEL$1 / "A"@"SEL$1"
U - use_nl(a b)
4 - SEL$1 / "B"@"SEL$1"
- use_nl(a b)
39 rows selected.
--//看了执行计划，才发现实际上还是单表的情况，cbc1仅仅控制循环次数，看id=4，starts=200次。
--//在打开statistics_level = all测试需要4秒，如果不打开不到1秒完成。
--//建立测试脚本:
$ cat loop7.txt
set verify off
DECLARE
l_count number;
BEGIN
FOR i IN 1..&&1
LOOP
SELECT /*+ use_nl(a b)*/ COUNT (*) INTO l_count FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
END LOOP;
END;
/
--quit
3.测试：
--//在测试前猜测应该存在少量cbc，因为上面的2个表涉及许多数据块，无法保证每个cbc链条上不存在写的数据块。
--//发现密集执行还是很慢的(20个并发的情况，循环测试1e4的情况下)，在不打开的statistics_level = all的情况下需要接近2秒完成。
SCOTT@book01p> sELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
COUNT(*)
----------
10883400
Elapsed: 00:00:01.98
--//感觉虚拟机CPU数量不足...
--//这样不能测试时间太长，如果测试6个并发，执行100次。需要6*100*2/60/4 = 5(注：CPU_count=4)。
drop table cbc1 purge ;
create table cbc1 as select * from dba_objects where owner='SYS' and rownum<101;
--//分析略。
$ zzdate ; seq 6 | xargs -IQ -P 6 sqlplus -s -l scott/book@book01p @loop7.txt 100 > /dev/null ;zzdate
trunc(sysdate)+09/24+46/1440+34/86400 -1762479994.191368391
trunc(sysdate)+09/24+47/1440+25/86400 1762480045.920942321
--//Sum = 51.72957393
--//并发没有这么多还是不需要这么多时间完成。
--//51.72957393 /6/100 = .08621595655.
SYS@book> @ ashtop sql_id,p1raw,p1,event 1=1 trunc(sysdate)+09/24+46/1440+34/86400 trunc(sysdate)+09/24+47/1440+25/86400
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID P1RAW P1 EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ----------------- ---------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
210 4.1 70% | bjw5n8xcqpq8f 65536 2025-11-07 09:46:35 2025-11-07 09:47:24 210 50 210
43 .8 14% | bjw5n8xcqpq8f 1611704768 2025-11-07 09:46:42 2025-11-07 09:47:24 43 43 43
32 .6 11% | bjw5n8xcqpq8f 1413697536 2025-11-07 09:46:35 2025-11-07 09:46:43 32 9 32
7 .1 2% | bjw5n8xcqpq8f 740869104 2025-11-07 09:46:35 2025-11-07 09:46:41 7 7 7
4 .1 1% | 100 2025-11-07 09:46:34 2025-11-07 09:47:13 1 3 3
1 .0 0% | 3g08183h1fph7 8 2025-11-07 09:46:37 2025-11-07 09:46:37 1 1 1
1 .0 0% | 0000000000000002 2 control file parallel write 2025-11-07 09:46:38 2025-11-07 09:46:38 1 1 1
1 .0 0% | 0 2025-11-07 09:46:34 2025-11-07 09:46:34 1 1 1
8 rows selected.
--//在我的测试环境根本不存在dml操作，ashtop根本没有抓取到latch cache buffers chains等待事件，再次验证现在oracle版本在读
--//读模式下不需要持有cbc latch，或者讲不再存在阻塞，以一种共享的方式持有。
SYS@book> @ sql_id bjw5n8xcqpq8f
-- SQL_ID = bjw5n8xcqpq8f come from shared pool
SELECT /*+ use_nl(a b)*/ COUNT (*) FROM CBC1 A, CBC2 B WHERE A.OWNER = B.OWNER;
--//PL/sql将语句转换为大写。
--//你可能觉得ashtop的输出有点奇怪P1有值，而P1raw没有，实际上tpt的ashtop.sql脚本的执行p1raw的输出有条件：
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p1 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p1hex
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p2 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p2hex
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p3 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p3hex
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p1 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p1raw
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p2 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p2raw
, TO_CHAR(CASE WHEN session_state = 'WAITING' THEN p3 ELSE null END, 'fm0XXXXXXXXXXXXXXX') p3raw
SYS@book> @ s2h bjw5n8xcqpq8f
SQL_ID HASH_VALUE KGL_BUCKET
------------- ----------- ----------
bjw5n8xcqpq8f 1500174606 55566
--//明显与sql_id=bjw5n8xcqpq8f无关。
SYS@book> @ sharepool/shp4 '' 740869104
HANDLE_TYPE KGLHDADR KGLHDPAR C40 KGLHDLMD KGLHDPMD KGLHDIVC KGLOBHD0 KGLOBHD6 KGLOBHS0 KGLOBHS6 KGLOBT16 N0_6_16 N20 KGLNAHSH KGLOBT03 KGLHDBID KGLOBT09
---------------------- ---------------- ---------------- ---------------------------------------- ---------- ---------- ---------- ---------------- ---------------- ---------- ---------- ---------- --------- ---------- ---------- ------------- ---------- ----------
child handle address 0000000065A9E0A0 00000000659A0660 DECLARE l_count number; BEGIN FOR 0 0 0 0000000068A2BF90 00000000681D3E68 16256 16464 3448 36168 36168 740869104 8cqcbynq2jhzh 50160 0
parent handle address 00000000659A0660 00000000659A0660 DECLARE l_count number; BEGIN FOR 0 0 0 0000000068A4E980 00 4064 0 0 4064 4064 740869104 8cqcbynq2jhzh 50160 65535
--//P1=740869104对应匿名PLsql语句。
SYS@book> @ sharepool/shp4 '' 1413697536
no rows selected
SYS@book> @ sharepool/shp4 '' 1611704768
no rows selected
4.尝试使用latchprofx.sql看看
--//并发20个用户同时执行。
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @loop7.txt 100 > /dev/null ;zzdate
trunc(sysdate)+10/24+11/1440+15/86400 -1762481475.053176431
trunc(sysdate)+10/24+14/1440+06/86400 1762481646.062249438
--//Sum = 171.009073007
--//测试中间执行如下：
SCOTT@book01p> sELECT /*+ use_nl(a b)*/ COUNT (*) FROM cbc1 a, cbc2 b WHERE a.owner = b.owner;
COUNT(*)
----------
5441700
Elapsed: 00:00:01.87
--//确实基本需要2秒完成。
SYS@book> @ tpt/latchprofx.sql laddr % cache 10000
-- LatchProfX 2.11 by Tanel Poder ( https://tanelpoder.com )
LADDR Held Gets Held % Held ms Avg hold ms
---------------- ---------- ---------- ------- ----------- -----------
000000007A763D38 506 32 5.06 153.824 4.807
000000007A767AA8 477 103 4.77 145.008 1.408
000000007A77C748 453 53 4.53 137.712 2.598
000000007A780FA8 420 42 4.20 127.680 3.040
000000007A771928 362 78 3.62 110.048 1.411
000000007A770560 360 42 3.60 109.440 2.606
000000007A760E60 348 21 3.48 105.792 5.038
000000007A7660A0 348 22 3.48 105.792 4.809
000000007A760C08 344 44 3.44 104.576 2.377
000000007A768CE0 340 20 3.40 103.360 5.168
000000007A77B020 289 34 2.89 87.856 2.584
000000007A75CF60 239 26 2.39 72.656 2.794
000000007A776C30 237 31 2.37 72.048 2.324
000000007A76D9A8 231 36 2.31 70.224 1.951
000000007A774A18 224 41 2.24 68.096 1.661
000000007A783840 217 31 2.17 65.968 2.128
000000007A770308 210 29 2.10 63.840 2.201
000000007A7778B0 201 35 2.01 61.104 1.746
000000007A7879D8 200 28 2.00 60.800 2.171
000000007A7771A8 197 25 1.97 59.888 2.396
000000007A78A938 196 15 1.96 59.584 3.972
000000007A78D0C8 194 32 1.94 58.976 1.843
000000007A788A40 190 14 1.90 57.760 4.126
000000007A76F3B0 188 12 1.88 57.152 4.763
000000007A7791F0 183 25 1.83 55.632 2.225
000000007A763BA8 182 22 1.82 55.328 2.515
000000007A75EE18 181 23 1.81 55.024 2.392
000000007A7849B0 178 13 1.78 54.112 4.162
000000007A773D58 172 18 1.72 52.288 2.905
000000007A76B000 172 23 1.72 52.288 2.273
000000007A760CD0 170 10 1.70 51.680 5.168
000000007A760B40 169 32 1.69 51.376 1.606
000000007A78D000 169 16 1.69 51.376 3.211
000000007A766400 165 13 1.65 50.160 3.858
000000007A76F928 152 31 1.52 46.208 1.491
000000007A776B68 151 16 1.51 45.904 2.869
000000007A7672D8 143 25 1.43 43.472 1.739
000000007A7676C0 133 9 1.33 40.432 4.492
000000007A7869F8 130 17 1.30 39.520 2.325
000000007A786B88 129 13 1.29 39.216 3.017
40 rows selected.
SYS@book> @ ashtop sql_id,p1raw,p1,event,session_state 1=1 trunc(sysdate)+10/24+11/1440+15/86400 trunc(sysdate)+10/24+14/1440+06/86400
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID P1RAW P1 EVENT SESSION FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ----------------- ---------- ------------------------------------------ ------- ------------------- ------------------- ---------- -------- -----------
2707 15.8 80% | bjw5n8xcqpq8f 65536 ON CPU 2025-11-07 10:11:19 2025-11-07 10:14:05 1620 166 1620
635 3.7 19% | bjw5n8xcqpq8f 1413697536 ON CPU 2025-11-07 10:11:15 2025-11-07 10:14:00 377 165 377
9 .1 0% | 758j92j7f1yhz 65536 ON CPU 2025-11-07 10:11:29 2025-11-07 10:11:37 1 9 1
9 .1 0% | d7ntu3r83d91t 65536 ON CPU 2025-11-07 10:11:44 2025-11-07 10:12:53 3 9 3
6 .0 0% | 100 ON CPU 2025-11-07 10:12:03 2025-11-07 10:13:45 1 6 6
4 .0 0% | 758j92j7f1yhz 131072 ON CPU 2025-11-07 10:11:38 2025-11-07 10:11:41 1 4 1
4 .0 0% | 0000000000000002 2 control file parallel write WAITING 2025-11-07 10:12:30 2025-11-07 10:13:15 1 4 4
3 .0 0% | 0000000000000001 1 log file parallel write WAITING 2025-11-07 10:12:34 2025-11-07 10:13:44 1 3 3
2 .0 0% | 3q9xacy69bumn 1413697536 ON CPU 2025-11-07 10:13:50 2025-11-07 10:13:51 1 2 1
1 .0 0% | 0jbnyaz07kjcq 65536 ON CPU 2025-11-07 10:12:15 2025-11-07 10:12:15 1 1 1
1 .0 0% | 1d25xwrbnv4ub 0 ON CPU 2025-11-07 10:12:14 2025-11-07 10:12:14 1 1 1
1 .0 0% | 3cdnf24kj3j68 524288 ON CPU 2025-11-07 10:12:20 2025-11-07 10:12:20 1 1 1
1 .0 0% | 3mk07wzbs6uc3 524288 ON CPU 2025-11-07 10:12:23 2025-11-07 10:12:23 1 1 1
1 .0 0% | 3p7m6kzdrkpp0 262144 ON CPU 2025-11-07 10:12:18 2025-11-07 10:12:18 1 1 1
1 .0 0% | 60vsw0fx68rvn 524288 ON CPU 2025-11-07 10:12:22 2025-11-07 10:12:22 1 1 1
1 .0 0% | 6v6k1dtjz3aq2 262144 ON CPU 2025-11-07 10:12:16 2025-11-07 10:12:16 1 1 1
1 .0 0% | 8tsfarqa5qm5x 65536 ON CPU 2025-11-07 10:12:44 2025-11-07 10:12:44 1 1 1
1 .0 0% | 9wncfacx0nj9h 0000000000000003 3 db file sequential read WAITING 2025-11-07 10:13:19 2025-11-07 10:13:19 1 1 1
1 .0 0% | abbh56uvstv2p 524288 ON CPU 2025-11-07 10:12:21 2025-11-07 10:12:21 1 1 1
1 .0 0% | c6j08t1chw12a 131072 ON CPU 2025-11-07 10:12:19 2025-11-07 10:12:19 1 1 1
1 .0 0% | f5x2rxssufdmh 262144 ON CPU 2025-11-07 10:12:17 2025-11-07 10:12:17 1 1 1
1 .0 0% | 300 ON CPU 2025-11-07 10:12:16 2025-11-07 10:12:16 1 1 1
1 .0 0% | 1413697536 ON CPU 2025-11-07 10:11:37 2025-11-07 10:11:37 1 1 1
23 rows selected.
--//一样看不到latch: cache buffers chains。
--//查询LADDR对应那些对象，注意要在pdb下查询，因为tpt的bhla.sql脚本里面使用dba_objects.查询靠前的2个。
--//laddr=000000007A763D38,000000007A767AA8
SYS@book01p> col state format 99999999
SYS@book01p> @ tpt/bhla 000000007A763D38
OBJ OBJECT_TYPE object CLASS TCH DBA STATE MODE_HELD DQ FLG_LRUFLG
------ --------------- ---------------------------- ---------- --- -------- ----- --------- --- -----------
168020 TABLE SCOTT.CBC2 data block 116 12 1355 1 0 0 80000:8
2 CLUSTER SYS.C_OBJ# data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.ICOL$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.COL$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.TAB$ data block 2 9 6088 1 0 0 0:4
18 TABLE SYS.OBJ$ data block 2 9 23038 1 0 0 80000:8
2 TABLE SYS.IND$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.CLU$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.TYPE_MISC$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.ATTRCOL$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.ASSEMBLY$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.LIBRARY$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.LOB$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.COLTYPE$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.SUBCOLTYPE$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.NTAB$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.REFCON$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.OPQTYPE$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.ICOLDEP$ data block 2 9 6088 1 0 0 0:4
2 TABLE SYS.VIEWTRCOL$ data block 2 9 6088 1 0 0 0:4
438 TABLE SYS.SMON_SCN_TIME data block 1 10 52000 1 0 0 80000:8
438 CLUSTER SYS.SMON_SCN_TO_TIME_AUX data block 1 10 52000 1 0 0 80000:8
168024 INDEX PARTITION SYS.SYS_IL0000016021C00016$$ data block 1 10 5515 1 0 0 200000:4
64 TABLE SYS.HISTGRM$ data block 1 9 35725 1 0 0 0:4
64 CLUSTER SYS.C_OBJ#_INTCOL# data block 1 9 35725 1 0 0 0:4
25 rows selected.
SYS@book01p> @ tpt/bhla 000000007A767AA8
OBJ OBJECT_TYPE object CLASS TCH DBA STATE MODE_HELD DQ FLG_LRUFLG
------ ----------- --------------------- ---------- ---- --------- ----- --------- --- ----------
168020 TABLE SCOTT.CBC2 data block 116 12 1639 1 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 116 12 354 1 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 116 12 252 1 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 116 12 1741 1 0 0 80000:8
--//4个不同dba的数据块在同一个laddr下。
18 TABLE SYS.OBJ$ data block 3 9 23322 1 0 0 80000:8
18 TABLE SYS.OBJ$ data block 3 9 28972 1 0 0 80000:8
274 TABLE SYS.RECYCLEBIN$ data block 3 9 36009 1 0 0 80000:8
795 TABLE SYS.KOTAD$ data block 1 9 5087 1 0 0 0:4
70 INDEX SYS.I_HH_OBJ#_INTCOL# data block 1 9 19059 1 0 0 0:8
64 TABLE SYS.HISTGRM$ data block 1 9 824 1 0 0 0:4
64 CLUSTER SYS.C_OBJ#_INTCOL# data block 1 9 824 1 0 0 0:4
386 TABLE SYS.IDL_UB2$ data block 1 9 10635 1 0 0 0:4
12 rows selected.
--//可以发现touch高的对象都是SCOTT.CBC2。
--//换一句讲，如果出现latch cache buffers chains，也许涉及dml语句。
--//优化sql的重点还是要减少逻辑读，以及执行次数(有一些开发以一种变态的方式频繁调用sql语句，类似死循环)。
5.继续测试：
SCOTT@book01p> update cbc2 set object_name=lower(object_name) where mod(object_id,10)=0;
7562 rows updated.
Elapsed: 00:00:00.11
--//不提交。
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @loop7.txt 100 > /dev/null ;zzdate
trunc(sysdate)+10/24+50/1440+02/86400 1762483802.989724861
SYS@book01p> @ ashtop sql_id,p1raw,p1,event,session_state 1=1 trunc(sysdate)+10/24+50/1440+02/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID P1RAW P1 EVENT SESSION FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ----------------- ---------- ------------------------------------------ ------- ------------------- ------------------- ---------- -------- -----------
26 .3 1% | bjw5n8xcqpq8f 000000007A776780 2054645632 latch: cache buffers chains WAITING 2025-11-07 10:50:49 2025-11-07 10:51:31 26 2 26
19 .2 1% | bjw5n8xcqpq8f 000000007A77C810 2054670352 latch: cache buffers chains WAITING 2025-11-07 10:50:57 2025-11-07 10:51:00 19 2 19
18 .2 1% | bjw5n8xcqpq8f 000000007A785F08 2054709000 latch: cache buffers chains WAITING 2025-11-07 10:50:14 2025-11-07 10:51:27 18 5 18
17 .2 1% | bjw5n8xcqpq8f 000000007A78B210 2054730256 latch: cache buffers chains WAITING 2025-11-07 10:50:27 2025-11-07 10:50:48 17 2 17
16 .2 1% | bjw5n8xcqpq8f 000000000000000C 12 buffer busy waits WAITING 2025-11-07 10:50:07 2025-11-07 10:50:49 16 5 16
16 .2 1% | bjw5n8xcqpq8f 000000007A783F48 2054700872 latch: cache buffers chains WAITING 2025-11-07 10:50:40 2025-11-07 10:50:40 16 1 16
15 .2 1% | bjw5n8xcqpq8f 000000007A7821E0 2054693344 latch: cache buffers chains WAITING 2025-11-07 10:51:15 2025-11-07 10:51:20 15 3 15
15 .2 1% | bjw5n8xcqpq8f 12 ON CPU 2025-11-07 10:50:11 2025-11-07 10:51:33 15 11 15
15 .2 1% | bjw5n8xcqpq8f 2054720864 ON CPU 2025-11-07 10:50:13 2025-11-07 10:50:28 15 3 15
14 .2 1% | bjw5n8xcqpq8f 000000007A784CD0 2054704336 latch: cache buffers chains WAITING 2025-11-07 10:50:43 2025-11-07 10:50:43 14 1 14
13 .1 1% | bjw5n8xcqpq8f 000000007A75DA50 2054543952 latch: cache buffers chains WAITING 2025-11-07 10:50:18 2025-11-07 10:50:18 13 1 13
13 .1 1% | bjw5n8xcqpq8f 000000007A766978 2054580600 latch: cache buffers chains WAITING 2025-11-07 10:50:38 2025-11-07 10:50:38 13 1 13
13 .1 1% | bjw5n8xcqpq8f 000000007A76B000 2054598656 latch: cache buffers chains WAITING 2025-11-07 10:51:12 2025-11-07 10:51:12 13 1 13
13 .1 1% | bjw5n8xcqpq8f 000000007A76D9A8 2054609320 latch: cache buffers chains WAITING 2025-11-07 10:50:42 2025-11-07 10:51:07 13 2 13
13 .1 1% | bjw5n8xcqpq8f 000000007A783390 2054697872 latch: cache buffers chains WAITING 2025-11-07 10:51:21 2025-11-07 10:51:21 13 1 13
13 .1 1% | bjw5n8xcqpq8f 000000007A786EA8 2054713000 latch: cache buffers chains WAITING 2025-11-07 10:50:09 2025-11-07 10:51:22 13 2 13
13 .1 1% | bjw5n8xcqpq8f 2054635840 ON CPU 2025-11-07 10:50:08 2025-11-07 10:51:29 13 4 13
12 .1 1% | bjw5n8xcqpq8f 000000007A764378 2054570872 latch: cache buffers chains WAITING 2025-11-07 10:51:25 2025-11-07 10:51:25 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A765290 2054574736 latch: cache buffers chains WAITING 2025-11-07 10:50:23 2025-11-07 10:50:23 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A7685D8 2054587864 latch: cache buffers chains WAITING 2025-11-07 10:51:28 2025-11-07 10:51:28 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A76F090 2054615184 latch: cache buffers chains WAITING 2025-11-07 10:51:08 2025-11-07 10:51:08 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A776DC0 2054647232 latch: cache buffers chains WAITING 2025-11-07 10:50:44 2025-11-07 10:50:44 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A7770E0 2054648032 latch: cache buffers chains WAITING 2025-11-07 10:51:04 2025-11-07 10:51:04 12 1 12
12 .1 1% | bjw5n8xcqpq8f 000000007A77E858 2054678616 latch: cache buffers chains WAITING 2025-11-07 10:50:32 2025-11-07 10:51:12 12 2 12
12 .1 1% | bjw5n8xcqpq8f 000000007A782758 2054694744 latch: cache buffers chains WAITING 2025-11-07 10:51:06 2025-11-07 10:51:06 12 1 12
12 .1 1% | bjw5n8xcqpq8f 2054598656 ON CPU 2025-11-07 10:50:23 2025-11-07 10:51:14 11 4 11
12 .1 1% | bjw5n8xcqpq8f 2054625576 ON CPU 2025-11-07 10:50:05 2025-11-07 10:51:19 12 3 12
12 .1 1% | bjw5n8xcqpq8f 2054683880 ON CPU 2025-11-07 10:50:16 2025-11-07 10:50:16 12 1 12
12 .1 1% | bjw5n8xcqpq8f 2054693344 ON CPU 2025-11-07 10:51:15 2025-11-07 10:51:20 12 2 12
11 .1 1% | bjw5n8xcqpq8f 000000007A76A278 2054595192 latch: cache buffers chains WAITING 2025-11-07 10:51:13 2025-11-07 10:51:13 11 1 11
30 rows selected.
--//查询大量的latch: cache buffers chains等待事件。
--//测试中间提交事务。
SCOTT@book01p> update cbc2 set object_name=lower(object_name) where mod(object_id,10)=0;
7562 rows updated.
Elapsed: 00:00:00.11
SCOTT@book01p> commit ;
Commit complete.
Elapsed: 00:00:00.00
--//等待测试结束。
$ zzdate ; seq 20 | xargs -IQ -P 20 sqlplus -s -l scott/book@book01p @loop7.txt 100 > /dev/null ;zzdate
trunc(sysdate)+10/24+50/1440+02/86400 -1762483802.989724861
trunc(sysdate)+10/24+54/1440+08/86400 1762484048.657759817
--//Sum = 245.668034956
SYS@book01p> @ ashtop sql_id,event 1=1 trunc(sysdate)+10/24+50/1440+02/86400 sysdate
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID EVENT FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ------------------------------------------ ------------------- ------------------- ---------- -------- -----------
3657 13.4 76% | bjw5n8xcqpq8f 2025-11-07 10:50:03 2025-11-07 10:54:08 1885 245 1885
1159 4.3 24% | bjw5n8xcqpq8f latch: cache buffers chains 2025-11-07 10:50:04 2025-11-07 10:52:08 737 120 737
16 .1 0% | bjw5n8xcqpq8f buffer busy waits 2025-11-07 10:50:07 2025-11-07 10:50:49 16 5 16
2 .0 0% | bjw5n8xcqpq8f latch: undo global data 2025-11-07 10:51:10 2025-11-07 10:51:35 2 2 2
1 .0 0% | dkqaz3vwf51g0 2025-11-07 10:50:25 2025-11-07 10:50:25 1 1 1
1 .0 0% | g55rj8y228yhm 2025-11-07 10:53:23 2025-11-07 10:53:23 1 1 1
6 rows selected.
--//latch: cache buffers chains出现的时间范围在2025-11-07 10:50:04 -- 2025-11-07 10:52:08之间，而整个测试结束时间是
--//trunc(sysdate)+10/24+54/1440+08/86400。
--//可以看出问题现在如果出现latch: cache buffers chains可能涉及dml的对象。
SYS@book01p> @ tpt/bhla 000000007A776780
OBJ OBJECT_TYPE object CLASS TCH DBA STATE MODE_HELD DQ FLG_LRUFLG
------- ----------- ------------------------ ---------- ---- -------- ----- ---------- --- -----------
168020 TABLE SCOTT.CBC2 data block 201 12 552 1 0 0 200000:8
168020 TABLE SCOTT.CBC2 data block 201 12 654 1 0 0 200000:8
168020 TABLE SCOTT.CBC2 data block 2 12 654 3 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 2 12 552 3 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 2 12 552 3 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 2 12 552 3 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 1 12 654 3 0 0 0:6
736 TABLE SYS.OPTSTAT_SNAPSHOT$ data block 1 9 37696 1 0 0 80000:8
438 CLUSTER SYS.SMON_SCN_TO_TIME_AUX data block 1 10 58234 1 0 0 80000:8
438 TABLE SYS.SMON_SCN_TIME data block 1 10 58234 1 0 0 80000:8
168020 TABLE SCOTT.CBC2 data block 1 12 552 3 0 0 80000:8
790 INDEX SYS.SYS_C00937 data block 0 9 33433 1 0 0 0:0
836 INDEX SYS.I_TABPART_BOPART$ data block 0 9 5387 1 0 0 200000:4
168020 TABLE SCOTT.CBC2 data block 0 12 654 3 0 0 0:8
168020 TABLE SCOTT.CBC2 data block 0 12 654 3 0 0 0:8
15 rows selected.
--//注意看dba列，对象SCOTT.CBC2上的数据块dba是相同的，dba=12 552 ,12 654.
--//后面的FLG_LRUFLG表示的细节不知道。
SYS@book> @ hidez _db_block_max_cr_dba
SYS@book> @ pr
==============================
NUM : 1984
N_HEX : 7C0
CON_ID : 0
NAME : _db_block_max_cr_dba
DESCRIPTION : Maximum Allowed Number of CR buffers per dba
DEFAULT_VALUE : TRUE
SESSION_VALUE : 6
SYSTEM_VALUE : 6
ISSES_MODIFIABLE : FALSE
ISSYS_MODIFIABLE : FALSE
PL/SQL procedure successfully completed.
--//可以发现1个数据块最大的允许的CR数量是6.每次执行sql访问数据块，因为对应数据块的修改没有提交，oracle要重构数据块，这样
--//每次读取要反复持有该latch。如果该链表的其他对象的数据块dml问题就没有这么严重，除非是反复dml操作。
--//理论讲12c以上的oracle数据库应该很少latch: cache buffers chains等待事件，优化的重点并没有变化减少逻辑读以及执行次数，
--//提高响应时间。
--//大家自己可以想象什么情况下会出现latch: cache buffers chains等待事件。
浙公网安备 33010602011771号