主題: [Oracle] 對 Oracle 回應速度變很慢, 且iowait 99%

[endure]

請教一個問題,不知道是什麼原因所引起,若知道原因或方向麻煩告知一下
問題:Oracle不定時變慢(一個月約1~2次, 時間日期不一定), 使得對他的請求均要很久才會回覆
OS : Red Hat Enterprise Linux ES release 4
Oracle : 9.2.0.1
狀況:(1) select , update, insert等語法均要很久才會回覆, 超過10min
       (2) 使用TOP查詢, 發現IOWAIT已吃滿50~99%以上, 但CPU的耗用量低於 10%
       (3) 使用iostat查詢, 不過tps佔很高, 並未發現有大量的資料讀取
       (4) 只要把oracle service 關掉, iowait就降下來.
       (5) 目前一定要透過oracle shutdown immediate關掉,再重新啟動才會好(abort關掉,重啟iowait一樣衝高)
       (6) alter.log一直出現cannot allocate new log 與 Checkpoint not complete錯誤, 發生問題時才出現,
            redolog常幾個小時才switch一次, 問題發生時, 2~6分鐘switch一次
       (7) 當發生問題時,把AP關掉後,只留oracle單獨運行,狀況並沒變好.
       ( Server HD並未出現警示, 有請系統工程師檢查HD,並無壞軌
       (9) 有透過dbminer去檢查redo到底在做什麼, 結果發現有百分之80以上是INTERNAL的運作,但其對應的
                    redo_sql欄位並無資料.

so...真的不知道怎麼處理了..現在維護廠商也說沒遇過這種問題..朝更新patch方式來試..
但我覺得應該不是oracle bug, 不然別人早就遇過了, 所以麻煩知道原因或知道怎麼查的人告知一下.謝謝

狀況說明:
(2)
</u2/oradb/admin/topdb/bdump> top
 16:07:24  up 90 days,  5:00,  5 users,  load average: 4.09, 3.91, 2.69
323 processes: 322 sleeping, 1 running, 0 zombie, 0 stopped
CPU states:  cpu    user    nice  system    irq  softirq  iowait    idle
           total    7.1%    0.0%    0.6%   0.0%     0.0%   69.1%   23.0%
           cpu00    9.1%    0.0%    0.0%   0.0%     0.0%   44.0%   46.7%
           cpu01    7.4%    0.0%    0.0%   0.0%     0.0%   47.2%   45.3%
           cpu02    4.5%    0.0%    0.9%   0.0%     0.0%   94.4%    0.0%
           cpu03    7.4%    0.0%    1.8%   0.0%     0.0%   90.7%    0.0%
Mem:  4091560k av, 4073536k used,   18024k free,       0k shrd,    7704k buff
                   2881744k actv,  560524k in_d,   75836k in_c
Swap: 8385920k av,   21908k used, 8364012k free                 3211592k cached

(3) 並無大量的資料讀寫, 不過tps佔很高
avg-cpu:  %user   %nice    %sys %iowait   %idle
          19.65    0.00    4.53   51.64   24.18

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
cciss/c0d0        0.00         0.00         0.00          0          0
cciss/c0d0p1      0.00         0.00         0.00          0          0
cciss/c0d0p2      0.00         0.00         0.00          0          0
cciss/c0d0p3      0.00         0.00         0.00          0          0
cciss/c0d1      130.30       274.75     11410.10        272      11296
cciss/c0d1p1    130.30       274.75     11410.10        272      11296
cciss/c0d1p2      0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice    %sys %iowait   %idle
          13.90    0.00    2.48   76.67    6.95

Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
cciss/c0d0        0.00         0.00         0.00          0          0
cciss/c0d0p1      0.00         0.00         0.00          0          0
cciss/c0d0p2      0.00         0.00         0.00          0          0
cciss/c0d0p3      0.00         0.00         0.00          0          0
cciss/c0d1      130.69       166.34     12411.88        168      12536
cciss/c0d1p1    130.69       166.34     12411.88        168      12536
cciss/c0d1p2      0.00         0.00         0.00          0          0

(6) 一直出現cannot allocate new log 與 Checkpoint not complete錯誤
Thread 1 advanced to log sequence 10737
  Current log# 2 seq# 10737 mem# 0: /u2/oradb/oradata/topdb/redo02.log
Wed Aug 27 08:41:09 2008
Thread 1 cannot allocate new log, sequence 10738
Checkpoint not complete
  Current log# 2 seq# 10737 mem# 0: /u2/oradb/oradata/topdb/redo02.log
Wed Aug 27 08:51:04 2008

[longtime]

不曉得你的系統平時的負載為何
一直出現 cannot allocate new log 的錯誤訊息
表示你的 redo log 寫出過慢, 導致 Checkpoint 來不及產生
這部份的錯誤通常都跟 I/O 的效能有關係

你可以試著先增加 redolog file 的數量看看
若狀況依然還是會發生
那你的 Raid 中可能有某一顆硬碟出了問題
或是跟儲存系統相關的設備有問題 (ex: Raid card, 排線....等等)
你可以用 iostat 在狀況發生時測試一下硬碟的寫入速度是否正常

[netman]

先用 iostat -x 1 看看  await  svctm  的數值如何？
還有 vmstat 1 看 swap 跟 io 的情況。

[endure]

relog的數量有增加過,目前設定為5個,一個200M.
平常3個小時以上切換一次...但發生問題時速度就變成幾分鐘切換一次...這是屬於瞬間產生
那麼多的量(對我們而言是屬不正常的),故增加relog並不能解決此問題.

至於硬碟的部份, 我們想過, 也請負責的人認是否有問題(沒問題)

等下次發生,我再搬資料看看..看io狀況會怎麼..

To netman
     下次發生時,我再看當時的狀再看看..

謝謝兩位的意見

------以下是正常狀態下的數值
iostat -x 1
avg-cpu:  %user   %nice    %sys %iowait   %idle
          52.50    0.00   22.00    0.25   25.25

Device:    rrqm/s wrqm/s   r/s   w/s  rsec/s  wsec/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
cciss/c0d0   0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d0p1
             0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d0p2
             0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d0p3
             0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d1   0.00   1.00  0.00  1.00    0.00   16.00     0.00     8.00    16.00     0.01   10.00  10.00   1.00
cciss/c0d1p1
             0.00   1.00  0.00  1.00    0.00   16.00     0.00     8.00    16.00     0.01   10.00  10.00   1.00
cciss/c0d1p2
             0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00


avg-cpu:  %user   %nice    %sys %iowait   %idle
          56.50    0.00   25.00    0.00   18.50

Device:    rrqm/s wrqm/s   r/s   w/s  rsec/s  wsec/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
cciss/c0d0   0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d0p1
             0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d0p2
             0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d0p3
             0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d1   0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d1p1
             0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
cciss/c0d1p2
             0.00   0.00  0.00  0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00


</u2/oradb/admin/topdb/bdump> vmstat 1
procs                      memory      swap          io     system         cpu
 r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us sy id wa
 2  0  21092  21428   8016 3320596    0    0     0     0    0     0  0  0  1  1
 2  0  21092  21416   8016 3320600    0    0     4     8  303   342 41  9 50  1
 3  0  21092  21576   8024 3320164    0    0    44     8  267   310 44 12 42  1
 3  1  21092  21500   8036 3320160    0    0    72   116  692   813 56 20 24  0
 2  0  21092  21328   8052 3320232    0    0   488   172 1866  2158 42 13 38  7
 2  0  21092  21508   8052 3319992    0    0    36   136 1195  1439 37 14 44  5
 3  0  21092  21500   8052 3319992    0    0     0     4  233   281 44 17 38  0
 2  0  21092  21416   8052 3320076    0    0     4   128  228   329 42 16 37  6
 3  1  21092  21500   8068 3318020    0    0     4   140  461   559 48 16 35  0
 3  0  21092  21384   8072 3316564    0    0     4   128  656   747 51 23 19  6

不曉得你的系統平時的負載為何
一直出現 cannot allocate new log 的錯誤訊息
表示你的 redo log 寫出過慢, 導致 Checkpoint 來不及產生
這部份的錯誤通常都跟 I/O 的效能有關係

你可以試著先增加 redolog file 的數量看看
若狀況依然還是會發生
那你的 Raid 中可能有某一顆硬碟出了問題
或是跟儲存系統相關的設備有問題 (ex: Raid card, 排線....等等)
你可以用 iostat 在狀況發生時測試一下硬碟的寫入速度是否正常