Topic: Flexbackup again...

[Thomas Kristensen]

Hi everybody,

I'm in deep trouble and if you can help I'll name my children after you...

SME 5.5 Update 2 - freshly installed. Restore from OnStream DI-30 tapebackup that has been running every night for the past 2 months.

Backup configured through the server-manager and I'm trying to restore through the server-manager. The DI-30 drive was setup using Dave Helmuth's exellent HOW-TO at http://www.helmuth.net/mitel-sme/FlexDI30/FlexDI30.html.

When I activate the restore these entries show up in the messages logfile:

Oct 16 12:38:48 frodo e-smith[2384]: Processing event: restore-tape
Oct 16 12:38:48 frodo e-smith[2384]: Running event handler: /etc/e-smith/events/restore-tape/S10tape-restore-flexbackup
Oct 16 12:39:27 frodo kernel: osst: recording read error at 2991
Oct 16 12:40:38 frodo kernel: osst0: Filemark lookup: prev mark -1 (match), skip 1 to 11
Oct 16 12:40:38 frodo kernel: osst0: Expected to find marker at block 11, not found
Oct 16 12:41:05 frodo e-smith[2384]: Tape restore failed: could not position tape at /dev/nst0.
Oct 16 12:41:05 frodo e-smith[2384]: S10tape-restore-flexbackup=action|Event|restore-tape|Action|S10tape-restore-flexbackup|Start|1034764728 924642|End|1034764865 540539|Elapsed|136.615897|Status|7424
Oct 16 12:41:05 frodo e-smith[2384]: Running event handler: /etc/e-smith/events/restore-tape/S50rewind-tape
Oct 16 12:41:34 frodo e-smith[2384]: S50rewind-tape=action|Event|restore-tape|Action|S50rewind-tape|Start|1034764865 541160|End|1034764894 305705|Elapsed|28.764545

I cycle through tapes on a regular basis and each and every one I get these errors. So I went and tried a manual restore as described on http://myezserver.com/downloads/mitel/howto/flexbackup-howto.html.

/bin/mt -f /dev/nst0 rewind    
/bin/mt -f /dev/nst0 fsf 1

After the second command I get an Input/Output error on the nst0 device and, needles to say, the restore itself doesn't work.

I've been searching these forums but have been unable to turn up sufficient info. What am I doing wrong????

Thanks in advance,
Thomas Kristensen

[jb]

What is the exact I/O error?  Can you do a flexbackup -toc?  Can you do a flexbackup - list.  Post any errors.  I'm not sure I can help, but I will try.

JB

[jb]

What is the exact I/O error?  Can you do a flexbackup -toc?  Can you do a flexbackup - list.  Post any errors.  I'm not sure I can help, but I will try.

JB

[jb]

What is the exact I/O error?  Can you do a flexbackup -toc?  Can you do a flexbackup - list.  Post any errors.  I'm not sure I can help, but I will try.

JB

[Darrell May]

My guess and only my guess at this point.... your backups may have never worked.  The only way to tell would be to review your latest backup report(s).  The key is understanding what the report tells you.  Pay attention to the tape position references.  This is the first key to determining if your backup is correctly positioning the tape, appending the backup sets and actually backing up data to the correct tape postion.

For instance if you review /sbin/e-smith/backup you will see that the first tape action is to write a block of data to the tape using dd.  This should position the tape somewhere after 0, different for each tape drive.  On an Seagate 20GB IDE this moves to block 85.  Then the first backup session is to place / on tape.  This will occur starting at the tape postion above, in this case 85.  The next backup session is /boot.  This will occur at a tape position much after 85, based on how much data was backed up.  Example: block 10845 or some other large number.

Once it is determined that your backup log looks right, then the only test that verifies the backup works is to delete a directory and perform a restore.  If the restore works you can be confident your backup works.  If the restore does not work, well chances are your backup never worked in the first place.

You can use the command line to position the tape and list the contents at each tape position following the HowTo.

Darrell

[David Helmuth]

I think that Darrell is right on, but then he usually is.

