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报告中发现细节来佐证自己的判断。 有时候问题排查的方向需要自己来按照合理的流程来做,有时候客户,同事提供的信息自己需要辨识,可能有些问题是他们没有意识到,但是对问题排查的方向影响还是比较大的。

原文发布于微信公众号 - 杨建荣的学习笔记(jianrong-notes)

原文发表时间:2015-01-17

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏杨建荣的学习笔记

复杂SQL性能优化的剖析(一)(r11笔记第36天)

今天本来是处理一个简单的故障,但是发现是一环套一环,花了我快一天的时间。 开始是早上收到一条报警: 报警内容: CPUutilization is too hi...

36112
来自专栏java达人

Java开发者编写SQL语句时常见的10种错误

Java开发者对于面向对象编程思维与命令行编程思维的协调程度,取决于他们如下几种能力的水平: 1. 技巧(任何人都可以编写命令行形式的代码) 2. 教条(有的...

2475
来自专栏自然语言处理

结巴中文分词原理分析1

更改分词器(默认为 jieba.dt)的 tmp_dir 和 cache_file 属性,可分别指定缓存文件所在的文件夹及其文件名,用于受限的文件系统。

3033
来自专栏杨建荣的学习笔记

Oracle中的段(r10笔记第81天)

Oracle的体系结构中,关于存储结构大家应该都很熟悉了。 估计下面这张图大家都看得熟悉的不能再熟悉了。 ? 简单来说,里面的一个重要概念就是段,如果是开发...

3618
来自专栏数据和云

SQL审核:OR展开与子查询优化案例详解

黄廷忠(网名:认真就输) 云和恩墨技术专家 个人博客:http://www.htz.pw/ 本篇整理内容是黄廷忠在“云和恩墨大讲堂”微信分享中的讲解案例,S...

3664
来自专栏小俊博客

[测评]云迪Host US-LA-SSD KVM Mini_384M VPS测评

最近博主买了KYRAHOST的LA CN2 VPS这款,SSD硬盘,从测试看,硬盘I/O还可以,有500-800左右,据商家说是SSD阵列RAID10,一个月才...

1231
来自专栏Fundebug

MongoDB复合索引详解

1194
来自专栏python3

django--ORM的单表操作

它的作用相当于 在该app下建立 migrations目录,并记录下你所有的关于modes.py的改动,比如0001_initial.py, 但是这个改动还没有...

1413
来自专栏数据和云

【云和恩墨大讲堂】复合索引与绑定变量

讲师简介 ? 邓秋爽(小鱼) 云和恩墨专家,有超过5年超大型数据库专业服务经验,擅长oracle 数据库优化、SQL优化和troubleshooting 今晚的...

3576
来自专栏数据和云

极限优化:从75到2000,由技能到性能提升岂止20倍

崔华,网名 dbsnake Oracle ACE Director,ACOUG 核心专家 编辑手记:感谢崔华授权我们独家转载其精品文章,也欢迎大家向“Oracl...

2534

扫码关注云+社区