Informix 11.5數(shù)據(jù)庫(kù)，雙機(jī)hdr熱備。這是背景。
我們提供的服務(wù)有：成都做網(wǎng)站、成都網(wǎng)站建設(shè)、成都外貿(mào)網(wǎng)站建設(shè)、微信公眾號(hào)開(kāi)發(fā)、網(wǎng)站優(yōu)化、網(wǎng)站認(rèn)證、平樂(lè)ssl等。為上1000家企事業(yè)單位解決了網(wǎng)站和推廣的問(wèn)題。提供周到的售前咨詢和貼心的售后服務(wù)，是有科學(xué)管理、有技術(shù)的平樂(lè)網(wǎng)站制作公司
這兩天出了個(gè)事情：由于一個(gè)大事務(wù)引起了邏輯日志耗盡，導(dǎo)致數(shù)據(jù)庫(kù)狀態(tài)進(jìn)入出現(xiàn)了叫做“長(zhǎng)事務(wù)阻塞Blocked:LONGTX”的狀態(tài)中，停止服務(wù)。本文分析其原理與解決辦法。
當(dāng)事務(wù)開(kāi)始時(shí)，數(shù)據(jù)會(huì)在在所在的邏輯日志文件中記錄一個(gè)檢查點(diǎn)Check Point，事務(wù)運(yùn)行時(shí)，這個(gè)檢查點(diǎn)及之后的邏輯日志都處于未提交狀態(tài)，要被保留一直到事務(wù)提交或是回滾，這些邏輯日志才能標(biāo)志為使用過(guò)，并能再次被循環(huán)利用。
如果事務(wù)中的操作很多，事務(wù)就會(huì)跨多個(gè)邏輯日志文件。當(dāng)事務(wù)使用的邏輯日志文件超過(guò)一定量后，就判斷為“長(zhǎng)事務(wù)”。因?yàn)槭聞?wù)回滾也是需要使用邏輯日志的，所以，當(dāng)數(shù)據(jù)庫(kù)發(fā)現(xiàn)長(zhǎng)事務(wù)使用的邏輯日志數(shù)目到達(dá)“回滾折返點(diǎn)”時(shí)，這就意味著如果繼續(xù)執(zhí)行事務(wù)，剩下的事務(wù)可能不足以保證此長(zhǎng)事務(wù)回滾，數(shù)據(jù)庫(kù)就會(huì)中斷事務(wù)執(zhí)行，并立即回滾。
但因?yàn)榛貪L過(guò)程也是需要使用邏輯日志的，在回滾中一但出現(xiàn)邏輯日志不夠用的情況，回滾操作用完了剩余的邏輯日志文件，卻還沒(méi)有回滾完成，數(shù)據(jù)庫(kù)就會(huì)發(fā)生“長(zhǎng)事務(wù)阻塞”。這種情況會(huì)出現(xiàn)在一個(gè)長(zhǎng)事務(wù)回退時(shí)，另一個(gè)事務(wù)又快速消耗剩余日志等情況下。
注意這里的邏輯日志不夠用指得不是有沒(méi)有ontape –c備份過(guò)，而是指因?yàn)槭聞?wù)的起始檢查點(diǎn)在第N個(gè)邏輯日志文件里，而現(xiàn)在已經(jīng)執(zhí)行到了第N-1個(gè)邏輯日志文件里（informix的邏輯文件是循環(huán)的，執(zhí)行到N-1號(hào)就意味著追了尾了），也就是所有的邏輯日志文件都處于未提交狀態(tài)，但是當(dāng)前事務(wù)還是不夠用，這種情況下，就算所有的日志文件都已經(jīng)被ontape –c備份過(guò)了，也不能被再次利用，因?yàn)槭聞?wù)的回滾或是提交還沒(méi)有完成。
請(qǐng)參考 http://www.ibm.com/developerworks/cn/data/library/techarticles/dm-1001haodh/index.html
在這時(shí)候，如果你檢查數(shù)據(jù)庫(kù)的狀態(tài)，會(huì)是如下的樣子：
infodb% onstat - IBM Informix Dynamic Server Version11.50.FC6 -- On-Line (Prim LONGTX) -- Up 35 days 16:41:40 -- 3920896 Kbytes Blocked:LONGTX
可以執(zhí)行onstat –x來(lái)檢查事務(wù)情況
infodb% onstat -x IBM Informix Dynamic Server Version9.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—“ 的事務(wù)，B狀態(tài)表示begined, 說(shuō)明這個(gè)事務(wù)還在執(zhí)行中。注意他的beginlg也就是開(kāi)始時(shí)的邏輯日志文件號(hào)為119408，而當(dāng)前的日志已經(jīng)到了119507, 兩者相差減加1就是100，正是這個(gè)informix系統(tǒng)里所設(shè)置的日志數(shù)量（您的系統(tǒng)可能不同），這說(shuō)明這個(gè)事務(wù)把所有的邏輯日志文件全部用完了。
如果執(zhí)行onstat –l檢查邏輯日志文件的使用情況，會(huì)看到下面的情況：
2a273c368 27 U-B---- 119506 7:250053 12500 12500 100.00 2a273c3d028 U---C-- 119507 7:262553 12500 0 18.50 2a273c43829 U-B---L 119408 7:275053 12500 2313 100.00 2a273c4a030 U-B---- 119409 7:287553 12500 12500 100.00 2a273c50831 U-B---- 119410 7:300053 12500 12500 100.00
所有的日志已經(jīng)備份過(guò)了，但是由于L標(biāo)示在119408，說(shuō)明有事務(wù)從這里開(kāi)始，現(xiàn)在還沒(méi)有提交或是回退，而當(dāng)前已經(jīng)到了119507，所有的邏輯文件用了一圈，已經(jīng)沒(méi)有日志可以用了，但當(dāng)時(shí)工作還沒(méi)有做完。
查看log文件（是指那個(gè)文本文件），會(huì)看到如下的內(nèi)容：
重慶分公司
重慶分公司
17:59:34 Aborting Long Transaction: tx: 0x1cd4d7918 username: informix uid: 300 17:59:35 Long Transaction 0x1cd4d7918 Aborted. Rollback Duration: 0 Seconds
… 這里是一大段檢查點(diǎn)與邏輯日志用完和備份的信息，直到……18:03:22 ALERT: The oldest logical log (119408) contains records from anopen transaction (0x1cd4d7918). Logical logging will
remain blocked until alog file is added. Add thelog file with the onparams -a command, using the -i
(insert) option, as in:
onparams-a -d -s -iThen complete the transaction as soon as possible.
這里的意思是說(shuō)，最老的那個(gè)邏輯日志文件包括了一個(gè)開(kāi)放著的事務(wù)，邏輯日志會(huì)阻塞，直到增加一個(gè)新的邏輯日志文件。要增加邏輯日志文件，可以用onparams –a，并使用-i選項(xiàng)，就像下面的命令，這樣就能盡快結(jié)束這個(gè)事務(wù)了。
onparams –a –d
這個(gè)命令的意思是：用dbspace的空間來(lái)增加一個(gè)邏輯日志文件，大小為size, 并插入在當(dāng)前日志的后面。
用onstat –d 看一看你的數(shù)據(jù)里還沒(méi)有4k塊(因?yàn)檫壿嬋罩局荒苡?k塊的chunk)的dbspace可以用，比如我的：
$ onstat -d Dbspaces addressnumber flags fchunk nchunks pgsize flags owner name 2a0e750281 0x40001 1 1 4096 N B informix rootdbs 2a273fdc02 0x42001 2 1 8192 N TB informix tempdbs01 2a27400283 0x42001 3 1 8192 N TB informix tempdbs02 2a27401c04 0x42001 4 1 8192 N TB informix tempdbs03 2a27403585 0x42001 5 1 8192 N TB informix tempdbs04 2a27404f06 0x40001 6 1 4096 N B informix plogdbs 2a27406887 0x40001 7 2 4096 N B informix llogdbs 2a27408209 0x40001 19 70 8192 N B informix datadbs8 active, 2047 maximum Chunks address chunk/dbs offset size free bpages flags pathname 2a0e751c01 1 0 500000 479443 PO-B- /informix.links/bej/rootchk 2a27409b82 2 0 512000 511947 PO-B- /informix.links/bej/tempchk01 2a2740ba83 3 0 512000 511947 PO-B- /informix.links/bej/tempchk02 2a2740d984 4 0 512000 511947 PO-B- /informix.links/bej/tempchk03 2a274b0285 5 0 512000 511947 PO-B- /informix.links/bej/tempchk04 2a274b2186 6 0 512000 266947 PO-B- /informix.links/bej/plogchk 2a274b4087 7 0 2048000 172947 PO-B- /informix.links/bej/llogchk1 2a274b5f88 7 0 2048000 2047997 PO-B- /informix.links/bej/llogchk2 2a274b7e89 9 0 1024000 1023997 PO-B- /informix.links/bej/indxchk01 2a274b9d810 9 0 1024000 1023997 PO-B- /informix.links/bej/indxchk02
注意第一個(gè)表里，4k的有rootdbs和llogdbs, llogdbs我在安裝時(shí)專用劃分了用于邏輯日志的dbspace。注意第二個(gè)列表里，對(duì)應(yīng)的llogdbs有兩個(gè)chunck，而第一個(gè)chunk llogchk1里還有free 172947塊，第二個(gè)llogchk2里則一點(diǎn)也沒(méi)用過(guò)呢，整整8G.
如果你事先沒(méi)有留一些空間，那就只好從其他4k塊的dbspace里找一些空間來(lái)用，如rootdbs, 如果沒(méi)有，那就只好再增加新的chunk。這不在本文范圍內(nèi)。
現(xiàn)在，要根據(jù)數(shù)據(jù)庫(kù)的提示，為之增加邏輯日志文件，如下命令：
Onparams –a –d llogdbs –s 500000 –i
上面的容量單位是KB, 500000就是500M。我本來(lái)的邏輯日志是50M，但這次為了能足夠空間用于回滾事務(wù)，就直接建立了500M的一個(gè)日志文件。
如果正常，數(shù)據(jù)庫(kù)就會(huì)有了新的邏輯日志用于繼續(xù)執(zhí)行事務(wù)回滾，如果還不夠，就只好再加。不過(guò)最好一次加足。
等一會(huì)兒事務(wù)回滾成功，長(zhǎng)事務(wù)阻塞狀態(tài)就解除了，原來(lái)的那個(gè)檢查點(diǎn)被回退，所有的邏輯日志恢復(fù)到可回收利用的狀態(tài)，恭喜你！
已經(jīng)增加的邏輯日志太大了，如果不愿意保留，可以通過(guò)下列的命令刪除之
onmode –l #強(qiáng)制跳過(guò)當(dāng)前日志文件，進(jìn)入下一個(gè)日志文件。 onmode –l #強(qiáng)制跳過(guò)當(dāng)前日志文件，進(jìn)入下一個(gè)日志文件。這里多跳一個(gè)，保險(xiǎn)一點(diǎn)。 onmode –c # 做一個(gè)檢查點(diǎn)，阻塞或是解阻塞數(shù)據(jù)庫(kù)服務(wù)器. onparams-d -l <邏輯日志文件編號(hào)> –y
邏輯日志文件編號(hào)可以用onstat –l來(lái)看，找到你剛剛加上的那個(gè)，第2列就是它的編號(hào)。
這樣就全完事兒了。建議立即做0級(jí)備份數(shù)據(jù)庫(kù)。
但是，昨天的實(shí)際情況是筆者沒(méi)有那么幸運(yùn)，在執(zhí)行完增加邏輯日志文件操作之后，數(shù)據(jù)庫(kù)立即down了，再起就起不來(lái)了，日志里顯示
19:34:32 Assert Failed: Unexpected virtual processor termination, pid = 213056, exit = 0x90009 19:34:32 IBM Informix Dynamic Server Version 11.50.FC619: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.de4055c819:34:32 See Also: /informix.dump/af.de4055c819: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 Died19:34:38 PANIC: Attempting to bring system down19:34:38 semctl: errno = 22 19:34:38 semctl: errno = 22 -------------------------------以上是增加邏輯日志文件后的系統(tǒng)報(bào)錯(cuò)，以下是重啟的日志--------------------------- 19:58:59 Log file 1 added to DBspace 7.19:58:59 Logical Log 59579 - Backup Completed19:58:59 Assert Failed: Dynamic Server must abort19:58:59 IBM Informix Dynamic Server Version 11.50.FC619: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 abort19:58:59 Action: Reinitialize shared memory19:58:59 stack trace for pid 176584 written to /informix.dump/af.4245b8319:58:59 See Also: /informix.dump/af.4245b8319: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的增加沒(méi)成功，在重啟后數(shù)據(jù)庫(kù)又在試著執(zhí)行上次當(dāng)機(jī)時(shí)未完成的操作，但還是出錯(cuò)了。我也不知道為什么，估計(jì)這是informix軟件的BUG之類的。這樣一來(lái)，主機(jī)基本就算完蛋了，反正我的能力是沒(méi)辦法了。
但技術(shù)解決不了的問(wèn)題，由運(yùn)維手段解決。我們的數(shù)據(jù)庫(kù)是hdr主備機(jī)的。接下來(lái)我就在備機(jī)上看onstat –x，那個(gè)長(zhǎng)事務(wù)也鎖在那里，但新增的logfile沒(méi)有同步過(guò)來(lái)。于是我只好把備機(jī)從”從機(jī)只讀”切為獨(dú)立模式。
強(qiáng)烈建議在做這個(gè)之前，從備機(jī)里把數(shù)據(jù)能備份的備份出來(lái)，只讀的數(shù)據(jù)庫(kù)是可以取出數(shù)據(jù)來(lái)的，一但進(jìn)入獨(dú)立主用模式，未完成的長(zhǎng)事務(wù)也會(huì)繼續(xù)執(zhí)行，也會(huì)進(jìn)行長(zhǎng)事務(wù)阻塞，你就不能連接數(shù)據(jù)庫(kù)了。做為一個(gè)悲催的IT人，這是你最后的生命線。
onmode –d standard
備機(jī)也立即進(jìn)入了長(zhǎng)事務(wù)阻塞模式。這是必然的，備機(jī)需要繼續(xù)回滾這個(gè)事務(wù)。
然后執(zhí)行相同的增加邏輯日志文件操作。
onparams –a –d llogdbs –s 500000 –i
這次成功了！備機(jī)很快回滾了事務(wù)，回到Online狀態(tài)。繼續(xù)執(zhí)行前面說(shuō)的：
onmode –l #強(qiáng)制跳過(guò)當(dāng)前日志文件，進(jìn)入下一個(gè)日志文件。 onmode –l #強(qiáng)制跳過(guò)當(dāng)前日志文件，進(jìn)入下一個(gè)日志文件。這里多跳一個(gè)，保險(xiǎn)一點(diǎn)。 onmode –c # 做一個(gè)檢查點(diǎn)，阻塞或是解阻塞數(shù)據(jù)庫(kù)服務(wù)器. onparams-d -l <邏輯日志文件編號(hào)> –y
檢查備機(jī)數(shù)據(jù)，確認(rèn)數(shù)據(jù)是最新的，業(yè)務(wù)數(shù)據(jù)到了阻塞時(shí)間點(diǎn)之前，這說(shuō)明你沒(méi)有損失數(shù)據(jù)。
接下來(lái)要做的，是從備機(jī)上做一個(gè)0級(jí)的備份到磁帶上去。
Ontape –s –L 0
把磁帶放到主機(jī)上，執(zhí)行恢復(fù)。
Ontape –r
完事后做onmode –m進(jìn)入online模式。檢查數(shù)據(jù)。
主機(jī)恢復(fù)成功后，同一盤磁帶放回備機(jī)上，執(zhí)行物理恢復(fù)：
Ontape –p
完成就可以做主備機(jī)hdr同步了：
主機(jī)上：
onmode -d primary <備機(jī)實(shí)例名>
備機(jī)上：
onmode -d secondary <主機(jī)實(shí)例名>
上述的備份、恢復(fù)與重建hdr過(guò)程我就不說(shuō)了，請(qǐng)按自家手冊(cè)進(jìn)行。
上述過(guò)程失敗了，而且您還沒(méi)有沒(méi)有備機(jī)？那你有過(guò)去的定期備份磁帶吧，有的話就按您家的手冊(cè)恢復(fù)。上次備份到現(xiàn)在更新的數(shù)據(jù)您就再想辦法吧。
還沒(méi)有備份磁帶？您干什么吃的呀！
不過(guò)，聽(tīng)說(shuō)IBM自己有辦法，把損壞的邏輯日志刪除或是修好，然后機(jī)器就又跑起來(lái)了。因?yàn)閿?shù)據(jù)其實(shí)都在數(shù)據(jù)庫(kù)里。
不過(guò)IBM的informix的服務(wù)好貴，而且……已經(jīng)停止對(duì)這個(gè)產(chǎn)品的服務(wù)了。
