SMON: recover undo segment與並行事務恢復

SMON: recover undo segment與並行事務恢復

 

 

現象：

20150107早上10點

客戶反映資料庫響應很慢，系統cpu很忙、io很高，業務請求幾乎無法響應、時好時壞；

smon回滾產生的trc檔案不停地增長迅速，幾個G；

 

最近操作：

20150106晚上做資料庫維護，備份資料、drop某個業務表、建索引，匯入資料，資料量大概幾個G，幾十萬條記錄；

第二天早上發現匯入還沒完成，怕影響白天的生產，於是手工取消了操作；

接下來發現異常，資料庫響應變慢，smon回滾產生的trc檔案增長迅速；

客戶早上10點shutdown abort關閉了資料庫後，重新啟動了資料庫；

 

檢查告警日誌：

資料庫版本 9.2.0.1.0.

作業系統 AIX 5.3

 

Wed Jan  7 09:37:40 2015

ARC1: Evaluating archive   log 2 thread 1 sequence 83967

ARC1: Beginning to archive log 2 thread 1 sequence 83967

Creating archive destination LOG_ARCHIVE_DEST_1: '/oradata/admin/orcl/archive/orcl_83967_1.arc'

Wed Jan  7 09:37:58 2015

ARC1: Completed archiving  log 2 thread 1 sequence 83967

Wed Jan  7 09:38:35 2015

Errors in file /oradata/admin/orcl/udump/orcl_ora_1302584.trc:

ORA-00600: internal error code, arguments: [6122], [0], [1], [0], [], [], [], []

Wed Jan  7 09:38:38 2015

Recovery of Online Redo Log: Thread 1 Group 3 Seq 83968 Reading mem 0

  Mem# 0 errs 0: /oradata/orcl/redo03.log

Recovery of Online Redo Log: Thread 1 Group 3 Seq 83968 Reading mem 0

  Mem# 0 errs 0: /oradata/orcl/redo03.log

 

 

Wed Jan  7 10:00:44 2015

Shutting down instance: further logons disabled

Wed Jan  7 10:01:27 2015

ARC1: Completed archiving  log 2 thread 1 sequence 83985

Wed Jan  7 10:01:27 2015

Shutting down instance (immediate)

Wed Jan  7 10:06:44 2015

Starting ORACLE instance (normal)

 

Wed Jan  7 10:07:37 2015

SMON: enabling tx recovery

Wed Jan  7 10:07:37 2015

Database Characterset is ZHS16GBK

Wed Jan  7 10:07:37 2015

SMON: about to recover undo segment 45

SMON: about to recover undo segment 45

SMON: mark undo segment 45 as available

SMON: about to recover undo segment 45

……

SMON: mark undo segment 45 as available

Wed Jan  7 10:24:04 2015

Undo Segment 43 Onlined

Wed Jan  7 10:24:04 2015

Undo Segment 44 Onlined

Wed Jan  7 10:24:05 2015

Undo Segment 45 Onlined

Wed Jan  7 10:24:05 2015

Undo Segment 46 Onlined

Wed Jan  7 10:24:05 2015

Undo Segment 47 Onlined

 

Wed Jan  7 10:34:26 2015

ARC1: Evaluating archive   log 1 thread 1 sequence 84008

ARC1: Beginning to archive log 1 thread 1 sequence 84008

Creating archive destination LOG_ARCHIVE_DEST_1: '/oradata/admin/orcl/archive/orcl_84008_1.arc'

Wed Jan  7 10:35:01 2015

Errors in file /oradata/admin/orcl/udump/orcl_ora_1577162.trc:

ORA-00600: internal error code, arguments: [6122], [0], [1], [0], [], [], [], []

Wed Jan  7 10:35:04 2015

Recovery of Online Redo Log: Thread 1 Group 2 Seq 84009 Reading mem 0

  Mem# 0 errs 0: /oradata/orcl/redo02.log

Wed Jan  7 10:35:11 2015

