自拍偷在线精品自拍偷,亚洲欧美中文日韩v在线观看不卡

為什么更換存儲(chǔ)之后一切正常但RAC集群啟動(dòng)不了？

作者：墨墨
存儲(chǔ) 存儲(chǔ)軟件
這是一次來自生產(chǎn)實(shí)踐的真實(shí)案例，某客戶核心生產(chǎn)庫由于進(jìn)行新老存儲(chǔ)替換變更操作后，Oracle RAC 兩個(gè)節(jié)點(diǎn)均無法打開，數(shù)據(jù)庫遭遇嚴(yán)重故障。

這是一次來自生產(chǎn)實(shí)踐的真實(shí)案例，某客戶核心生產(chǎn)庫由于進(jìn)行新老存儲(chǔ)替換變更操作后，Oracle RAC 兩個(gè)節(jié)點(diǎn)均無法打開，數(shù)據(jù)庫遭遇嚴(yán)重故障。

先來看看告警日志中記錄的錯(cuò)誤信息，我們注意到數(shù)據(jù)庫能夠正常Mount，但是在Open階段遇到錯(cuò)誤，提示某個(gè)數(shù)據(jù)文件不能被鎖定：

  1. ALTER DATABASE MOUNT  
  2. This instance was first to mount 
  3. Fri Dec 16 03:20:34 2016 
  4. Successful mount of redo thread 2, with mount id 3052566649 
  5. Fri Dec 16 03:20:40 2016 
  6. Database mounted in Shared Mode (CLUSTER_DATABASE=TRUE) 
  7. Lost write protection disabled 
  8. Completed: ALTER DATABASE MOUNT  
  9. ALTER DATABASE OPEN  
  10. This instance was first to open 
  11. Fri Dec 16 03:00:53 2016 
  12. Errors in file /diag/ojtdb/ojtdb2/trace/ojtdb2_ora_1569.trc: 
  13. ORA-01157: cannot identify/lock data file 1311 - see DBWR trace file 
  14. ORA-01110: data file 1311: '/dev/vx/rdsk/ora_ojt10/ora_dev1311' 
  15. ORA-1157 signalled during: ALTER DATABASE OPEN 

通常遇到這個(gè)錯(cuò)誤，最常見的原因是存儲(chǔ)未正常掛載，或者數(shù)據(jù)文件損壞丟失。

[[234038]]

通過dd檢測(cè)發(fā)現(xiàn)I/O讀正常，dbv檢測(cè)數(shù)據(jù)文件也正常，這說明存儲(chǔ)和數(shù)據(jù)文件的基本表現(xiàn)都屬正常，而且不存在權(quán)限問題：

  1. oracle$  time dd if=/dev/vx/rdsk/ora_ojt10/ora_dev1311 of=/dev/null bs=1024k count=1000 
  2. 1000+0 records in 
  3. 1000+0 records out 
  4.  
  5. real    0m1.654s 
  6. user    0m0.006s 
  7. sys     0m0.316s 
  8.  
  9. oracle$  dbv file=/dev/vx/rdsk/ora_ojt10/ora_dev1311 blocksize=8192 

那么顯然，這個(gè)問題跳出了傳統(tǒng)的故障原因。

我們?cè)倩仡櫼幌洛e(cuò)誤信息，數(shù)據(jù)庫啟動(dòng)失敗源自DBWR報(bào)錯(cuò)，可以通過進(jìn)程跟蹤來分析進(jìn)程的工作狀態(tài)。

在此我們通過v$session，分析DBW0進(jìn)程當(dāng)前的等待事件，排查dbwr進(jìn)程遲遲不向其他進(jìn)程發(fā)送相關(guān)ipc message的原因：

  1. SQL> select event from v$session where paddr in  
  2. (select addr from v$process where pid=<13>); 
  3. EVENT 
  4. ------------------------ 
  5. Disk file operations I/O 

DBWR 始終在執(zhí)行磁盤 I/O 操作，Disk file operations I/O等待事件的官方解釋如下：

This event is used to wait for disk file operations (for example, open, close, seek, and resize). It is also used for miscellaneous I/O operations such as block dumps and password file accesses.

