Topic: Nice Input No Output On Tape

[Kenneth Pepiton]

We've recently installed a Seagate Hornet 20/40 GB Tape Drive (STT22000) into our SME 5.5 Server and configured it to back up onto the tape.  We've been trying to figure out why it isn't working correctly with its default settings.  We've tried other suggestions on modifying the size of the blocks.  We were able to do a successful backup using /dev/st0 with everytime is accessed of course goes back to the beginning to the tape and rewrites the data over the other backup.  We're able to rewind the tape manually and erase manually.  I've included the status of the drive and the backup log.

Any suggestions would be helpful.

*********************************************************************
[root@server /root]# mt -f /dev/nst0 stat
SCSI 2 tape drive:
File number=0, block number=0, partition=0.
Tape block size 512 bytes. Density code 0x0 (default).
Soft error count since last status=0
General status bits on (41010000):
 BOT ONLINE IM_REP_EN

*********************************************************************
[root@server /root]# /sbin/e-smith/backup

flexbackup version 0.9.8
/etc/flexbackup.conf syntax OK

|------------------------------------------------
| Trying "mt defblksize" instead of "mt setblk"
| Doing level 0 backup of all using dump
| Retensioning tape...
| Rewinding & erasing tape...
/dev/nst0: Input/output error
| Creating index key 200210101341.50
| Tape #0
| Filesystems = / /boot
|------------------------------------------------
At block 64.
|------------------------------------------------
| File number 1, index key 200210101341.50
| Backup of: /
| Date of this level 0 backup: Thu Oct 10 13:41:50 2002
| Date of last level 0 backup: the epoch
|------------------------------------------------
| (dump -0 -b 10 -a -f - / | gzip -4) | buffer -m 3m -s 10k -u 100 -t -p 75 -B \
|  -o /dev/nst0
|------------------------------------------------
  DUMP: Date of this level 0 dump: Thu Oct 10 13:41:50 2002
  DUMP: Date of last level 0 dump: the epoch
  DUMP: Dumping /dev/md1 (/) to standard output
  DUMP: Label: none
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 8366001 tape blocks.
  DUMP: Volume 1 started at: Thu Oct 10 13:43:22 2002
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
buffer (writer): write of data failed: Input/output error
bytes to write=10240, bytes written=-1, total written         30K
  DUMP: Broken pipe
  DUMP: The ENTIRE dump is aborted.
|------------------------------------------------
| Backup start: Thu Oct 10 13:41:50 2002
| Backup end:   Thu Oct 10 13:44:25 2002
|------------------------------------------------
At block 64.
|------------------------------------------------
| File number 2, index key 200210101341.50
| Backup of: /boot
| Date of this level 0 backup: Thu Oct 10 13:44:36 2002
| Date of last level 0 backup: the epoch
|------------------------------------------------
| (dump -0 -b 10 -a -f - /boot | gzip -4) | buffer -m 3m -s 10k -u 100 -t -p \
|  75 -B -o /dev/nst0
|------------------------------------------------
  DUMP: Date of this level 0 dump: Thu Oct 10 13:44:36 2002
  DUMP: Date of last level 0 dump: the epoch
  DUMP: Dumping /dev/md0 (/boot) to standard output
  DUMP: Label: none
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 2945 tape blocks.
  DUMP: Volume 1 started at: Thu Oct 10 13:44:37 2002
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
  DUMP: Volume 1 completed at: Thu Oct 10 13:44:38 2002
  DUMP: Volume 1 took 0:00:01
  DUMP: Volume 1 transfer rate: 2937 KB/s
  DUMP: 2937 tape blocks (2.87MB)
  DUMP: finished in 1 seconds, throughput 2937 KBytes/sec
  DUMP: Date of this level 0 dump: Thu Oct 10 13:44:36 2002
  DUMP: Date this dump completed:  Thu Oct 10 13:44:38 2002
  DUMP: Average transfer rate: 2937 KB/s
  DUMP: DUMP IS DONE
buffer (writer): write of data failed: Input/output error
bytes to write=10240, bytes written=-1, total written          0K
|------------------------------------------------
| Backup start: Thu Oct 10 13:44:36 2002
| Backup end:   Thu Oct 10 13:44:38 2002
|------------------------------------------------
At block 64.
|------------------------------------------------
| Rewinding...
| Compressing log (all.0.20021010.gz)
| Linking all.latest.gz -> all.0.20021010.gz
|------------------------------------------------

File  Contents    (tape index 200210101341.50)
-----------------------------------------------
0  
1   level 0 / Thu Oct 10 13:41:50 2002 dump+gzip from server
2   level 0 /boot Thu Oct 10 13:44:36 2002 dump+gzip from server
******************************

[Darrell May]

