从业务角度分析奇怪的数据库高负载问题 (r4笔记第35天)

今天到公司以后,照例查看了数据库的负载情况,发现有一些异常。11点开始到12点的时候,数据库的负载格外的高。按照平时的经验,这个时间段内不会有太多的高峰业务在运行,为了简单验证,自己抓取了近几天的数据库负载情况。 自己抓取了2月1号,1月30号的负载情况,发现在这个时间段内数据库的负载其实不高。

snap_begin

snap_end

start_time

level

duration(mins)

DB time(mins)

30775

30776

3

Feb

2015

10:50

1

10

875

30776

30777

3

Feb

2015

11:00

1

10

1203

30777

30778

3

Feb

2015

11:10

1

10

1176

30778

30779

3

Feb

2015

11:20

1

10

1202

30779

30780

3

Feb

2015

11:30

1

10

1152

30780

30781

3

Feb

2015

11:40

1

10

1313

30781

30782

3

Feb

2015

11:50

1

10

1401

30782

30783

3

Feb

2015

12:00

1

10

1089

30783

30784

3

Feb

2015

12:10

1

10

1124

30784

30785

3

Feb

2015

12:20

1

10

1195

30785

30786

3

Feb

2015

12:30

1

10

1118

30786

30787

3

Feb

2015

12:40

1

10

1083

30787

30788

3

Feb

2015

12:50

1

10

980

30788

30789

3

Feb

2015

13:00

1

10

968

30789

30790

3

Feb

2015

13:10

1

10

860

30790

30791

3

Feb

2015

13:20

1

10

758

30791

30792

3

Feb

2015

13:30

1

10

736

30792

30793

3

Feb

2015

13:40

1

10

655

30793

30794

3

Feb

2015

13:50

1

10

489

30794

30795

3

Feb

2015

14:00

1

10

571

30795

30796

3

Feb

2015

14:10

1

10

576

30796

30797

3

Feb

2015

14:20

1

10

687

30797

30798

3

Feb

2015

14:30

1

10

727

30798

30799

3

Feb

2015

14:40

1

10

550

30799

30800

3

Feb

2015

14:50

1

10

648

30487

30488

1

Feb

2015

10:50

1

10

312

30488

30489

1

Feb

2015

11:00

1

10

489

30489

30490

1

Feb

2015

11:10

1

10

429

30490

30491

1

Feb

2015

11:20

1

10

311

30491

30492

1

Feb

2015

11:30

1

10

331

30492

30493

1

Feb

2015

11:40

1

10

288

30493

30494

1

Feb

2015

11:50

1

10

221

30494

30495

1

Feb

2015

12:00

1

10

335

30495

30496

1

Feb

2015

12:10

1

10

530

30496

30497

1

Feb

2015

12:20

1

10

430

30497

30498

1

Feb

2015

12:30

1

10

366

30498

30499

1

Feb

2015

12:40

1

10

370

30499

30500

1

Feb

2015

12:50

1

10

288

30500

30501

1

Feb

2015

13:00

1

10

286

30501

30502

1

Feb

2015

13:10

1

10

283

30502

30503

1

Feb

2015

13:20

1

10

193

30503

30504

1

Feb

2015

13:30

1

10

215

30504

30505

1

Feb

2015

13:40

1

10

205

30505

30506

1

Feb

2015

13:50

1

10

200

30506

30507

1

Feb

2015

14:00

1

10

239

30507

30508

1

Feb

2015

14:10

1

10

202

30508

30509

1

Feb

2015

14:20

1

10

175

30509

30510

1

Feb

2015

14:30

1

10

229

30510

30511

1

Feb

2015

14:40

1

10

226

30511

30512

1

Feb

2015

14:50

1

10

216

30199

30200

30

Jan

2015

10:50

1

10

377

30200

30201

30

Jan

2015

11:00

1

10

572

30201

30202

30

Jan

2015

11:11

1

10

428

30202

30203

30

Jan

2015

11:20

1

9

664

30203

30204

30

Jan

2015

11:30

1

10

580

30204

30205

30

Jan

2015

11:40

1

10

409

30205

30206

30

Jan

2015

11:50

1

10

277

30206

30207

30

Jan

2015

12:00

1

10

464

30207

30208

30

Jan

2015

12:10

1

10

365

30208

30209

30

Jan

2015

12:20

1

10

333

30209

30210

30

Jan

2015

12:30

1

10

315

30210

30211

30

Jan

2015

12:40

1

10

355

30211

30212

30

Jan