此事件用于等待磁盤文件操作（例如，打開，關(guān)閉，搜索和調(diào)整大?。?它也用于一些其他I / O操作，例如塊轉(zhuǎn)儲(chǔ)和密碼文件訪問。

這個(gè)等待事件的三個(gè)參數(shù)p1，p2，p3 含義如下：

持續(xù)觀察DBWR該事件的參數(shù)值，發(fā)現(xiàn) p1=2，意思是 file open，在進(jìn)行文件打開操作；p3=2，意思是操作數(shù)據(jù)文件。

而 p2 一直在遞增變化，其含義是文件號(hào)，不斷順序的打開不同的數(shù)據(jù)文件。

說明DBW0正在逐個(gè)檢查并打開數(shù)據(jù)文件，查詢得知該庫數(shù)據(jù)文件有1560個(gè)，在逐個(gè)檢查進(jìn)行到900秒后，后臺(tái)alert日志中出現(xiàn)了如下錯(cuò)誤，這一次出現(xiàn)問題的是另外一個(gè)文件：

  1. ORA-01157: cannot identify/lock data file 1401 - see DBWR trace file 
  2. ORA-01110: data file 1401: '/dev/vx/rdsk/ora_ojt10/ora_dev1401' 
  3. ORA-1157 signalled during: ALTER DATABASE OPEN  

在啟動(dòng)過程中，我們發(fā)現(xiàn)從mount到open階段，報(bào)出 ORA-01157 和 ORA-01110 花費(fèi)的時(shí)間很長，需要十幾分鐘，然后報(bào)錯(cuò)，使得啟動(dòng)過程強(qiáng)制終止；

最終是后臺(tái)dbw進(jìn)程在輸出日志，為了進(jìn)一步分析該過程中具體流程，于是開啟10046事件跟蹤dbw0進(jìn)程：

  1. *** 2016-12-16 12:03:30.798--這里時(shí)間是12點(diǎn)03，開始執(zhí)行open操作 
  2. WAIT #0: nam='SQL*Net message from client' ela= 7344875 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=8068132685065 
  3. XCTEND rlbk=0, rd_only=1, tim=8068132685665 
  4. ===================== 
  5. PARSING IN CURSOR #18446744071440810672 len=19 dep=0 uid=0 oct=35 lid=0 tim=8068132686043 hv=1907384048 ad='176ffabd68' sqlid='a01hp0psv0rrh' 
  6. alter database open 
  7.  
  8. *** 2016-12-16 12:18:49.122 
  9. WAIT #18446744071440810672: nam='rdbms ipc reply' ela= 2010056 from_process=23 timeout=2 p3=0 obj#=-1 tim=8069051099141 
  10. *** 2016-12-16 12:18:51.038--之前都是空閑等待，從這個(gè)時(shí)間點(diǎn)開始，當(dāng)前進(jìn)程等待超時(shí) ，發(fā)送超時(shí)消息給dbw0進(jìn)程。而這個(gè)時(shí)間點(diǎn)18分。 
  11. WAIT #18446744071440810672: nam='ksdxexeotherwait' ela= 1915544 p1=0 p2=0 p3=0 obj#=-1 tim=8069053014980 
  12. WAIT #18446744071440810672: nam='control file sequential read' ela= 818 file#=0 block#=1 blocks=1 obj#=-1 tim=8069053016115 
  13. WAIT #18446744071440810672: nam='control file sequential read' ela= 496 file#=0 block#=39 blocks=1 obj#=-1 tim=8069053016665 
  14. WAIT #18446744071440810672: nam='control file sequential read' ela= 393 file#=0 block#=41 blocks=1 obj#=-1 tim=8069053017100 
  15. WAIT #18446744071440810672: nam='control file sequential read' ela= 8212 file#=0 block#=2300 blocks=1 obj#=-1 tim=8069053025356 
  16. WAIT #18446744071440810672: nam='CSS initialization' ela= 20622 p1=0 p2=0 p3=0 obj#=-1 tim=8069053046642 
  17. WAIT #18446744071440810672: nam='CSS operation: action' ela= 2656 function_id=65 p2=0 p3=0 obj#=-1 tim=8069053049357 