Kenneth Pepiton wrote:
>
> We were able to do a successful backup using /dev/st0

How about posting your successful /dev/st0 report.  The one you posted using /dev/nst0 above was definitely not successful at all.

> DUMP: Broken pipe
> DUMP: The ENTIRE dump is aborted.

Darrell

[Kenneth Pepiton]

This was the successful /dev/st0 backup (/dev/tape is a symlink to /dev/st0)
**********************
|------------------------------------------------
| Trying "mt defblksize" instead of "mt setblk"
| Doing level 0 backup of all using dump
| Retensioning tape...
| Rewinding & erasing tape...
| Creating index key 200210090033.59
| Tape #0
| Filesystems = / /boot
|------------------------------------------------
At block 0.
|------------------------------------------------
| File number 1, index key 200210090033.59
| Backup of: /
| Date of this level 0 backup: Wed Oct 09 00:34:17 2002
| Date of last level 0 backup: the epoch
|------------------------------------------------
| (dump -0 -b 10 -a -f - / | gzip -4) | buffer -m 3m -s 10k -u 100 -t -p 75 -B \
|  -o /dev/tape
|------------------------------------------------
  DUMP: Date of this level 0 dump: Wed Oct  9 00:34:17 2002
  DUMP: Date of last level 0 dump: the epoch
  DUMP: Dumping /dev/md1 (/) to standard output
  DUMP: Label: none
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 8356906 tape blocks.
  DUMP: Volume 1 started at: Wed Oct  9 00:35:45 2002
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
  DUMP: 2.54% done, finished in 3:12
  DUMP: 5.01% done, finished in 3:09
  DUMP: 8.08% done, finished in 2:50
  DUMP: 10.41% done, finished in 2:52
  DUMP: 12.88% done, finished in 2:49
  DUMP: 14.97% done, finished in 2:50
  DUMP: 17.85% done, finished in 2:41
  DUMP: 20.25% done, finished in 2:37
  DUMP: 22.59% done, finished in 2:34
  DUMP: 25.16% done, finished in 2:28
  DUMP: 27.07% done, finished in 2:28
  DUMP: 29.08% done, finished in 2:26
  DUMP: 31.60% done, finished in 2:20
  DUMP: 34.05% done, finished in 2:15
  DUMP: 36.42% done, finished in 2:10
  DUMP: 38.69% done, finished in 2:06
  DUMP: 41.01% done, finished in 2:02
  DUMP: 43.76% done, finished in 1:55
  DUMP: 45.92% done, finished in 1:51
  DUMP: 48.38% done, finished in 1:46
  DUMP: 51.00% done, finished in 1:40
  DUMP: 53.70% done, finished in 1:34
  DUMP: 56.30% done, finished in 1:29
  DUMP: 58.86% done, finished in 1:23
  DUMP: 61.80% done, finished in 1:17
  DUMP: 64.20% done, finished in 1:12
  DUMP: 66.88% done, finished in 1:06
  DUMP: 70.17% done, finished in 0:59
  DUMP: 72.79% done, finished in 0:54
  DUMP: 75.26% done, finished in 0:49
  DUMP: 77.34% done, finished in 0:45
  DUMP: 80.65% done, finished in 0:38
  DUMP: 83.07% done, finished in 0:33
  DUMP: 85.59% done, finished in 0:28
  DUMP: 88.30% done, finished in 0:23
  DUMP: 90.97% done, finished in 0:17
  DUMP: 93.46% done, finished in 0:12
  DUMP: 95.54% done, finished in 0:08
  DUMP: 97.88% done, finished in 0:04
  DUMP: 99.83% done, finished in 0:00
  DUMP: Volume 1 completed at: Wed Oct  9 03:59:28 2002
  DUMP: Volume 1 took 3:23:43
  DUMP: Volume 1 transfer rate: 692 KB/s
  DUMP: 8466764 tape blocks (8268.32MB)
  DUMP: finished in 12223 seconds, throughput 692 KBytes/sec
  DUMP: Date of this level 0 dump: Wed Oct  9 00:34:17 2002
  DUMP: Date this dump completed:  Wed Oct  9 03:59:28 2002
  DUMP: Average transfer rate: 692 KB/s
  DUMP: DUMP IS DONE
