Why is this happening ?
Posted in 2003
An ON-Bar cold restore (onbar -r -n 4200) completed the physical restore but failed at logical log 4198 with "XBSA Error: (BSAQueryObject) Backup object does not exist in Storage Manager," even though ixbar showed the log as backed up. Replies pointed at LTAPEDEV=/dev/null, which makes Informix mark logs backed up without saving them and blocks log salvage; suggestions included checking the storage manager's own catalog/filenames and restarting with onbar -r -p plus onbar -r -l. The poster fixed /dev/null and a version mismatch (9.30 UC1 backup into FC4X8), but his final post reports a new failure ("Unable to write storage space restore data... buc_fe.c line 904") with no further replies, so no final resolution is recorded.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Topics: Backup & Restore, Storage & Space Management, Logging & Checkpoints
Hi all,
I am trying onbar -r -n 4200 and it is crashing at the logical log number
4198. The logs show that it was backed up successfully. Ixbar.0 has the record
of logical log 4198.
I have attached the bar_act.log erro below. Can someone shed light to this to
troubleshoot what could be wrong ?
Thanks.
bash-2.03$ cat bar_act*
2003-12-11 05:19:51 26449 26447 /opt/informix/IDS_9.30.FC8X4/bin/onbar_d -r -n4200
2003-12-11 05:19:51 26449 26447 Logical Logs will not be backed up / salvaged
because LTAPEDEV value is /dev/null
2003-12-11 05:19:51 26449 26447 Successfully connected to Storage Manager.
2003-12-11 05:20:30 26449 26447 Begin cold level 0 restore rootdbs (Storage
Manager copy ID: 1071159307 1071159308).
2003-12-11 05:20:52 26449 26447 Completed cold level 0 restore rootdbs.
2003-12-11 05:21:33 26449 26447 Begin cold level 0 restore dbspace1 (Storage
Manager copy ID: 1071159359 1071159361).
2003-12-11 05:51:13 26449 26447 Completed cold level 0 restore dbspace1.
2003-12-11 05:51:13 26449 26447 Successfully connected to Storage Manager.
2003-12-11 05:51:15 26449 26447 XBSA Error: (BSAQueryObject) Backup object
does not exist in Storage Manager.
2003-12-11 05:51:15 26449 26447 ON-Bar could not get logical log 4198 from the
storage manager.
2003-12-11 05:51:15 26449 26447 ON-Bar suspended the logical restore on log
4198 (expected to restore to 4200).
2003-12-11 05:51:25 26449 26447 /opt/informix/IDS_9.30.FC8X4/bin/onbar_d
complete, returning 100 (0x64)
2003-12-11 05:53:18 26540 26538 /opt/informix/IDS_9.30.FC8X4/bin/onbar_d ---
2003-12-11 05:53:19 26540 26538 onbar usage
---------------------------------
Do you Yahoo!?
New Yahoo! Photos - easier uploading and sharing
Probably the below:
"Logical Logs will not be backed up / salvaged because LTAPEDEV value is
/dev/null"
Hard to do a restore from the bit bucket, I believe. If you could
do that, I would be very impressed! (Ditto the "storage manager" would be.)
Mike Smith wrote:
> Hi all,
> I am trying onbar -r -n 4200 and it is crashing at the logical log number
4198. The logs show that it was backed up successfully. Ixbar.0 has the record
of logical log 4198.
> I have attached the bar_act.log erro below. Can someone shed light to this
to troubleshoot what could be wrong ?
>
> Thanks.
>
>
> bash-2.03$ cat bar_act*
> 2003-12-11 05:19:51 26449 26447 /opt/informix/IDS_9.30.FC8X4/bin/onbar_d -r
-n 4200> 2003-12-11 05:19:51 26449 26447 Logical Logs will not be backed up /
salvaged because LTAPEDEV value is /dev/null
> 2003-12-11 05:19:51 26449 26447 Successfully connected to Storage Manager.
> 2003-12-11 05:20:30 26449 26447 Begin cold level 0 restore rootdbs (Storage
Manager copy ID: 1071159307 1071159308).
> 2003-12-11 05:20:52 26449 26447 Completed cold level 0 restore rootdbs.
> 2003-12-11 05:21:33 26449 26447 Begin cold level 0 restore dbspace1 (Storage
Manager copy ID: 1071159359 1071159361).
> 2003-12-11 05:51:13 26449 26447 Completed cold level 0 restore dbspace1.
> 2003-12-11 05:51:13 26449 26447 Successfully connected to Storage Manager.
> 2003-12-11 05:51:15 26449 26447 XBSA Error: (BSAQueryObject) Backup object
does not exist in Storage Manager.
> 2003-12-11 05:51:15 26449 26447 ON-Bar could not get logical log 4198 from
the storage manager.
> 2003-12-11 05:51:15 26449 26447 ON-Bar suspended the logical restore on log
4198 (expected to restore to 4200).
> 2003-12-11 05:51:25 26449 26447 /opt/informix/IDS_9.30.FC8X4/bin/onbar_d
complete, returning 100 (0x64)
> 2003-12-11 05:53:18 26540 26538 /opt/informix/IDS_9.30.FC8X4/bin/onbar_d ---
> 2003-12-11 05:53:19 26540 26538 onbar usage
>
>
>
> ---------------------------------
> Do you Yahoo!?
> New Yahoo! Photos - easier uploading and sharing
>
--
( ______
)) .-- Scott MacKenzie; Dine' College ISD --. >===<--.
C|~~| (>--- Phone/Voice Mail: 928-724-6639 ---<) | ; o |-'
| | \\\\--- Senior DBA/CARS Coordinator/Etc. --/ | _ |
`--' `-- E: scottm at dinecollege dot edu -' `-----'
Onbar defaults to attempting to
salvage (restore) the log files. Since
you are dumping your logs to /dev/null, you don't have them to restore.
Restart the restore using onbar -r -p -w and onbar -r -l to skip log
salvage and bring the engine back online. See Chapter 6 (v9) of the fine
manual for help.
Christine Normile
I/T Specialist, Informix Solutions
Data Management Worldwide Technical Enablement
Telephone: 877-252-5399 T/L 273-0981
Mobile: 210-365-5073
"Scott MacKe...." <scottm@dinecollege.edu>
Sent by: forum.subscriber@iiug.org
12/11/2003 05:00 PM
To: ids@iiug.org
cc:
Subject: Re: Why is this happening ? [2343]
Probably the below:
"Logical Logs will not be backed up / salvaged because LTAPEDEV value is
/dev/null"
Hard to do a restore from the bit bucket, I believe. If you could
do that, I would be very impressed! (Ditto the "storage manager" would
be.)
Mike Smith wrote:
> Hi all,
> I am trying onbar -r -n 4200 and it is crashing at the logical log
number 4198. The logs show that it was backed up successfully. Ixbar.0
has the record of logical log 4198.
> I have attached the bar_act.log erro below. Can someone shed light to
this to troubleshoot what could be wrong ?
>
> Thanks.
>
>
> bash-2.03$ cat bar_act*
> 2003-12-11 05:19:51 26449 26447
/opt/informix/IDS_9.30.FC8X4/bin/onbar_d -r -n 4200> 2003-12-11 05:19:51 26449 26447 Logical Logs will not be backed up /
salvaged because LTAPEDEV value is /dev/null
> 2003-12-11 05:19:51 26449 26447 Successfully connected to Storage
Manager.
> 2003-12-11 05:20:30 26449 26447 Begin cold level 0 restore rootdbs
(Storage Manager copy ID: 1071159307 1071159308).
> 2003-12-11 05:20:52 26449 26447 Completed cold level 0 restore
rootdbs.
> 2003-12-11 05:21:33 26449 26447 Begin cold level 0 restore dbspace1
(Storage Manager copy ID: 1071159359 1071159361).
> 2003-12-11 05:51:13 26449 26447 Completed cold level 0 restore
dbspace1.
> 2003-12-11 05:51:13 26449 26447 Successfully connected to Storage
Manager.
> 2003-12-11 05:51:15 26449 26447 XBSA Error: (BSAQueryObject) Backup
object does not exist in Storage Manager.
> 2003-12-11 05:51:15 26449 26447 ON-Bar could not get logical log 4198
from the storage manager.
> 2003-12-11 05:51:15 26449 26447 ON-Bar suspended the logical restore
on log 4198 (expected to restore to 4200).
> 2003-12-11 05:51:25 26449 26447
/opt/informix/IDS_9.30.FC8X4/bin/onbar_d complete, returning 100 (0x64)
> 2003-12-11 05:53:18 26540 26538
/opt/informix/IDS_9.30.FC8X4/bin/onbar_d ---
> 2003-12-11 05:53:19 26540 26538 onbar usage
>
>
>
> ---------------------------------
> Do you Yahoo!?
> New Yahoo! Photos - easier uploading and sharing
>
--
( ______
)) .-- Scott MacKenzie; Dine' College ISD --. >===<--.
C|~~| (>--- Phone/Voice Mail: 928-724-6639 ---<) | ; o |-'
| | \\\\--- Senior DBA/CARS Coordinator/Etc. --/ | _ |
`--' `-- E: scottm at dinecollege dot edu -' `-----'
Scott's right.
Sending logs to /dev/null results in an "SOL" situation for you.
/dev/null is special. Informix won't bother to check other settings, if
it sees dev/null, it simply flips a bit to mark the log backed up
without really doing anything with it.
However, if you set this to /dev/null only for the restore, but normally
run with a setting to something other than /dev/null, you probably do
have logs backed up as you indicated. Maybe you were just trying to
avoid the log salvage that Informix does on restore? If so, check on
the storage manager side for messages. Obviously Informix knows what
log it wants, but the storage manager can't help.
In our case, our storage manager (Veritas Netbackup) initially backs up
our logs to disk. We hold X days on disk, then we have a secondary
Netbackup process that takes those logs, backs them to tape, and empties
the disk directory. We use the second Netbackup process because it has
a different catalog than the first one. If the first netbackup process
backed these to tape, it would change the records in it's catalog and
would not be able to give informix the log when requested.
We have tested situations where we knew the log was backed up to disk
and properly recorded by both Informix and Netbackup. Then we renamed
the log on disk, then we tried to restore. Informix knew what it
wanted, Netbackup understood, but returned an error that the log could
not be found. When we renamed the log to the proper filename, Netbackup
happily passed it back to Informix and all was well with the world.
I don't know about all the storage managers, but Informix and Netbackup
produce verbose messages that are quite understandable.
If indeed you did back up the logs, try the restore again without the
/dev/null setting and see what happens.
good luck,
Norma Jean
-----Original Message-----
From: scottm@dinecollege.edu [mailto:scottm@dinecollege.edu]
Sent: Thursday, December 11, 2003 5:00 PM
To: ids@iiug.org; forum.subscriber@iiug.org
Subject: Re: Why is this happening ? [2343]
Probably the below:
"Logical Logs will not be backed up / salvaged because LTAPEDEV value is
/dev/null"
Hard to do a restore from the bit bucket, I believe. If you could
do that, I would be very impressed! (Ditto the "storage manager" would
be.)
Mike Smith wrote:
> Hi all,
> I am trying onbar -r -n 4200 and it is crashing at the logical
log number 4198. The logs show that it was backed up successfully.
Ixbar.0 has the record of logical log 4198.
> I have attached the bar_act.log erro below. Can someone shed light to
this to troubleshoot what could be wrong ?
> Thanks.
>
> bash-2.03$ cat bar_act*
> 2003-12-11 05:19:51 26449 26447
/opt/informix/IDS_9.30.FC8X4/bin/onbar_d -r -n 4200> 2003-12-11 05:19:51 26449 26447 Logical Logs will not be backed up /
salvaged because LTAPEDEV value is /dev/null
> 2003-12-11 05:19:51 26449 26447 Successfully connected to Storage
Manager.
> 2003-12-11 05:20:30 26449 26447 Begin cold level 0 restore rootdbs
(Storage Manager copy ID: 1071159307 1071159308).
> 2003-12-11 05:20:52 26449 26447 Completed cold level 0 restore
rootdbs.
> 2003-12-11 05:21:33 26449 26447 Begin cold level 0 restore dbspace1
(Storage Manager copy ID: 1071159359 1071159361).
> 2003-12-11 05:51:13 26449 26447 Completed cold level 0 restore
dbspace1.
> 2003-12-11 05:51:13 26449 26447 Successfully connected to Storage
Manager.
> 2003-12-11 05:51:15 26449 26447 XBSA Error: (BSAQueryObject) Backup
object does not exist in Storage Manager.
> 2003-12-11 05:51:15 26449 26447 ON-Bar could not get logical log
4198 from the storage manager.
> 2003-12-11 05:51:15 26449 26447 ON-Bar suspended the logical restore
on log 4198 (expected to restore to 4200).
> 2003-12-11 05:51:25 26449 26447
/opt/informix/IDS_9.30.FC8X4/bin/onbar_d complete, returning 100 (0x64)
> 2003-12-11 05:53:18 26540 26538
/opt/informix/IDS_9.30.FC8X4/bin/onbar_d ---
> 2003-12-11 05:53:19 26540 26538 onbar usage
>
-----------------------------------------
============================================================
The information contained in this message may be privileged
and confidential and protected from disclosure. If the
reader of this message is not the intended recipient, or an
employee or agent responsible for delivering this message to
the intended recipient, you are hereby notified that any
reproduction, dissemination or distribution of this
communication is strictly prohibited. If you have received
this communication in error, please notify us immediately by
replying to the message and deleting it from your computer.
Thank you.
Tellabs
============================================================
Ok, thanks to everyone who shared their ideas on
this issue. I have fixed the /dev/null issue. But, still the restore is
crashing. Could it be becuase I am trying to restore a 9.30 UC1 version's
backup into a 9.30 FC4X8 instance ? (Basically what I am saying is that the
Informix versions are different on this restore effort). Physical restore
finishes fine but when I kick off the logical restore it starts giving me
assert failures on the online.log. Now I am in the process of making sure both
Informix versions are the same before my next restore effort on this.
"NormaJean.S...." <NormaJean.Sebastian@tellabs.com> wrote:Scott's right.
Sending logs to /dev/null results in an "SOL" situation for you.
/dev/null is special. Informix won't bother to check other settings, if
it sees dev/null, it simply flips a bit to mark the log backed up
without really doing anything with it.
However, if you set this to /dev/null only for the restore, but normally
run with a setting to something other than /dev/null, you probably do
have logs backed up as you indicated. Maybe you were just trying to
avoid the log salvage that Informix does on restore? If so, check on
the storage manager side for messages. Obviously Informix knows what
log it wants, but the storage manager can't help.
In our case, our storage manager (Veritas Netbackup) initially backs up
our logs to disk. We hold X days on disk, then we have a secondary
Netbackup process that takes those logs, backs them to tape, and empties
the disk directory. We use the second Netbackup process because it has
a different catalog than the first one. If the first netbackup process
backed these to tape, it would change the records in it's catalog and
would not be able to give informix the log when requested.
We have tested situations where we knew the log was backed up to disk
and properly recorded by both Informix and Netbackup. Then we renamed
the log on disk, then we tried to restore. Informix knew what it
wanted, Netbackup understood, but returned an error that the log could
not be found. When we renamed the log to the proper filename, Netbackup
happily passed it back to Informix and all was well with the world.
I don't know about all the storage managers, but Informix and Netbackup
produce verbose messages that are quite understandable.
If indeed you did back up the logs, try the restore again without the
/dev/null setting and see what happens.
good luck,
Norma Jean
-----Original Message-----
From: scottm@dinecollege.edu [mailto:scottm@dinecollege.edu]
Sent: Thursday, December 11, 2003 5:00 PM
To: ids@iiug.org; forum.subscriber@iiug.org
Subject: Re: Why is this happening ? [2343]
Probably the below:
"Logical Logs will not be backed up / salvaged because LTAPEDEV value is
/dev/null"
Hard to do a restore from the bit bucket, I believe. If you could
do that, I would be very impressed! (Ditto the "storage manager" would
be.)
Mike Smith wrote:
> Hi all,
> I am trying onbar -r -n 4200 and it is crashing at the logical
log number 4198. The logs show that it was backed up successfully.
Ixbar.0 has the record of logical log 4198.
> I have attached the bar_act.log erro below. Can someone shed light to
this to troubleshoot what could be wrong ?
> Thanks.
>
> bash-2.03$ cat bar_act*
> 2003-12-11 05:19:51 26449 26447
/opt/informix/IDS_9.30.FC8X4/bin/onbar_d -r -n 4200> 2003-12-11 05:19:51 26449 26447 Logical Logs will not be backed up /
salvaged because LTAPEDEV value is /dev/null
> 2003-12-11 05:19:51 26449 26447 Successfully connected to Storage
Manager.
> 2003-12-11 05:20:30 26449 26447 Begin cold level 0 restore rootdbs
(Storage Manager copy ID: 1071159307 1071159308).
> 2003-12-11 05:20:52 26449 26447 Completed cold level 0 restore
rootdbs.
> 2003-12-11 05:21:33 26449 26447 Begin cold level 0 restore dbspace1
(Storage Manager copy ID: 1071159359 1071159361).
> 2003-12-11 05:51:13 26449 26447 Completed cold level 0 restore
dbspace1.
> 2003-12-11 05:51:13 26449 26447 Successfully connected to Storage
Manager.
> 2003-12-11 05:51:15 26449 26447 XBSA Error: (BSAQueryObject) Backup
object does not exist in Storage Manager.
> 2003-12-11 05:51:15 26449 26447 ON-Bar could not get logical log
4198 from the storage manager.
> 2003-12-11 05:51:15 26449 26447 ON-Bar suspended the logical restore
on log 4198 (expected to restore to 4200).
> 2003-12-11 05:51:25 26449 26447
/opt/informix/IDS_9.30.FC8X4/bin/onbar_d complete, returning 100 (0x64)
> 2003-12-11 05:53:18 26540 26538
/opt/informix/IDS_9.30.FC8X4/bin/onbar_d ---
> 2003-12-11 05:53:19 26540 26538 onbar usage
>
-----------------------------------------
============================================================
The information contained in this message may be privileged
and confidential and protected from disclosure. If the
reader of this message is not the intended recipient, or an
employee or agent responsible for delivering this message to
the intended recipient, you are hereby notified that any
reproduction, dissemination or distribution of this
communication is strictly prohibited. If you have received
this communication in error, please notify us immediately by
replying to the message and deleting it from your computer.
Thank you.
Tellabs
============================================================
---------------------------------
Do you Yahoo!?
New Yahoo! Photos - easier uploading and sharing
Hello Informix Gurus,
Now I have Informix versions issue corrected, but I am still having problems
with my restore. Please read the errors from the bar_act.log right below and
do feel free to offer your suggestioins. Thanks.
2003-12-16 00:10:25 8664 8662 /opt/informix/IDS_9.30.UC3/bin/onbar_d -r
2003-12-16 00:10:25 8664 8662 Logical Logs will not be backed up / salvaged
because LTAPEDEV value is /dev/null
2003-12-16 00:10:27 8664 8662 Successfully connected to Storage Manager.
2003-12-16 00:12:37 8664 8662 Begin cold level 0 restore rootdbs (Storage
Manager copy ID: 1071526197 1071526198).
2003-12-16 00:13:00 8664 8662 Completed cold level 0 restore rootdbs.
2003-12-16 00:13:43 8664 8662 Begin cold level 0 restore dbspace1 (Storage
Manager copy ID: 1071526238 1071526240).
2003-12-16 00:44:05 8664 8662 Completed cold level 0 restore dbspace1.
2003-12-16 00:44:06 8664 8662 Successfully connected to Storage Manager.
2003-12-16 00:44:11 8664 8662 Begin restore logical log 4320 (Storage Manager
copy ID: 1071526460 1071526461).
2003-12-16 00:47:10 8664 8662 Unable to write storage space restore data to
the database server: buc_fe.c : Archive API processing failed at line 904 for
msgtype.
2003-12-16 00:47:10 8664 8662 Unable to close the storage space restore:
buc_fe.c : Archive API processing failed at line 904 for msgtype.
2003-12-16 00:47:15 8664 8662 /opt/informix/IDS_9.30.UC3/bin/onbar_d complete,
returning 130 (0x82)
-----Original Message-----
From: forum.subscriber@iiug.org [mailto:forum.subscriber@iiug.org] On Behalf
Of Mike Smith
Sent: 12 December 2003 00:39
To: ids@iiug.org
Subject: Why is this happening ? [2342]
Hi all,
I am trying onbar -r -n 4200 and it is crashing at the logical log number
4198. The logs show that it was backed up successfully. Ixbar.0 has the record
of logical log 4198.
I have attached the bar_act.log erro below. Can someone shed light to this to
troubleshoot what could be wrong ?
Thanks.
bash-2.03$ cat bar_act*
2003-12-11 05:19:51 26449 26447 /opt/informix/IDS_9.30.FC8X4/bin/onbar_d -r -n4200
2003-12-11 05:19:51 26449 26447 Logical Logs will not be backed up / salvaged
because LTAPEDEV value is /dev/null
2003-12-11 05:19:51 26449 26447 Successfully connected to Storage Manager.
2003-12-11 05:20:30 26449 26447 Begin cold level 0 restore rootdbs (Storage
Manager copy ID: 1071159307 1071159308).
2003-12-11 05:20:52 26449 26447 Completed cold level 0 restore rootdbs.
2003-12-11 05:21:33 26449 26447 Begin cold level 0 restore dbspace1 (Storage
Manager copy ID: 1071159359 1071159361).
2003-12-11 05:51:13 26449 26447 Completed cold level 0 restore dbspace1.
2003-12-11 05:51:13 26449 26447 Successfully connected to Storage Manager.
2003-12-11 05:51:15 26449 26447 XBSA Error: (BSAQueryObject) Backup object
does not exist in Storage Manager.
2003-12-11 05:51:15 26449 26447 ON-Bar could not get logical log 4198 from the
storage manager.
2003-12-11 05:51:15 26449 26447 ON-Bar suspended the logical restore on log
4198 (expected to restore to 4200).
2003-12-11 05:51:25 26449 26447 /opt/informix/IDS_9.30.FC8X4/bin/onbar_d
complete, returning 100 (0x64)
2003-12-11 05:53:18 26540 26538 /opt/informix/IDS_9.30.FC8X4/bin/onbar_d ---
2003-12-11 05:53:19 26540 26538 onbar usage
---------------------------------
Do you Yahoo!?
New Yahoo! Photos - easier uploading and sharing
This e-mail is sent on the Terms and Conditions that can be accessed by
Clicking on this link http://www.vodacom.net/legal/email.asp "
---------------------------------
Do you Yahoo!?
New Yahoo! Photos - easier uploading and sharing