haoxiaobo

从C到C++又到.net, 有一些心得, 和大家交流下...
  博客园  :: 首页  :: 新随笔  :: 联系 :: 订阅 订阅  :: 管理

Informix 11.5数据库,双机hdr热备。这是背景。

这两天出了个事情:由于一个大事务引起了逻辑日志耗尽,导致数据库状态进入出现了叫做“长事务阻塞Blocked:LONGTX”的状态中,停止服务。本文分析其原理与解决办法。

1   长事务阻塞的原理

当事务开始时,数据会在在所在的逻辑日志文件中记录一个检查点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

2   现象与检查

在这时候,如果你检查数据库的状态,会是如下的样子:

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, 并插入在当前日志的后面。

3   如果正常处理的话……

用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级备份数据库。

4   但是有时运气不好,如果你还有备机……

但是,昨天的实际情况是笔者没有那么幸运,在执行完增加逻辑日志文件操作之后,数据库立即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过程我就不说了,请按自家手册进行。

5   最坏的坏果

上述过程失败了,而且您还没有没有备机?那你有过去的定期备份磁带吧,有的话就按您家的手册恢复。上次备份到现在更新的数据您就再想办法吧。

还没有备份磁带?您干什么吃的呀!

不过,听说IBM自己有办法,把损坏的逻辑日志删除或是修好,然后机器就又跑起来了。因为数据其实都在数据库里。

不过IBM的informix的服务好贵,而且……已经停止对这个产品的服务了。