一次資料庫響應緩慢的問題排查

531968912發表於2015-12-26
今天客戶說有一個job跑的特別慢。想看看到底是不是資料庫這邊有什麼問題了。
使用top來檢視,io wait將近30%,已經算是負載比較重的了。


和客戶確認從什麼時候發現速度開始變慢的,他們說大概是從中午以後。
使用sar來看一下,確實是從iowait從:1:00開始有了大量的io 

10:40:01 AM       CPU     %user     %nice   %system   %iowait    %steal     %idle

10:50:02 AM       all      7.59      0.00      1.38      3.82      0.00     87.21

11:00:01 AM       all      7.59      0.00      1.48      4.21      0.00     86.72

11:10:01 AM       all      7.46      0.00      1.69      4.52      0.00     86.33

11:20:01 AM       all      7.59      0.00      1.66      4.61      0.00     86.14

11:30:01 AM       all      7.47      0.00      1.53      4.37      0.00     86.62

11:40:01 AM       all      6.40      0.00      0.73      2.17      0.00     90.71

11:50:01 AM       all      6.04      0.00      0.55      1.51      0.00     91.89

12:00:02 PM       all      5.92      0.00      0.54      1.64      0.00     91.91

12:10:01 PM       all      5.95      0.00      0.82      2.01      0.00     91.23

12:20:02 PM       all      6.28      0.00      0.82      1.92      0.00     90.98

12:30:01 PM       all      6.82      0.00      0.90      2.06      0.00     90.22

12:40:01 PM       all      7.94      0.00      1.47      3.52      0.00     87.06

12:50:01 PM       all      8.01      0.00      1.55      3.78      0.00     86.65

01:00:01 PM       all      8.45      0.00      1.27     26.44      0.00     63.83

01:10:01 PM       all      7.28      0.00      1.05     47.89      0.00     43.78

01:20:01 PM       all      7.25      0.00      0.96     47.00      0.00     44.78

01:30:02 PM       all      7.62      0.00      1.04     44.31      0.00     47.03

01:40:01 PM       all      7.80      0.00      1.14     40.77      0.00     50.29

01:50:02 PM       all      7.99      0.00      1.15     44.40      0.00     46.46

02:00:01 PM       all      7.90      0.00      1.15     38.89      0.00     52.07

02:10:01 PM       all      7.16      0.00      1.15     43.83      0.00     47.85

02:20:01 PM       all      7.27      0.00      1.06     38.18      0.00     53.49

02:30:01 PM       all      7.29      0.00      1.04     35.64      0.00     56.03

02:40:01 PM       all      7.13      0.00      1.13     43.12      0.00     48.62

02:50:01 PM       all      8.45      0.01      1.36     43.24      0.00     46.95

03:00:02 PM       all      7.89      0.00      1.20     36.92      0.00     53.98

03:10:01 PM       all      6.73      0.00      1.09     42.51      0.00     49.68

03:20:02 PM       all      6.82      0.00      0.96     42.68      0.00     49.54

03:30:01 PM       all      6.64      0.00      0.95     44.15      0.00     48.26

03:40:02 PM       all      7.19      0.00      1.09     37.35      0.00     54.36

03:50:01 PM       all      6.70      0.00      1.06     39.24      0.00     53.00

04:00:02 PM       all      6.70      0.00      1.04     43.66      0.00     48.60

04:10:01 PM       all      6.98      0.00      1.08     40.17      0.00     51.77

04:20:02 PM       all      6.96      0.00      1.02     31.54      0.00     60.48

Average:          all      6.41      0.00      0.75      9.96      0.00     82.87


對於cpu的使用率高的問題,據我所知,這幾天在做效能測試,cpu的消耗是可以接受的。
但是io的問題得有一個讓人信服的結論,於是我使用dd來做了一個簡單地測試,發現確實有很大的差距,
> time dd if=/dev/zero bs=1M count=204 of=direct_200M
414+0 records in
414+0 records out
434110464 bytes (434 MB) copied, 103.742 seconds, 4.2 MB/s

在另外一個環境中做了對比測試,

> time dd if=/dev/zero bs=1M count=204 of=direct_200M
204+0 records in
204+0 records out
213909504 bytes (214 MB) copied, 1.44182 seconds, 148 MB/s

real    0m1.445s
user    0m0.001s
sys     0m0.039s

所以問題可以和unix team來協調了。昨天晚上的時候客戶反饋確實是san儲存出了問題,當時正在做san儲存的切換,所以導致訪問速度受到影響。
早上就驗證了一下。
> time dd if=/dev/zero bs=1M count=204 of=direct_200M
204+0 records in
204+0 records out
213909504 bytes (214 MB) copied, 0.448161 seconds, 477 MB/s

real    0m0.459s
user    0m0.001s
sys     0m0.061s


來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/23718752/viewspace-1190187/,如需轉載,請註明出處,否則將追究法律責任。

相關文章