job处理缓慢的性能问题排查与分析（r4笔记第18天)

时间:2022-05-04
本文章向大家介绍job处理缓慢的性能问题排查与分析（r4笔记第18天)，主要内容包括其使用实例、应用技巧、基本知识点总结和需要注意事项，具有一定的参考价值，需要的朋友可以参考一下。

昨天开发的同事找到我说，生产有个job处理数据的速度很慢，想让我帮忙看看是怎么回事，最近碰到这种问题相对比较多了，但是问题的原因也是五花八门。我还是大体找他们了解了下情况，说有一个Job是处理文件传输的，但是从目前的运行情况来看，处理速度很慢，基本没什么进展，我向他们确认这几天是否有数据变更的操作，他们说没有。得到这个确认查看问题的方向就有明显的不同，我还是照例查看了一下数据库负载，锁情况。但是么有发现什么信息。 从数据库的负载来看，负载倒不高。

Snap Id

Snap Time

Sessions

Cursors/Session

Begin Snap:

17844

16-Jan-15 12:00:37

303

4.2

End Snap:

17845

16-Jan-15 13:00:40

303

4.4

Elapsed:

60.04 (mins)

DB Time:

119.10 (mins)

Load Profile

Per Second

Per Transaction

Per Exec

Per Call

DB Time(s):

2.0

0.1

0.00

0.00

DB CPU(s):

1.2

0.1

0.00

0.00

Redo size:

1,222,354.8

56,665.6

Logical reads:

54,092.4

2,507.6

Block changes:

4,395.0

203.7

Physical reads:

5,172.7

239.8

Physical writes:

273.2

12.7

User calls:

4,952.3

229.6

Parses:

12.9

0.6

Hard parses:

1.1

0.1

W/A MB processed:

1.0

0.1

Logons:

0.1

0.0

Executes:

3,000.2

139.1

Rollbacks:

0.0

0.0

Transactions:

21.6

接下来看看等待事件，还是没有发发现特殊之处。

Top 5 Timed Foreground Events

Event

Waits

Time(s)

Avg wait (ms)

% DB time

Wait Class

DB CPU

4,204

58.83

db file sequential read

1,539,592

3,003

2

42.03

User I/O

log file sync

79,884

164

2

2.30

Commit

direct path read

14,973

68

5

0.95

User I/O

control file sequential read

43,790

18

0

0.25

System I/O

从时间模型的情况来看，资源消耗还在在I/O上。

Statistic Name

Time (s)

% of DB Time

sql execute elapsed time

6,440.43

90.12

DB CPU

4,204.39

58.83

RMAN cpu time (backup/restore)

88.32

1.24

这个时候和开发做一个简短的沟通，最起码得明确一些信息，要不大海捞针的查问题还是针对性不强，他们说Job处理速度慢，是哪个job呢，他们反馈说是MF1ppMD的job 我从Sql Order by Elapsed time中查得MFppMD的相关top sql有几个，但是这几个语句执行时间都很短，都在0.01秒以内，性能算是不错的了。

Executions

%Total

%IO

SQL Module

/* */ select count (1) from RP...

775.20

1,671,968

0.00

10.85

23.36

79.06

gqy0gxb05ycg4

pm1EnvelopeMT@ccbdbpr2 (TNS V1-V3)

select L9_SPLIT_PERIOD into :b...

717.11

14,042

0.05

10.03

99.84

0.00

b91t3s9kz9fg8

pm1EnvelopeMT@ccbdbpr2 (TNS V1-V3)

/* */ SELECT SUBSCRIBER_ID, EF...

394.40

1,167,196

0.00

5.52

39.54

63.55

dm1d93bw2jdzc

MF1ppMD@ccbdbpr1 (TNS V1-V3)