從dbw0進(jìn)程的跟蹤日志來看，發(fā)現(xiàn)進(jìn)程等待超時(shí)，然后發(fā)送超時(shí)消息給dbw0進(jìn)程。從12:03分發(fā)起open操作，到12:18分出現(xiàn)超時(shí)消息，（18-3）*60 s = 900 s，即900秒后，后臺(tái)發(fā)送超時(shí)消息給dbw0進(jìn)程，而這個(gè)時(shí)間點(diǎn)正是后臺(tái)報(bào)錯(cuò)而啟動(dòng)終止的時(shí)間。

這個(gè)信息給出了很好的分析線索，隨即繼續(xù)分析跟蹤文件，詳細(xì)分析每一次I/O的狀態(tài)：

  1. waited for 'Disk file operations I/O', seq_num: 617 
  2.       p1: 'FileOperation'=0x2 
  3.       p2: 'fileno'=0x1a9 
  4.       p3: 'filetype'=0x2 
  5.       time_waited: 0.696732 sec (sample interval: 0 sec) 
  6.   [1 sample,                                                          07:57:37] 
  7.     waited for 'Disk file operations I/O', seq_num: 614 
  8.       p1: 'FileOperation'=0x2 
  9.       p2: 'fileno'=0x1a7 
  10.       p3: 'filetype'=0x2 
  11.       time_waited: 0.699569 sec (sample interval: 0 sec) 
  12.   [1 sample,                                                          07:57:36] 
  13.     waited for 'Disk file operations I/O', seq_num: 613 
  14.       p1: 'FileOperation'=0x2 
  15.       p2: 'fileno'=0x1a6 
  16.       p3: 'filetype'=0x2 
  17.       time_waited: 0.682626 sec (sample interval: 0 sec) 
  18.   [1 sample,                                                          07:57:35] 
  19.     waited for 'Disk file operations I/O', seq_num: 611 
  20.       p1: 'FileOperation'=0x2 
  21.       p2: 'fileno'=0x1a4 
  22.       p3: 'filetype'=0x2 
  23.       time_waited: 0.695486 sec (sample interval: 0 sec) 
  24.   [1 sample,                                                          07:57:34] 
  25.     waited for 'Disk file operations I/O', seq_num: 610 
  26.       p1: 'FileOperation'=0x2 
  27.       p2: 'fileno'=0x1a3 
  28.       p3: 'filetype'=0x2 
  29.       time_waited: 0.700244 sec (sample interval: 0 sec) 
  30.   [1 sample,                                                          07:57:33] 
  31.     waited for 'Disk file operations I/O', seq_num: 608 
  32.       p1: 'FileOperation'=0x2 
  33.       p2: 'fileno'=0x1a1 
  34.       p3: 'filetype'=0x2 
  35.       time_waited: 0.682131 sec (sample interval: 0 sec) 
  36. --------------------------------------------------- 
  37. Sampled Session History Summary: 
  38.   longest_non_idle_wait: 'Disk file operations I/O' 
  39.   [1 sample, 07:57:51 ] 
  40.       time_waited: 0.910736 sec (sample interval: 0 sec) 

注意以上日志，可以發(fā)現(xiàn)平均打開一個(gè)數(shù)據(jù)文件的Disk file operations I/O操作大概需要0.7s左右，該庫共有 1560個(gè) 數(shù)據(jù)文件，照此計(jì)算，打開所有數(shù)據(jù)文件大約需要1092秒，這個(gè)時(shí)間超出了之前得出的從發(fā)起open到報(bào)錯(cuò)終止的900秒的。

那么我們接下來要想辦法，讓數(shù)據(jù)庫在報(bào)錯(cuò)之前等待更久。

怎么辦呢？讓我們思考1秒鐘。。。

數(shù)據(jù)庫中有一個(gè)隱藏參數(shù) _controlfile_enqueue_timeout 默認(rèn)為900s，該參數(shù)的意思是在數(shù)據(jù)庫的 Open 階段，鎖定控制文件讀取相關(guān)的數(shù)據(jù)文件并打開的允許超時(shí)時(shí)間，如果超過了900s閾值則認(rèn)為數(shù)據(jù)庫超時(shí)，會(huì)拋出異常，中斷操作。

