I have a *different* problem with a new tape drive and btape, also failing during the append test.

The read/write test passes with no trouble, but the append test not only fails, but it takes the tape drive offline.  Once this happens, the drive is not accessible until the tape is physically dismounted and then remounted.  Once this happens, the drive comes back to life, but it will go offline again if the append test is re-attempted.

The btape failure message suggested using a fixed block size, but making that change didn't seem to make any difference.

I tried downloading the IBM ITDT utility and running all its tests, but the drive passed with flying colors in the ITDT diagnostics.

I am running bacula 7.4.4 on a new Debian stretch (Debian 9) server with a new tape library and tape drive. The new drive is an IBM ULT3580-HH6 LTO-6 drive in a Dell TL-2000 library.  I have an existing bacula instance running on a Debian jesse (debian 8) server, and my plan is to add the new tape library as an additional pool for the existing instance.  For now, though, unless I can get the drive to work with bacula, planning how to set bacula itself up doesn't matter.

What steps can I do to troubleshoot this?

One thing I notice is that lsscsi shows the tape drive twice, but there is only one actual drive.  Could this be a part of the problem?


root@odin:/etc/bacula/scripts# ./mtx-changer /dev/autochanger1 load 1 /dev/nst0 0
Loading media from Storage Element 1 into drive 0...done


root@odin:/etc/bacula/scripts# ./mtx-changer /dev/autochanger1 listall
D:0:F:1:000015L6
S:1:E
S:2:F:000018L6
S:3:F:000021L6
S:4:F:CLNU00L1
S:5:F:000014L6
S:6:F:000017L6
S:7:F:000020L6
S:8:F:CLN005L3
S:9:F:000013L6
S:10:F:000016L6
S:11:F:000019L6
S:12:F:000012L6
S:13:F:000009L6
S:14:F:000006L6
S:15:F:000003L6
S:16:F:000011L6
S:17:F:000008L6
S:18:F:000005L6
S:19:F:000002L6
S:20:F:000010L6
S:21:F:000007L6
S:22:F:000004L6
S:23:F:000001L6
I:24:E


root@odin:/etc/bacula/scripts# btape -c ../bacula-sd.conf /dev/nst0
Tape block granularity is 1024 bytes.
btape: butil.c:291-0 Using device: "/dev/nst0" for writing.
test
btape: btape.c:471-0 open device "Drive-1" (/dev/nst0): OK
*

=== Write, rewind, and re-read test ===

I'm going to write 10000 records and an EOF
then write 10000 records and an EOF, then rewind,
and re-read the data to verify that it is correct.

This is an *essential* feature ...

btape: btape.c:1154-0 Wrote 10000 blocks of 64412 bytes.
btape: btape.c:606-0 Wrote 1 EOF to "Drive-1" (/dev/nst0)
btape: btape.c:1170-0 Wrote 10000 blocks of 64412 bytes.
btape: btape.c:606-0 Wrote 1 EOF to "Drive-1" (/dev/nst0)
btape: btape.c:1212-0 Rewind OK.
10000 blocks re-read correctly.
Got EOF on tape.
10000 blocks re-read correctly.
=== Test Succeeded. End Write, rewind, and re-read test ===

btape: btape.c:1279-0 Block position test
btape: btape.c:1291-0 Rewind OK.
Reposition to file:block 0:4
Block 5 re-read correctly.
Reposition to file:block 0:200
Block 201 re-read correctly.
Reposition to file:block 0:9999
Block 10000 re-read correctly.
Reposition to file:block 1:0
Block 10001 re-read correctly.
Reposition to file:block 1:600
Block 10601 re-read correctly.
Reposition to file:block 1:9999
Block 20000 re-read correctly.
=== Test Succeeded. End Write, rewind, and re-read test ===



=== Append files test ===

This test is essential to Bacula.

I'm going to write one record  in file 0,
                   two records in file 1,
             and three records in file 2

