Archive backup terminated prematurely

Problem: The last several level-0 backups (using ontape –s –L 0)have failed, with the only clue being an “Archive backup terminated prematurely” message. Normally, the backup creates 639 2G backup files; now, it terminates after 110. I also noticed that there are some missing pages in one of the sbspaces, sb_a18. Environment: IDS 9.30 UC3 $ uname -aSunOS server01p 5.8 Generic_117350-38 sun4u sparc SUNW,Sun-Fire-880 Questions: 1. Is the ontape backup failing because of this sbspace corruption? 2. When the oncheck utility gives an “ERROR: Missing pages between” message, is it referring to the line before or the line after the message? 3. Is the corruption a hardware issue with the raw partition with the missing pages? (see below)? Or is it a problem with Informix pointers? 4. Will bouncing the database fix the corruption or do I need to restore sb_a18 from backup? 5. Do I need to have the raw partition(s) rebuilt before doing the restore? 6. If I bounce the database, will I be able to bring it back up with this corruption still in place? ========================================== Output from our backup script: . . . Please mount tape 109 on /dev/ifmx/archtape and press Return to continue ... Tape is full ... Please label this tape as number 109 in the arc tape sequence. Please mount tape 110 on /dev/ifmx/archtape and press Return to continue ... 100 percent done. Archive failed - Archive backup terminated prematurely. Program over. ========================================== $oncheck -ce sb_a18 Validating extents for Space 'sb_a18' ... Chunk Pathname Size Used Free 42 /dev/ifmx/prod/raw055 500000 499901 0 43 /dev/ifmx/prod/raw001 500000 499418 0 57 /dev/ifmx/prod/raw055 500000 498678 0 175 /dev/ifmx/prod/raw018 500000 499137 0 ERROR: Missing pages between 233438 and 233440 211 /dev/ifmx/prod/raw264 500000 466876 0 247 /dev/ifmx/prod/raw212 500000 497655 0 275 /dev/ifmx/prod/raw214 500000 481525 0 307 /dev/ifmx/prod/raw278 500000 466878 0 377 /dev/ifmx/prod/raw336 500000 466878 0 421 /dev/ifmx/prod/raw193 500000 466878 0 453 /dev/ifmx/prod/raw403 500000 466878 0 498 /dev/ifmx/prod/raw432 500000 466878 0 541 /dev/ifmx/prod/raw474 1000000 933783 0 618 /dev/ifmx/prod/raw550 1000000 933783 0 707 /dev/ifmx/prod/raw649 1000000 933783 0 771 /dev/ifmx/prod/raw713 1000000 286930 646853 Note: 'Used' = used metadata space + used user data space. 'Free' = free user data space.