在此之前，我們估算了打開所有數(shù)據(jù)文件需要至少1092秒，這里在參數(shù)文件將該參數(shù)修改為9000s后，重新執(zhí)行啟動(dòng)流程，最終成功打開了數(shù)據(jù)庫的第二節(jié)點(diǎn)。

  1. Fri Dec 16 12:52:22 2016 
  2. ALTER SYSTEM SET _controlfile_enqueue_timeout=9000 SCOPE=SPFILE; 
  3. Fri Dec 16 12:52:22 2016 
  4. Shutting down instance (abort) 
  5. License high water mark = 5 
  6. USER (ospid: 18936): terminating the instance 
  7. Instance terminated by USER, pid = 18936 
  8. Fri Dec 16 12:52:30 2016 
  9. Instance shutdown complete 
  10. Fri Dec 16 12:52:34 2016 
  11. Starting ORACLE instance (normal) 
  12. Fri Dec 16 12:52:47 2016 
  13. … 
  14. Fri Dec 16 12:56:39 2016 
  15. Database mounted in Shared Mode (CLUSTER_DATABASE=TRUE) 
  16. Lost write protection disabled 
  17. Completed: ALTER DATABASE   MOUNT 
  18. Fri Dec 16 12:57:19 2016 
  19. alter database open 
  20. Fri Dec 16 13:15:42 2016 
  21. GTX0 started with pid=92, OS id=26326  
  22. replication_dependency_tracking turned off (no async multimaster replication found) 
  23. Starting background process QMNC 
  24. Fri Dec 16 13:15:43 2016 
  25. QMNC started with pid=93, OS id=26332  
  26. Completed: alter database open 

從日志中，也清晰的看到，從12:57發(fā)起 alter database open 到***完成open，耗時(shí)18分鐘后，數(shù)據(jù)庫成功open，數(shù)據(jù)庫恢復(fù)正常。

這個(gè)案例給我們的警示是：

在可能的情況下，任何變更都應(yīng)該進(jìn)行 1：1 真實(shí)測(cè)試，***可能發(fā)現(xiàn)隱患；

事關(guān)存儲(chǔ)的變更，必須做好存儲(chǔ)的讀寫I/O基準(zhǔn)測(cè)試；

這個(gè)案例的后續(xù)是，分析新存儲(chǔ)的I/O性能為何出現(xiàn)衰減，導(dǎo)致啟動(dòng)超時(shí)。這和存儲(chǔ)的規(guī)劃、磁盤劃分、緩存配置等有關(guān)，數(shù)據(jù)庫的案例到此就處理完成了。

責(zé)任編輯：武曉燕 來源： 數(shù)據(jù)和云
存儲(chǔ)RAC集群
相關(guān)推薦

2011-03-18 19:38:05

趨勢(shì)科技業(yè)務(wù)運(yùn)營支持服務(wù)

2017-03-08 14:35:22

存儲(chǔ)云計(jì)算華云網(wǎng)際

2019-11-12 08:48:46

容器KubernetesDevOps

2025-03-12 08:00:26

2019-08-20 09:24:54

Python編程語言Java

2017-09-04 11:03:04

數(shù)據(jù)中心服務(wù)

2010-02-22 14:53:49

Ubuntu ngin

2016-08-31 17:24:05

大數(shù)據(jù)分析

2012-12-31 11:22:58

開源開放

2020-09-11 10:55:10

useState組件前端

2023-11-27 07:53:44

2021-02-28 09:47:54

軟件架構(gòu)軟件開發(fā)軟件設(shè)計(jì)

2012-11-05 15:22:59

康普光纜DCD

2018-11-23 11:17:24

負(fù)載均衡分布式系統(tǒng)架構(gòu)

2021-02-19 23:08:27

軟件測(cè)試軟件開發(fā)

2021-09-01 07:21:39

Exporter指標(biāo)監(jiān)控

2022-08-31 16:29:09

數(shù)字孿生物聯(lián)網(wǎng)

2020-09-11 09:43:18

移動(dòng)網(wǎng)絡(luò)測(cè)試網(wǎng)絡(luò)速度網(wǎng)絡(luò)通信

2025-03-10 13:11:00

點(diǎn)贊
收藏

51CTO技術(shù)棧公眾號(hào)