btape: btape.c:576-0 Rewound "Drive-1" (/dev/nst0)
btape: btape.c:1909-0 Wrote one record of 64412 bytes.
btape: btape.c:1911-0 Wrote block to device.
btape: btape.c:606-0 Wrote 1 EOF to "Drive-1" (/dev/nst0)
btape: btape.c:1909-0 Wrote one record of 64412 bytes.
btape: btape.c:1911-0 Wrote block to device.
btape: btape.c:1909-0 Wrote one record of 64412 bytes.
btape: btape.c:1911-0 Wrote block to device.
btape: btape.c:606-0 Wrote 1 EOF to "Drive-1" (/dev/nst0)
btape: btape.c:1909-0 Wrote one record of 64412 bytes.
btape: btape.c:1911-0 Wrote block to device.
btape: btape.c:1909-0 Wrote one record of 64412 bytes.
btape: btape.c:1911-0 Wrote block to device.
btape: btape.c:1909-0 Wrote one record of 64412 bytes.
btape: btape.c:1911-0 Wrote block to device.
btape: btape.c:606-0 Wrote 1 EOF to "Drive-1" (/dev/nst0)
btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

13-Jul 16:07 btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error


Append test failed. Attempting again.
Setting "Hardware End of Medium = no
    and "Fast Forward Space File = no
and retrying append test.



=== Append files test ===

This test is essential to Bacula.

I'm going to write one record  in file 0,
                   two records in file 1,
             and three records in file 2

btape: btape.c:573-0 Bad status from rewind. ERR=tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

13-Jul 16:07 btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

btape: block.c:144-0 Attempt to write on read-only Volume. dev="Drive-1" (/dev/nst0)
13-Jul 16:07 btape JobId 0: Fatal error: block.c:144 Attempt to write on read-only Volume. dev="Drive-1" (/dev/nst0)
btape: btape.c:1906-0 Error writing block to device.
btape: Fatal Error at tape_dev.c:918 because:
tape_dev.c:917 Bad call to weof_dev. Device not open
13-Jul 16:07 btape: Fatal Error at tape_dev.c:918 because:
tape_dev.c:917 Bad call to weof_dev. Device not open
btape: btape.c:602-0 Bad status from weof. ERR=tape_dev.c:917 Bad call to weof_dev. Device not open

btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

13-Jul 16:07 btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

btape: btape.c:1906-0 Error writing block to device.
btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

13-Jul 16:07 btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

btape: btape.c:1906-0 Error writing block to device.
btape: Fatal Error at tape_dev.c:918 because:
tape_dev.c:917 Bad call to weof_dev. Device not open
13-Jul 16:07 btape: Fatal Error at tape_dev.c:918 because:
tape_dev.c:917 Bad call to weof_dev. Device not open
btape: btape.c:602-0 Bad status from weof. ERR=tape_dev.c:917 Bad call to weof_dev. Device not open

btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

13-Jul 16:07 btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

btape: btape.c:1906-0 Error writing block to device.
btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

13-Jul 16:07 btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

btape: btape.c:1906-0 Error writing block to device.
btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

13-Jul 16:07 btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

btape: btape.c:1906-0 Error writing block to device.
btape: Fatal Error at tape_dev.c:918 because:
tape_dev.c:917 Bad call to weof_dev. Device not open
13-Jul 16:07 btape: Fatal Error at tape_dev.c:918 because:
tape_dev.c:917 Bad call to weof_dev. Device not open
btape: btape.c:602-0 Bad status from weof. ERR=tape_dev.c:917 Bad call to weof_dev. Device not open

btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

13-Jul 16:07 btape: Fatal Error at btape.c:467 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error



That appears *NOT* to have corrected the problem.

Append test failed.


!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Unable to correct the problem. You MUST fix this
problem before Bacula can use your tape drive correctly

Perhaps running Bacula in fixed block mode will work.
Do so by setting:

Minimum Block Size = nnn
Maximum Block Size = nnn

in your Storage daemon's Device definition.
nnn must match your tape driver's block size, which
can be determined by reading your tape manufacturers
information, and the information on your kernel dirver.
Fixed block sizes, however, are not normally an ideal solution.

Some systems, e.g. OpenBSD, require you to set
   Use MTIOCGET= no
in your device resource. Use with caution.
*quit


root@odin:/etc/bacula/scripts# btape -c ../bacula-sd.conf /dev/nst0
Tape block granularity is 1024 bytes.
btape: butil.c:291-0 Using device: "/dev/nst0" for writing.
btape: Fatal Error at device.c:300 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