I'm going to strongly suggest that you open a support case with IBM before doing ANYTHING! Art Art S. Kagel Advanced DataTools (www.advancedatatools.com) Blog: http://informix-myview.blogspot.com/ Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on my employer, Advanced DataTools, the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Thu, Jan 19, 2012 at 1:22 PM, JOSEPH ORNDORFF <joseph.orndorff@nike.com>wrote: > Problem: The last several level-0 backups (using ontape –s –L 0)have > failed, > with the only clue being an “Archive backup terminated prematurely” > message. > Normally, the backup creates 639 2G backup files; now, it terminates after > 110. I also noticed that there are some missing pages in one of the > sbspaces, > sb_a18. > > Environment: > IDS 9.30 UC3 > $ uname -a> SunOS server01p 5.8 Generic_117350-38 sun4u sparc SUNW,Sun-Fire-880 > > Questions: > 1. Is the ontape backup failing because of this sbspace corruption? > 2. When the oncheck utility gives an “ERROR: Missing pages between” > message, > is it referring to the line before or the line after the message? > 3. Is the corruption a hardware issue with the raw partition with the > missing > pages? (see below)? Or is it a problem with Informix pointers? > 4. Will bouncing the database fix the corruption or do I need to restore > sb_a18 from backup? > 5. Do I need to have the raw partition(s) rebuilt before doing the restore? > 6. If I bounce the database, will I be able to bring it back up with this > corruption still in place? > > ========================================== > > Output from our backup script: > .. > .. > .. > Please mount tape 109 on /dev/ifmx/archtape and press Return to continue > ... > Tape is full ... > > Please label this tape as number 109 in the arc tape sequence. > > Please mount tape 110 on /dev/ifmx/archtape and press Return to continue > ... > 100 percent done. > Archive failed - Archive backup terminated prematurely. > > Program over. > > ========================================== > > $oncheck -ce sb_a18 > > Validating extents for Space 'sb_a18' ... > > Chunk Pathname Size Used Free > > 42 /dev/ifmx/prod/raw055 500000 499901 0 > > 43 /dev/ifmx/prod/raw001 500000 499418 0 > > 57 /dev/ifmx/prod/raw055 500000 498678 0 > > 175 /dev/ifmx/prod/raw018 500000 499137 0 > ERROR: Missing pages between 233438 and 233440 > > 211 /dev/ifmx/prod/raw264 500000 466876 0 > > 247 /dev/ifmx/prod/raw212 500000 497655 0 > > 275 /dev/ifmx/prod/raw214 500000 481525 0 > > 307 /dev/ifmx/prod/raw278 500000 466878 0 > > 377 /dev/ifmx/prod/raw336 500000 466878 0 > > 421 /dev/ifmx/prod/raw193 500000 466878 0 > > 453 /dev/ifmx/prod/raw403 500000 466878 0 > > 498 /dev/ifmx/prod/raw432 500000 466878 0 > > 541 /dev/ifmx/prod/raw474 1000000 933783 0 > > 618 /dev/ifmx/prod/raw550 1000000 933783 0 > > 707 /dev/ifmx/prod/raw649 1000000 933783 0 > > 771 /dev/ifmx/prod/raw713 1000000 286930 646853 > > Note: 'Used' = used metadata space + used user data space. > > 'Free' = free user data space. > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --14dae934086366f1c104b6e5cfdb

as for the "missing pages", that can probably be fixed by tech support , it's a problem with the pointers as you say. as for the failing archive, the circumstance surrounding the failure is usually posted in the online message log, look in there. Mark

>> Environment: IDS 9.30 UC3 >> [Art] I'm going to strongly suggest that you open a support case with IBM before doing ANYTHING! Almost certainly in vain I'd have thought. When did 9.30 go out of support? 2004?

