暂无图片
暂无图片
暂无图片
暂无图片
暂无图片

Troubleshooting "latch: row cache objects" case and Event 10089 to do.

原创 Anbob 2019-02-01
1289
"row cache objects"是序列化latch,用于保护对SGA中dictionary cache的访问。 只要是参考dictionary cache中的元数据对象,就会获取此latch。 Row Cache Objects Latch 是 shared pool latch 相关,目的是为访问Oracle中缓存的 data dictionary area的用户进程提供数据保护。
这里记录一个11.2.0.3 RAC环境中的案例, 几年前写过一篇分析脚本《Tuning ‘latch: row cache objects’ Event
SQL> @sw "select sid from v$session where event='latch: row cache objects'"
SID STATE EVENT SEQ# SEC_IN_WAIT P1 P2 P3 P1TRANSL
------- ------- ---------------------------------------- ---------- ----------- ------------------- ------------------- ------------------- ------------------------------------------
557 WAITING latch: row cache objects 47722 0 address= number= 280 tries= 0 0xC0000015B3ABB538: row cache objects[c8]
0xC0000015B3ABB538
16325 WAITING latch: row cache objects 3555 0 address= number= 280 tries= 0 0xC0000015B3ABB538: row cache objects[c8]
0xC0000015B3ABB538
948 WAITING latch: row cache objects 5190 0 address= number= 280 tries= 0 0xC0000015B3ABB538: row cache objects[c8]
0xC0000015B3ABB538
1363 WAITING latch: row cache objects 12934 0 address= number= 280 tries= 0 0xC0000015B3ABB538: row cache objects[c8]
0xC0000015B3ABB538
1622 WAITING latch: row cache objects 27639 0 address= number= 280 tries= 0 0xC0000015B3ABB538: row cache objects[c8]
0xC0000015B3ABB538
717 WAITING latch: row cache objects 64778 0 address= number= 280 tries= 0 0xC0000015B3ABB538: row cache objects[c8]
0xC0000015B3ABB538
SQL> select * from v$latch_children where addr='C0000015B3ABB538';
ADDR LATCH# CHILD# LEVEL# NAME HASH GETS MISSES SLEEPS IMMEDIATE_GETS IMMEDIATE_MISSES WAITERS_WOKEN WAITS_HOLDING_LATCH SPIN_GETS SLEEP1 SLEEP2 SLEEP3 SLEEP4 SLEEP5 SLEEP6 SLEEP7 SLEEP8 SLEEP9 SLEEP10 SLEEP11 WAIT_TIME
---------------- ---------- ---------- ---------- ---------------------------------------------------------------- ---------- ---------- ---------- ---------- -------------- ---------------- ------------- ------------------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
C0000015B3ABB538 280 8 4 row cache objects 2412510220 2086493595 593790459 155653120 47042 3177 0 0 451293450 0 0 0 0 0 0 0 0 0 0 0 6.1216E+12
SQL> select * from x$kqrst where kqrstcln=8;
ADDR INDX INST_ID KQRSTCID KQRSTSNO KQRSTTYP KQRSTTXT KQRSTCSZ KQRSTOSZ KQRSTFCS KQRSTUSG KQRSTGRQ KQRSTGMI KQRSTSRQ KQRSTSMI KQRSTSCO KQRSTMRQ KQRSTMFL Child# KQRSTILR KQRSTIFR KQRSTISR
---------------- ---------- ---------- ---------- ---------- ---------- -------------------------------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ------ ---------- ---------- ----------
C0000015B3ABA1C0 7 1 10 0 1 dc_users 101 0 0 101 4153788437 49022 0 0 0 413 413 8 48800 7 47468
C0000015B3ABAD00 52 1 7 0 2 dc_users 0 0 0 0 0 0 0 0 0 0 0 8 0 0 0
C0000015B3ABAE40 57 1 7 1 2 dc_users 50 0 0 50 3329238869 14418 0 0 0 0 0 8 0 0 0
C0000015B3ABAE80 58 1 7 2 2 dc_users 0 0 0 0 0 0 0 0 0 0 0 8 0 0 0
SQL> oradebug setorapid 1601
Oracle pid: 1601, Unix process pid: 29755, image: oracle@qdyyc1
SQL> oradebug short_stack;
SQL> oradebug setorapid 1601
Oracle pid: 1601, Unix process pid: 29755, image: oracle@qdyyc1
SQL> oradebug short_stack;
ksedsts()+544<-ksdxfstk()+48<-ksdxcb()+3216<-sspuser()+688<-<kernel><-_pw_wait()+48<-pw_wait()+112<-sskgpwwait()+432<-skgpwwait()+320<-kslges()+2208<-kslgetl()+784<-kqreqd()+448<-kqrprl()+384<-ktatminextsz()+1024<-qerhjComputeFanoutAndBPS()+480<-kkejnc()+4176<-kkojnp()+19488<-kkocnp()+96<-kkooqb()+3120<-kkoqbc()+4304<-apakkoqb()+384<-apaqbdDescendents()+896<-apaqbdList()+160<-apaqbdDescendents()+1088<-apaqbdList()+160<-apaqbdDescendents()+496<-apaqbdList()+160<-apaqbdDescendents()+496<-apaqbdList()+160<-apaqbdDescendents()+496<-apaqbd()+128<-apadrv()+1664<-opitca()+4832<-kksSetBindType()+13504<-kksfbc()+11872<-opiexe()+5104<-kpoal8()+4624<-opiodr()+2416<-ttcpip()+2416<-opitsk()+2960<-opiino()+1696<-opiodr()+2416<-opidrv()+1616<-sou2o()+256<-opimai_real()+656<-ssthrdmain()+576<-main()+336<-main_opd_entry()+80
SQL> oradebug short_stack;
ksedsts()+544<-ksdxfstk()+48<-ksdxcb()+3216<-sspuser()+688<-<kernel><-kcbgtcr()+4145<-ktrget3()+1632<-ktrget2()+160<-kdst_fetch()+1344<-kdstf11001010000km()+1600<-kdsttgr()+3344<-qertbFetch()+1520<-rwsfcd()+320<-qerhjFetch()+1040<-rwsfcd()+320<-qerhjFetch()+1616<-rwsfcd()+320<-qeruaFetch()+848<-qervwFetch()+352<-qersoProcessULS()+496<-qersoFetch()+896<-qervwFetch()+352<-qergsFetch()+4112<-opifch2()+9600<-kpoal8()+7360<-opiodr()+2416<-ttcpip()+2416<-opitsk()+2960<-opiino()+1696<-opiodr()+2416<-opidrv()+1616<-sou2o()+256<-opimai_real()+656<-ssthrdmain()+576<-main()+336<-main_opd_entry()+80
SQL> oradebug short_stack;
ksedsts()+544<-ksdxfstk()+48<-ksdxcb()+3216<-sspuser()+688<-<kernel><-_read_sys()+48<-_read()+224<-$cold_skgfqio()+880<-ksfd_skgfqio()+208<-ksfd_io()+1168<-ksfdread()+304<-kcfrbd1()+1248<-kcbzib()+2464<-kcbgtcr()+14336<-ktrget3()+1632<-ktrget2()+160<-kdsgrp()+336<-qetlbr()+432<-qertbFetchByRowID()+1728<-qerjotFetch()+1504<-qerjotFetch()+1504<-qervwFetch()+352<-rwsfcd()+320<-qerhjFetch()+2080<-rwsfcd()+320<-qeruaFetch()+848<-$cold_qervwFetch()+2384<-qersoProcessULS()+496<-qersoFetch()+896<-qervwFetch()+352<-qergsFetch()+4112<-opifch2()+9600<-kpoal8()+7360<-opiodr()+2416<-ttcpip()+2416<-opitsk()+2960<-opiino()+1696<-opiodr()+2416<-opidrv()+1616<-sou2o()+256<-opimai_real()+656<-ssthrdmain()+576<-main()+336<-main_opd_entry()+80
SQL> oradebug short_stack;
ksedsts()+544<-ksdxfstk()+48<-ksdxcb()+3216<-sspuser()+688<-<kernel><-kkoiop()+96<-kkoiop()+304<-kkobrfio()+368<-kkoij2()+1360<-kkoixj()+704<-kkotap()+11120<-kkoiqb()+16704<-kkooqb()+1104<-kkoqbc()+4304<-apakkoqb()+384<-apaqbdDescendents()+896<-apaqbd()+128<-kkqctCostTransfQB()+608<-kkqctdrvJPPD()+2288<-kkqjpdctr()+2736<-kkqctInterleaveJPPD()+368<-kkqctdrvSU()+3920<-kkqutruns()+736<-kkqutruns()+208<-kkqutruns()+208<-kkqutruns()+208<-kkqutruns()+432<-kkqutruns()+240<-kkqutruns()+240<-kkqudrv()+784<-kkqctdrvTD()+2240<-kkqdrv()+5360<-kkqctdrvIT()+1424<-apadrv()+3376<-opitca()+4832<-kksFullTypeCheck()+144<-rpiswu2()+1120<-kksSetBindType()+4640<-kksfbc()+11872<-opiexe()+5104<-kpoal8()+4624<-opiodr()+2416<-ttcpip()+2416<-opitsk()+2960<-opiino()+1696<-opiodr()+2416<-opidrv()+1616<-sou2o()+256<-opimai_real()+656<-ssthrdmain()+576<-main()+336<-main_opd_entry()+80
SQL> oradebug short_stack;
ksedsts()+544<-ksdxfstk()+48<-ksdxcb()+3216<-sspuser()+688<-<kernel><-_write_sys()+48<-write()+176<-$cold_skgfqio()+784<-ksfd_skgfqio()+208<-ksfd_io()+1168<-ksfdread()+304<-kcfrbd1()+1248<-kcbzib()+2464<-kcbgtcr()+14336<-ktrget3()+1632<-ktrget2()+160<-kdsgrp()+336<-qetlbr()+432<-qertbFetchByRowID()+1728<-qerjotFetch()+3664<-qerjotFetch()+3664<-qervwFetch()+352<-rwsfcd()+320<-qerhjFetch()+2080<-rwsfcd()+320<-qeruaFetch()+848<-qervwFetch()+352<-qersoProcessULS()+496<-qersoFetch()+896<-qervwFetch()+352<-qergsFetch()+4112<-opifch2()+9600<-kpoal8()+7360<-opiodr()+2416<-ttcpip()+2416<-opitsk()+2960<-opiino()+1696<-opiodr()+2416<-opidrv()+1616<-sou2o()+256<-opimai_real()+656<-ssthrdmain()+576<-main()+336<-main_opd_entry()+80
SQL> col cache# head "Cache|no" form 999
SQL> col parameter head "Parameter" form a25
SQL> col type head "Type" form a12
SQL> col subordinate# head "Sub|ordi|nate" form 9999
SQL> col rcgets head "Cache|Gets" form 999999999999
SQL> col rcmisses head "Cache|Misses" form 999999999999
SQL> col rcmodifications head "Cache|Modifica|tions" form 999999999999
SQL> col rcflushes head "Cache|Flushes" form 999999999999
SQL> col kqrstcln head "Child#" form 999
SQL> col lagets head "Latch|Gets" form 999999999999
SQL> col lamisses head "Latch|Misses" form 999999999999
SQL> col laimge head "Latch|Immediate|gets" form 999999999999
SQL>
SQL> select dc.kqrstcid CACHE#, dc.kqrsttxt PARAMETER, decode(dc.kqrsttyp, 1,'PARENT','SUBORDINATE') type,
2 decode(dc.kqrsttyp, 2, kqrstsno, null) subordinate#,
3 dc.kqrstgrq rcgets, dc.kqrstgmi rcmisses, dc.kqrstmrq rcmodifications, dc.kqrstmfl rcflushes, dc.kqrstcln,
4 la.gets lagets, la.misses lamisses, la.immediate_gets laimge
5 from x$kqrst dc,
6 v$latch_children la
7 where dc.inst_id = userenv('instance')
8 and la.child# = dc.kqrstcln
9 and la.name = 'row cache objects'
10 order by rcgets desc;
Sub Cache Latch
Cache ordi Cache Cache Modifica Cache Latch Latch Immediate
no Parameter Type nate Gets Misses tions Flushes Child# Gets Misses gets
----- ------------------------- ------------ ----- ------------- ------------- ------------- ------------- ------ ------------- ------------- -------------
10 dc_users PARENT 3734912072 48997 413 413 8 819920633 250124586 47007
8 dc_objects PARENT 3620833881 130864169 2454725 2441251 9 2558015670 2412030590 3164403
7 dc_users SUBORDINATE 1 3314778444 14412 0 0 8 819920633 250124586 47007
2 dc_segments PARENT 2419992098 208986999 5565215 5565144 4 409661609 261272169 14687358
16 dc_histogram_defs PARENT 1339720402 51147414 1146382 1123333 13 956389160 3386779019 8520219
0 dc_tablespaces PARENT 1152376656 14361 0 0 5 3457243305 3385062240 16133
3 dc_rollback_segments PARENT 566714092 2910 1509 1508 1 1492039470 1286974917 85
16 dc_histogram_data SUBORDINATE 0 503513763 946170 3141 2354 13 956389160 3386779019 8520219
14 dc_profiles PARENT 358817542 795 1 1 18 1076461125 4088737 1358
16 dc_histogram_data SUBORDINATE 1 289546279 296203 3031 2044 13 956389160 3386779019 8520219
6 dc_files PARENT 214370418 148014 15 15 7 644323538 320328 12272