Here is an example from my backup tape and log from last night...

******
flexbackup version 0.9.8
/etc/flexbackup.conf syntax OK

|------------------------------------------------
| Doing level 0 backup of all using dump
| Retensioning tape...
| Rewinding & erasing tape...
| Creating index key 200210152313.18
| Tape #0
| Filesystems = / /boot
|------------------------------------------------
At block 13.
|------------------------------------------------
| File number 1, index key 200210152313.18
| Backup of: /
| Date of this level 0 backup: Tue Oct 15 23:15:45 2002
| Date of last level 0 backup: the epoch
|------------------------------------------------
| (dump -0 -b 32 -a -f - / | gzip -4) | buffer -m 3m -s 32k -u 100 -t -p 75 -B \
|  -o /dev/nst0
|------------------------------------------------
  DUMP: Date of this level 0 dump: Tue Oct 15 23:15:46 2002
  DUMP: Date of last level 0 dump: the epoch
  DUMP: Dumping /dev/hde6 (/) to standard output
  DUMP: Label: none
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 2671169 tape blocks.
  DUMP: Volume 1 started at: Tue Oct 15 23:18:22 2002
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
  DUMP: 4.74% done, finished in 1:40
  DUMP: 15.16% done, finished in 0:55
  DUMP: 24.78% done, finished in 0:45
  etc....
*****

In particular look at the line that says "At Block 13"  That is the point on the tape that says where the first data is being written.  Now I don't know if this makes sense or not, but I have seen that float between 10 and 13 on my 4 different tapes that I rotate.  (I think this osst.o relocating data if it thinks it finds a "media error")  What you need to do is determine where that is for this tape you are trying to restore.

Now I too used Darrel's How-To mentioned above to create the following shell script that I use to restore files if I need to.

*****  restore-list.sh

cd /root
mkdir restore-list
cd restore-list
/bin/mt -f "/dev/nst0" rewind
flexbackup -list
/usr/bin/flexbackup -extract -files /root/flexbackup/extract-list
/bin/mt -f "/dev/nst0" rewind

*****
Note that I used "flexbackup -list" rather than a "/bin/mt -f /dev/nst0 fsf 1".  I think the reason I did that was because that "flexbackup -list" helped me find that first block on the tape easier.

Now it have been a while since I did a restore, but I running a quick as I am writing this.  I just checked on it and it did restore the files I told it to.  It is still running, but I will report back if it acts "funny" in any way.

I hope some of this helps!  Please let me know how it goes!

[JB]

As you can see from last night, I was experiencing toddler issues.  Sorry for all the posts.  I was trying to make the exact point Darell made.  I wanted to see what the block size was set at, what the tape position was, and where in the backup the I/O errors were occurring.  I had a similar issue with this.  Mine ended up being that my tape was full so it couldn't write any more data.  After a little bit of cleaning up, my issues were resolved.

[Thomas Kristensen]

Hi all,

Thanks for all your input. My backup log from last night looks very much like yours, Dave, but if I try your restore shell script this is what I get:

[root@frodo restore-list]# /bin/mt -f "/dev/nst0" rewind                        [root@frodo restore-list]# flexbackup -list                                    
flexbackup version 0.9.8
/etc/flexbackup.conf syntax OK

|------------------------------------------------
| Reading from current tape position
|------------------------------------------------
At block 10.
|------------------------------------------------
| buffer -m 24m -s 32k -u 100 -t -p 75 -B -i /dev/nst0 | gzip -dq | restore -t \
|  -v -b 32 -f -
|------------------------------------------------
gzip: stdin: not in gzip format
restore: Tape read error on first record
Verify tape and initialize maps
Input is from file/pipe
|------------------------------------------------
At block 13.
|------------------------------------------------

The backup log from last night look like this:
flexbackup version 0.9.8
/etc/flexbackup.conf syntax OK