Kilobytes Out 5957750
|------------------------------------------------
| Backup start: Wed Oct 09 00:34:17 2002
| Backup end:   Wed Oct 09 04:00:21 2002
|------------------------------------------------
At block 0.
|------------------------------------------------
| File number 2, index key 200210090033.59
| Backup of: /boot
| Date of this level 0 backup: Wed Oct 09 04:00:37 2002
| Date of last level 0 backup: the epoch
|------------------------------------------------
| (dump -0 -b 10 -a -f - /boot | gzip -4) | buffer -m 3m -s 10k -u 100 -t -p \
|  75 -B -o /dev/tape
|------------------------------------------------
  DUMP: Date of this level 0 dump: Wed Oct  9 04:00:37 2002
  DUMP: Date of last level 0 dump: the epoch
  DUMP: Dumping /dev/md0 (/boot) to standard output
  DUMP: Label: none
  DUMP: mapping (Pass I) [regular files]
  DUMP: mapping (Pass II) [directories]
  DUMP: estimated 2945 tape blocks.
  DUMP: Volume 1 started at: Wed Oct  9 04:00:38 2002
  DUMP: dumping (Pass III) [directories]
  DUMP: dumping (Pass IV) [regular files]
  DUMP: Volume 1 completed at: Wed Oct  9 04:00:40 2002
  DUMP: Volume 1 took 0:00:02
  DUMP: Volume 1 transfer rate: 1468 KB/s
  DUMP: 2937 tape blocks (2.87MB)
  DUMP: finished in 2 seconds, throughput 1468 KBytes/sec
  DUMP: Date of this level 0 dump: Wed Oct  9 04:00:37 2002
  DUMP: Date this dump completed:  Wed Oct  9 04:00:40 2002
  DUMP: Average transfer rate: 1468 KB/s
  DUMP: DUMP IS DONE
Kilobytes Out 1740
|------------------------------------------------
| Backup start: Wed Oct 09 04:00:37 2002
| Backup end:   Wed Oct 09 04:00:57 2002
|------------------------------------------------
At block 0.
|------------------------------------------------
| Rewinding...
|------------------------------------------------

[Roger Oswills]

This appears to be a bug in Mitel's software.  They refuse to admit it, but many people have the same problem with flexbackup not getting a proper backup.

It fails on the first attempt, and is successful on the second.  This is true especially if you change tapes or reboot the server.

[Wayne Bollinger]

To work around the problem of backups failing on the first attempt, I made a copy of the /sbin/e-smith/backup script (with nightly backups enabled), then added a few lines at the top of the script to "wake up" the Travan 10/20 SCSI drive:

# First wake up the tape drive - usually seems to timeout loading
# the SCSI modules on the first attempt

echo "Waking up tape drive"
/bin/mt -f "/dev/st0" tell >/dev/null 2>&1
echo "Waiting 15 seconds..."
sleep 15


With this addition, the backups work every time, on the first try.  I've disabled the SME built-in nightly backups, and fire off my own script manually or from a cron job.  It would probably be cleaner to do this via a custom template fragment, which I haven't investigated.

-Wayne

[Darrell May]

I've just spent some time looking into issues I experienced with a new install of an Onstream ADR2.60 ide TBU.  This may help as there are some similarities in your report.  Basically the backup failed with:

DUMP: Broken pipe
DUMP: The ENTIRE dump is aborted.

I was unable to get a 'dump' backup to work.  For testing I changed the following /etc/flexbackup.conf variables:

$blksize = '32';
$erase_rewind_only = 'false';
$erase_tape_all_level_zero = 'false';
$type = 'tar';

Note your 'blksize' should match your drive specifics.  The Onstream uses 32.

I then altered /sbin/e-smith/backup as follows:

[root@test e-smith]# cat backup
#!/bin/sh

#------------------------------------------------------------
# DO NOT MODIFY THIS FILE! It is updated automatically by the
# e-smith server and gateway software. Instead, modify the source
# template in the /etc/e-smith/templates directory. For more
# information, see http://www.e-smith.org.
#
# copyright (C) 1999-2001 e-smith, inc.
#------------------------------------------------------------

# Tape backups are enabled

export PATH=$PATH:/sbin

/sbin/e-smith/signal-event mysql-delete-dumps > /dev/null 2>&1
/sbin/e-smith/signal-event mysql-dump-tables > /dev/null 2>&1

if /bin/mt -f "/dev/nst0" tell > /dev/null 2>&1
then
    # Some drives require zeroing the data before
    # they can be overwritten.

    /bin/mt -f "/dev/nst0" rewind > /dev/null 2>&1
    /bin/dd if=/dev/zero of="/dev/nst0" bs=32k count=1 > /dev/null 2>&1
else
    echo "Backup aborted: No tape loaded"
    exit 1
fi
/usr/bin/flexbackup -fs / -norewind
/usr/bin/flexbackup -fs /boot -norewind

/sbin/e-smith/signal-event mysql-delete-dumps > /dev/null 2>&1

/bin/mt -f "/dev/nst0" rewind

#------------------------------------------------------------
# TEMPLATE END
#------------------------------------------------------------

Note the removal of the 'rewind' after /bin/dd if=/dev/zero ... and the removal/replacement of /usr/bin/flexbackup -fs all.  These changes stop the tape drive from rewinding and overwriting itself.  I am now able to perform successful tar backup with the Onstream ADR2.60.

