Re: [Bacula-users] btape fill failure on HP LTO6/4 drives

Hello,

btape uses all the same libraries as Bacula, and while the sequence of
calls to the low level libraries may be different from what Bacula does,
it does indicate a problem.  It appears that the OS tape driver does not
properly implement back space record after an EOT.  This is a defect of
the operating system driver, but it is not fatal for Bacula. 

You will very likely see this defect show up when Bacula fills a tape
and writes the final EOT mark then tries to verify that the last block
was written correctly.  Due to the OS driver defect this will fail, but
it is only a check and your data may still be good.  The results from
btape re-reading what was written does not look encouraging, and it may
indicate that the last block is not properly written.  I personally
would be worried.

This can happen if you are not running the tape drive in the right mode
-- since I have not looked at the Solaris tape drive naming conventions
for about 8 years now, I forget.  I suggest that you verify that using

/dev/rmt/0mbn

is what is recommended in the manual.

If you can really do multi-volume restores correctly and you have
verified that every byte is correct then you are probably OK.

Best regards,
Kern

On 03/28/2014 01:01 PM, Roberts, Ben wrote:
> Hi all,
>
> While setting up a new tape library with HP LTO6 drives, btape test runs 
> successfully, but btape fill fails with what looks like a problem handling 
> the last block on the tape (perhaps an off-by-one error?). The outputs below 
> are repeatable with both LTO6 and LTO4 media, but I've been able to do a 
> multi-tape backup and restore OK; so I think the problem is isolated to btape 
> rather than Bacula-sd and any common code between them. Will do some more 
> testing, but obviously filling multiple LTO6 tapes takes a little while!
>
> Has anyone seen this before?
>
> This is on Solaris 5.11 (x86_64) running Bacula 5.2.13, locally compiled.
>
> ------------
> btape output:
> ..snip..
> Wrote block=19090000, file,blk=954,10936 VolBytes=2,499,540,811,776 
> rate=107.7 MB/s
> 19-Mar 15:23 btape JobId 0: End of Volume "TestVolume1" at 954:11250 on 
> device "drive-0-tapestore1" (/dev/rmt/0mbn). Write of 131072 bytes got 0.
> 19-Mar 15:23 btape JobId 0: Error: Backspace record at EOT failed. ERR=I/O 
> error
> btape: btape.c:2714-0 Last block at: 954:11249 this_dev_block_num=11250
> btape: btape.c:2749-0 End of tape 954:-1. Volume Bytes=2,499,581,968,384. 
> Write rate = 107.7 MB/s
> btape: btape.c:2320-0 Wrote 1000 blocks on second tape. Done.
> Done writing 0 records ...
> btape: btape.c:2389-0 Wrote state file last_block_num1=11249 last_block_num2=0
> btape: btape.c:2404-0
>
> 15:23:52 Done filling tape at 954:-1. Now beginning re-read of tape ...
> btape: btape.c:2485-0 Enter do_unfill
> 19-Mar 15:24 btape JobId 0: Ready to read from volume "TestVolume1" on device 
> "drive-0-tapestore1" (/dev/rmt/0mbn).
> Rewinding.
> Reading the first 10000 records from 0:0.
> 10000 records read now at 1:2502
> Reposition from 1:2502 to 954:11249
> Reposition error. ERR=dev.c:1366 ioctl MTFSR 11249 error on 
> "drive-0-tapestore1" (/dev/rmt/0mbn). ERR=I/O error.
>
> btape: btape.c:2412-0 do_unfill failed.
>
> ------------
> tapeinfo -f /dev/rmt/0mbn
> Product Type: Tape Drive
> Vendor ID: 'HP      '
> Product ID: 'Ultrium 6-SCSI  '
> Revision: '338B'
> Attached Changer API: No
> SerialNumber: 'xxxxxxxx'
> MinBlock: 1
> MaxBlock: 16777215
> Ready: no
>
> ------------
> Relevant Bacula-sd.conf snippet:
>
> Autochanger {
>   Name = tapestore1-autochanger
>   Device = drive-0-tapestore1, drive-1-tapestore1
>   Device = drive-2-tapestore1, drive-3-tapestore1
>   Changer Device = /dev/scsi/changer/c1t5d1
>   Changer Command = "/opt/bacula/etc/mtx-changer %c %o %S %a %d"
> }
>
> Device {
>   Name = drive-0-tapestore1
>   Archive Device = /dev/rmt/0mbn
>   Device Type = Tape
>   Media Type = LT06
>   AutoChanger = yes
>   Removable media = yes;
>   Label Media = no
>   Random access = no;
>   Requires Mount = no;
>   Maximum Changer Wait = 180
>   Drive Index = 0
>   Maximum Spool Size = 100G
> }
>
> ------------
> Full btape test output:
> Tape block granularity is 1024 bytes.
> btape: butil.c:290-0 Using device: "/dev/rmt/0mbn" for writing.
> btape: btape.c:477-0 open device "drive-0-tapestore1" (/dev/rmt/0mbn): OK
> *test
>
> === 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:1157-0 Wrote 10000 blocks of 130972 bytes.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1173-0 Wrote 10000 blocks of 130972 bytes.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1215-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:1283-0 Block position test
> btape: btape.c:1295-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:579-0 Rewound "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:477-0 open device "drive-0-tapestore1" (/dev/rmt/0mbn): OK
> btape: btape.c:579-0 Rewound "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1427-0 Now moving to end of medium.
> btape: btape.c:630-0 Moved to end of medium.
> We should be in file 3. I am at file 3. This is correct!
>
> Now the important part, I am going to attempt to append to the tape.
>
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:579-0 Rewound "drive-0-tapestore1" (/dev/rmt/0mbn)
> Done appending, there should be no I/O errors
>
> Doing Bacula scan of blocks:
> 1 block of 131008 bytes in file 1
> End of File mark.
> 2 blocks of 131008 bytes in file 2
> End of File mark.
> 3 blocks of 131008 bytes in file 3
> End of File mark.
> 1 block of 131008 bytes in file 4
> End of File mark.
> Total files=4, blocks=7, bytes = 917,056
> End scanning the tape.
> We should be in file 4. I am at file 4. This is correct!
>
> The above Bacula scan should have output identical to what follows.
> Please double check it ...
> === Sample correct output ===
> 1 block of 64448 bytes in file 1
> End of File mark.
> 2 blocks of 64448 bytes in file 2
> End of File mark.
> 3 blocks of 64448 bytes in file 3
> End of File mark.
> 1 block of 64448 bytes in file 4
> End of File mark.
> Total files=4, blocks=7, bytes = 451,136
> === End sample correct output ===
>
> If the above scan output is not identical to the
> sample output, you MUST correct the problem
> or Bacula will not be able to write multiple Jobs to
> the tape.
>
>
> === Write, backup, and re-read test ===
>
> I'm going to write three records and an EOF
> then backup over the EOF and re-read the last record.
> Bacula does this after writing the last block on the
> tape to verify that the block was written correctly.
>
> This is not an *essential* feature ...
>
> btape: btape.c:579-0 Rewound "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:816-0 Wrote first record of 130972 bytes.
> btape: btape.c:827-0 Wrote second record of 130972 bytes.
> btape: btape.c:838-0 Wrote third record of 130972 bytes.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:854-0 Backspaced over EOF OK.
> btape: btape.c:859-0 Backspace record OK.
> btape: btape.c:877-0
> Block re-read correct. Test succeeded!
> === End Write, backup, and re-read test ===
>
>
>
> === Forward space files test ===
>
> This test is essential to Bacula.
>
> I'm going to write five files then test forward spacing
>
> btape: btape.c:579-0 Rewound "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1914-0 Wrote one record of 130972 bytes.
> btape: btape.c:1916-0 Wrote block to device.
> btape: btape.c:609-0 Wrote 1 EOF to "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:579-0 Rewound "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1641-0 Now forward spacing 1 file.
> We should be in file 1. I am at file 1. This is correct!
> btape: btape.c:1653-0 Now forward spacing 2 files.
> We should be in file 3. I am at file 3. This is correct!
> btape: btape.c:579-0 Rewound "drive-0-tapestore1" (/dev/rmt/0mbn)
> btape: btape.c:1666-0 Now forward spacing 4 files.
> We should be in file 4. I am at file 4. This is correct!
>
> btape: btape.c:1684-0 Now forward spacing 1 more file.
> We should be in file 5. I am at file 5. This is correct!
>
> === End Forward space files test ===
>
>
> Ah, I see you have an autochanger configured.
> To test the autochanger you must have a blank tape
> that I can write on in Slot 1.
>
> Do you wish to continue with the Autochanger test? (y/n): n
> *
>
> Regards,
> Ben Roberts
>
>
>
>
> This email and any files transmitted with it contain confidential and 
> proprietary information and is solely for the use of the intended recipient.  
> If you are not the intended recipient please return the email to the sender 
> and delete it from your computer and you must not use, disclose, distribute, 
> copy, print or rely on this email or its contents.  This communication is for 
> informational purposes only.  It is not intended as an offer or solicitation 
> for the purchase or sale of any financial instrument or as an official 
> confirmation of any transaction.   Any comments or statements made herein do 
> not necessarily reflect those of GSA Capital. GSA Capital Partners LLP is 
> authorised and regulated by the Financial Conduct Authority and is registered 
> in England and Wales at Stratton House, 5 Stratton Street, London W1J 8LA, 
> number OC309261. GSA Capital Services Limited is registered in England and 
> Wales at the same address, number 5320529.
>
>
> ------------------------------------------------------------------------------
> _______________________________________________
> Bacula-users mailing list
> Bacula-users AT lists.sourceforge DOT net
> https://lists.sourceforge.net/lists/listinfo/bacula-users
>



------------------------------------------------------------------------------
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users