|------------------------------------------------
| Doing level 0 backup of all using dump
| Retensioning tape...
| Rewinding & erasing tape...
| Creating index key 200210170216.08
| Tape #0
| Filesystems = / /boot
|------------------------------------------------
At block 13.
|------------------------------------------------
| File number 1, index key 200210170216.08
| Backup of: /
| Date of this level 0 backup: Thu Oct 17 02:18:36 2002
| Date of last level 0 backup: the epoch
|------------------------------------------------
| (dump -0 -b 32 -a -f - / | gzip -4) | buffer -m 24m -s 32k -u 100 -t -p 75 \
|  -B -o /dev/nst0
|------------------------------------------------
  DUMP: Date of this level 0 dump: Thu Oct 17 02:18:36 2002
  DUMP: Dumping /dev/md1 (/) to standard output
  DUMP: Added inode 7 to exclude list (resize inode)
  DUMP: Label: /1
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 1567300 tape blocks.
  DUMP: Volume 1 started with block 1 at: Thu Oct 17 02:22:48 2002
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
  DUMP: 17.92% done at 936 kB/s, finished in 0:22
  DUMP: 31.92% done at 833 kB/s, finished in 0:21
  DUMP: 47.33% done at 824 kB/s, finished in 0:16
  DUMP: 62.50% done at 816 kB/s, finished in 0:12
  DUMP: 77.22% done at 806 kB/s, finished in 0:07
  DUMP: 93.15% done at 811 kB/s, finished in 0:02
  DUMP: Volume 1 completed at: Thu Oct 17 02:55:14 2002
  DUMP: Volume 1 1598304 tape blocks (1560.84MB)
  DUMP: Volume 1 took 0:32:26
  DUMP: Volume 1 transfer rate: 821 kB/s
  DUMP: 1598304 tape blocks (1560.84MB)
  DUMP: finished in 1946 seconds, throughput 821 kBytes/sec
  DUMP: Date of this level 0 dump: Thu Oct 17 02:18:36 2002
  DUMP: Date this dump completed:  Thu Oct 17 02:55:14 2002
  DUMP: Average transfer rate: 821 kB/s
  DUMP: DUMP IS DONE
Kilobytes Out 1233984
|------------------------------------------------
| Backup start: Thu Oct 17 02:18:36 2002
| Backup end:   Thu Oct 17 02:57:51 2002
|------------------------------------------------
At block 38586.
|------------------------------------------------
| File number 2, index key 200210170216.08
| Backup of: /boot
| Date of this level 0 backup: Thu Oct 17 02:58:25 2002
| Date of last level 0 backup: the epoch
|------------------------------------------------
| (dump -0 -b 32 -a -f - /boot | gzip -4) | buffer -m 24m -s 32k -u 100 -t -p \
|  75 -B -o /dev/nst0
|------------------------------------------------
  DUMP: Date of this level 0 dump: Thu Oct 17 02:58:25 2002
  DUMP: Dumping /dev/md0 (/boot) to standard output
  DUMP: Added inode 7 to exclude list (resize inode)
  DUMP: Label: /boot1
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 2992 tape blocks.
  DUMP: Volume 1 started with block 1 at: Thu Oct 17 02:58:25 2002
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
  DUMP: Volume 1 completed at: Thu Oct 17 02:58:29 2002
  DUMP: Volume 1 2976 tape blocks (2.91MB)
  DUMP: Volume 1 took 0:00:04
  DUMP: Volume 1 transfer rate: 744 kB/s
  DUMP: 2976 tape blocks (2.91MB)
  DUMP: finished in 4 seconds, throughput 744 kBytes/sec
  DUMP: Date of this level 0 dump: Thu Oct 17 02:58:25 2002
  DUMP: Date this dump completed:  Thu Oct 17 02:58:29 2002
  DUMP: Average transfer rate: 744 kB/s
  DUMP: DUMP IS DONE
Kilobytes Out 1760
|------------------------------------------------
| Backup start: Thu Oct 17 02:58:25 2002
| Backup end:   Thu Oct 17 03:00:57 2002
|------------------------------------------------
At block 38642.
|------------------------------------------------
| Rewinding...
| Compressing log (all.0.20021017.gz)
| Linking all.latest.gz -> all.0.20021017.gz
|------------------------------------------------

