当前位置: 首页 > EVENT > 正文

latch:row cache objects

           下面是一个客户环境中出现大量的latch:row cache objects等待时间,消耗大量的CPU资源。本地文件目录

d:\wendang\\company\enmo\customer\…..\2015_05_04_crm_latch_row_cache_objects_11.2.0.4

 

1 环境介绍

 

OS:HP_UNIX 

GRID/DB:11.2.0.4

 

2 故障时AWR报告

 

两个节点RAC,故障出现在2节点,1节点相对来说比较正常。

节点2AWR

 

Host Name

Platform

CPUs

Cores

Sockets

Memory (GB)

htz.pw

HP-UX IA (64-bit)

32

32

16

191.74

 

 

Snap Id

Snap Time

Sessions

Cursors/Session

Instances

Begin Snap:

4259

29-Apr-15 17:00:16

1496

6.5

2

End Snap:

4260

29-Apr-15 18:00:14

1458

6.3

2

Elapsed:

 

59.97 (mins)

 

 

 

DB Time:

 

3,464.09 (mins)

 

 

 

 

Load Profile

 

 

Per Second

Per Transaction

Per Exec

Per Call

DB Time(s):

57.8

0.2

0.00

0.00

DB CPU(s):

20.8

0.1

0.00

0.00

Redo size (bytes):

2,391,158.8

9,995.3

 

 

Logical read (blocks):

707,896.5

2,959.1

 

 

Block changes:

10,272.8

42.9

 

 

Physical read (blocks):

1,302.9

5.5

 

 

Physical write (blocks):

690.2

2.9

 

 

Read IO requests:

773.8

3.2

 

 

Write IO requests:

361.9

1.5

 

 

Read IO (MB):

20.4

0.1

 

 

Write IO (MB):

10.8

0.1

 

 

Global Cache blocks received:

2,202.7

9.2

 

 

Global Cache blocks served:

2,250.1

9.4

 

 

User calls:

22,486.6

94.0

 

 

Parses (SQL):

5,796.2

24.2

 

 

Hard parses (SQL):

352.8

1.5

 

 

SQL Work Area (MB):

442.8

1.9

 

 

Logons:

2.0

0.0

 

 

Executes (SQL):

13,316.0

55.7

 

 

Rollbacks:

18.3

0.1

 

 

Transactions:

239.2

 

 

 

 

Event

Waits

Total Wait Time (sec)

Wait Avg(ms)

% DB time

Wait Class

DB CPU

 

74.8K

 

36.0

 

latch: row cache objects

820,132

48.6K

59

23.4

Concurrency

db file sequential read

1,871,661

17.4K

9

8.4

User I/O

gc cr block 2-way

2,932,064

10.2K

3

4.9

Cluster

gc current block 2-way

3,758,226

8631.2

2

4.2

Cluster

gc buffer busy acquire

901,346

7318

8

3.5

Cluster

reliable message

824,300

6986.4

8

3.4

Other

log file sync

868,259

4955.7

6

2.4

Commit

enq: SV – contention

536,253

4948

9

2.4

Other

gc cr block busy

728,480

4762.5

7

2.3

Cluster

这里发现latch:row cache objects消耗了23.4%db time 平均等待59MS,这个值还不算高。在LOAD PROFILE中,我们可以发现硬分析很严重。

 

Cache

Get Requests

Pct Miss

Scan Reqs

Pct Miss

Mod Reqs

Final Usage

dc_awr_control

150

0.67

0

 

1

1

dc_files

19,316

6.82

0

 

0

439

dc_global_oids

5,036

1.65

0

 

0

37

dc_histogram_data

70,250,808

0.03

0

 

0

12,014

dc_histogram_defs

27,873,600

0.10

0

 

0

8,975

dc_object_grants

199,783

0.06

0

 

0

48

dc_objects

231,454,978

0.00

0

 

0

3,634

dc_profiles

16,645

0.11

0

 

0

9

dc_rollback_segments

3,289,744

0.00

0

 

0

2,605

dc_segments

35,460,063

0.08

0

 

34

2,915

dc_sequences

9,600

36.78

0

 

9,600

30

dc_tablespace_quotas

8

50.00

0

 

0

1

dc_tablespaces

11,942,025

0.00

0

 

0

39

dc_users

25,182,525

0.00

0

 

0

187

global database name

8,317

0.00

0

 

0

1

outstanding_alerts

244

98.77

0

 

6

0

sch_lj_oids

5

100.00

0

 

0

0

smo rowcache

20

100.00

0

 

0

0

这里发现dc_objectsget requests数远远大于其它的,初步怀疑是由于dc_objects导致的,不通的数据库版本这里的cache名字是不一样的。

 

row cache objects

kqreqd: reget

0

416,902

217,122

row cache objects

kqrpre: find obj

0

271,171

379,667

row cache objects

kqreqd

0

153,875

242,882

row cache objects

kqrso

0

5,918

8,336

row cache objects

kqrbip

0

345

93

row cache objects

kqrbgl

0

223

227

row cache objects

kqrigt

0

199

102

row cache objects

kqrbtm: pop parent

0

161

122

这里看到在row cache objects上面等待的函数的信息。

kqreqd: regetkqreqd reacquires latch before removing enqueue

kqreqd:kqreqd acquires latch

kqrpre: find objfind details of an object being parsed in the row cache

 

在故障处理过程中对数据库做了hanganalyze等分析,这里就不列出来了。

 

3 解决方案

 

下面是MOS体统的解决方案

 