SQL> select * from v$latch_misses where parent_name='row cache objects' and WTR_SLP_COUNT>1 order by 4;
PARENT_NAME WHERE NWFAIL_COUNT SLEEP_COUNT WTR_SLP_COUNT LONGHOLD_COUNT LOCATION
-------------------- -------------------------------------------------------------------------------- ------------ ----------- ------------- -------------- --------------------------------------------------------------------------------
....
row cache objects kqrigt 0 33041 13374 0 kqrigt
row cache objects kqrbip 0 60479 26413 0 kqrbip
row cache objects kqrso 0 1143654 1491449 0 kqrso
row cache objects kqreqd 0 35450260 71020564 0 kqreqd
row cache objects kqrpre: find obj 0 76579666 129201124 0 kqrpre: find obj
row cache objects kqreqd: reget 0 120729099 32281153 0 kqreqd: reget


# AWR
Load Profile



















































































































Per SecondPer TransactionPer ExecPer Call
DB Time(s):177.00.30.010.00
DB CPU(s):59.90.10.000.00
Redo size:2,367,829.53,705.1
Logical reads:2,942,702.44,604.6
Block changes:13,108.520.5
Physical reads:34,802.054.5
Physical writes:709.61.1
User calls:54,072.284.6
Parses:1,338.62.1
Hard parses:217.00.3
W/A MB processed:135.00.2
Logons:9.40.0
Executes:26,684.241.8
Rollbacks:260.70.4
Transactions:639.1