File  Contents    (tape index 200210170216.08)
-----------------------------------------------
0  
1   level 0 / Thu Oct 17 02:18:36 2002 dump+gzip from frodo
2   level 0 /boot Thu Oct 17 02:58:25 2002 dump+gzip from frodo

All I want for future events is a backup that I can actually restore. Please, if you have a bulletproof setup I would really like to hear about it...

Cheers,
Thomas

[David Helmuth]

I am not sure why, but the way I am reading your log file and the output from the "restore script", it looks like we still haven't gotten the tape to position at "Block 13", which is where your log file says that it started writing the first backup.

Try taking that script file and duplicating the line that reads:

/usr/bin/flexbackup -extract -files /root/flexbackup/extract-list

and putting that in the file 2 time in a row like:

/usr/bin/flexbackup -extract -files /root/flexbackup/extract-list
/usr/bin/flexbackup -extract -files /root/flexbackup/extract-list

What I am hoping that does is make flexbackup start reading from Block 13, which is where it leaves you after complaining about reading from Block 10.

RE:  When you run the "restore-list.sh"

You are getting something reads:

gzip: stdin: not in gzip format
restore: Tape read error on first record
Verify tape and initialize maps
Input is from file/pipe

What I get is the following, it is

gzip: stdin: not in gzip format
restore: Tape is not a dump tape
Verify tape and initialize maps
End-of-tape encountered

Notice the two "restore lines" are different.  I am not exactly sure about what/why the differences mean.  Anyone else familiar with "restore"?  I am still assuming the most important part of this is to get the tape drive to "position" to the correct place first.

One other thing I noticed in your log files.  There is a message about adding inode 7 to an exclude list.  I am not sure, but I think that you would want to run fsck and/or investigate if you have disk irregularites.

RE:  Bulletproof setup.  I think I hear some frustration with how difficult this is.  I would completely agree with you!  If you are looking for bullet proof, I would suggest that you dump the DI30 and purchase a more directly supported tape drive.  (SCSI - or one of the IDE's that are on the "supported" list.)  Right now, the DI30 is NOT supported by MITEL, in fact they say it will not work.  However, since I already had a DI30 laying around and didn't want to spend $600-$700 for a good tape drive for my home machines, it seemed reasonable to try and make it work.

Thanks and please put back any findings!

[Darrell May]

David Helmuth wrote:
> I would suggest that you dump the DI30 and purchase a more directly
> supported tape drive.

The answer is not to replace hardware but simply to configure flexbackup correctly for each unique tape drive specifics requirements.

Unfortunately this is not easy for someone that is not familiar with the SME template system and flexbackup.

I have opened a bug report with Mitel and have sent them updates to make this entire process easier.  They have replied that they are reviewing my updates so a resolution should be coming soon.

Regards,

Darrell

[Thomas Kristensen]

Well, well, well, whaddaya know... All it takes is a little tinkering with the tape, a little swearing, some threats and a few kicks administered to the pc and it all works

My restore sequence is like this:

1) /bin/mt -f "/dev/nst0" rewind
2) flexbackup -list (this fails)
3) flexbackup -list (this works)
4) edit the flexbackup.list.log and save as extract-files
5) /bin/mt -f "/dev/nst0" rewind
6) flexbackup -list (fails but positions the tape)
7) flexbackup -extract -files ./extract-files

This restores the files in extract-files.

I tried to restore the entire server using "flexbackup -extract" from the / directory, but this is apparently NOT a good idea since it completely crashed the server. And to make my day complete, I reinstalled and restored it once more and crashed once more

I'll have to agree with Darrell that dumping hardware is not a way forward. The DI30 is an inexpensive tape drive well suited for small home servers like my own. And the DI30 apparently works once you figure out how. It would be great though if Mitel were to incorporate better support, ie make it possible to restore from server-manager what you backed up from server-manager...

Thanks for all your help, guys...

Cheers,
Thomas