INSERT INTO RATED_EVENT (L3_NE...

236.40

1

236.40

3.31

81.22

9.47

477uum1qjcpqh

oracle@ccbstbpr2 (TNS V1-V3)

SELECT "A1"."TABLE_ISSUE_CODE"...

198.10

1

198.10

2.77

79.23

10.20

4uddwupn9fw9b

TOAD 9.6.0.27

/* */ SELECT SUBSCRIBER_ID, DY...

136.72

1,166,948

0.00

1.91

34.69

67.32

7p5kmytfrygy2

MF1ppMD@ccbdbpr1 (TNS V1-V3)

/* */ Update RPR1_SUBS_RERATE ...

80.38

196,631

0.00

1.12

22.43

79.87

7x26ag6bsacb3

pm1EnvelopeMT@ccbdbpr2 (TNS V1-V3)

insert into MF1_DUPCHECK_KEYS ...

从系统优化的角度来说，ppMD的性能问题还是比较奇怪的。 继续查看其它的指标类型，一边注意ppMD相关的job，一边留意是否是其它的原因导致的。 当我看到Sql Order by Executions的时候。注意到一个奇怪的地方，执行频率最高的正是ppMD这个job

Rows Processed

Elapsed Time (s)

%IO

SQL Module

<span color:white;"="" style="word-wrap: break-word;font-size: 11px">SQL Text

2,333,806

0

0.00

43.03

106.28

0.00

a69bnysapnrt5

MF1ppMD@ccbdbpr1 (TNS V1-V3)

select ROWID , PRIM_RESOURCE_T...

1,671,968

1,664,009

1.00

775.20

23.36

79.06

gqy0gxb05ycg4

pm1EnvelopeMT@ccbdbpr2 (TNS V1-V3)

/* */ SELECT CYCLE_CODE, CYCLE...

1,167,196

1,166,977

1.00

394.40

39.54

63.55

dm1d93bw2jdzc

MF1ppMD@ccbdbpr1 (TNS V1-V3)

select sk.rowid , sk.subscribe...

但是仔细查看会发现一个奇怪的现象， Rows Processed却是0.这是一个比较特殊的情况，这个参数代表的意思是SQL在快照时间内累计执行所处理的总行数。代表0说明执行了几百万次，但是没有任何数据处理，相当于空跑。 来看看执行的sql语句是什么。 

select ROWID,
       PRIM_RESOURCE_TP,
       PRIM_RESOURCE_VAL,
       TO_CHAR(EFFECTIVE_DATE, 'YYYYMMDDHH24MISS'),
       TO_CHAR(EXPIRATION_DATE, 'YYYYMMDDHH24MISS'),
       TO_CHAR(SYS_CREATION_DATE, 'YYYYMMDDHH24MISS'),
       TO_CHAR(SYS_UPDATE_DATE, 'YYYYMMDDHH24MISS'),
       OPERATOR_ID,
       APPLICATION_ID,
       DL_SERVICE_CODE,
       DL_UPDATE_STAMP,
       FUTURE_1,
       FUTURE_2,
       FUTURE_3
  into :b0  :b1,
       :b2  :b3,
       :b4  :b5,
       :b6  :b7,
       :b8  :b9,
       :b10 :b11,
       :b12 :b13,
       :b14 :b15,
       :b16 :b17,
       :b18 :b19,
       :b20 :b21,
       :b22 :b23,
       :b24 :b25,
       :b26 :b27
  from MI9_PAID_SUBSCR
where (((PRIM_RESOURCE_TP = :b2 and PRIM_RESOURCE_VAL = :b4) and
       EFFECTIVE_DATE <= TO_DATE(:b6, 'YYYYMMDDHH24MISS')) and
       (EXPIRATION_DATE is null or
       EXPIRATION_DATE > TO_DATE(:b6, 'YYYYMMDDHH24MISS')))

这是一个很简单的查询，一看这个表，我就恍然大悟了，这个表是在这两天才做的变更，在最新的需求中需要创建这个表，从目前的需求来看，这个表需要同步一些数据，但是数据的同步机制还没有达成共识，所以最后临时决定先把这个表创建好，让job在校验的时候不出错，但是表里面没有数据，暂时先按照dummy表来处理。但是在升级中没有包含这个变更,只是提供了临时的补丁做了修复。 看来这个dummy表还是对数据的处理造成了严重的影响，导致了Job空跑。开发有时候提供的信息还是需要斟酌的，不一定都是正确的。需要我们在特定的问题情况下去确认。 最后和开发做了沟通，他们在做了进一步的分析之后确认是这个新表导致的问题，需要进一步讨论技术实现细节。 最后小结一下。 可能有些问题的处理和诊断，不一定是IO,CPU等异常导致的，很可能是业务层出现的问题，需要我们从awr报告中发现细节来佐证自己的判断。 有时候问题排查的方向需要自己来按照合理的流程来做，有时候客户，同事提供的信息自己需要辨识，可能有些问题是他们没有意识到，但是对问题排查的方向影响还是比较大的。

随机文章
本站知识点必读
最近更新