数据库服务器CPU 突然持续100%后自动下降原因诊断

标签： 数据库 服务器 cpu | 发表时间：2014-12-15 05:00 | 作者：ljunjie82
出处：http://blog.csdn.net

1、CPU接近100% nmon数据


8月5日在9：20—9：40之间，出现CPU接近100%的情况，特点表现为9：20左右CPU急剧攀升，在9：45左右又快速下降

 

2、原因分析结果总述

2.1 持续时间与恢复方式

此次CPU攀高时间持续约20分钟，在无人工干预的情况下自动恢复

2.2 原因分析总述：

经过分析，原因为：4条SQL语句ORACLE优化器对LB_T_XXXVIDER视图、LB_T_XXXJECT_PROVIDER表、LA_XXCKAGE表的基数数据评估发生了巨大的差错，导致选择了错误的执行计划，消耗大量的CPU资源

2.3 错误执行计划估算数据与正确执行计划估算数据对比

此处为选择一条最严重的SQL语句为例，其它语句原因相同

错误执行计划基数估算值

Execution Plan

Id

Operation

Name

Rows

Bytes

Cost (%CPU)

0

SELECT STATEMENT

 

 

 

315 (100)

1

   COUNT STOPKEY

 

 

 

 

2

     VIEW

 

1

180

315 (2)

3

       SORT ORDER BY STOPKEY

 

1

151

315 (2)

4

         HASH UNIQUE

 

1

151

314 (1)

5

           FILTER

 

 

 

 

6

             NESTED LOOPS OUTER

 

1

151

313 (1)

7

               NESTED LOOPS

 

1

86

35 (0)

8

                 TABLE ACCESS BY INDEX ROWID

LB_T_XXXJECT_PROVIDER

1

61

34 (0)

9

                   INDEX RANGE SCAN

IDX_LB_T_XXXJECT_PROVIDER_003

183

 

3 (0)

10

                 TABLE ACCESS BY INDEX ROWID

LA_XXCKAGE

1

25

1 (0)

11

                   INDEX UNIQUE SCAN

PK_LA_XXCKAGE

1

 

0 (0)

12

               VIEW PUSHED PREDICATE

LB_T_XXXVIDER

1

65

278 (1)

13

                 MERGE JOIN OUTER

 

1

64

278 (1)

14

                   TABLE ACCESS BY INDEX ROWID

XXCC_SUPPLIER

1

45

146 (0)

15

                     INDEX FULL SCAN

PK_XXCC_SUPPLIER

1

 

145 (0)

16

                   SORT JOIN

 

17998

333K

132 (2)

17

                     VIEW

 

17998

333K

131 (1)

18

                       SORT GROUP BY

 

17998

544K

131 (1)

19

                         TABLE ACCESS FULL

XXCC_SUPPLIER_CONTACT

30058

909K

130 (0)

正确执行计划基数估算值

Execution Plan

Id

Operation

Name

Rows

Bytes

Cost (%CPU)

0

SELECT STATEMENT

 

 

 

64460 (100)

1

   COUNT STOPKEY

 

 

 

 

2

     VIEW

 

224K

38M

64460 (1)

3

       SORT ORDER BY STOPKEY

 

224K

28M

64460 (1)

4

         HASH UNIQUE

 

224K

28M

58849 (1)

5

           FILTER

 

 

 

 

6

             HASH JOIN OUTER

 

224K

28M

53237 (1)

7

               NESTED LOOPS

 

 

 

 

8

                 NESTED LOOPS

 

347

29842

528 (0)

9

                   TABLE ACCESS BY INDEX ROWID

LB_T_XXXJECT_PROVIDER

347

21167

181 (0)

10

                     INDEX RANGE SCAN

IDX_PROJECT_PROVIDER_COMB1

182

 

4 (0)

11

                   INDEX UNIQUE SCAN

PK_LA_XXCKAGE

1

 

0 (0)

12

                 TABLE ACCESS BY INDEX ROWID

LA_XXCKAGE

1

25

1 (0)

13

               VIEW

LB_T_XXXVIDER

9125K

409M

52700 (1)

14

                 HASH JOIN OUTER

 

9125K

556M

52700 (1)

