Re: [Bacula-users] btape multivolume fill test fails on 7.4.4 but succee

Hell Caribe,

Thanks for the feedback and the thanks. Having the btape fill command fail was really very annoying. I am glad that is behind us. It is not likely to happen again, because there are now two regression tests that detect this problem.

Thanks for using Bacula :-)

Kern

On 02/09/2017 04:57 PM, Caribe Schreiber wrote:

Hi Kern,

I can also confirm that the btape fill test change succeeds on 7.4.5. The output is below. Thank you for all your hard work!

~Caribe

Wrote block=38770000, file,blk=251,17749 VolBytes=2,501,130,175,488 rate=138.6 MB/s
Wrote block=38775000, file,blk=251,22749 VolBytes=2,501,452,735,488 rate=138.6 MB/s
09-Feb 04:49 btape JobId 0: End of Volume "TestVolume1" at 251:26147 on device "Drive-1" (/dev/nst0). Write of 64512 bytes got -1.
09-Feb 04:49 btape JobId 0: Re-read of last block succeeded.
btape: btape.c:2712-0 Last block at: 251:26146 this_dev_block_num=26147
btape: btape.c:2747-0 End of tape 251:0. Volume Bytes=2,501,671,947,264. Write rate = 138.5 MB/s
09-Feb 04:49 btape JobId 0: End of medium on Volume "TestVolume1" Bytes=2,501,671,947,264 Blocks=38,778,397 at 09-Feb-2017 04:49.
09-Feb 04:49 btape JobId 0: 3307 Issuing autochanger "unload slot 1, drive 0" command for vol TestVolume1.
09-Feb 04:50 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive 0" command for vol TestVolume2.
09-Feb 04:50 btape JobId 0: 3305 Autochanger "load slot 2, drive 0", status is OK for vol TestVolume2.
Wrote Volume label for volume "TestVolume2".
09-Feb 04:51 btape JobId 0: Wrote label to prelabeled Volume "TestVolume2" on tape device "Drive-1" (/dev/nst0)
09-Feb 04:51 btape JobId 0: New volume "TestVolume2" mounted on device "Drive-1" (/dev/nst0) at 09-Feb-2017 04:51.
btape: btape.c:2315-0 Wrote 1000 blocks on second tape. Done.
Done writing 0 records ...
Wrote End of Session label.
btape: btape.c:2384-0 Wrote state file last_block_num1=26146 last_block_num2=1001
btape: btape.c:2402-0

04:51:13 Done filling tapes at 0:1003. Now beginning re-read of first tape ...
btape: btape.c:2480-0 Enter do_unfill
09-Feb 04:51 btape JobId 0: 3307 Issuing autochanger "unload slot 2, drive 0" command for vol TestVolume1.
09-Feb 04:52 btape JobId 0: 3304 Issuing autochanger "load slot 1, drive 0" command for vol TestVolume1.
09-Feb 04:52 btape JobId 0: 3305 Autochanger "load slot 1, drive 0", status is OK for vol TestVolume1.
09-Feb 04:53 btape JobId 0: Ready to read from volume "TestVolume1" on tape device "Drive-1" (/dev/nst0).
Rewinding.
Reading the first 10000 records from 0:0.
10000 records read now at 1:5084
Reposition from 1:5084 to 251:26146
Reading block 26146.

The last block of the first tape matches.

09-Feb 04:53 btape JobId 0: 3307 Issuing autochanger "unload slot 1, drive 0" command for vol TestVolume2.
09-Feb 04:54 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive 0" command for vol TestVolume2.
09-Feb 04:55 btape JobId 0: 3305 Autochanger "load slot 2, drive 0", status is OK for vol TestVolume2.
09-Feb 04:55 btape JobId 0: Ready to read from volume "TestVolume2" on tape device "Drive-1" (/dev/nst0).
Reposition from 0:0 to 0:1
Reading block 1.

The first block on the second tape matches.

Reposition from 0:2 to 0:1001
Reading block 1001.

The last block on the second tape matches. Test succeeded.

On 02/08/2017 04:31 AM, Kern Sibbald wrote:
Hello Laurent,

Thanks for the confirmation :-)

That is a really nice tape drive that you have. It has a really nice capacity and very nice throughput.

Best regards,
Kern

On 02/08/2017 07:35 AM, Laurent ALONSO wrote:
Hello,

Thanks for this fix
I tested it with an LTO7 tape in IBM drives with a SCALAR i-500 librairy.

It works !

btape