Top 5 Timed Foreground Events



















































EventWaitsTime(s)Avg wait (ms)% DB timeWait Class
latch: row cache objects892,736112,09812634.94Concurrency
DB CPU108,64533.86
db file sequential read24,567,15857,141217.81User I/O
db file scattered read1,797,2358,20652.56User I/O
gc cr grant 2-way11,853,5986,79612.12Cluster

Dictionary Cache Stats



  • "Pct Misses" should be very low (< 2% in most cases)

  • "Final Usage" is the number of cache entries being used






























































































































































CacheGet RequestsPct MissScan ReqsPct MissMod ReqsFinal Usage
dc_awr_control380.00021
dc_files27,4880.0000859
dc_global_oids8,5230.180030
dc_histogram_data67,5420.9800820
dc_histogram_defs45,560,3660.050013,260
dc_object_grants1,6283.4400313
dc_objects90,488,0820.02035,801
dc_profiles31,7010.00004
dc_rollback_segments591,8730.00002,556
dc_segments5,818,6591.39012882,721
dc_sequences53756.4205375
dc_table_scns2536.00055
dc_tablespaces60,356,7060.000036
global database name17,6060.01001
outstanding_alerts99100.00000
sch_lj_oids60.00001

Wait Event Histogram
















































% of Waits
EventTotal Waits<1ms<2ms<4ms<8ms<16ms<32ms<=1s>1s
latch: row cache objects894.8K23.62.61.81.51.62.566.3.0