15

                   TABLE ACCESS FULL

XXCC_SUPPLIER

26139

1148K

404 (0)

16

                   VIEW

 

6283K

113M

52287 (1)

17

                     SORT GROUP BY

 

6283K

185M

52287 (1)

18

                       TABLE ACCESS FULL

XXCC_SUPPLIER_CONTACT

10M

309M

148 (9)
  • cardinality feedback used for this statement

说明上面统计信息与实际数据存在非常大的差异，是引起执行计划错误的真正原因

 

2.4 错误执行计划与正确执行计划CPU资源消耗差异巨大对比

  此处为选择一条最严重的SQL语句为例，其它语句比例相近

SQL ID: bj75p9188y410

#

Plan Hash Value

Total Elapsed Time(ms)

Executions

1st Capture Snap ID

Last Capture Snap ID

1

3990363694

4,585,425

9

33676

33677

2

6178145

2,838

2

33677

33677

3

2354817963

1,461

1

33677

33677

错误执行计划CPU消耗是最优执行计划CPU消耗的348倍

 

2.5  问题自动修复原因

ORACLE11G 的新功能cardinality feedback可以在上次运行完成后，得到上一次运行的基数真正结果，智能的调整后面语句运行时的执行计划，通过cardinality feedback功能得到准确基数数据后调整的执行计划，会给出下面提示：

cardinality feedback used for this statement

 

3、数据库时间与AWR快照对应信息

    此在列出时间与AWR快照对应信息的原因为后续分析依赖时间与快照的关系，展示阶段性数据

序号

snap_id

BEGIN_INTERVAL_TIME

END_INTERVAL_TIME

1

33675

05-8月 -13 08.30.41.054

05-8月 -13 09.00.09.786

2

33676

05-8月 -13 09.00.09.786

05-8月 -13 09.30.10.502

3

33677

05-8月 -13 09.30.10.502

05-8月 -13 10.00.26.364

4

33678

05-8月 -13 10.00.26.364

05-8月 -13 10.30.18.791

5

33679

05-8月 -13 10.30.18.791

05-8月 -13 11.00.24.540

 

4、总体原因具体分析

8月5日9：00—10：00AWR报告分析

SQL ordered by CPU Time

NO

CPU Time (s)

Executions

CPU per Exec (s)

Elapsed Time (s)

%CPU

%IO

SQL Id

SQL Text

1

2,927.66

12

243.97

4,589.72

63.79

0.00

bj75p9188y410