2015

12:50

1

10

304

30212

30213

30

Jan

2015

13:00

1

10

287

30213

30214

30

Jan

2015

13:10

1

10

234

30214

30215

30

Jan

2015

13:20

1

10

255

30215

30216

30

Jan

2015

13:30

1

10

321

30216

30217

30

Jan

2015

13:40

1

10

329

30217

30218

30

Jan

2015

13:50

1

10

273

30218

30219

30

Jan

2015

14:00

1

10

398

30219

30220

30

Jan

2015

14:10

1

10

347

30220

30221

30

Jan

2015

14:20

1

10

363

30221

30222

30

Jan

2015

14:30

1

10

511

30222

30223

30

Jan

2015

14:40

1

10

527

30223

30224

30

Jan

2015

14:50

1

10

356

从客户那里了解的情况是,他们昨天晚上对系统打了补丁,但是没有修改其它的地方。 为了查找问题,我抓取了问题时间段内的awr报告。 得到的等待事件情况如下:

Top 5 Timed Foreground Events

Event

Waits

Time(s)

Avg wait (ms)

% DB time

Wait Class

direct path read

757,842

25,844

34

36.61

User I/O

db file sequential read

6,253,924

24,112

4

34.16

User I/O

DB CPU

8,433

11.95

read by other session

1,736,151

5,387

3

7.63

User I/O

log file sync

98,407

2,715

28

3.85

Commit

可以看到等待时间都是和IO紧密相关的。从等待事件direct path read来看,我的一个直观感觉就是并行查询导致的。 使用并行扫描的SQL语句也会影响系统范围的direct path read等待事件。在并行执行过程中,direct path read等待事件与从属查询有关,而与父查询无关,运行父查询的会话基本上会在PX Deq:Execute Reply上等待,从属查询会产生direct path read等待事件。 从SQL Order by Elapsed time这个章节,可以看到几个消耗很大的语句都和一个信控相关的扫描服务相关。

Elapsed Time (s)

Executions

Elapsed Time per Exec (s)

%Total

%CPU

%IO

SQL Id

SQL Module

SQL Text

14,326.71

24

596.95

20.30

8.58

89.48

4gz51fphuarsw

JDBC Thin Client

