您好,登錄后才能下訂單哦!
Informix 11.5數據庫,雙機hdr熱備。這是背景。
這兩天出了個事情:由于一個大事務引起了邏輯日志耗盡,導致數據庫狀態進入出現了叫做“長事務阻塞Blocked:LONGTX”的狀態中,停止服務。本文分析其原理與解決辦法。
當事務開始時,數據會在在所在的邏輯日志文件中記錄一個檢查點Check Point,事務運行時,這個檢查點及之后的邏輯日志都處于未提交狀態,要被保留一直到事務提交或是回滾,這些邏輯日志才能標志為使用過,并能再次被循環利用。
如果事務中的操作很多,事務就會跨多個邏輯日志文件。當事務使用的邏輯日志文件超過一定量后,就判斷為“長事務”。因為事務回滾也是需要使用邏輯日志的,所以,當數據庫發現長事務使用的邏輯日志數目到達“回滾折返點”時,這就意味著如果繼續執行事務,剩下的事務可能不足以保證此長事務回滾,數據庫就會中斷事務執行,并立即回滾。
但因為回滾過程也是需要使用邏輯日志的,在回滾中一但出現邏輯日志不夠用的情況,回滾操作用完了剩余的邏輯日志文件,卻還沒有回滾完成,數據庫就會發生“長事務阻塞”。這種情況會出現在一個長事務回退時,另一個事務又快速消耗剩余日志等情況下。
注意這里的邏輯日志不夠用指得不是有沒有ontape –c備份過,而是指因為事務的起始檢查點在第N個邏輯日志文件里,而現在已經執行到了第N-1個邏輯日志文件里(informix的邏輯文件是循環的,執行到N-1號就意味著追了尾了),也就是所有的邏輯日志文件都處于未提交狀態,但是當前事務還是不夠用,這種情況下,就算所有的日志文件都已經被ontape –c備份過了,也不能被再次利用,因為事務的回滾或是提交還沒有完成。
請參考 http://www.ibm.com/developerworks/cn/data/library/techarticles/dm-1001haodh/index.html
在這時候,如果你檢查數據庫的狀態,會是如下的樣子:
infodb% onstat - IBM Informix Dynamic Server Version 11.50.FC6 -- On-Line (Prim LONGTX) -- Up 35 days 16:41:40 -- 3920896 Kbytes Blocked:LONGTX
可以執行onstat –x來檢查事務情況
infodb% onstat -x IBM Informix Dynamic Server Version 9.40.FC7 -- On-Line (LONGTX) -- Up 35 days 16:41:56 -- 3920896 Kbytes Blocked:LONGTX Transactions address flags userthread locks beginlg curlog logposit isol retrys coord 1c8b2b298 A---- 1c8ae9850 0 0 0 0x0 COMMIT 0 1c8b2b508 A---- 1c8aea078 0 0 0 0x0 COMMIT 0 1cd4d7918 A-B-- 1d44fdcb0 2 119408 119507 0x39722c DIRTY 0 1cd4d8068 A---- 1cd576e38 1 0 0 0x0 COMMIT 0 1cd4d82d8 A---- 1cd577660 1 0 0 0x0 DIRTY 0
注意其中的flags為 “A-B—“ 的事務,B狀態表示begined, 說明這個事務還在執行中。注意他的beginlg也就是開始時的邏輯日志文件號為119408,而當前的日志已經到了119507, 兩者相差減加1就是100,正是這個informix系統里所設置的日志數量(您的系統可能不同),這說明這個事務把所有的邏輯日志文件全部用完了。
如果執行onstat –l檢查邏輯日志文件的使用情況,會看到下面的情況:
2a273c368 27 U-B---- 119506 7:250053 12500 12500 100.00 2a273c3d0 28 U---C-- 119507 7:262553 12500 0 18.50 2a273c438 29 U-B---L 119408 7:275053 12500 2313 100.00 2a273c4a0 30 U-B---- 119409 7:287553 12500 12500 100.00 2a273c508 31 U-B---- 119410 7:300053 12500 12500 100.00
所有的日志已經備份過了,但是由于L標示在119408,說明有事務從這里開始,現在還沒有提交或是回退,而當前已經到了119507,所有的邏輯文件用了一圈,已經沒有日志可以用了,但當時工作還沒有做完。
查看log文件(是指那個文本文件),會看到如下的內容:
17:59:34 Aborting Long Transaction: tx: 0x1cd4d7918 username: informix uid: 300 17:59:35 Long Transaction 0x1cd4d7918 Aborted. Rollback Duration: 0 Seconds … 這里是一大段檢查點與邏輯日志用完和備份的信息,直到…… 18:03:22 ALERT: The oldest logical log (119408) contains records from an open transaction (0x1cd4d7918). Logical logging will remain blocked until a log file is added. Add the log file with the onparams -a command, using the -i (insert) option, as in: onparams -a -d <dbspace> -s <size> -i Then complete the transaction as soon as possible.
這里的意思是說,最老的那個邏輯日志文件包括了一個開放著的事務,邏輯日志會阻塞,直到增加一個新的邏輯日志文件。要增加邏輯日志文件,可以用onparams –a,并使用-i選項,就像下面的命令,這樣就能盡快結束這個事務了。
onparams –a –d <dbspace> -s <size> -i
這個命令的意思是:用dbspace的空間來增加一個邏輯日志文件,大小為size, 并插入在當前日志的后面。
用onstat –d 看一看你的數據里還沒有4k塊(因為邏輯日志只能用4k塊的chunk)的dbspace可以用,比如我的:
$ onstat -d Dbspaces address number flags fchunk nchunks pgsize flags owner name 2a0e75028 1 0x40001 1 1 4096 N B informix rootdbs 2a273fdc0 2 0x42001 2 1 8192 N TB informix tempdbs01 2a2740028 3 0x42001 3 1 8192 N TB informix tempdbs02 2a27401c0 4 0x42001 4 1 8192 N TB informix tempdbs03 2a2740358 5 0x42001 5 1 8192 N TB informix tempdbs04 2a27404f0 6 0x40001 6 1 4096 N B informix plogdbs 2a2740688 7 0x40001 7 2 4096 N B informix llogdbs 2a2740820 9 0x40001 19 70 8192 N B informix datadbs 8 active, 2047 maximum Chunks address chunk/dbs offset size free bpages flags pathname 2a0e751c0 1 1 0 500000 479443 PO-B- /informix.links/bej/rootchk 2a27409b8 2 2 0 512000 511947 PO-B- /informix.links/bej/tempchk01 2a2740ba8 3 3 0 512000 511947 PO-B- /informix.links/bej/tempchk02 2a2740d98 4 4 0 512000 511947 PO-B- /informix.links/bej/tempchk03 2a274b028 5 5 0 512000 511947 PO-B- /informix.links/bej/tempchk04 2a274b218 6 6 0 512000 266947 PO-B- /informix.links/bej/plogchk 2a274b408 7 7 0 2048000 172947 PO-B- /informix.links/bej/llogchk1 2a274b5f8 8 7 0 2048000 2047997 PO-B- /informix.links/bej/llogchk2 2a274b7e8 9 9 0 1024000 1023997 PO-B- /informix.links/bej/indxchk01 2a274b9d8 10 9 0 1024000 1023997 PO-B- /informix.links/bej/indxchk02
注意第一個表里,4k的有rootdbs和llogdbs, llogdbs我在安裝時專用劃分了用于邏輯日志的dbspace。注意第二個列表里,對應的llogdbs有兩個chunck,而第一個chunk llogchk1里還有free 172947塊,第二個llogchk2里則一點也沒用過呢,整整8G.
如果你事先沒有留一些空間,那就只好從其他4k塊的dbspace里找一些空間來用,如rootdbs, 如果沒有,那就只好再增加新的chunk。這不在本文范圍內。
現在,要根據數據庫的提示,為之增加邏輯日志文件,如下命令:
Onparams –a –d llogdbs –s 500000 –i
上面的容量單位是KB, 500000就是500M。我本來的邏輯日志是50M,但這次為了能足夠空間用于回滾事務,就直接建立了500M的一個日志文件。
如果正常,數據庫就會有了新的邏輯日志用于繼續執行事務回滾,如果還不夠,就只好再加。不過最好一次加足。
等一會兒事務回滾成功,長事務阻塞狀態就解除了,原來的那個檢查點被回退,所有的邏輯日志恢復到可回收利用的狀態,恭喜你!
已經增加的邏輯日志太大了,如果不愿意保留,可以通過下列的命令刪除之
onmode –l #強制跳過當前日志文件,進入下一個日志文件。 onmode –l #強制跳過當前日志文件,進入下一個日志文件。這里多跳一個,保險一點。 onmode –c # 做一個檢查點,阻塞或是解阻塞數據庫服務器. onparams -d -l <邏輯日志文件編號> –y
邏輯日志文件編號可以用onstat –l來看,找到你剛剛加上的那個,第2列就是它的編號。
這樣就全完事兒了。建議立即做0級備份數據庫。
但是,昨天的實際情況是筆者沒有那么幸運,在執行完增加邏輯日志文件操作之后,數據庫立即down了,再起就起不來了,日志里顯示
19:34:32 Assert Failed: Unexpected virtual processor termination, pid = 213056, exit = 0x90009 19:34:32 IBM Informix Dynamic Server Version 11.50.FC6 19:34:32 Who: Session(5450877, life2@WIN-3XZYO8F2ZGA.lifebj.int, 3124, 7000002b0b548d0) Thread(5691992, sqlexec, 7000002a1335bb8, 1) File: mt.c Line: 14124 19:34:32 stack trace for pid 164620 written to /informix.dump/af.de4055c8 19:34:32 See Also: /informix.dump/af.de4055c8 19:34:36 mt.c, line 14124, thread 5691992, proc id 164620, Unexpected virtual processor termination, pid = 213056, exit = 0x90009 . 19:34:38 The Master Daemon Died 19:34:38 PANIC: Attempting to bring system down 19:34:38 semctl: errno = 22 19:34:38 semctl: errno = 22 -------------------------------以上是增加邏輯日志文件后的系統報錯,以下是重啟的日志--------------------------- 19:58:59 Log file 1 added to DBspace 7. 19:58:59 Logical Log 59579 - Backup Completed 19:58:59 Assert Failed: Dynamic Server must abort 19:58:59 IBM Informix Dynamic Server Version 11.50.FC6 19:58:59 Who: Session(23, informix@bejlif, 0, 2a133e5b8) Thread(60, fast_rec, 2a1308878, 5) File: rslog.c Line: 3629 19:58:59 Results: Dynamic Server must abort 19:58:59 Action: Reinitialize shared memory 19:58:59 stack trace for pid 176584 written to /informix.dump/af.4245b83 19:58:59 See Also: /informix.dump/af.4245b83 19:59:02 rslog.c, line 3629, thread 60, proc id 176584, Dynamic Server must abort. 19:59:03 Fatal error in ADM VP at mt.c:13851 19:59:03 Unexpected virtual processor termination, pid = 176584, exit = 0x100 19:59:03 PANIC: Attempting to bring system down
可以看到logfile的增加沒成功,在重啟后數據庫又在試著執行上次當機時未完成的操作,但還是出錯了。我也不知道為什么,估計這是informix軟件的BUG之類的。這樣一來,主機基本就算完蛋了,反正我的能力是沒辦法了。
但技術解決不了的問題,由運維手段解決。我們的數據庫是hdr主備機的。接下來我就在備機上看onstat –x,那個長事務也鎖在那里,但新增的logfile沒有同步過來。于是我只好把備機從”從機只讀”切為獨立模式。
強烈建議在做這個之前,從備機里把數據能備份的備份出來,只讀的數據庫是可以取出數據來的,一但進入獨立主用模式,未完成的長事務也會繼續執行,也會進行長事務阻塞,你就不能連接數據庫了。做為一個悲催的IT人,這是你最后的生命線。
onmode –d standard
備機也立即進入了長事務阻塞模式。這是必然的,備機需要繼續回滾這個事務。
然后執行相同的增加邏輯日志文件操作。
onparams –a –d llogdbs –s 500000 –i
這次成功了!備機很快回滾了事務,回到Online狀態。繼續執行前面說的:
onmode –l #強制跳過當前日志文件,進入下一個日志文件。 onmode –l #強制跳過當前日志文件,進入下一個日志文件。這里多跳一個,保險一點。 onmode –c # 做一個檢查點,阻塞或是解阻塞數據庫服務器. onparams -d -l <邏輯日志文件編號> –y
檢查備機數據,確認數據是最新的,業務數據到了阻塞時間點之前,這說明你沒有損失數據。
接下來要做的,是從備機上做一個0級的備份到磁帶上去。
Ontape –s –L 0
把磁帶放到主機上,執行恢復。
Ontape –r
完事后做onmode –m進入online模式。檢查數據。
主機恢復成功后,同一盤磁帶放回備機上,執行物理恢復:
Ontape –p
完成就可以做主備機hdr同步了:
主機上:
onmode -d primary <備機實例名>
備機上:
onmode -d secondary <主機實例名>
上述的備份、恢復與重建hdr過程我就不說了,請按自家手冊進行。
上述過程失敗了,而且您還沒有沒有備機?那你有過去的定期備份磁帶吧,有的話就按您家的手冊恢復。上次備份到現在更新的數據您就再想辦法吧。
還沒有備份磁帶?您干什么吃的呀!
不過,聽說IBM自己有辦法,把損壞的邏輯日志刪除或是修好,然后機器就又跑起來了。因為數據其實都在數據庫里。
不過IBM的informix的服務好貴,而且……已經停止對這個產品的服務了。
免責聲明:本站發布的內容(圖片、視頻和文字)以原創、轉載和分享為主,文章觀點不代表本網站立場,如果涉及侵權請聯系站長郵箱:is@yisu.com進行舉報,并提供相關證據,一經查實,將立刻刪除涉嫌侵權內容。