ARC1: Completed archiving  log 1 thread 1 sequence 84008

Wed Jan  7 10:35:51 2015

Thread 1 advanced to log sequence 84010

  Current log# 3 seq# 84010 mem# 0: /oradata/orcl/redo03.log

Wed Jan  7 10:35:51 2015

ARC0: Evaluating archive   log 2 thread 1 sequence 84009

ARC0: Beginning to archive log 2 thread 1 sequence 84009

Creating archive destination LOG_ARCHIVE_DEST_1: '/oradata/admin/orcl/archive/orcl_84009_1.arc'

Wed Jan  7 10:36:20 2015

ARC0: Completed archiving  log 2 thread 1 sequence 84009

Wed Jan  7 10:36:46 2015

Errors in file /oradata/admin/orcl/udump/orcl_ora_1577162.trc:

ORA-00600: internal error code, arguments: [6122], [0], [1], [0], [], [], [], []

 

 

分析與處理：

客戶早上取消了匯入操作，資料庫需要回滾，10點鐘客戶使用shutdown abort方式關閉了資料庫，隨後啟動資料庫，10點07分開始大事務回滾，告警日誌資訊表明45號回滾段出現問題，SMON不斷嘗試恢復該回滾段，同時不斷產生trace佔用空間；這個恢復嘗試佔用了大量的cpu資源。

詢問使用者當時的情況是，資料庫執行及其緩慢，使用者請求得不到響應，就強行關閉了資料庫。在此提醒大家，使用abort方式關閉資料庫是具有相當風險的，具體執行時應該相當謹慎。

進一步檢查資料庫的當前狀態，查詢檢視，發現資料庫當前存在大量等待：

select sid,event from v$session_wait where event not like 'SQL%';

其中存在大量佇列競爭，我們進而檢查檢視v$lock；

SQL> select * from v$lock where type<>'MR';

從以上輸出中注意到，大量session的請求都被阻塞，而阻塞這些session的程式正是smon程式（sid=5）

 

最終解決方法

調整引數

設定fast_start_parallel_rollback引數為false，關閉資料庫的並行恢復功能，重啟資料庫，資料庫正常，故障消失。

ALTER SYSTEM SET fast_start_parallel_rollback='FALSE' SCOPE=BOTH;

客戶反映，磁碟io等待從100%迅速下降，系統響應恢復正常，可以了。

 

 

FAST_START_PARALLEL_ROLLBACK

Parameter type	String
Syntax	FAST_START_PARALLEL_ROLLBACK = {HI | LO | FALSE}
Default value	LOW
Parameter class	Dynamic: ALTER SYSTEM

Values:

• FALSE indicates that parallel rollback is disabled
• LOW limits the number of rollback processes to 2 * CPU_COUNT
• HIGH limits the number of rollback processes to 4 * CPU_COUNT

 

透過這三種情況下的每秒鐘回滾undo資料塊數量比較可以知道在LOW狀態下最快，HIGH狀態下次之，FALSE最慢。其實這個實驗沒有任何實際說明力，只是想說明幾個問題：
1)Oracle大事物回滾，是沒有辦法取消，但是可以透過FAST_START_PARALLEL_ROLLBACK干預回滾速度
2)資料庫的併發效率高於低，取決於系統的資源情況(如果你係統的cpu非常強大，那麼可能設定HIGH速度最快)
3)回滾的資料型別，在回滾表中資料時可能設定併發比FALSE快，
但是如果是要回滾序列資料(如:index),那麼可能序列方法方式速度更快
4)根據你的系統的使用狀況，比如你想讓系統的業務受到的影響最小，那麼設定FALSE可能是個不錯的選擇。

 

 

遺留問題

密切監控

ORA-00600: 內部錯誤程式碼，引數: [6122]   索引損壞  需要重建或者刪除後再建立

 

 

參考檔案

http://blog.itpub.net/7199859/viewspace-608944/

 

http://blog.itpub.net/26634508/viewspace-735208/