Latch Miss Sources


Convert to CSV





























































Latch NameWhereNoWait MissesSleepsWaiter Sleeps
row cache objectskqreqd: reget0563,517128,828
row cache objectskqrpre: find obj0255,237554,836
row cache objectskqreqd0102,913236,755
row cache objectskqrso01,0922,518
row cache objectskqrbip0889
row cache objectskqrbgl06646

##  hanganalyze trace show blocker
and is blocked by
=> Oracle session identified by:
{
instance: 1 (weejar.weejar1)
os id: 25694
process id: 8158, oracle@qdyyc1
session id: 17647
session serial #: 51605
}
which is not in a wait:
{
last wait: 0.000000 sec ago
blocking: 5 sessions
current sql: select * from (select row_.*, rownum rownum_ from ( select distinct m.prodname, m.privname, m.privna, decode((select count(1)
from anbob.****vilege t, anbob.***scriber s where s.****umber = :1
short stack: ksedsts()+544<-ksdxfstk()+48<-ksdxcb()+3216<-sspuser()+688<-<kernel><-_pw_wait()+48<-pw_wait()+112<-sskgpwwait()+432<-skgpwwait()+320<-kslges()+2208<-kslgetl()+784<-kqreqd()+
448<-kqrprl()+384<-ktatminextsz()+1024<-qerhjComputeFanoutAndBPS()+480<-kkejnc()+4176<-kkojnp()+19488<-kkocnp()+96<-kkooqb()+3120<-kkoqbc()+4304<-apakkoqb()+384<-apaqbdDescendents()+896<-apaqbdList()+
160<-apaqbdDescendents()+496<-apaqbd()+128<-kkqctCostTransfQB()+608<-kkqctdrvJPPD()+2288<-kkqjpdctr()+2736<-qksqbApplyToQbcLoc()+864<-qksqbApplyT
wait history:
1. event: 'latch: row cache objects'
time waited: 0.360363 sec
wait id: 34094 p1: 'address'=0xc0000015b3abb538
p2: 'number'=0x118
p3: 'tries'=0x0
* time between wait #1 and #2: 0.034827 sec
这个案例主要的问题
1. hard parse & soft parse 太高
2.  相关的BUG 有
Bug 13902396 Hash joins cause "row cache objects" latch gets and "shared pool" latch gets
Bug 17799716 High row cache requests for a query with many indexes
不过从上面看当时一个bloker会话正在执行的SQL表上索引是不少(10+), 而且与bug 17799716 call stack有些相似。是在当前版本中当执行计划用不同索引cost相同时,排序索引名称取第一个, 在11.2.0.3[|4]中CBO引入的更多的查询转换所以会持有更长时间的row cache latch比10g时。 解决方法如改SQL降硬解析使用绑定变量;修改优化器为10.2.0.4;使用event 10089 level 1;
SQL> alter system set events '10089 trace name context forever, level 1';

SQL> alter system set event = '10089 trace name context forever, level 1' scope=spfile

What 's Event 10089 level 1


Event 10089 level 1: CBO disable index sorting.
默认情况 下CBO 使用 排除决策的方法,当两个执行计划中index 的cost相同时,使用索引名称字母排序选择第一个索引. 使用10053 event 可以看到是当两个执行计划中两个索引COST相同时如何选择索引。默认10089 event没有配置,而是使用索引名称排除的, 但是当启用了event 10089 level 1, CBO就不会在当cost相同时使用index name排序,而是改为按index created 创建时间排序。 这个event 有助于降低"get" row cache  dc_objects的竞争。
「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论