/* ProcInstScanner_selectAv...

10,674.05

23

464.09

15.12

6.01

92.01

6fu3z8pqd2y9g

JDBC Thin Client

/* WaitScanner_selectWorkab...

5,641.97

24

235.08

7.99

6.90

93.09

fg5mc598u799u

JDBC Thin Client

select /*+ leading (bpm_ai bpm...

1,628.99

5

325.80

2.31

2.85

98.39

b56c37kvdwn1m

JDBC Thin Client

select /*+ leading(s) index(s ...

这几个服务的启动时间大概是在10点左右,但是今天却在11点多开始对数据库有相当的压力。当时也没多想,继续查看并行的部分来验证direct path read的想法。 结果在并行的部分发现了一些问题。 下面标黄的部分是weblogic节点的连接用户,按照规律来看都是truwlxxx的样式,但是今天看到是确实truwld5,truwld4这种类型的。这个问题没有做过多的确认,但是感觉已经是个问题了。 和最近的系统升级联系起来,最近在生产库中加入了一些weblogic节点来分担一部分的业务压力,但是据我所知,这些新加入的节点都是不需要开启信控服务的。

SESS_ID         USERNAME        OSUSER          MACHINE              PROGRAM                        QCSID       SQL_ID 
------------------------------------------------------------------------------------------------------------------------------------
3787,15127      PRDAPPC         truwld5         ccbpr13            JDBC Thin Client                3787            4gz51fphuarsw
5199,3205       PRDAPPC         pblwrk01        ccbpr1             bl1b@ccbdbpr1 (TNS V1- V3)   5199            cjfjyu20nhaws                                                                    
9198,11215      PRDAPPC         pcmwrk01        ccbpr1             JDBC Thin Client                9198            9s6vg5rnupjv9
18629,16045     PRDAPPC         truwld5         ccbpr13            JDBC Thin Client                18629            6fu3z8pqd2y9g
13255,52127     PRDAPPC         pblwrk01        ccbpr1             sqlplus@ccbdbpr1 (TNS V1- V3)   13255            55u2k96k7bx91
3053,36995      PRDAPPC         pcmwrk01        ccbpr1             JDBC Thin Client                3053            cq7p84hrug0wx
18716,785       PRDAPPC         truwld4         ccbpr13            JDBC Thin Client                18716            4gz51fphuarsw
1753,1793       PRDAPPC         truwl25         ccbpr2             JDBC Thin Client                1753            4gz51fphuarsw
7478,19407      CCBSFMDEV       Phongs4         TIT-C25            plsqldev.exe                    7478
4792,5385       PRDAPPC         truwld2         ccbpr13            JDBC Thin Client                4792            4gz51fphuarsw

带着这种半信半疑,还是给客户发送了邮件,让他们确认一下,是否开启了新加的weblogic节点的信控服务,他们在查找之后最后反馈,确实是启用了这些服务,马上做了禁用操作。 系统负载马上就降下来了。最后客户对相关的节点都做了检验,从我的监控来看,再也没有捕捉到新节点的并行进程。问题的处理就告一段落了。 从这个问题的分析来看,有几个关键的注意点,首先从负载上来看可能存在着问题,但是单纯从负载来看也不能说明问题,需要自己对系统的业务情况进行一个基本的了解,这样在分析问题的时候才能更加的准备到位,可以自己沉淀一些监控的数据,在问题发生之后及时做比对,就很能够说明一些看似复杂的问题。 这个问题的分析结果也是在了解了近期的系统变更上,自己了解了信控服务的特点,所以在分析问题的时候按照这个基准来验证新加入的节点可能有问题。然后逐步分析验证了自己的推论。这个时候如果单纯从技术角度来看,可能这些并行进程的执行还真不是问题,很可能看做是业务需要,导致分析到最后可能在sql调优上反复下很多的功夫,最后发现调优的工作已经很难有改进空间了,导致问题方向性的错误。 最后一个就是敢于质疑,如果你的推论正确了,就可以避免一次不必要的系统问题,如果你的推论错了,可能还需要从其他的角度来分析这些问题,对自己也没有什么害处,切忌不要抱着抓到客户小辫子的态度,这样客户也会显得不够配合。

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

原文发表时间:2015-02-03

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

发表于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏Jerry的SAP技术分享

利用CRM中间件Middleware从ERP下载Customer Material的常见错误

下图是我在ERP创建的Material,为其维护了一个Customer Material AOP。

3948
来自专栏一只程序汪的自我修养

半个小时教你写一个装(bi)逼(she)之地图搜租房

首先需要一个Python3环境,怎么准备我就不多说了,实在不会的出门右转看一下廖雪峰老师的博客.

41710
来自专栏FreeBuf

适用于渗透测试不同阶段的工具收集整理

该资源清单列表涵盖了一系列,适用于渗透测试不同阶段的开源/商业工具。如果你想为此列表添加贡献,欢迎你向我发送pull request。

1K0
来自专栏deepcc

微信公众号-开发者-自定义菜单-CLICK事件处理

35610
来自专栏Script Boy (CN-SIMO)

重临命令行

   今天我又开始接触Linux命令行界面,我异常兴奋,本来是敲c++的时间,结果全部都用在了这里,因为已经有好几年没有动过这个界面了,以前学的命令行都几乎忘关...

2000
来自专栏NetCore

微信公众平台快速开发框架 For Core 2.0 beta –JCSoft.WX.Core 5.2.0 beta发布

写在前面 最近比较忙,都没有好好维护博客,今天拿个半成品来交代吧。 记不清上次关于微信公众号快速开发框架(简称JCWX)的更新是什么时候了,自从更新到支持.Ne...

2778
来自专栏carven

win7 安装 mac虚拟机

  一周前社团ios方向刚完成招新,图新鲜的我也试装了一下虚拟机。自己装的时候是按教程来的,很轻松就装成了。 ios的经理见我装的那么溜,就把几个需要装虚拟机的...

1084
来自专栏C语言及其他语言

【程序源码】女神节特供

今天3月8号喽,女神节,咱们还是程序猿,最容易孤生的一个人种,得看别人各种虐,小编这就不乐意了,所以奉上祖传源码助大家一臂之力告别单身,各位,瞧好了。 效果...

2675
来自专栏数据和云

动手为王 | Oracle 数据库跨版本升级迁移实践

作者简介 ? 李真旭 Oracle ACE 专家,拥有超过10年的 Oracle 运维管理使用经验,参与过众多移动、电信、联通、银行等大型数据库交付项目,具有...

4244
来自专栏禁心尽力

Shiro眼皮下玩ajax,玩出302 Found

1   public static String sendCode(String url,String encoded,String mobile,Stri...

2498

扫码关注云+社区

领取腾讯云代金券