13-Jul 16:10 btape: Fatal Error at device.c:300 because:
dev open failed: tape_dev.c:164 Unable to open device "Drive-1" (/dev/nst0): ERR=Input/output error

btape: butil.c:199-0 Cannot open "Drive-1" (/dev/nst0)
13-Jul 16:10 btape JobId 0: Fatal error: butil.c:199 Cannot open "Drive-1" (/dev/nst0)


root@odin:/etc/bacula/scripts# ./mtx-changer /dev/autochanger1 unload 1 /dev/nst0 0
Unloading drive 0 into Storage Element 1...done

root@odin:/etc/bacula/scripts# ./mtx-changer /dev/autochanger1 load 1 /dev/nst0 0
Loading media from Storage Element 1 into drive 0...done


root@odin:/etc/bacula/scripts# btape -c ../bacula-sd.conf /dev/nst0
Tape block granularity is 1024 bytes.
btape: butil.c:291-0 Using device: "/dev/nst0" for writing.
btape: btape.c:471-0 open device "Drive-1" (/dev/nst0): OK
*

root@odin:/etc/bacula/scripts# lsscsi -g
[0:2:0:0]    disk    DELL     PERC H730 Mini   4.27  /dev/sda   /dev/sg0
[1:0:0:0]    tape    IBM      ULT3580-HH6      G9P1  /dev/st0   /dev/sg2
[1:0:0:1]    mediumx IBM      3573-TL          E.30  /dev/sch0  /dev/sg3
[1:0:1:0]    tape    IBM      ULT3580-HH6      G9P1  /dev/st1   /dev/sg4
[1:0:1:1]    mediumx IBM      3573-TL          E.30  /dev/sch1  /dev/sg5
[6:2:0:0]    disk    DELL     PERC H830 Adp    4.27  /dev/sdb   /dev/sg1
[12:0:0:0]   cd/dvd  PLDS     DVD-ROM DS-8DBSH MD52  /dev/sr0   /dev/sg6


root@odin:/etc/bacula/scripts# tapeinfo -f /dev/sg2
Product Type: Tape Drive
Vendor ID: 'IBM     '
Product ID: 'ULT3580-HH6     '
Revision: 'G9P1'
Attached Changer API: No
SerialNumber: '10WT110956'
MinBlock: 1
MaxBlock: 8388608
SCSI ID: 0
SCSI LUN: 0
Ready: yes
BufferedMode: yes
Medium Type: 0x68
Density Code: 0x5a
BlockSize: 0
DataCompEnabled: yes
DataCompCapable: yes
DataDeCompEnabled: yes
CompType: 0xff
DeCompType: 0xff
BOP: yes
Block Position: 0
Partition 0 Remaining Kbytes: -1
Partition 0 Size in Kbytes: -1
ActivePartition: 0
EarlyWarningSize: 0
NumPartitions: 0
MaxPartitions: 3


Device {
  Name = Drive-1                      #
  Description = "LT06 inside Dell TL2000 Library"
  Drive Index = 0
  Media Type = LT06
  Archive Device = /dev/nst0
  AutomaticMount = yes;               # when device opened, read it
  AlwaysOpen = yes;
  RemovableMedia = yes;
  RandomAccess = no;
  AutoChanger = yes
  SpoolDirectory = "/var/spool/bacula"
  MaximumSpoolSize = 485G
  Maximum Network Buffer Size = 65536
#  MaximumBlockSize = 256k
#  MinimumBlockSize = 256k
  Offline On Unmount = yes
#  #
#  # Enable the Alert command only if you have the mtx package loaded
#  # Note, apparently on some systems, tapeinfo resets the SCSI controller
#  #  thus if you turn this on, make sure it does not reset your SCSI
#  #  controller.  I have never had any problems, and smartctl does
#  #  not seem to cause such problems.
#  #
#Alert Command = "sh -c 'tapeinfo -f %c |grep TapeAlert|cat'"
#  If you have smartctl, enable this, it has more info than tapeinfo
  Alert Command = "sh -c 'smartctl -H -l error %c'"
}


--
Steve Garcia
Ignorance killed the cat, curiosity was framed.

------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users