Note of course that both '/etc/flexbackup.conf' and '/sbin/e-smith/backup' are templated so after you determine what works, create the appropriate custom template fragments.

Also consider this an alpha report.  I'm still testing all backup and restore functionality and have not completed.

Regards,

Darrell

[Joshua]

Hello,

I've run into this same problem (error message about broken pipe) on a Dell Poweredge 600sc with a Powervault T100 TR40 (Seagate Travan 40) drive.  I tried everything listed here and also the items listed in the errata on the Doc CD.  It boiled down to changing 1 line in /etc/flexbackup.conf

The drive was listed as "'/dev/nst0'".  I changed it to "'/dev/st0'" and everything works fine.  Why is that.  What is /dev/nst0 anyway?

Thanks,

Joshua

[Guck Puppy]

nst0 and nht0 are the "non-rewinding" devices. I.e., they don't automatically rewind after use.

[Kenneth Pepiton]

>
> The drive was listed as "'/dev/nst0'".  I changed it to
> "'/dev/st0'" and everything works fine.  Why is that.  What
> is /dev/nst0 anyway?
>

st0 makes the tape rewind when a command is sent to it while nst0 allows for writing on the tape then writing another file and not rewinding.  Kinda wordy but the easiest explanation I can give

[Kenneth Pepiton]

I was able to get it working to backup the basic server anyway.  I changed the /etc/flexbackup.conf file to read:

$filesystems[0] = '/';

instead of:

$filesystems[0] = '/ /boot';

So it does one backup and changed it to /dev/st0 in the /sbin/e-smith/backup.  So it's just doing one backup instead of two different backup.  I don't understand why it would want to do a backup of the boot directory seperate from the main backup which it's doing anyways.  So it's basically doing a backup of the same area twice.

[Joshua]

Any idea why then the backup works fine to st0 and not nst0?  That's the only change made from the original config file.  Is there somewhere you can change the deffinition of nst0? or is it standard and unmodifiable?

Thanks,

Joshua B.

Kenneth Pepiton wrote:
>
> st0 makes the tape rewind when a command is sent to it while
> nst0 allows for writing on the tape then writing another file
> and not rewinding.  Kinda wordy but the easiest explanation I
> can give

[Charlie Brady]

Joshua wrote:

> Any idea why then the backup works fine to st0 and not nst0?

It doesn't. See below.

> Kenneth Pepiton wrote:
> >
> > st0 makes the tape rewind when a command is sent to it while
> > nst0 allows for writing on the tape then writing another file
> > and not rewinding.

Kenneth has made a very small error. Using st0, the tape rewinds *after completing* the command which is sent. If you use /dev/st0 as the device, then flexbackup with write an index onto the tape, rewind it, write a dump of one partition onto the tape, then rewind it, then write a dump of another partition onto the tape, then rewind it. You can see that in the report above which reports the tape to be positioned at block 0 multiple times. You won't end up with a full backup this way. In the example you give, you only have /boot backup, since the / backup has been overwritten.

Back to your original problem:

| Doing level 0 backup of all using dump
| Retensioning tape...
| Rewinding & erasing tape...
/dev/nst0: Input/output error
| Creating index key 200210101341.50
| Tape #0
| Filesystems = / /boot

Are you sure that your tape is 100% OK? Are there any "st0" related kernel messages in /var/log/messages?

Charlie

[Kenneth Pepiton]

Charlie Brady wrote:
>
> Are you sure that your tape is 100% OK? Are there any "st0"
> related kernel messages in /var/log/messages?

The errors in the messages log reads:

Oct 15 04:01:28 server kernel: st0: Error with sense data: [valid=0] Info fld=0
x0, Current st09:00: sense key Illegal Request

[Charlie Brady]

Kenneth Pepiton wrote:

> Charlie Brady wrote:
> >
> > Are you sure that your tape is 100% OK? Are there any "st0"
> > related kernel messages in /var/log/messages?
>
> The errors in the messages log reads:
>
> Oct 15 04:01:28 server kernel: st0: Error with sense data:
> [valid=0] Info fld=0
> x0, Current st09:00: sense key Illegal Request

That indicates a failure in communication between the tape drive itself and the SCSI tape driver module. I'm assuming that your tape drive is an IDE/ATA drive, in which case there is an ide-scsi driver between the tape drive and the SCSI tape driver which provides a compatibility layer. The "compatibility" may be incomplete.

Have you tried using IDE native protocol (using /dev/nht0 with ide-scsi unloaded and ide-tape loaded)?

Charlie

[Rick]

I have the same error over here, with a SCSI tape drive. The error occured a week or two ago for the first time. Before I had no problems at all.