Thanks, Mark. One of the ontape backup failures occurred on Wed Dec 28 22:19:15 PST 2011. I don't think I see anything odd in the logs around the time of failure that wasn't there for a previous successful backup: onconfig.prod ============= MSGPATH /bml/logs/informix/prod.log # System message log file path CONSOLE /bml/logs/informix/prod.log # System console message path BAR_ACT_LOG /bml/logs/informix/prod_bar_act.log BAR_ACT_LOG (/bml/logs/informix/prod_bar_act.log ) ==================================================== 2011-12-28 16:38:07 7570 7568 /apps/informix/IF9.30.UC3-1/bin/onbar_d -b -l 2011-12-28 16:38:07 7570 7568 A log backup is already running. Can't start another. 2011-12-28 16:38:12 7570 7568 /apps/informix/IF9.30.UC3-1/bin/onbar_d complete, returning 152 (0x98) 2011-12-28 16:41:35 14801 14799 /apps/informix/IF9.30.UC3-1/bin/onbar_d -b -l 2011-12-28 16:41:35 14801 14799 A log backup is already running. Can't start another. 2011-12-28 16:41:40 14801 14799 /apps/informix/IF9.30.UC3-1/bin/onbar_d complete, returning 152 (0x98) 2011-12-28 23:43:33 15849 15847 Completed backup logical log 56392 (Storage Manager copy ID: 1325101151 1325101152). 2011-12-28 23:43:33 15849 15847 Begin backup logical log 56393. 2011-12-28 23:43:47 15849 15847 Completed backup logical log 56393 (Storage Manager copy ID: 1325144614 1325144616). 2011-12-28 23:43:47 15849 15847 Begin backup logical log 56394. 2011-12-28 23:44:01 15849 15847 Completed backup logical log 56394 (Storage Manager copy ID: 1325144627 1325144630). 2011-12-28 23:44:01 15849 15847 Begin backup logical log 56395. 2011-12-28 23:49:11 15849 15847 Completed backup logical log 56395 (Storage Manager copy ID: 1325144643 1325144647). 2011-12-28 23:49:11 15849 15847 Begin backup logical log 56396. MSGPATH (/bml/logs/informix/prod.log ) ================================================= 18:20:07 Checkpoint Completed: duration was 0 seconds. 18:20:07 Checkpoint loguniq 56406, logpos 0x1486018 18:20:07 Maximum server connections 280 18:45:06 Checkpoint Completed: duration was 0 seconds. 18:45:06 Checkpoint loguniq 56406, logpos 0x1487018 18:45:06 Checkpoint loguniq 56406, logpos 0x1487018 18:45:06 Maximum server connections 280 18:50:06 Checkpoint Completed: duration was 0 seconds. 18:50:06 Checkpoint loguniq 56406, logpos 0x1488018 18:50:06 Maximum server connections 280 18:55:06 Fuzzy Checkpoint Completed: duration was 0 seconds, 308 buffers not flushed. 18:55:06 Checkpoint loguniq 56406, logpos 0x14da41c 18:55:06 Maximum server connections 280 19:00:06 Fuzzy Checkpoint Completed: duration was 0 seconds, 2612 buffers not flushed. 19:00:06 Checkpoint loguniq 56406, logpos 0x182c2f4 19:00:06 Maximum server connections 280 19:05:06 Fuzzy Checkpoint Completed: duration was 0 seconds, 3516 buffers not flushed. 19:05:06 Checkpoint loguniq 56406, logpos 0x1a53788 19:05:06 Maximum server connections 280 19:09:05 Checkpoint Completed: duration was 0 seconds. 19:09:05 Checkpoint loguniq 56406, logpos 0x1b12018 19:09:05 Maximum server connections 280 19:09:18 Level 0 Archive started on rootdbs, physlog, loglog, dbspa01, sb_a01, sb_a02, sb_a03, sb_a04, sb_a05, sb_a06, sb_a07, sb_a08, sb_a09, sb_a10 , sb_a11, sb_a12, sb_a13, sb_a14, sb_a15, sb_a16, sb_a17, sb_a18, sb_a19, sb_a20, dbspnims, sbsp00, sb_a00, dbspe01, dbspe02, dbspa02, dbspnx1, dbspf0 1, dbspf02, dbspfx1, dbspfx2, sb_f01, sb_f02, sb_f03, sb_f04, sb_f05, sb_f06, sb_f07, sb_f08, sb_f09, sb_f10, sb_f11, dbspe03 19:14:06 Checkpoint Completed: duration was 0 seconds. 19:14:06 Checkpoint loguniq 56406, logpos 0x1b13018 19:14:06 Maximum server connections 280 19:44:06 Checkpoint Completed: duration was 0 seconds. 19:44:06 Checkpoint loguniq 56406, logpos 0x1b14018 19:44:06 Maximum server connections 280 19:49:06 Checkpoint Completed: duration was 0 seconds. 19:49:06 Checkpoint loguniq 56406, logpos 0x1b15018 19:49:06 Maximum server connections 280 19:54:06 Checkpoint Completed: duration was 0 seconds. 19:54:06 Checkpoint loguniq 56406, logpos 0x1b16018 19:54:06 Maximum server connections 280 19:59:06 Checkpoint Completed: duration was 0 seconds. 19:59:06 Checkpoint loguniq 56406, logpos 0x1b17018 19:59:06 Maximum server connections 280 20:04:06 Checkpoint Completed: duration was 0 seconds. 20:04:06 Checkpoint loguniq 56406, logpos 0x1b18018 20:04:06 Maximum server connections 280 20:14:07 Checkpoint Completed: duration was 0 seconds. 20:14:07 Checkpoint loguniq 56406, logpos 0x1b19018 20:14:07 Checkpoint loguniq 56406, logpos 0x1b19018 20:14:07 Maximum server connections 280 20:24:07 Checkpoint Completed: duration was 0 seconds. 20:24:07 Checkpoint loguniq 56406, logpos 0x1b1a018 20:24:07 Maximum server connections 280 20:39:09 Checkpoint Completed: duration was 0 seconds. 20:39:09 Checkpoint loguniq 56406, logpos 0x1b1b018 20:39:09 Maximum server connections 280 20:49:09 Checkpoint Completed: duration was 0 seconds. 20:49:09 Checkpoint loguniq 56406, logpos 0x1b1c018 20:49:09 Maximum server connections 280 20:59:10 Checkpoint Completed: duration was 0 seconds. 20:59:10 Checkpoint loguniq 56406, logpos 0x1b1d018 20:59:10 Maximum server connections 280 21:14:11 Checkpoint Completed: duration was 0 seconds. 21:14:11 Checkpoint loguniq 56406, logpos 0x1b1e018 21:14:11 Maximum server connections 280 21:19:11 Checkpoint Completed: duration was 0 seconds. 21:19:11 Checkpoint loguniq 56406, logpos 0x1b1f018 21:19:11 Maximum server connections 280 21:24:11 Checkpoint Completed: duration was 0 seconds. 21:24:11 Checkpoint loguniq 56406, logpos 0x1b20018 21:24:11 Maximum server connections 280 21:29:12 Fuzzy Checkpoint Completed: duration was 0 seconds, 115 buffers not flushed. 21:29:12 Checkpoint loguniq 56406, logpos 0x1b9f290 21:29:12 Maximum server connections 280 21:34:13 Fuzzy Checkpoint Completed: duration was 0 seconds, 241 buffers not flushed. 21:34:13 Checkpoint loguniq 56406, logpos 0x1bfd6f8 21:34:13 Maximum server connections 280 21:39:14 Fuzzy Checkpoint Completed: duration was 0 seconds, 300 buffers not flushed. 21:39:14 Checkpoint loguniq 56406, logpos 0x1c6742c 21:39:14 Maximum server connections 280 21:44:15 Fuzzy Checkpoint Completed: duration was 0 seconds, 360 buffers not flushed. 21:44:15 Checkpoint loguniq 56406, logpos 0x1cc02b4 21:44:15 Maximum server connections 280 21:49:15 Fuzzy Checkpoint Completed: duration was 0 seconds, 404 buffers not flushed. 21:49:15 Checkpoint loguniq 56406, logpos 0x1d100e4 21:49:15 Maximum server connections 280 21:54:16 Fuzzy Checkpoint Completed: duration was 0 seconds, 451 buffers not flushed. 21:54:16 Checkpoint loguniq 56406, logpos 0x1d47344 21:54:16 Fuzzy Checkpoint Completed: duration was 0 seconds, 451 buffers not flushed. 21:54:16 Checkpoint loguniq 56406, logpos 0x1d47344 21:54:16 Maximum server connections 280 21:59:18 Fuzzy Checkpoint Completed: duration was 0 seconds, 493 buffers not flushed. 21:59:18 Checkpoint loguniq 56406, logpos 0x1d7d5bc 21:59:18 Maximum server connections 280 22:04:18 Fuzzy Checkpoint Comp