select * from ( select distinc...

2

1,771.52

3,820

0.46

2,660.05

66.60

0.00

gwz243zx18jk0

SELECT * FROM PUB_STRU_TYPE_RE...

3

1,687.68

6

281.28

1,981.37

85.18

0.00

gmfktzfsd6hj3

select * from ( select row_.*,...

4

1,320.77

18

73.38

2,050.40

64.42

0.00

1d44jc4at7xt6

select count(0) from ( select ...

5

870.33

745

1.17

1,288.11

67.57

0.00

4x0jsx8xmrq3c

select count(1) rcount from ( ...

6

856.20

63

13.59

1,096.32

78.10

0.00

1ztsa8nc1arn1

SELECT DISTINCT RFX2.rootId F...

7

752.07

429

1.75

1,145.77

65.64

0.00

9rpn6kmf9vwwh

select p.package_id, p.package...

8

729.02

94

7.76

853.01

85.46

0.00

bq1x40gqtd1r3

SELECT DISTINCT RFX2.rootId F...

9

683.45

12

56.95

1,538.29

44.43

37.32

f760vj05hjpww

SELECT DISTINCT RFX1.rootId F...

10

595.38

2

297.69

632.09

94.19

0.00

fh86uz0ch9z9w

select count(0) from ( select ...

 

分析：

（1）   上述标红色语句共四条，其中第4条和第10条其实为同一条SQL语句

（2）   上述四条标红色SQL语句分析为最消耗CPU资源的语句

（3）   上述四条标红色SQL语句在出问题前都没有运行，基本都集中在9：00以后开始运行

（4）   上述标红色语句的问题有共同特性，都调用了LB_T_XXXVIDER视图、LB_T_XXXJECT_PROVIDER表、LA_XXCKAGE

（5）   上述标红色语句都是因为优化器对LB_T_XXXVIDER视图、LB_T_XXXJECT_PROVIDER表、LA_XXCKAGE表的基数数据评估发生了巨大的差错，导致选择了错误的执行计划，消耗大量的CPU资源，导致CPU接近100%

（6）   上述标红色语句都是在几次错误选择后有效的利用了ORACLE11g的新特性cardinalityfeedback功能，最终得到准确的基数数据，自行修正了执行计划

 

5、问题语句逐条剖析

5.1 第一条：SQL_ID：bj75p9188y410

SQL ID: bj75p9188y410

#

Plan Hash Value

Total Elapsed Time(ms)

Executions

1st Capture Snap ID

Last Capture Snap ID

1

3990363694

4,585,425

9

33676

33677

2

6178145

2,838

2

33677

33677

3

2354817963

1,461

1

33677

33677

分析：

（1）标红色的为错误的执行计划及其统计信息

（2）9：00—10：00之间，共发生9次错误的执行计划

（3）在前面发生9次错误的执行计划之后，由于ORACLE 11G的cardinality feedback新功能，最终得到准确的基数，在9：30-10：00之间，自动纠正了执行计划

 

5.2 第二条：SQL_ID： gmfktzfsd6hj3

SQL ID: gmfktzfsd6hj3

#

Plan Hash Value

Total Elapsed Time(ms)

Executions

1st Capture Snap ID

Last Capture Snap ID

1

617277444

2,602,874

6

33677

33678

2

2335536944

2,725

2

33678

33678

3

687995303

1,437

1

33678

33678

分析：

（1）标红色的为错误的执行计划及其统计信息

（2）9：30—10：30之间，共发生6次错误的执行计划

（3）在前面发生6次错误的执行计划之后，由于ORACLE 11G的cardinality feedback新功能，最终得到准确的基数，在10：00-10：30之间，自动纠正了执行计划

 

5.3 第三条：SQL_ID： 1d44jc4at7xt6

SQL ID: 1d44jc4at7xt6

#

Plan Hash Value

Total Elapsed Time(ms)

Executions

1st Capture Snap ID

Last Capture Snap ID

1

3265929876

2,029,525

4

33676

33677

2

2949667951

19,116

13

33676

33677

3

1227972422

1,761

1

33676

33677

分析：

（1）标红色的为错误的执行计划及其统计信息

（2）9：00—10：00之间，共发生4次错误的执行计划，其中

（3）在前面发生4次错误的执行计划之后，由于ORACLE 11G的cardinality feedback新功能，最终得到准确的基数，在9：30-10：00之间，自动纠正了执行计划

 

5.4 第四条：SQL_ID：fh86uz0ch9z9w

SQL ID: fh86uz0ch9z9w

#

Plan Hash Value

Total Elapsed Time(ms)

Executions

1st Capture Snap ID

Last Capture Snap ID

1

3265929876

1,247,089

4

33676

33681

2

2949667951

2,624

2

33681

33681

3

1227972422

1,291

1

33681

33681

分析：

（1）标红色的为错误的执行计划及其统计信息

（2）9：00—11：30之间，共发生4次错误的执行计划，其中两次发生在9：00-9：30间

（3）在前面发生4次错误的执行计划之后，由于ORACLE 11G的cardinality feedback新功能，最终得到准确的基数，在11：00-11：30之间，自动纠正了执行计划

 

6、引发执行计划错误原因分析

6.1 表统计信息统计历史

6.1.1  LB_T_XXXJECT_PROVIDER

序号

用户名

表名

分析历史时间

1

BIDPRO

LB_T_XXXJECT_PROVIDER

11-8月 -13 20.06.16.630512

2

BIDPRO

LB_T_XXXJECT_PROVIDER

03-8月 -13 20.22.23.332654

3

BIDPRO

LB_T_XXXJECT_PROVIDER

26-7月 -13 22.18.08.386638

在8月5日开标前，该表已经有10天未统计

 

6.1.2  LA_XXCKAGE

序号

用户名

表名

分析历史时间

1

BIDPRO

LA_XXCKAGE

15-8月 -13 20.01.28.232128

2

BIDPRO

LA_XXCKAGE

09-8月 -13 20.04.35.224700

3

BIDPRO

LA_XXCKAGE

26-7月 -13 20.08.49.666682

    在8月5日开标前，该表已经有10天未统计

 

6.1.3  XXCC_SUPPLIER

序号

用户名

表名

分析历史时间

1

BIDPRO

XXCC_SUPPLIER

18-8月 -13 20.13.21.031834

2

BIDPRO

XXCC_SUPPLIER

10-8月 -13 20.07.04.740643

3

BIDPRO

XXCC_SUPPLIER

31-7月 -13 22.00.39.107474

4

BIDPRO

XXCC_SUPPLIER

22-7月 -13 22.01.26.170018

  在8月5日开标前，该表已经有5天未统计

 

6.1.4  XXCC_SUPPLIER_CONTACT

序号

用户名

表名

分析历史时间

1

BIDPRO

XXCC_SUPPLIER_CONTACT

17-8月 -13 20.03.30.834585

2

BIDPRO

XXCC_SUPPLIER_CONTACT

09-8月 -13 22.03.30.402420

3

BIDPRO

XXCC_SUPPLIER_CONTACT

26-7月 -13 22.07.06.696581

在8月5日开标前，该表已经有10天未统计

 

6.2 表数据变化分析

6.2.1  8月5日前最后一次统计时间至8月5日时的block_changes数量

序号

表名

最后一次统计时间

block_changes

1

LB_T_XXXJECT_PROVIDER

26-7月 -13 22.18

158560

2

LA_XXCKAGE

26-7月 -13 20.08

168224

3

XXCC_SUPPLIER

31-7月 -13 22.00

608

4

XXCC_SUPPLIER_CONTACT

26-7月 -13 22.07

576

 

6.3 错误执行计划预估数据量与真正数据量差异对比

SQL_ID

执行计划对错区分

对表的ROWS评估数

XXCC_SUPPLIER_CONTACT

XXCC_SUPPLIER

LA_XXCKAGE

LB_T_XXXJECT_PROVIDER

bj75p9188y410

错误执行计划

30058

1

1

1

正确执行计划

10M

26139

1

347

gmfktzfsd6hj3

错误执行计划

30058

1

1

1

正确执行计划

10M

26139

1

347

1d44jc4at7xt6

错误执行计划

30058

1

1

1

正确执行计划

10M

26139

1

347

fh86uz0ch9z9w

错误执行计划

30058

1

1

1

正确执行计划

7763K

26139

1

347

 

7、解决方案建议

   建议对上述四条发生执行计划错误的SQL语句，采用SQL_PROFILE对执行计划进行固定，可以避免下次开标时出现同样的问题




本文作者：黎俊杰（网名：踩点），从事”系统架构、操作系统、存储设备、数据库、中间件、应用程序“六个层面系统性的性能优化工作

欢迎加入 系统性能优化专业群，共同探讨性能优化技术。群号：258187244


作者：ljunjie82 发表于2014-12-14 21:00:23 原文链接
阅读：0 评论：0 查看评论

相关 [数据库 服务器 cpu] 推荐：

Mysql数据库服务器的CPU占用很高分析

- - ITeye博客
　　 MySQl服务器CPU占用很高. 　　一个简单的接口，根据传入的号段查询号码归属地，运行. 性能测试脚本，20个并发mysql的CPU就很高，监控发现只有一个select语句，且表建立了索引. 　　查询语句索引没有命中导致. 　　开始时的select. 咨询说where中使用SUBSTRING函数不行，修改函数为LEFT，语句为 SELECT `province_name`, `city_name` FROM `conf_phoneno_section` WHERE LEFT(?, phoneno_section_len) = phoneno_section LIMIT ?.

数据库服务器CPU 突然持续100%后自动下降原因诊断

- - CSDN博客推荐文章
1、CPU接近100% nmon数据. 8月5日在9：20—9：40之间，出现CPU接近100%的情况，特点表现为9：20左右CPU急剧攀升，在9：45左右又快速下降. 2.1 持续时间与恢复方式. 此次CPU攀高时间持续约20分钟，在无人工干预的情况下自动恢复. 经过分析，原因为：4条SQL语句ORACLE优化器对LB_T_XXXVIDER视图、LB_T_XXXJECT_PROVIDER表、LA_XXCKAGE表的基数数据评估发生了巨大的差错，导致选择了错误的执行计划，消耗大量的CPU资源.

sysbench测试MySQL服务器性能（cpu，io，内存，mysql等）

- - CSDN博客数据库推荐文章
Sysbench的安装请参考http://blog.csdn.net/mchdba/article/details/8951289. sysbench采用寻找最大素数的方式来测试CPU的性能. 首先生成需要的测试文件，文件总大小1000M，16个并发线程，随机读写模式. 执行完后会在当前目录下生成一堆小文件.

Java项目服务器cpu占用100%解决办法

- - 互联网 - ITeye博客
       项目上线后运行一段时间，突然发现cpu 8个逻辑核心都占用100%，心情很紧张，然后就在网上找了一些解决方法，具体如下：.        1.查找哪些进程在耗cpu .        进入服务器，top 命令看一下，发现进程6633占用了800% .        2.把进程的栈dump到文件里，以便后面的分析.

mysql服务器CPU使用过高的优化方案

- - 数据库 - ITeye博客
当然除了一些加索引的还有少量的通过改代码进行sql语句优化的(例如参数赋值时的数据类型必须要和数据库定义的字段类型相一致，如果是关联查询中，关联字段的数据类型和编码、长度也都要一致，否则很有可能用不上索引)，主要是正确的添加索引. 另外也学习了一点：mysql函数 now()、current_date()都是实时变化的，mysql 不会将查询的结果放到查询缓存里，从而降低了查询缓存的命中率.

可伸缩Web架构的4个问题：瓶颈，CPU，数据库，IO

- - 互联网 - ITeye博客
在这篇文章中我将谈到关于大规模网站架构扩展和性能方面的一些问题. 首先让我们先来了解一些术语. 稍后我将对Web应用扩展过程中所遇到的不同问题进行讲解，例如：. Web系统的性能受多方面因素的影响，但大多数开发人员主要关心的是响应时间和可扩展性这两方面. 响应时间是指Web应用从收到请求到返回响应结果所花费的时间.

检查MySQL数据库服务器的shell脚本

- 铭文 - MySQLOPS 数据库与运维自动化技术分享
某著名电子商务公司的同事，编写的shell脚本，用于获得数据库服务器的数据库性能和配置，以及服务器负载LOAD等信息. shell脚本较长，也对shell脚本做了部分修改，同时为使技术朋友们更容易理解和使用，添加相关的文字和图片描述作为手册. 1.         功能描述. 执行shell命令：sh Get_Local_Kpi.sh –help，能显示相关信息，如图1-1：.

应用服务器上在线备份Oracle数据库代码

- - CSDN博客数据库推荐文章
做在线备份时，输出做一个修改，动态把输出内容传到浏览器页面上去. 作者：qm4050 发表于2013-2-28 10:34:34 原文链接. 阅读：75 评论：0 查看评论.

生产上数据库大量的latch free 导致的CPU资源耗尽的问题的解决

- - CSDN博客推荐文章
中午的时候，我们生产上的某个数据库，cpu一直居高不下. 通过如下的sql语句，我们查看当时数据库的等待，争用的情况：. 从event可以看到，是latch 的争用导致的原因. 通过如果的sql，查看是什么样的latch. P2就是 这个latch的name，通过v$latchname这个视图就可以知道哪个具体的latch.

微服务架构下，MySQL 读写分离后，数据库 CPU 飙升卡壳问题解析

- - IT瘾-dev
最近系统（基于SpringCloud+K8s）上线，运维团队早上8点左右在群里反馈，系统登录无反应. 我的第一反应是Mysql数据库扛不住了. 排查问题也是一波三折，有网络问题，也有mysql读写分离后数据库参数优化问题. 1、运维团队早上8点左右在群里反馈，系统登录无反应. 2、DevOps团队通过查看Kibana日志，发现ELK、k8s集群、Redis、Mongodb、Nigix、文件服务器全部报：”Connect Unknown Error“，惊出一身冷汗.