onbar restore blocked on checkpoint

Hi all. I've tried to find a solution for this on the net, but no luck so far, so I feel I have to check in with you... Trying to make a restore with onbar using Tivoli Storage Manager. During tests this have worked without any problems, but now it (since we've put it all in production) simply doesn't work. We are running 10.00.TC6X2 on Windows Server 2003 with TSM 5.2.1. We are running parallel restore/backups, so backups are taken with onbar -b and restores are done with onbar -r -p onbar -r -lor onbar -r -p -t "..." onbar -r -l -t "..." Either way, when the restore seems to go in to its final phase, the logical recovery. This is what it looks like in online.log for one of the attempts with a PIT restore: 13:46:32 Maximum server connections 0 13:46:32 PIT reached - logid: 444, logpos: 0x99b2a0 13:46:37 Logical Recovery has reached the transaction cleanup phase. After that it hangs. I've determined that the server does nothing (nothing moves in onstat -p). I saw some suggestion on the net to just try and do onstat -m, but this only adds the following to online.log: 13:54:33 No logical log restore will be performed. 13:54:33 A Logical Restore is active. 13:54:33 Cannot change to On-Line Mode. I've done several attempts on different times and backups with the same result which is becoming a real issue now. Am I missing something obvious here? Any suggestions are very welcome - especially the quick ones ;o) thanks for listening.

Just wanted to add a few observations from my last (unsuccessful) tests: I saw some note on using onmode -O but this did not improve the situation. Killing the server and then try to bring it up does not work. The online.log looks like this for a restore to a specific log file: 15:41:13 Maximum server connections 0 15:41:18 Logical Recovery has reached the transaction cleanup phase. and the online.log for a PIT restore looks like this: 15:53:41 Maximum server connections 0 15:54:35 PIT reached - logid: 413, logpos: 0x60e044 15:54:39 Logical Recovery has reached the transaction cleanup phase. No errors whatsoever in the onbar log file. Current situation is that I have not been able to restore any production backups so the customer is now in the process of scheduling ontape backups to disk instead...however, they really want the TSM backups to work since it would make their backup/restore routines a lot more efficient - so please don't hesitate to make suggestions.

> -----Original Message----- > From: ids-bounces@iiug.org [mailto:ids-bounces@iiug.org] > Sent: Monday, March 17, 2008 11:05 AM > To: ids@iiug.org > Subject: Re: onbar restore blocked on checkpoint [11631] > > Just wanted to add a few observations from my last (unsuccessful) tests: > > I saw some note on using onmode -O but this did not improve the situation. > Killing the server and then try to bring it up does not work. Assuming you're trying to restore a backup and bring the engine online from the restored back, why not follow the manual: To perform a complete cold or warm restore, use the onbar -r command. ON-Bar restores the storage spaces in parallel. To speed up restores, you can add additional CPU virtual processors. To perform a restore, use the following command: onbar -r You should be able to follow this with onmode -m to bring the engine online. --EEM > > The online.log looks like this for a restore to a specific log file: > > 15:41:13 Maximum server connections 0 > 15:41:18 Logical Recovery has reached the transaction cleanup phase. > > and the online.log for a PIT restore looks like this: > > 15:53:41 Maximum server connections 0 > 15:54:35 PIT reached - logid: 413, logpos: 0x60e044 > 15:54:39 Logical Recovery has reached the transaction cleanup phase. > > No errors whatsoever in the onbar log file. > > Current situation is that I have not been able to restore any production > backups so the customer is now in the process of scheduling ontape backups > to > disk instead...however, they really want the TSM backups to work since it > would make their backup/restore routines a lot more efficient - so please > don't hesitate to make suggestions. > > > ************************************************************************ ** > ***** > Forum Note: Use "Reply" to post a response in the discussion forum. > > See you at the IIUG Informix 2008 Conference > The Power Conference for Informix Professionals > April 27 - 30, 2008 Marriott Overland Park (Kansas City), Kansas > http://www.iiug.org/conf > Registration Now Open!!

> Assuming you're trying to restore a backup and bring the engine online > from the restored back, why not follow the manual: > To perform a complete cold or warm restore, use the onbar -r command. > ON-Bar restores the storage spaces in parallel. To speed up restores, > you can add additional CPU virtual processors. To perform a restore, use > the following command: > onbar -r > You should be able to follow this with onmode -m to bring the engine > online. Thanks for your response, Everett. However, I believe I have read the manual and from there I have come to the conclusion that onbar -r is the same as backing up existing logs with onbar -b -l doing a physical restore with onbar -r -p doing a logical restore with onbar -r -l Since I am doing a restore into a blank system I don't need to do the first step, so therefore I am doing the two other steps "manually". Is this a mistake? I will perform an onbar -r later today to make sure.

what does your TSM log say? perhaps there are useful messages coming from TSM. are you trying to restore the DB back to itself or to another instance/server?

Thanks for your response! There are no messages in the TSM error logs. Maybe I should have pointed out that this is an imported restore, so I am restoring to another instance on another machine (but with identical hardware, disk configuration and software setup). Prior to starting onbar, I am copying * sm_versions * ixbar.0 * oncfg_* * onconfig (changing dbservername to match target instance) from the source (production) instance to the target (test) instance. Since last post I have tried onbar -r with the same (negative) results. However, I managed to get the server to online mode by skipping the logical restore using the following command sequence: onbar -r -p ... onmode -m But from what I understand, this kind of restore won't guarantee a consistent database since the backup was taken in parallel. Is this correct? Would it be consistent if a serial (whole, -w) backup is being made instead? This could be useful information for setting up an intermediate solution while trying to locate the checkpoint problem. Thanks.

Hi, last question first: Yes, a whole system backup and restore will bring up the restored system in a consistent state even without logical log restore. Now to the original problem: I would (again) like to know in more detail, what onbar is doing when the logical log restore phase begins (or should begin). At one point (I think) you said that there is no message in the ON-Bar activity log file, but this sounds a bit strange. To me it is not clear whether onbar was able to restore any logical log files or no log files were restored at all. Does the hang occur before any log file is restored? Or after some log files, but not all those necessary, were restored? Or does the hang occur after all necessary log files were restored? In the latter case it would most probably be a problem in the server. In the other two cases it may well be a problem of onbar (and/or the SM or its configuration). To get more info from onbar it is possible to switch on some tracing by setting the onconfig file parameter BAR_DEBUG to a value like 6 (medium tracing). You also need to set parameter BAR_DEBUG_LOG to an absolute file pathname, so that the information can be written to that file. Regards, Martin -- Martin Fuerderer IBM Informix Development Munich, Germany Information Management IBM Deutschland Entwicklung GmbH Chairman of the Supervisory Board: Martin Jetter Board of Management: Herbert Kircher Corporate Seat: Boeblingen, Germany Reg.-Gericht: Amtsgericht Stuttgart, HRB 243294 ids-bounces@iiug.org wrote on 18.03.2008 14:47:03: > Thanks for your response! > > There are no messages in the TSM error logs. > > Maybe I should have pointed out that this is an imported restore, so I am > restoring to another instance on another machine (but with identicalhardware, > disk configuration and software setup). > > Prior to starting onbar, I am copying > > * sm_versions > * ixbar.0 > * oncfg_* > * onconfig (changing dbservername to match target instance) > > from the source (production) instance to the target (test) instance. > > Since last post I have tried > > onbar -r> > with the same (negative) results. > > However, I managed to get the server to online mode by skipping the logical > restore using the following command sequence: > > onbar -r -p ... > onmode -m> > But from what I understand, this kind of restore won't guarantee a consistent > database since the backup was taken in parallel. Is this correct? Would it be > consistent if a serial (whole, -w) backup is being made instead? > This could be > useful information for setting up an intermediate solution while trying to > locate the checkpoint problem. > > Thanks. > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > See you at the IIUG Informix 2008 Conference > The Power Conference for Informix Professionals > April 27 - 30, 2008 Marriott Overland Park (Kansas City), Kansas > http://www.iiug.org/conf > Registration Now Open!!

please also check if you can increase the output/messages from TSM. we use netbackup and we can change the level of output messages for it as well.

Hi, > I would (again) like to know in more detail, what onbar > is doing when the logical log restore phase begins > (or should begin). At one point (I think) you said that > there is no message in the ON-Bar activity log file, > but this sounds a bit strange. Sorry for the confusion, but I meant that there were no error messages reported in the ON-Bar activity log. The last lines in the ON-Bar activity log shows: 2008-03-18 13:55:38 2900 2900 Completed restore logical log 493. 2008-03-18 13:55:38 2900 2900 Begin restore logical log 494 (Storage Manager copy ID: 0 792714572). 2008-03-18 13:55:57 2900 2900 Completed restore logical log 494. 2008-03-18 13:55:58 2900 2900 Begin restore logical log 495 (Storage Manager copy ID: 0 793388666). 2008-03-18 13:56:15 2900 2900 Completed restore logical log 495. ...where log 495 is the last log that should be restored. > To me it is not clear whether onbar was able to restore > any logical log files or no log files were restored at all. > Does the hang occur before any log file is restored? > Or after some log files, but not all those necessary, were > restored? Or does the hang occur after all necessary > log files were restored? The hang occurs after all necessary log files have been restored. In the last lines of online.log there is: 13:56:16 Maximum server connections 0 13:56:16 Checkpoint Completed: duration was 0 seconds. 13:56:16 Checkpoint loguniq 495, logpos 0x1374290, timestamp: 0x1ec3f9fc 13:56:16 Maximum server connections 0 13:56:20 Logical Recovery has reached the transaction cleanup phase. ...and that is where it all stops and leaves the instance in this state: IBM Informix Dynamic Server Version 10.00.TC6X2 -- Fast Recovery (CKPT REQ) -- Up 04:33:37 -- 1149120 KbytesBlocked:CKPT >In the latter case it would most probably be a problem >in the server. In the other two cases it may well be a >problem of onbar (and/or the SM or its configuration). I've been trying to dig through the thread stacks and I do see the threads waiting for the checkpoint to complete (the ontape thread). However, I do not see the checkpoint() function being called by the main_loop thread which I think is the normal sign of a checkpoint in action - the main_loop thread is just sitting there with 0x00ab876a (oninit)_mt_yield(0x1, 0x0, 0x50879c00, 0x0) 0x004050a3 (oninit)_main_loop(0x0, 0x0, 0x0, 0x0) 0x00ae1814 (oninit)_startup > To get more info from onbar it is possible to switch on > some tracing by setting the onconfig file parameter > BAR_DEBUG to a value like 6 (medium tracing). > You also need to set parameter BAR_DEBUG_LOG > to an absolute file pathname, so that the information > can be written to that file. I will make a new run again first thing tomorrow with increased debug levels on both Onbar and TSM. cheers Johan