1) Rewrite the application to use bind variables to lower the hard parse rate from 350/second

2) Enable the cursor_sharing = force

3) Do not use first_rows_x optimization and use all_rows instead

4) Set optimizer_feature_enabled = 10.2.0.4

5) Set event 10089 level 1 to disable index sorting.

 

这里我们通过event 10089来禁用了11G在分析时索引排序的功能。

 

4 优化后的AWR报告

 

 

Snap Id

Snap Time

Sessions

Cursors/Session

Instances

 

Begin Snap:

4204

27-Apr-15 10:00:05

1357

6.3

2

End Snap:

4205

27-Apr-15 11:00:11

1373

6.4

2

Elapsed:

 

60.11 (mins)

 

 

 

DB Time:

 

1,636.77 (mins)

 

 

 

Report Summary

Load Profile

 

 

Per Second

Per Transaction

Per Exec

Per Call

DB Time(s):

27.2

0.1

0.00

0.00

DB CPU(s):

15.9

0.1

0.00

0.00

Redo size (bytes):

2,178,129.5

9,015.9

 

 

Logical read (blocks):

586,839.7

2,429.1

 

 

Block changes:

8,842.1

36.6

 

 

Physical read (blocks):

985.8

4.1

 

 

Physical write (blocks):

486.8

2.0

 

 

Read IO requests:

742.5

3.1

 

 

Write IO requests:

367.1

1.5

 

 

Read IO (MB):

15.4

0.1

 

 

Write IO (MB):

7.6

0.0

 

 

Global Cache blocks received:

1,786.8

7.4

 

 

Global Cache blocks served:

1,955.2

8.1

 

 

User calls:

16,187.6

67.0

 

 

Parses (SQL):

5,128.1

21.2

 

 

Hard parses (SQL):

299.4

1.2

 

 

SQL Work Area (MB):

339.5

1.4

 

 

Logons:

1.6

0.0

 

 

Executes (SQL):

8,547.8

35.4

 

 

Rollbacks:

24.0

0.1

 

 

Transactions:

241.6

 

 

 

Instance Efficiency Percentages (Target 100%)

 

Buffer Nowait %:

99.97

Redo NoWait %:

99.99

Buffer Hit %:

99.84

In-memory Sort %:

100.00

Library Hit %:

91.40

Soft Parse %:

94.16

Execute to Parse %:

40.01

Latch Hit %:

98.17

Parse CPU to Parse Elapsd %:

84.76

% Non-Parse CPU:

85.88

Top 10 Foreground Events by Total Wait Time

 

Event

Waits

Total Wait Time (sec)

Wait Avg(ms)

% DB time

Wait Class

DB CPU

 

57.3K

 

58.3

 

db file sequential read

2,313,978

16.3K

7

16.6

User I/O

gc current block 2-way

3,476,514

4657.5

1

4.7

Cluster

gc cr block 2-way

2,151,589

3889.5

2

4.0

Cluster

reliable message

737,692

2517.5

3

2.6

Other

log file sync

916,284

2490.7

3

2.5

Commit

gc cr block busy

562,894

2289.5

4

2.3

Cluster

gc buffer busy acquire

322,799

1480.6

5

1.5

Cluster

gc current grant busy

699,967

1126.6

2

1.1

Cluster

latch: row cache objects

309,062

1022.1

3

1.0

Concurrency

 

Cache

Get Requests

Pct Miss

Scan Reqs

Pct Miss

Mod Reqs

Final Usage

dc_awr_control

102

0.98

0

 

1

1

dc_files

19,755

3.96

0

 

0

439

dc_global_oids

5,107

1.64

0

 

0

50

dc_histogram_data

55,552,354

0.03

0

 

0

11,652

dc_histogram_defs

21,468,217

0.13

0

 

0

9,453

dc_object_grants

113,759

0.10

0

 

0

56

dc_objects

172,775,743

0.01

0

 

0

3,720

dc_profiles

18,797

0.04

0

 

0

6

dc_rollback_segments

2,268,991

0.04

0

 

4,570

2,595

dc_segments

26,314,252

0.09

0

 

29

2,578

dc_sequences

12,395

27.58

0

 

12,395

35

dc_tablespaces

9,610,590

0.00

0

 

0

39

dc_users

19,642,512

0.00

0

 

0

190

global database name

8,766

0.00

0

 

0

1

outstanding_alerts

236

100.00

0

 

0

0

sch_lj_oids

6

100.00

0

 

0

2

smo rowcache

68

97.06

0

 

0

13

 

不过这里我感觉通过配置event没有达到根本解决这个问题,如果要根本解决这个问题我们需要减少硬分析。

 

5 参考文档

 

How to Diagnose: ‘Latch: Row Cache Objects’ Contention (Doc ID 1111263.1)

Bug 14483535 : HIGH LATCH ROW CACHE OBJECTS CONCURRENCY AFTER UPGRADE TO 11.2.0.3 FROM 10.2.0.4

LATCH: ROW CACHE OBJECTS (Doc ID 42183.1)

Resolving Issues Where ‘Row Cache Lock’ Waits are Occurring (Doc ID 1476670.1)

Data Server Internals: Row Cache, Log Buffer

本文固定链接: http://www.htz.pw/2015/05/04/latchrow-cache-objects.html | 认真就输

该日志由 huangtingzhong 于2015年05月04日发表在 EVENT 分类下, 通告目前不可用,你可以至底部留下评论。
原创文章转载请注明: latch:row cache objects | 认真就输
关键字: