point-in-time restore
Mark Scranton (IDS 11.50.FC8, AIX, ON-Bar/TSM) tried a point-in-time restore of an archive that had been restored to an interim box and re-archived (to stop it ageing off TSM). The physical restore succeeded, but the logical restore aborted with "Checkpoint Record not Found in Logical Log" and an engine assert. Art Kagel explained that the restored logs apparently contained no checkpoint for the logical recovery to roll back to, and suggested a full/whole-system archive, which begins with a checkpoint; David recommended onbar -w for a cross-dbspace checkpoint. Mark noted the archive had already been taken with -b -w, and in his final post reported the assert still occurred, so no resolution is recorded.
Auto-generated by DrWatson from the posts below — may be imperfect; read the full thread.
Need another set of eyes on something I've done numerous times in the past.
Engine assert failing on logical restore (physical worked fine) ... my
apologies for length of the "setup" below:
IDS 11.5.FC8/AIX 7.1; onbar; TSM
1. Archive exists on TSM dated 4/24 for production:engine_a. These archives
roll off TSM after 10 days.
2. restored 4/24 image to test_box_1:engine_b.
3. Took a full archive to TSM of engine_b (to preserve it for a future restore
to test_box_2 of the 4/24 image. It won't get pushed off since it's the only
archive out there for engine_b. )
4. moved ixbar.1 to test_box_2.
5. did point-in-time restore of test_box_2:engine_b ("onbar -r -t <timestamp>"
in ixbar.1 correlates/matches the 4/24 image - it's the time of the archive of
course, not "2015-04-24").
6. Physical restore works fine.
7. Logical restore blows up and knocks the engine over.
The message "Checkpoint Record not found in logical log" is the first issue.
Is this a obvious as I think it is? ie: the logical log that being reapplied
simply doesn't have a checkpoint? I still wouldn't expect this result.
message log below:
15:48:08 Start Logical Recovery - Start Log 546324, End Log ?
15:48:08 Starting Log Position - 546324 0xaeb4018
15:48:08 Clearing the physical and logical logs has started
15:50:22 Cleared 68965 MB of the physical and logical logs in 134 seconds
15:50:26 Checkpoint Record not Found in Logical Log.
15:50:26 Logical Recovery ABORTED.
Aborted by client.
15:50:27 Assert Failed: Logical Recovery ABORTED.
Dynamic Server must abort
15:50:27 IBM Informix Dynamic Server Version 11.50.FC8
bar_act.log below:
2015-05-13 15:48:59 22282414 14811280 Begin restore logical log 546324
(Storage Manager copy ID: 0 929145123).
2015-05-13 15:50:26 22282414 14811280 Unable to write storage space restore
data to the database server: .
2015-05-13 15:50:30 22282414 14811280 Unable to close the storage space
restore: buc_fe.c : Archive API processing failed at line 945 for msgtype.
2015-05-13 15:50:30 22282414 14811280 /home/informix/prod/bin/onbar_d
complete, returning 131 (0x83)
The onbar command is: onbar -r -t "2015-05-07 04:15:52"
I believe I had tried a physical-only and will try it again next (the restore
takes about 5 hours so ...).
Another point: I'm actually doing this for 2 engines. One working fine, the
other blowing up. I suspect it's simply an issue with the specific log trying
to be applied.
Thanks in advance -
Mark Scranton
The Mark Scranton Group
www.markscranton.com
mark@markscranton.com
More likely NONE of the restore logical logs contains a checkpoint for the
logical restore to roll back to before starting the log roll forward. It
may be that the server has so few logical logs that it is possible that
none of the logs on disk at the time of the archive contained a checkpoint!
The logical restore portion of a point-in-time restore needs to rollback
all dbspaces to the last checkpoint it knows about (so that is recorded in
the logical logs on disk after the physical restore) then begin rolling
forward the logs up to the desired point-in-time.
Art
Art S. Kagel, President and Principal Consultant
ASK Database Management
www.askdbmgt.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 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 Wed, May 13, 2015 at 6:26 PM, MARK SCRANTON <mark@markscranton.com>
wrote:
> Need another set of eyes on something I've done numerous times in the past.
> Engine assert failing on logical restore (physical worked fine) ... my
> apologies for length of the "setup" below:
>
> IDS 11.5.FC8/AIX 7.1; onbar; TSM
>
> 1. Archive exists on TSM dated 4/24 for production:engine_a. These archives
> roll off TSM after 10 days.
> 2. restored 4/24 image to test_box_1:engine_b.
> 3. Took a full archive to TSM of engine_b (to preserve it for a future
> restore
> to test_box_2 of the 4/24 image. It won't get pushed off since it's the
> only
> archive out there for engine_b. )
> 4. moved ixbar.1 to test_box_2.
> 5. did point-in-time restore of test_box_2:engine_b ("onbar -r -t
> <timestamp>"
> in ixbar.1 correlates/matches the 4/24 image - it's the time of the
> archive of
> course, not "2015-04-24").
> 6. Physical restore works fine.
> 7. Logical restore blows up and knocks the engine over.
>
> The message "Checkpoint Record not found in logical log" is the first
> issue.
> Is this a obvious as I think it is? ie: the logical log that being
> reapplied
> simply doesn't have a checkpoint? I still wouldn't expect this result.
>
> message log below:
>
> 15:48:08 Start Logical Recovery - Start Log 546324, End Log ?
> 15:48:08 Starting Log Position - 546324 0xaeb4018
> 15:48:08 Clearing the physical and logical logs has started
> 15:50:22 Cleared 68965 MB of the physical and logical logs in 134 seconds
> 15:50:26 Checkpoint Record not Found in Logical Log.
> 15:50:26 Logical Recovery ABORTED.
>
> Aborted by client.
> 15:50:27 Assert Failed: Logical Recovery ABORTED.
>
> Dynamic Server must abort
> 15:50:27 IBM Informix Dynamic Server Version 11.50.FC8
>
> bar_act.log below:
>
> 2015-05-13 15:48:59 22282414 14811280 Begin restore logical log 546324
> (Storage Manager copy ID: 0 929145123).
> 2015-05-13 15:50:26 22282414 14811280 Unable to write storage space restore
> data to the database server: .
> 2015-05-13 15:50:30 22282414 14811280 Unable to close the storage space
> restore: buc_fe.c : Archive API processing failed at line 945 for msgtype.
> 2015-05-13 15:50:30 22282414 14811280 /home/informix/prod/bin/onbar_d
> complete, returning 131 (0x83)
>
> The onbar command is: onbar -r -t "2015-05-07 04:15:52"
>
> I believe I had tried a physical-only and will try it again next (the
> restore
> takes about 5 hours so ...).
>
> Another point: I'm actually doing this for 2 engines. One working fine, the
> other blowing up. I suspect it's simply an issue with the specific log
> trying
> to be applied.
>
> Thanks in advance -
> Mark Scranton
> The Mark Scranton Group
> www.markscranton.com
> mark@markscranton.com
>
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
>
--001a113efd6228a7100515fe58a7
Thanks Art. This engine of the original archive burns through about 90 logical logs per day. BUT to your point ... I did the restore of the older image, did the archive right away on the test box, which was very quiet and most likely hadn't marched through any logs. If that was the case, I assume what you're saying is correct. That also explains why when I was trying this and pointing to a specific log it also failed. I had also considered a whole system archive/restore to avoid logs altogether. Perhaps I should have used that approach? Thanks - Mark
Ya, a full restore from a full archive would likely work because the full archive starts with a checkpoint. A parallel archive would probably have the same problem as the PIT restore since the dbspace archives all start at different times there is no "archive" checkpoint, so any restore of a parallel archive needs to rollback some things to the last known checkpoint which would have to be in the logs that are restored along with the rootdbs and logical log dbspace. Art Art S. Kagel, President and Principal Consultant ASK Database Management www.askdbmgt.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 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 Wed, May 13, 2015 at 6:51 PM, MARK SCRANTON <mark@markscranton.com> wrote: > Thanks Art. > > This engine of the original archive burns through about 90 logical logs per > day. BUT to your point ... I did the restore of the older image, did the > archive right away on the test box, which was very quiet and most likely > hadn't marched through any logs. If that was the case, I assume what you're > saying is correct. That also explains why when I was trying this and > pointing > to a specific log it also failed. I had also considered a whole system > archive/restore to avoid logs altogether. Perhaps I should have used that > approach? > > Thanks - > Mark > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001a113efd62dc85ef0515fed048
Two things hit me on the drive home: 1) you already mentioned - I was thinking a full archive will force a checkpoint first. 2) I thought I had done this "numerous times" as I mentioned. But the other times (during a multi-box hardware migration) there wasn't the "hop" between the restore from production and the target box. So any logical logs needed were still available from TSM as needed. To state the objective simply: to restore test_box_A from a production image of say 0424 a few weeks after 0424. But - that image will roll off of TSM after 10 days. So it needs to be "captured" so it doesn't disappear. Thus the middle restore/archive step. On IDS 11.5 so that might limit our choices. Anyone? Thanks - Mark
What is the backup command which is used?
If you have an unlogged database on the server the onbar command must include
-w
otherwise you can get restore errors similar to the one you are seeing.
Regards,
David.
> On 14 May 2015 at 01:36 MARK SCRANTON <mark@markscranton.com> wrote:
>
>
> Two things hit me on the drive home: 1) you already mentioned - I was
thinking
> a full archive will force a checkpoint first. 2) I thought I had done this
> "numerous times" as I mentioned. But the other times (during a multi-box
> hardware migration) there wasn't the "hop" between the restore from
production
> and the target box. So any logical logs needed were still available from TSM
> as needed.
>
> To state the objective simply: to restore test_box_A from a production image
> of say 0424 a few weeks after 0424. But - that image will roll off of TSM
> after 10 days. So it needs to be "captured" so it doesn't disappear. Thus the
> middle restore/archive step.
>
> On IDS 11.5 so that might limit our choices. Anyone?
>
> Thanks -
> Mark
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
onbar -w is needed to get the checkpoint across all dbspaces at the start ofthe
archive.
In later IDS versions onbar -w was made parallel, I can't find exactly when in
the release notes at the moment!
Regards,
David.
> On 14 May 2015 at 00:17 Art Kagel <art.kagel@gmail.com> wrote:
>
>
> Ya, a full restore from a full archive would likely work because the full
> archive starts with a checkpoint. A parallel archive would probably have
> the same problem as the PIT restore since the dbspace archives all start at
> different times there is no "archive" checkpoint, so any restore of a
> parallel archive needs to rollback some things to the last known checkpoint
> which would have to be in the logs that are restored along with the rootdbs
> and logical log dbspace.
>
> Art
>
> Art S. Kagel, President and Principal Consultant
> ASK Database Management
> www.askdbmgt.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 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 Wed, May 13, 2015 at 6:51 PM, MARK SCRANTON <mark@markscranton.com>
> wrote:
>
> > Thanks Art.
> >
> > This engine of the original archive burns through about 90 logical logs per
> > day. BUT to your point ... I did the restore of the older image, did the
> > archive right away on the test box, which was very quiet and most likely
> > hadn't marched through any logs. If that was the case, I assume what you're
> > saying is correct. That also explains why when I was trying this and
> > pointing
> > to a specific log it also failed. I had also considered a whole system
> > archive/restore to avoid logs altogether. Perhaps I should have used that
> > approach?
> >
> > Thanks -
> > Mark
> >
> >
> >
> >
>
*******************************************************************************
> > Forum Note: Use "Reply" to post a response in the discussion forum.
> >
> >
>
> --001a113efd62dc85ef0515fed048
>
>
>
*******************************************************************************
> Forum Note: Use "Reply" to post a response in the discussion forum.
>
David - Thanks - the original archive was a whole system (onbar_d -b -w) as per the bar_act.log. I had tried a couple of different approaches, and the whole system was what I thought was the best originally, but thought I had scrapped it. And it makes sense with what we're seeing. Thanks to all for responding - Mark Scranton The Mark Scranton Group
Oddly enough - it isn't the issue of the type of backup/restore (whole system versus "normal"). The engine continues to fall over with an assertion failure. Still working on it. Thanks - Mark