2. 程式人生 > >資料庫伺服器CPU 突然持續100%後自動下降原因診斷

資料庫伺服器CPU 突然持續100%後自動下降原因診斷

阿新 • • 發佈：2019-02-14

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

4,585,425

9

33676

33677

2

2,838

2

33677

33677

3

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

select * from ( select distinc...

2

1,771.52

3,820

0.46

2,660.05

66.60

0.00

SELECT * FROM PUB_STRU_TYPE_RE...

3

1,687.68

6

281.28

1,981.37

85.18

0.00

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

4

1,320.77

18

73.38

2,050.40

64.42

0.00

select count(0) from ( select ...

5

870.33

745

1.17

1,288.11

67.57

0.00

select count(1) rcount from ( ...

6

856.20

63

13.59

1,096.32

78.10

0.00

SELECT DISTINCT RFX2.rootId F...

7

752.07

429

1.75

1,145.77

65.64

0.00

select p.package_id, p.package...

8

729.02

94

7.76

853.01

85.46

0.00

SELECT DISTINCT RFX2.rootId F...

9

683.45

12

56.95

1,538.29

44.43

37.32

SELECT DISTINCT RFX1.rootId F...

10

595.38

2

297.69

632.09

94.19

0.00

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

4,585,425

9

33676

33677

2

2,838

2

33677

33677

3

1,461

1

33677

33677

分析：

（1）標紅色的為錯誤的執行計劃及其統計資訊

（2）9：00—10：00之間，共發生9次錯誤的執行計劃

（3）在前面發生9次錯誤的執行計劃之後，由於ORACLE 11G的cardinality feedback新功能，最終得到準確的基數，在9：30-10：00之間，自動糾正了執行計劃

SQL ID: gmfktzfsd6hj3

#

Plan Hash Value

Total Elapsed Time(ms)

Executions

1st Capture Snap ID

Last Capture Snap ID

1

2,602,874

6

33677

33678

2

2,725

2

33678

33678

3

1,437

1

33678

33678

分析：

（1）標紅色的為錯誤的執行計劃及其統計資訊

（2）9：30—10：30之間，共發生6次錯誤的執行計劃

（3）在前面發生6次錯誤的執行計劃之後，由於ORACLE 11G的cardinality feedback新功能，最終得到準確的基數，在10：00-10：30之間，自動糾正了執行計劃

SQL ID: 1d44jc4at7xt6

#

Plan Hash Value

Total Elapsed Time(ms)

Executions

1st Capture Snap ID

Last Capture Snap ID

1

2,029,525

4

33676

33677

2

19,116

13

33676

33677

3

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

1,247,089

4

33676

33681

2

2,624

2

33681

33681

3

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


相關推薦

資料庫伺服器CPU 突然持續100%後自動下降原因診斷

1、CPU接近100% nmon資料 8月5日在9：20—9：40之間，出現CPU接近100%的情況，特點表現為9：20左右CPU急劇攀升，在9：45左右又快速下降 2、原因分析結果總述 2.1 持續時間與恢復方式 此次CPU攀高時間持續約20分鐘，在無人工干預的情況

【故障公告】阿里雲 RDS 資料庫伺服器 CPU 100% 造成全站故障

非常非常抱歉，今晚 19:34 ~ 21:16 園子所使用的阿里雲 RDS 資料庫伺服器突然出現 CPU 100% 問題，造成全站無法正常訪問，由此您帶來了很大的麻煩，請您諒解。 故障經過是這樣的。19:34 這個時間點本來是一個訪問低峰，資料庫壓力比訪問高峰時低很多，但資料庫伺服器卻異想天開、吃飽了

【故障公告】資料庫伺服器 CPU 近 100% 引發的故障（源於 .NET Core 3.0 的一個 bug）

非常抱歉，這次故障給您帶來麻煩了，請您諒解。 今天早上 10:54 左右，我們所使用的資料庫服務（阿里雲 RDS 例項 SQL Server 2016 標準版）CPU 突然飆升至 90% 以上，應用日誌中出現大量資料庫查詢超時的錯誤。 Microsoft.Data.SqlClient.SqlEx

【故障公告】資料庫伺服器 CPU 近 100% 引發的故障

非常抱歉，今天上午 10:48 ~ 11:33 期間，我們所使用的資料庫服務（阿里雲 RDS 例項 SQL Server 2016 標準版）又出現了 CPU 近 100% 問題，由此給您帶來麻煩，請您諒解。 這次剛開始出現 CPU 近 100% 問題時，沒有造成大的影響，後來有段時間 CPU 降了

【故障公告】訪問高峰資料庫伺服器 CPU 100% 引發全站故障

今天上午11:10，我們又中“獎”了，我們使用的阿里雲 RDS 例項（SQL Server 2016 標準版，16核32G）突發出現 CPU 100%，引發全站故障，直到 12:15 才完全恢復，由此給您帶來很大的麻煩，請您諒解。 這是我們今年的第3次中“獎&

監控伺服器程式，掛掉後自動重啟

1、定時呼叫ps，檢查程式是否活著。如果不在了就啟動程式 #!/bin/bash name=$1 while true do         c=`ps -x | grep $name | grep -v grep

一.背景 先說下windbg使用場景.各位coder在工作中或多或少都會遇到下面四種情況 1.原生代碼好好的,放伺服器上執行一段時間後,IIS服務突然佔用 w3wp.exe CPU突然100% ,

一.背景 先說下windbg使用場景.各位coder在工作中或多或少都會遇到下面四種情況 1.原生代碼好好的,放伺服器上執行一段時間後,IIS服務突然佔用 w3wp.exe CPU突然100% ,不得不回收應用程式池,如果哪次回收晚了,被客戶發現,後果很痛苦~ 2.你的w3wp.

CPU使用率報警100%之伺服器再次被黑！

繼上次伺服器被黑之後，今天發現又一次被黑進當成挖礦肉雞（當然不是同一臺啦），從CPU使用率報警90%之後，登陸伺服器發現有一個程序達到了100%之上，請看下圖： Wipsws這是個清理儲存空間的系統程序，此情此景不應該出現在這裡。 至此！小編一刀可以定義：此事定有蹊蹺！ 順藤

伺服器tomcat繫結域名後 http80埠自動跳轉https443埠

   2.4修改war包路徑（可選） ---------------------  作者：涓滴之水  來源：CSDN  原文：https://blog.csdn.net/u013344860/article/details/79591519&nb

Mysql cpu 持續100%執行解決過程

通過上一篇部落格分析了slow_log和general_log,給耗時較長的sql添加了組合索引，執行時間從原來的0.9s優化到0.02s;給併發較高的sql加上了快取，但是cpu使用率還是未出現一點下降，其實從日誌分析報告中已經可以看出，這些即使不優化也絕不至於會讓cpu持

django遷移完資料庫後自動生成表資料

步驟如下: 1.檢視MySQL資料庫日誌 檢視mysql資料庫日誌可以檢視對資料庫的操作記錄。 mysql日誌檔案預設沒有產生，需要做如下配置： sudo vi /etc/mysql/mysql.conf.d/mysqld.cnf  把68，69行前面的#去除，然後儲

雲伺服器的cpu突然不夠用，可能不是你的應用出了問題噢

最近每天早上十點高峰，應用伺服器突然就卡死，cpu跑滿，程式碼撤回幾天前，檢查各種服務，流量都無異常，一時找不到問題，懷疑網路慢，檢測之後也無問題，最後在檢視磁碟io的時候撇到了cpu的幾個佔用率     user 代表使用者的應用使用佔比 system代表

Jenkins構建完成後自動部署到指定伺服器（二）

來源：https://www.cnblogs.com/xiao-fy/p/7532139.html 主要分為兩步： 1、傳送Jenkins構建好的war包到指定伺服器 2、執行部署指令碼 這裡是通過使用  publish over ssh 外掛。 外掛管理中搜索publ

jmeter壓測時持續併發但是吞吐量和伺服器CPU並未上來

在jmeter併發壓力測試時，設定的執行緒數比較高，且持續併發中，但是Throughput始終沒有上升，一直保持在不到3/sec，並且服務CPU一直保持在1%以下，壓力並沒有上來。 解決辦法： 在請求

Jenkins構建完成後自動部署到指定伺服器

主要分為兩步： 1、傳送Jenkins構建好的war包到指定伺服器 2、執行部署指令碼 這裡是通過使用  publish over ssh 外掛。 外掛管理中搜索publish over ssh 安裝，完成後系統設定中就可以看到相關設定項了。 Jenkins伺服器上

Java專案伺服器cpu佔用100%解決辦法

 專案上線後執行一段時間，突然發現cpu 8個邏輯核心都佔用100%，心情很緊張，然後就在網上找了一些解決方法，具體如下：         1.查詢哪些程序在耗cpu          進入伺服器，top 命令看一下，發現程序6633佔用了800%         [[e

svn客戶端提交專案程式碼後自動同步svn伺服器上的專案程式碼到linux伺服器上

1.在linux伺服器建立專案資料夾  mkdir phsystem 2.手動同步svn伺服器上的程式碼到linux伺服器 svn  co  svn://192.168.1.99/hsh/phsystem(svn伺服器檔案路徑)       /home/phsystem（

解決asp+access資料庫佔用cpu 100%的方法

今天公司伺服器突然cpu一致100%，導致所有站點開啟十分緩慢，最後就根本無法開啟，開始以為是有站點的程式寫的有問題或者是access損壞造成，於是把機器上所有的站點全部停掉一個一個的試，發現除了使用sql資料庫的和純靜態頁面的站定可以正常執行外，其他連access資料庫的

Oracle伺服器CPU 100%案例分析(轉)

        今天收到開發人員的反應，公司一個非常重要的系統，資料庫伺服器CPU消耗100%，幾乎全是oracle.exe佔用的，但是系統的速度並沒有受到太大影響（或許並非高峰期），而且CPU消耗居高不下，導致系統變得很慢。系統環境：作業系統：Windows Server 2003 SP2Oracle：Or

Linux定位伺服器CPU負載100%居高不下的問題

最近，Linux伺服器上總是經常會出現幾個CPU利用率達到100%並且一直高居不下，如下圖所示，再Linux上，輸入 top 命令，然後再按一下 1，就會顯示你伺服器邏輯CPU的數量以及現在伺服器CP