Row Cache 或 Data Dictionary Cache 是共享池中的一个内存区域，用于保存数据字典信息以减少数据字典表的物理 I/O。行高速缓存锁主要用于序列化对数据字典的更改，当需要对数据字典高速缓存进行锁定时，将等待该锁,数据字典行上的锁称为row cache lock。等待此事件通常表示发生了某种形式的 DDL，或者可能是递归操作，例如存储管理和递增序列号。
每个行缓存锁将位于特定的数据字典对象上。这称为 enqueue 类型，可以在 v$rowcache 视图中找到。
等待参数（行缓存锁定等待）
| 参数 | 描述 |
|---|---|
| p1 | 与 V$ROWCACHE 的 CACHE# 列对应的数字 表示需要行锁的数据字典表 |
| p2 | 已持有锁的模式 |
| p3 | 需要锁定的模式 |
p1：
SELECT cache#, type, parameter FROM v$rowcache WHERE cache# = &P1;
P2 和 P3：
- KQRMNULL 0 空模式 – 未锁定
- KQRMS 3 共享模式
- KQRMX 5 专属模式
- KQRMFAIL 10 获取实例锁失败
使用以下查询查找正在等待的缓存（缓存 ID）：-
SQL> select p1text,p1,p2text,p2,p3text,p3 from v$session where event='row cache lock'; P1TEXT P1 P2TEXT P2 P3TEXT P3 ----- -- ----- --- ------ ---- cache id 8 mode 0 request 3 SQL> select parameter,count,gets,getmisses,modifications from v$rowcache where cache#=8; PARAMETER COUNT GETS GETMISSES MODIFICATIONS ---------- ------ ---- -------- ------------- DC_SEQUENCES 869 76843 508432 4500
Oracle 不希望获取行高速缓存排队锁，并且 conversions 阻止的时间超过几秒钟。因此，行缓存锁每 3 秒等待一次超时， 如果在 100 次超时 （5 分钟），则假定存在内部死锁，并且操作为 中止，alert log 显示“WAITED TOO LONG FOR A ROW CACHE ENQUEUE LOCK” 进程状态转储为 写入跟踪文件。
相关视图
Oralce 提供了 3 种关于行缓存对象的视图。
- V$ROWCACHE (X$KQRST):统计数据的概要视图。底层 X$ 表中的后缀“ST”可能表示“统计”。一个特殊的列：FASTGETS 被标记为保留供内部使用，这可能表明正在进行一些新的开发工作。V$ROWCACHE 是一个统计视图。
- V$ROWCACHE_PARENT (X$KQRFS):即时查看数据中心活动。它包含 4 个实时栏目：LOCK_MODE、LOCK_REQUEST、TXN、SADDR 这表明该视图能够即时反映每个锁的所有者和每个排队的成员。这是一个运行时视图，具有动态的行数）。
- V$ROWCACHE_SUBORDINATE (X$KQRFP):列出 4 个已存在的子缓存（下级)
ROWCACHE 内容
我们可以编写查询来列出所有字典缓存及其内容。每个查询都类似于 Oracle 执行递归查询访问行缓存的方式。 （ 请注意，小端字节序）首先 ，创建一个转换函数。
create or replace function dump_hex2str (dump_hex varchar2) return varchar2 is
l_str varchar2(100);
begin
with sq_pos as (select level pos from dual connect by level <= 1000)
,sq_chr as (select pos, chr(to_number(substr(dump_hex, (pos-1)*2+1, 2), 'XX')) ch
from sq_pos where pos <= length(dump_hex)/2)
select listagg(ch, '') within group (order by pos) word
into l_str
from sq_chr;
return l_str;
end;
/
常见原因
DC_SEQUENCES：在使用序列期间，可能会出现此行缓存锁等待。通过检查序列来优化，以查看它们是否指定了 cache 选项，以及该 cache 值是否反映了应用程序预期的同时插入。
DC_OBJECTS：在重新编译对象期间，可能会发生此行缓存锁定等待。如果正在进行对象编译，则可能需要一个排他锁，这将阻止其他活动。通过检查无效对象和依赖项进行优化，检查是否有频繁DDL。
DC_ROLLBACK_SEGS： 高并发导致的UNDO段相关的争用，检查undo使用率或长事务，大事务.
演示
我们将通过一个测试用例演示“行缓存锁”， 这里模拟dc_users,环境26ai。ksun在自己的blog写了好几篇关于row cache lock的测试。
方法：2个会话频繁的更改同一用户的密码。
create or replace procedure alter_user(p_cnt number) as
begin
for i in 1..p_cnt loop
execute immediate 'alter user test_user identified by 123';
end loop;
end;
/
-- 两个会话同时运行.
SQL> exec alter_user(1e6);
— 会话3 分析
select sid, event, total_waits, total_timeouts, time_waited, average_wait, max_wait, time_waited_micro
from v$session_event
where event = 'row cache lock'
/
SID EVENT TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT MAX_WAIT TIME_WAITED_MICRO
---------- ------------------------------------------ ----------- -------------- ----------- ------------ ---------- -----------------
984 row cache lock 1 0 0 .11 0 1059
1473 row cache lock 13079 0 6639 .51 6 66393759
1833 row cache lock 7 0 1 .16 0 10961
1837 row cache lock 13192 0 6341 .48 7 63408164
select event, total_waits, total_timeouts, time_waited, average_wait
,total_waits_fg, total_timeouts_fg, time_waited_fg, average_wait_fg
from v$system_event where lower(event) like '%row cache%';
EVENT TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT TOTAL_WAITS_FG TOTAL_TIMEOUTS_FG TIME_WAITED_FG AVERAGE_WAIT_FG
------------------------------------------ ----------- -------------- ----------- ------------ -------------- ----------------- -------------- ---------------
row cache mutex 301 0 142 .47 300 0 142 .47
row cache lock 32572 0 16053 .49 32571 0 16053 .49
row cache read 13 0 0 0 13 0 0 0
select chain_signature, osid, pid, sid, blocker_is_valid bvalid, blocker_sid,
p1, p1_text, p2, p3, in_wait_secs, num_waiters
from v$wait_chains w
order by in_wait_secs desc nulls first;
CHAIN_SIGNATURE
----------------------
OSID PID SID BVALID BLOCKER_SID P1 P1_TEXT P2 P3 IN_WAIT_SECS NUM_WAITERS
-------------------------------------------------- ---------- ---------- ---------- ----------- ---------- -------------------------
'row cache lock'<='row cache lock'
1066236 124 1473 FALSE 10 cache id 0 3 0 1
'row cache lock'<='row cache lock'
1061728 127 1837 TRUE 1473 10 cache id 0 5 0 0
SQL> select * from v$lock where sid in (1473,1837);
ADDR KADDR SID TYPE ID1 ID2 LMODE REQUEST CTIME BLOCK CON_ID
---------------- ---------------- ---------- ---- ---------- ---------- ---------- ---------- ---------- ---------- ----------
00000000A2AAFE38 00000000A2AAFE68 1473 AE 140 2914785930 4 0 231 0 0
00000000A2AB2CD0 00000000A2AB2D00 1837 DT 0 0 4 0 0 0 3
00000000A2AB2F58 00000000A2AB2F88 1837 AE 140 2914785930 4 0 486 0 0
SQL> select * from v$rowcache where cache#=10;
CACHE# TYPE SUBORDINATE# PARAMETER COUNT USAGE FIXED GETS FASTGETS GETMISSES SCANS SCANMISSES SCANCOMPLETES MODIFICATIONS FLUSHES DLM_REQUESTS DLM_CONFLICTS DLM_RELEASES CON_ID
---------- ---------------------- ------------ --------------------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ------------- ------------- ---------- ------------ ------------- ------------ ----------
10 PARENT dc_users 227 227 0 3321231 1635369 986 0 0 0 59260 59260 0 0 0 0
SQL> @snapper ash1=event+p1+sid 5 1 all
Sampling SID all with interval 5 seconds, taking 1 snapshots...
-- Session Snapper v4.34 - by Tanel Poder ( https://tanelpoder.com/snapper ) - Enjoy the Most Advanced Oracle Troubleshooting Script on the Planet! :)
---------------------------------------------------------------------------------------------------------------
ActSes %Thread | INST | SQL_ID | SQL_CHILD | EVENT | WAIT_CLASS
---------------------------------------------------------------------------------------------------------------
1.03 (103%) | 1 | 4dq0n3hjpcshj | | row cache lock | Concurrency
.39 (39%) | 1 | 4dq0n3hjpcshj | 0 | ON CPU | ON CPU
.39 (39%) | 1 | 4dq0n3hjpcshj | 1 | ON CPU | ON CPU
.25 (25%) | 1 | | 0 | log file parallel write | System I/O
.11 (11%) | 1 | | | ON CPU | ON CPU
.06 (6%) | 1 | 4dq0n3hjpcshj | 1 | Disk file operations I/O | User I/O
.03 (3%) | 1 | 4dq0n3hjpcshj | | row cache mutex | Concurrency
.03 (3%) | 1 | | 0 | ON CPU | ON CPU
----------------------------------------------------------------------------------------
ActSes %Thread | EVENT | P1 | SID
----------------------------------------------------------------------------------------
.53 (53%) | row cache lock | 10 | 1473
.50 (50%) | row cache lock | 10 | 1837
.44 (44%) | ON CPU | | 1837
.44 (44%) | ON CPU | | 1473
.25 (25%) | log file parallel write | 2 | 856
.03 (3%) | Disk file operations I/O | 5 | 1837
.03 (3%) | row cache mutex | 10 | 1473
.03 (3%) | Disk file operations I/O | 2 | 1837
.03 (3%) | ON CPU | | 856
-- End of ASH snap 1, end=2026-03-03 16:14:48, seconds=5, samples_taken=36, AAS=2.3
分析dc_user内容
select user_or_role_name, indx, hash, address, cache#, cache_name, existent, lock_mode, lock_request from (
select to_number(substr(key, 3, 2)||substr(key, 1, 2), 'XXXX') key_len,
dump_hex2str(rtrim(substr(key, 5, 2*to_number(substr(key, 3, 2)||substr(key, 1, 2), 'XXXX')), '0')) user_or_role_name,
v.*
from v$rowcache_parent v
where cache_name in ('dc_users')
order by key)
where user_or_role_name in ('TEST_USER');
USER_OR_ROLE_NAME INDX HASH ADDRESS CACHE# CACHE_NAME EX LOCK_MODE LOCK_REQUEST
---------------------------------------- ---------- ---------- ---------------- ---------- ---------------------------------------- -- ---------- ------------
TEST_USER 2666 21447 00000000BB603380 10 dc_users Y 5 0
TEST_USER 2665 21447 00000000BB603380 10 dc_users Y 0 3
使用10046 和 10704跟踪
SID1 > alter session set events='10046 trace name context forever, level 1 : 10704 trace name context forever, level 3'
tracefile_identifier='10704_rcl_7';
[oracle@db1 tpt-oracle-master]$ oerr ora 10704
10704, 00000, "Print out information about what enqueues are being obtained"
// *Document: NO
// *Cause: When enabled, prints out arguments to calls to ksqcmi and
// ksqlrl and the return values.
// *Action: Level indicates details:
// Level: 1-4: print out basic info for ksqlrl, ksqcmi
// 5-9: also print out stuff in callbacks: ksqlac, ksqlop
// 10+: also print out time for each line
ksqrcl: TX-00040006-007717CE-00000000-00000000
ksqrcl: TM-0018475C-00000000-00000000-00000000
ksqrcl: DT-00000000-00000000-00000000-00000000
我们可以看到，在执行 ALTER 语句后，DT 锁立即被获取。DT 代表默认临时表空间入队请求，用于序列化更改默认临时表空间和创建用户。
对于普通的表更新，不需要 DT 锁。TM和 TX 锁在执行最后一个 UPDATE 语句之前获取。“TM-0018475C”锁位于 sys.user$ 表上。
select owner, object_name, object_id, object_type
from dba_objects where object_id = to_number('18475C', 'XXXXXX');
OWNER OBJECT_NAM OBJECT_ID OBJECT_TYPE
----- ---------- --------- -----------
SYS USER$ 1591132 TABLE我们还可以扩展查询，以查找涉及的会话和（递归）事务：
select user_or_role_name, r.indx, hash, address, cache#, cache_name, existent, lock_mode, lock_request, txn, r.saddr, s.*, t.* from (
select to_number(substr(key, 3, 2)||substr(key, 1, 2), 'XXXX') key_len,
dump_hex2str(rtrim(substr(key, 5, 2*to_number(substr(key, 3, 2)||substr(key, 1, 2), 'XXXX')), '0')) user_or_role_name,
v.*
from v$rowcache_parent v
where cache_name in ('dc_users')
order by key) r, gv$session s, x$ktcxb t
where r.saddr = s.saddr(+) and r.txn = t.ktcxbxba(+)
and txn not in ('00');如果是查找dc_objects
select sid, dc_object_name, r.indx, hash, address, cache#, cache_name, existent, lock_mode, lock_request,
txn, r.saddr, s.blocking_session --, s.*, t.*
from (
select to_number(ltrim((substr(key, 7, 2)||substr(key, 5, 2)||substr(key, 3, 2)||substr(key, 1, 2)), '0'), 'XXXX') user_id,
(select username from dba_users where user_id =
to_number(ltrim((substr(key, 7, 2)||substr(key, 5, 2)||substr(key, 3, 2)||substr(key, 1, 2)), '0'), 'XXXX')) user_name,
dump_hex2str(rtrim(substr(key, 13), '0')) dc_object_name,
to_number(trim(both '0' from substr(key, 11, 2)||substr(key, 9, 2)), 'XXXX') key_len, v.*
from v$rowcache_parent v
where cache_name in ('dc_objects') and address like upper('%9c79f958')
order by key) r, gv$session s, x$ktcxb t
where r.saddr = s.saddr(+) and r.txn = t.ktcxbxba(+);这可以列出涉及的会话和（递归）事务：（注意：gv$transaction 定义在 x$ktcxb 上，过滤器为：bitand (ksspaflg, 1) != 0 和 bitand (ktcxbflg, 2) != 0。我们使用 x$ktcxb 是因为它们是递归事务，而递归事务在 gv$transaction 中已被过滤掉。）
其他row cache查询
--dc_users
select to_number(substr(key, 3, 2)||substr(key, 1, 2), 'XXXX') key_len,
dump_hex2str(rtrim(substr(key, 5, 2*to_number(substr(key, 3, 2)||substr(key, 1, 2), 'XXXX')), '0')) user_or_role_name
--,v.*
,indx,v.cache#,hash,cache_name
from v$rowcache_parent v
where cache_name in ('dc_users')
order by 2;
-- dc_objects
select to_number(ltrim((substr(key, 7, 2)||substr(key, 5, 2)||substr(key, 3, 2)||substr(key, 1, 2)), '0'), 'XXXX') Schema_User_ID,
(select username from dba_users where user_id =
to_number(ltrim((substr(key, 7, 2)||substr(key, 5, 2)||substr(key, 3, 2)||substr(key, 1, 2)), '0'), 'XXXX')) username,
dump_hex2str(rtrim(substr(key, 13), '0')) dc_object_name,
to_number(trim(both '0' from substr(key, 11, 2)||substr(key, 9, 2)), 'XXXX') key_str_len,
v.*
from v$rowcache_parent v
where cache_name in ('dc_objects')
and rownum<= 100 -- select 100 for test
order by key; 深入分析dc_objects
检查 DIAG dia0 或 mmnl 跟踪文件，我们可以看到 X 模式下阻塞的会话、阻塞会话和请求的行缓存父地址 (po 0x9c79f958)。
--testdb_dia0_10885_base_1.trc
--testdb_mmnl_10915.trc
*** 2021-06-25T11:37:49.281348+02:00
kqrhngc ph1: po 0x9c79f958 req X from session 0xb8d1d508 lock 0x9cbfb5e8
kqrhngc ph1: blocker #1 owner mode X session 0xb8990bb8 lock 0x9d32f7e0
通过以下查询，我们可以找到争用对象
select to_number(ltrim((substr(key, 7, 2)||substr(key, 5, 2)||substr(key, 3, 2)||substr(key, 1, 2)), '0'), 'XXXX') user_id,
(select username from dba_users where user_id =
to_number(ltrim((substr(key, 7, 2)||substr(key, 5, 2)||substr(key, 3, 2)||substr(key, 1, 2)), '0'), 'XXXX')) user_name,
dump_hex2str(rtrim(substr(key, 13), '0')) dc_object_name,
to_number(trim(both '0' from substr(key, 11, 2)||substr(key, 9, 2)), 'XXXX') key_len,
indx, hash, address, cache#, cache_name, existent, lock_mode, lock_request, txn, saddr --,v.*
from v$rowcache_parent v
where cache_name in ('dc_objects') and address like upper('%9c79f958');-- dc_sequence
create sequence test_seq start with 1 cache 1000;
with sq as (
select to_number(substr(key, 5, 2)||substr(key, 3, 2)||substr(key, 1, 2), 'XXXXXX') seq_object_id
,v.*
from v$rowcache_parent v
where cache_name in ('dc_sequences'))
select o.object_name, seq_object_id, cache#, cache_name
--,sq.*
from dba_objects o, sq
where o.object_id = sq.seq_object_id
and o.object_name = 'TEST_SEQ';
OBJECT_NAME SEQ_OBJECT_ID CACHE# CACHE_NAME
------------------------------ ------------- ---------- ----------------------------------------
TEST_SEQ 72582 13 dc_sequences
SQL> select count(*) cnt from v$rowcache_parent where cache_name = 'dc_sequences' ;
CNT
----------
12
select (hash+1) Hash_Bucket, count(*) Hash_Bucket_Size from v$rowcache_parent where cache_name = 'dc_sequences'
group by hash order by 1;
HASH_BUCKET HASH_BUCKET_SIZE
----------- ----------------
35 1
37 1
43 1
48 1
61 1
94 1
98 2
106 1
116 1
122 1
127 1
11 rows selected.可以看到 dc_sequences 中的 12 个 rowcache 对象分布在 11 个哈希桶中,桶的大小为1和2。任何大于 1 的大小都会导致哈希冲突。
row cache dump 转储
alter session set tracefile_identifier = 'dc_props_dump';
-- dump level 0xf2b: f is cache id 15 ('dc_props'), 2 is single cacheiddump, b is level of 11
alter session set events 'immediate trace name row_cache level 0xf2b';
alter session set events 'immediate trace name row_cache off';事件 10222 来跟踪row cache object Get 操作
# oerr ora 10222
10222, 00000, "row cache"
// *Document: NO
// *Cause:
// *Action:
SQL> alter session set tracefile_identifier = 'row_cache_10222_4294967295';
Session altered.
alter session set events '10222 trace name context forever, level 4294967295';
Session altered.
SQL> select value from nls_database_parameters where parameter = 'NLS_CHARACTERSET';
VALUE
--------------------------------------------------------------------------------------------------------------------------------
AL32UTF8
SQL> alter session set events '10222 trace name context off';
Session altered.
SQL> @t
TRACEFILE
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/anbob/anbob/trace/anbob_ora_1090252_row_cache_10222_4294967295.trc
SQL> host
[oracle@db1 tpt-oracle-master]$ cat /u01/app/oracle/diag/rdbms/anbob/anbob/trace/anbob_ora_1090252_row_cache_10222_4294967295.trc
Trace file /u01/app/oracle/diag/rdbms/anbob/anbob/trace/anbob_ora_1090252_row_cache_10222_4294967295.trc
Oracle AI Database 26ai Enterprise Edition Release 23.26.1.0.0 - Production
Version 23.26.1.0.0
Build label: RDBMS_23.26.1.0.0DBRU_LINUX.X64_260116.1
ORACLE_HOME: /u01/app/oracle/product/26.0.0/dbhome_1
System name: Linux
Node name: db1
Release: 5.15.0-3.60.5.1.el8uek.x86_64
Version: #2 SMP Wed Oct 19 20:04:48 PDT 2022
Machine: x86_64
CLID: P
Instance name: anbob
Instance number: 1
Database name: anbob
Database unique name: anbob
Database id: 1600991291
Database role: PRIMARY
Redo thread mounted by this instance: 1
Oracle binary inode: 5328062
Oracle process number: 133
Unix process pid: 1090252
NID: 4026531836
created: 2026-03-03T16:41:39.-1713613736+08:00
image: oracle@db1 (TNS V1-V3)
*** 2026-03-03T18:23:21.555505+08:00 (PDB11(3))
*** SESSION ID:(618.38618) 2026-03-03T18:23:21.555521+08:00
*** CLIENT ID:() 2026-03-03T18:23:21.555558+08:00
*** SERVICE NAME:(pdb11) 2026-03-03T18:23:21.555573+08:00
*** MODULE NAME:(sqlplus@db1 (TNS V1-V3)) 2026-03-03T18:23:21.555587+08:00
*** ACTION NAME:() 2026-03-03T18:23:21.555600+08:00
*** CLIENT DRIVER:(SQL*PLUS) 2026-03-03T18:23:21.555613+08:00
*** CONTAINER ID:(3) 2026-03-03T18:23:21.555626+08:00
*** CLIENT IP:(N/A) 2026-03-03T18:23:21.555639+08:00
*** CONNECTION ID:(TBusGrQmosvgY6YWFKzGCA==) 2026-03-03T18:23:21.555654+08:00
*** TRACE CONTINUED FROM FILE /u01/app/oracle/diag/rdbms/anbob/anbob/trace/anbob_ora_1090252_row_cache_10222_4.trc ***
kqrSetHashChainProperty(): cid 15 bucket 57 set new property 1 (KQRDEBUG event forced)
Row Cache: cid 15 bucket 57 marked HOT (KQRDEBUG event forced)
kqrpre2(): start cid=15 hash=b3763d79 mode=S idx=0 dur=CALL opt=TRUE hot=TRUE
kqrProcessOptimisticRequest(): hash=b3763d79
kqrSearchFastPathCache(): searching cache 0 po 0x76514b60 hash 5c02963a ver 1
kqrSearchFastPathCache(): searching cache 1 po 0x80ab34a8 hash 83ced5bd ver 1
kqrSearchFastPathCache(): searching cache 2 po 0x7e5ec8e8 hash 644246c3 ver 1
kqrSearchFastPathCache(): searching cache 3 po 0x7ea7ea68 hash 687d9af7 ver 1
kqrSearchFastPathCache(): searching cache 4 po 0xb720b698 hash 12014be6 ver 1
kqrSearchFastPathCache(): searching cache 5 po 0xb5e6b928 hash 28de8bb3 ver 1
kqrSearchFastPathCache(): searching cache 6 po 0x76c63c50 hash 69ff0d9 ver 1
kqrSearchFastPathCache(): searching cache 7 po 0x7e18af58 hash 728c50ad ver 1
kqrSearchFastPathCache(): searching cache 8 po 0x823d6820 hash 5b751bc9 ver 1
kqrSearchFastPathCache(): searching cache 9 po 0x7e188fd8 hash 44dd15e1 ver 1
kqrProcessOptimisticRequest(): reading hash mtx addr=0x94fb4efc version=18
kqrFastPoRead(): processing po 0xb5f73d20 mtx addr=0xb5f73e40 version=6
kqrFastPoRead(): lock mode 0 flag 00000002
kqrProcessOptimisticRequest(): copied po 0xb5f73d20 to cache 7
kqrProcessOptimisticRequest(): optimistic lookup: success
kqrDoneTrace(): po=0x7fbe1946aa98 cid=15 flg=2 eq=0x80996230 pso=0xa7805368 dur=CALL
kqrDoneTrace(): keyIndex=0 hash=b3763d79 0 0 inc=1, pdbinc=1
kqrDoneTrace(): SQL=select value from nls_database_parameters where parameter = 'NLS_CHARACTERSET' kqrDoneTrace(): time=208587548
kqrDoneTrace(): po=0x7fbe1946aa98 cid=15 stack: ----- Abridged Call Stack Trace -----
ksedsts()+409<-kqrDoneTrace()+2729<-kqrpre2()+20199<-kqrpre1()+40<-kkdlpExecSqlCbk()+412<-kkdlpExecSql()+171<-kkdlpGet()+461<-kkdlpftld()+421<-qerfxFetch()+9086<-opifch2()+3789<-kpoal8()+4501<-opiodr()+1485<-ttcpip()+1303<-opitsk()+2133<-opiino()+1111<-opiodr()+1485<-opidrv()+1048<-sou2o()+153<-opimai_real()+448<-ssthrdmain()+535<-main()+313<-__libc_start_main()+229<-_start()+46
----- End of Abridged Call Stack Trace -----
Partial short call stack signature: 0xe15f7e11796e1732
kqrDoneTrace():
kqrDoneTrace(): returnVal: TRUE
kqrprl(): eq=0x80996230 fpInUse=TRUE
----- Abridged Call Stack Trace -----
ksedsts()+409<-kqrprl()+2137<-kkdlpExecSqlCbk()+502<-kkdlpExecSql()+171<-kkdlpGet()+461<-kkdlpftld()+421<-qerfxFetch()+9086<-opifch2()+3789<-kpoal8()+4501<-opiodr()+1485<-ttcpip()+1303<-opitsk()+2133<-opiino()+1111<-opiodr()+1485<-opidrv()+1048<-sou2o()+153<-opimai_real()+448<-ssthrdmain()+535<-main()+313<-__libc_start_main()+229<-_start()+46
----- End of Abridged Call Stack Trace -----
“cid”表示缓存 ID；“kqrpre1”表示行缓存对象读取；“po”表示父对象。
SQL> select * from v$rowcache_parent where address like upper('%b5f73d20');
INDX HASH ADDRESS CACHE# CACHE_NAME EX LOCK_MODE LOCK_REQUEST TXN SADDR INST_LOCK_REQUEST INST_LOCK_RELEASE INST INST_LOC INST_LOC KEY CON_ID
---------- ---------- ---------------- ---------- ---------------------------------------- -- ---------- ------------ ---------------- ---------------- ----------------- ----------------- ---- -------- -------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ----------
5302 57 00000000B5F73D20 15 dc_props Y 0 0 00 00 0 0 00 00 4E4C535F434841524143544552534554000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
SQL> select * from v$rowcache_parent where address like upper('%76514b60');
INDX HASH ADDRESS CACHE# CACHE_NAME EX LOCK_MODE LOCK_REQUEST TXN SADDR INST_LOCK_REQUEST INST_LOCK_RELEASE INST INST_LOC INST_LOC KEY CON_ID
---------- ---------- ---------------- ---------- ---------------------------------------- -- ---------- ------------ ---------------- ---------------- ----------------- ----------------- ---- -------- -------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ----------
1063 5690 0000000076514B60 8 dc_objects Y 0 0 00 00 0 0 00 00 0000000018005359535F494C30303030303030333432433030303136242400000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
3136 3810 0000000076514B60 11 dc_objects Y 0 0 00 00 0 0 00 00 58010000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
SQL> select * from v$rowcache_parent where address like upper('%80ab34a8');
INDX HASH ADDRESS CACHE# CACHE_NAME EX LOCK_MODE LOCK_REQUEST TXN SADDR INST_LOCK_REQUEST INST_LOCK_RELEASE INST INST_LOC INST_LOC KEY CON_ID
---------- ---------- ---------------- ---------- ---------------------------------------- -- ---------- ------------ ---------------- ---------------- ----------------- ----------------- ---- -------- -------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ----------
392 21949 0000000080AB34A8 2 dc_segments Y 0 0 00 00 0 0 00 00 00000000000400005001000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
SQL> select * from v$rowcache_parent where cache#=15;
INDX HASH ADDRESS CACHE# CACHE_NAME EX LOCK_MODE LOCK_REQUEST TXN SADDR INST_LOCK_REQUEST INST_LOCK_RELEASE INST INST_LOC INST_LOC KEY CON_ID
---------- ---------- ---------------- ---------- ---------------------------------------- -- ---------- ------------ ---------------- ---------------- ----------------- ----------------- ---- -------- -------- -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ----------
0 12 00000000B754A978 15 dc_props Y 0 0 00 00 0 0 00 00 5245434F5F4C4F47494E5F50415353574F5244000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
1 12 00000000BBE65D28 15 dc_props N 0 0 00 00 0 0 00 00 4D41585F535452494E475F53495A455F4D4947524154450000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
2 17 00000000BBC9FCB8 15 dc_props Y 0 0 00 00 0 0 00 00 44454641554C545F45444954494F4E00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
3 37 0000000071955E40 15 dc_props Y 0 0 00 00 0 0 00 00 5245434F5F4C4F47494E5F555345524E414D45000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
4 53 00000000B4C55190 15 dc_props Y 0 0 00 00 0 0 00 00 474C4F42414C5F44425F4E414D450000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
5 57 00000000B5F73D20 15 dc_props Y 0 0 00 00 0 0 00 00 4E4C535F434841524143544552534554000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
6 61 000000007870CA28 15 dc_props Y 0 0 00 00 0 0 00 00 4E4C535F4E434841525F434841524143544552534554000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 3
7 rows selected.
SQL> select * from v$rowcache where cache#=15;
CACHE# TYPE SUBORDINATE# PARAMETER COUNT USAGE FIXED GETS FASTGETS GETMISSES SCANS SCANMISSES SCANCOMPLETES MODIFICATIONS FLUSHES DLM_REQUESTS DLM_CONFLICTS DLM_RELEASES CON_ID
---------- ---------------------- ------------ ---------------------------------------------------------------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ------------- ------------- ---------- ------------ ------------- ------------ ----------
15 PARENT dc_props 15 15 0 916 2297208 909 1 0 1 0 0 0 0 0 0
10222 跟踪导入和分析脚本
drop table raw_10222_trc_ext;
create table raw_10222_trc_ext
( text1 varchar2(1000)
)
organization external
(type oracle_loader
default directory PLSHPROF_DIR
access parameters
(
records delimited by newline CHARACTERSET AL32UTF8
badfile aaa_db_io:'trc_ext.bad'
logfile aaa_db_io:'trc_ext.log'
discardfile aaa_db_io:'trc_ext.dsc'
fields terminated by ',' OPTIONALLY ENCLOSED BY '"'
missing field values are null
( text1 position(1:1000)
)
)
location ('testdb_ksun_trc_row_cache_10222_15.trc')
) reject limit unlimited;
select rownum line_nbr, text1 from raw_10222_trc_ext;
drop table import_10222_trc;
create table import_10222_trc (run number, line_nbr number, cid number, ts_us number, po_address varchar2(32),
cid_type varchar2(12), cid_subordinate# number, cid_parameter varchar2(40),
obobn number, obname varchar2(100), sql varchar2(100), raw_lines varchar2(4000));
create or replace procedure import_10222_trc_proc (p_run number, p_trc_file varchar2, p_delete_old boolean := true) as
l_line_sep varchar2(3) := '###';
l_pos_1 number;
l_pos_2 number;
l_raw_lines varchar2(32000);
l_line_nbr number := 1;
l_cid number;
l_ts_us number;
l_po_address varchar2(32000);
l_obobn number;
l_obname varchar2(32000);
l_sql varchar2(32000);
begin
-- setup trace file location
execute immediate 'alter table raw_10222_trc_ext location (''' || p_trc_file || ''')';
-- delete old RUN
if p_delete_old then
delete from import_10222_trc where run = p_run;
commit;
end if;
-- concatenate same PO lines into one line
for c in (select rownum line_nbr, text1 from raw_10222_trc_ext) loop
dbms_output.put_line('Raw line_nbr: '||c.line_nbr ||'--text1: '||c.text1);
if l_raw_lines is null then
l_raw_lines := c.text1;
else
l_raw_lines := l_raw_lines ||l_line_sep||c.text1;
end if;
if c.text1 like 'kqrpre1 : found po=%' or c.text1 like 'kqrpad: new po%' then
l_raw_lines := substr(l_raw_lines, 1, 4000);
insert into import_10222_trc(run, line_nbr, raw_lines) values(p_run, l_line_nbr, l_raw_lines);
commit;
l_line_nbr := c.line_nbr;
l_raw_lines := c.text1;
end if;
end loop;
-- insert last line
if length(l_raw_lines) > 0 then
l_raw_lines := substr(l_raw_lines, 1, 4000);
insert into import_10222_trc(run, line_nbr, raw_lines) values(p_run, l_line_nbr, l_raw_lines);
commit;
end if;
-- parse raw_lines
for c in (select line_nbr, raw_lines from import_10222_trc
where raw_lines like 'kqrpre1 : found po=%' or raw_lines like 'kqrpad: new po%') loop
dbms_output.put_line('Parsing line_nbr: '||c.line_nbr||'--text1: '||c.raw_lines);
l_cid := regexp_substr(c.raw_lines, 'cid=(\d*)', 1, 1, 'i', 1);
l_pos_1 := instr(c.raw_lines, 'time=', -1);
if l_pos_1 > 0 then
l_ts_us := regexp_substr(c.raw_lines, 'time=(\d*)', l_pos_1, 1, 'i', 1);
end if;
l_po_address := substr(upper(regexp_substr(c.raw_lines, 'po=(\S*)', 1, 1, 'i', 1)), 1, 32);
l_obobn := regexp_substr(c.raw_lines, 'obobn=(\d*)', 1, 1, 'i', 1);
l_obname := substr(regexp_substr(c.raw_lines, 'obname=(\S*)', 1, 1, 'i', 1), 1, 100);
l_pos_2 := instr(c.raw_lines, 'SQL=', 1) + 4;
if (l_pos_2 > 4) then
l_pos_1 := instr(c.raw_lines, 'time=', l_pos_2);
if l_pos_1 = 0 then l_pos_1 := l_pos_2 + 100; end if;
l_sql := substr(substr(c.raw_lines, l_pos_2, l_pos_1 - l_pos_2), 1, 100);
else
l_sql := null;
end if;
update import_10222_trc
set cid = l_cid
,ts_us = l_ts_us
,po_address = l_po_address
,obobn = l_obobn
,obname = l_obname
,sql = l_sql
where run = p_run and line_nbr = c.line_nbr;
commit;
end loop;
-- add v$rowcache info
update import_10222_trc t
set (cid_type, cid_subordinate#, cid_parameter) =
(select type, subordinate#, parameter from v$rowcache r where r.cache# = t.cid and rownum=1)
where run = p_run;
commit;
end;
/还有一个事件：10205，内容如下：
10205, 00000, "row cache debugging"
// *Cause:
// *Action:
/ At level 1, KQR will dump out latch clean-up debugging traces.
/ At level 2, KQR will dump out bootstrap debugging traces.
/ At level 3, KQR will invalidate, remove from the cache and put 0xff's
/ in row cache objects that are not currently locked.无法使用 10205 生成跟踪文件。
Dtrace 脚本
当然也可以使用dtrace
-. rco_dtrace_cache：跟踪每个行缓存对象及其参数。
-. rco_dtrace_latch：打印出每个行缓存锁存器获取调用堆栈。
rco_dtrace_cache
sudo dtrace -n \
'pid$target::kqrLockAndPinPo:entry /execname == "oracle"/ {
@cid_addr_cnt[arg0, arg1] = count();
@cid_cnt[arg0] = count();
@cid_cnt_total = count();
ustack(5, 0);
printf("\nCID = %-4d ADDR = %-16X\n", arg0, arg1);}
END {
/** Only first call in new opened Sqlplus has not double counting **/
printf("\n\n*************** CID Stats with Address (double counting) ****************");
printa("\nCID = %-4d ADDR = %-16X CNT = %-10@d", @cid_addr_cnt);
printf("\n*************** CID Stats ****************");
printa("\nCID = %-4d CNT = %-10@d", @cid_cnt);
printf("\n*************** CID Stats Summary ****************");
printa("\nCNT = %-10@d", @cid_cnt_total); }
' -p $1
rco_dtrace_latch
sudo dtrace -F -n \
'
BEGIN {roread = 0; step = 1; self->func = "ne"; self->name = "na"; prev_ts = timestamp;}
pid$target::kqrpre1:entry /execname == "oracle" && self->func != probefunc / {roread = 1;
printf("\n---------Step %d at %Y (Elapsed-ns=%d)---------", step, walltimestamp, (timestamp-prev_ts));
self->func = probefunc; self->name = probename; step = step + 1; prev_ts = timestamp;
@cnt[probefunc] = count();}
pid$target::kqrpre1:return /roread ==1/ {roread = 0;
printf("\n---------Step %d at %Y (Elapsed-ns=%d)---------", step, walltimestamp, (timestamp-prev_ts));
self->func = probefunc; self->name = probename; step = step + 1; prev_ts = timestamp;}
pid$target::kslgetl:entry /step > 1 && self->func != probefunc / {
printf("\n---------Step %d at %Y (Elapsed-ns=%d)---------", step, walltimestamp, (timestamp-prev_ts));
self->func = probefunc; self->name = probename; step = step + 1; prev_ts = timestamp;
@cnt[probefunc] = count();}
pid$target::kslgetl:return /self->func == probefunc && self->name != probename/{
printf("\n---------Step %d at %Y (Elapsed-ns=%d)---------", step, walltimestamp, (timestamp-prev_ts));
self->func = probefunc; self->name = probename; step = step + 1; prev_ts = timestamp;}
pid$target::kslfre:entry /step > 1 && self->func != probefunc / {
printf("\n---------Step %d at %Y (Elapsed-ns=%d)---------", step, walltimestamp, (timestamp-prev_ts));
self->func = probefunc; self->name = probename; step = step + 1; prev_ts = timestamp;
@cnt[probefunc] = count();}
pid$target::kslfre:return /self->func == probefunc && self->name != probename/{
printf("\n---------Step %d at %Y (Elapsed-ns=%d)---------", step, walltimestamp, (timestamp-prev_ts));
self->func = probefunc; self->name = probename; step = step + 1; prev_ts = timestamp;}
pid$target::kqrLockAndPinPo:entry /step > 1 && self->func != probefunc / {
printf("\n---------Step %d at %Y (Elapsed-ns=%d)---------", step, walltimestamp, (timestamp-prev_ts));
self->func = probefunc; self->name = probename; step = step + 1; prev_ts = timestamp;
@cnt[probefunc] = count();}
pid$target::kqrLockAndPinPo:return /self->func == probefunc && self->name != probename/{
printf("\n---------Step %d at %Y (Elapsed-ns=%d)---------", step, walltimestamp, (timestamp-prev_ts));
self->func = probefunc; self->name = probename; step = step + 1; prev_ts = timestamp;}
' -p $1gdb 脚本
运行脚本之前，需要调整断点编号和地址。
### ----================ gdb script: gdb -x gdb_cmd_script2 -p 18158 ================----
set pagination off
set logging file /temp/mutex-test2.log
set logging overwrite on
set logging on
set $k = 0
set $g = 0
set $r = 0
set $spacex = ' '
rbreak ^kqr.*
rbreak ^kgx.*
command 1-333
continue
end
#kqrmpin
delete 133
#kqrpre1
delete 138
#kgxExclusive
delete 326
#kgxRelease
delete 331
#10222 trc pso, processstate dump SOC (State Object Call): $r8
break *kqrpre1
command
printf "<<<==================== (%i) kqrpre1 pso (SOC): %x ====================>>>\n", ++$k, $r8
set $g = 0
set $r = 0
continue
end
#kqrhsh+109 retq, output hash value in "oradebug dump row_cache 0xf2b" (0xf2b is for "dc_props")
break *0x00000000126df8ad
command
printf "%5c(%i) kqrhsh retq hash (rax): hash=%x\n", $spacex, $k, $rax
continue
end
break *kgxExclusive
command
printf "%5c(%i-%i) ---> kgxExclusive Mutex addr (rsi): %x\n", $spacex, $k, ++$g, $rsi
continue
end
break *kgxRelease
command
printf "%5c(%i-%i) <--- kgxRelease Mutex addr (*rsi): %x\n", $spacex, $k, ++$r, *((int *)$rsi)
continue
end
#output v$rowcache_parent.address for row cache object
break *kqrmpin
command
printf "%5c(%i) kqrmpin v$rowcache_parent.address (rdi): addr=%x cid=%i\n", $spacex, $k, $rdi, $r11
continue
end
create or replace procedure alter_user(p_cnt number) as
begin
for i in 1..p_cnt loop
execute immediate 'alter user test_user identified by 123';
end loop;
end;
/— over —