*fill
.....
.....
Wrote block=15275000, file,blk=188,56939 VolBytes=6,006,374,006,784 rate=292.7 MB/s
Wrote block=15280000, file,blk=188,61939 VolBytes=6,008,340,086,784 rate=292.7 MB/s
Wrote block=15285000, file,blk=188,66939 VolBytes=6,010,306,166,784 rate=292.7 MB/s
Wrote block=15290000, file,blk=188,71939 VolBytes=6,012,272,246,784 rate=292.7 MB/s
Wrote block=15295000, file,blk=188,76939 VolBytes=6,014,238,326,784 rate=292.7 MB/s
Wrote block=15300000, file,blk=189,559 VolBytes=6,016,204,406,784 rate=292.7 MB/s
07-févr. 20:01 btape JobId 0: End of Volume "TestVolume1" at 189:3427 on device "Drive-1" (/dev/tape/by-id/scsi-3500308c3a347d000-nst). Write of 393216 bytes got -1.
07-févr. 20:01 btape JobId 0: Re-read of last block succeeded.
btape: btape.c:2712-0 Last block at: 189:3426 this_dev_block_num=3427
btape: btape.c:2747-0 End of tape 189:0. Volume Bytes=6,017,332,150,272. Write rate = 292.6 MB/s
07-févr. 20:01 btape JobId 0: End of medium on Volume "TestVolume1" Bytes=6,017,332,150,272 Blocks=15,302,867 at 07-févr.-2017 20:01.
07-févr. 20:01 btape JobId 0: 3307 Issuing autochanger "unload slot 1, drive 0" command for vol TestVolume1.
07-févr. 20:03 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive 0" command for vol TestVolume2.
07-févr. 20:03 btape JobId 0: 3305 Autochanger "load slot 2, drive 0", status is OK for vol TestVolume2.
Wrote Volume label for volume "TestVolume2".
07-févr. 20:03 btape JobId 0: Wrote label to prelabeled Volume "TestVolume2" on tape device "Drive-1" (/dev/tape/by-id/scsi-3500308c3a347d000-nst)
07-févr. 20:03 btape JobId 0: New volume "TestVolume2" mounted on device "Drive-1" (/dev/tape/by-id/scsi-3500308c3a347d000-nst) at 07-févr.-2017 20:03.
btape: btape.c:2315-0 Wrote 1000 blocks on second tape. Done.
Done writing 0 records ...
Wrote End of Session label.
btape: btape.c:2384-0 Wrote state file last_block_num1=3426 last_block_num2=1001
btape: btape.c:2402-0

20:03:36 Done filling tapes at 0:1003. Now beginning re-read of first tape ...
btape: btape.c:2480-0 Enter do_unfill
07-févr. 20:03 btape JobId 0: 3307 Issuing autochanger "unload slot 2, drive 0" command for vol TestVolume1.
07-févr. 20:04 btape JobId 0: 3304 Issuing autochanger "load slot 1, drive 0" command for vol TestVolume1.
07-févr. 20:05 btape JobId 0: 3305 Autochanger "load slot 1, drive 0", status is OK for vol TestVolume1.
07-févr. 20:05 btape JobId 0: Ready to read from volume "TestVolume1" on tape device "Drive-1" (/dev/tape/by-id/scsi-3500308c3a347d000-nst).
Rewinding.
Reading the first 10000 records from 0:0.
10000 records read now at 1:834
Reposition from 1:834 to 189:3426
Reading block 3426.

The last block of the first tape matches.

07-févr. 20:05 btape JobId 0: 3307 Issuing autochanger "unload slot 1, drive 0" command for vol TestVolume2.
07-févr. 20:07 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive 0" command for vol TestVolume2.
07-févr. 20:07 btape JobId 0: 3305 Autochanger "load slot 2, drive 0", status is OK for vol TestVolume2.
07-févr. 20:07 btape JobId 0: Ready to read from volume "TestVolume2" on tape device "Drive-1" (/dev/tape/by-id/scsi-3500308c3a347d000-nst).
Reposition from 0:0 to 0:1
Reading block 1.

The first block on the second tape matches.

Reposition from 0:2 to 0:1001
Reading block 1001.

The last block on the second tape matches. Test succeeded.

*

2017-01-28 12:34 GMT+01:00 Kern Sibbald <kern AT sibbald DOT com>:

Hello,

Update: The problem of the btape fill command not working has been
around since about 2012. I now have a fix for it, and can safely say
that the problem resulted from some debug code that apparently only
affected the btape fill command. The debug code cleared some fields in
the block after the block was written.

So, bottom line: the failure is a false alert.

I will push a patch to the Bacula repository this weekend and will
consider releasing a version 7.4.5, since the fill command is important
when doing a new installation.

Best regards,
Kern

On 01/28/2017 10:42 AM, Kern Sibbald wrote:
> Actually, the situation is a bit more complicated.
>
> It seems to be a false alert, but I haven't found the exact problem
> yet. The problem does not exist in version 5.2, but it does exist in
> 7.0, 7.2, and 7.4., and the problem does not exist in the Enterprise
> Edition, so nothing is really fixed yet in the community version. It is
> interesting that is has been "broken" since version 5.2 -- quite a long
> time.
>
> For the moment it seems to be a trivial problem of the last block being
> "saved" too early before the checksum is computed so that checksum in
> the saved "last block" does not correspond to the block read back (i.e.
> most likely a false alert). By the way, the failure occurs with either
> the single or the multiple tape test.
>
> I am looking at the issue ...
>
> Best regards,
> Kern
>
> On 01/27/2017 06:04 PM, Alan Brown wrote:
>> On 27/01/17 00:36, Caribe Schreiber wrote:
>>> Hi all,
>>>
>>> I'm hoping someone can help point me in the right direction to get the
>>> btape multivolume fill test to work under bacula-7.4.4.
>> You can't. It's broken.
>>
>> It was fixed recently but that fix hasn't rolled into the public release
>> stream yet
>> (and it looks like there's still another but in the test part of the code)
>>
>>
>>
>>
>>
>> ------------------------------------------------------------------------------
>> 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
>>
>
> ------------------------------------------------------------------------------
> 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
>

------------------------------------------------------------------------------
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
------------------------------------------------------------------------------
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 AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users
------------------------------------------------------------------------------
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 AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users
--
Caribe Schreiber
IT Engineer
Auction Harmony
Phone: (612) 605-7301 x 105
Fax: (612) 605-7302
www.AuctionHarmony.com
Join Us!

------------------------------------------------------------------------------
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 AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users

Re: [Bacula-users] btape multivolume fill test fails on 7.4.4 but succeeds on 5.2.13