Kern Sibbald said:
> On Wednesday 22 November 2006 08:12, Ralf Gross wrote:
>> Ralf Gross schrieb:
>> > I'm testing bacula 1.39.28 with our new NEC-T40A changer (LTO3
Ultrium
>> > drive). btape's test and fill commands were successful. Only bfill
finished with an error message.
>> >
>> > +++++++++++++++++++++++++++++++++++++++++++++++++19-Nov 21:58 btape:
End of Volume "" at 425:8650 on device "NEC-T40A" (/dev/nst0). Write
of 64512 bytes got -1.
>> > 19-Nov 21:58 btape: Re-read of last block succeeded.
>> >
>> > Write failed at block 6596150.
>> > 19-Nov 21:58 btape: Fatal Error at dev.c:1655 because:
>> > dev.c:1654 Attempt to WEOF on non-appendable Volume
>> > btape: btape.c:483 Bad status from weof. ERR=dev.c:1654 Attempt to
WEOF on non-appendable Volume
>> >
>> >
>> > Is this something I have to worry about?
>> Any ideas on this? I just want to know if this is something I have to
take care about before I declare the T40A changer is working fine with
bacula.
>
> Without knowing the details, this does not look too good. It appears
more
> like a bug than a tape problem, but if I were you I would resolve the
problem
> before relying on the changer. Possibly part of the problem is that you
have
> edited the output rather than presenting everything so I cannot see
everything.
>
> In any case, btape should not be getting this kind of error. At a first
glance, it looks like btape attempted to write on the tape after
re-reading
> the last block, which is not what it normally does -- I suspect this is
because you edited the messages. In any case, with the little snipit of
output it is impossible to get an idea of what is causing the problem.
>
Well, bfill doesn't give me much more output than the above.
------- bfill -------
*bfill
btape: btape.c:2536 Begin writing Bacula blocks of 64512 bytes.
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
[bacula is filling the tape]
++++++++++++++++++++++++++++++++++++++++++++++++++++22-Nov 15:05 btape:
End of Volume "" at 427:8518 on device "LTO3" (/dev/nst0). Write of 64512
bytes got -1.
22-Nov 15:05 btape: Re-read of last block succeeded.
Write failed at block 6596018.
22-Nov 15:05 btape: Fatal Error at dev.c:1655 because:
dev.c:1654 Attempt to WEOF on non-appendable Volume
btape: btape.c:483 Bad status from weof. ERR=dev.c:1654 Attempt to WEOF on
non-appendable Volume
Here is btape's output:
------- test -------
./btape /dev/nst0
Tape block granularity is 1024 bytes.
btape: butil.c:272 Using device: "/dev/nst0" for writing.
22-Nov 13:08 btape: 3301 Issuing autochanger "loaded? drive 0" command.
22-Nov 13:08 btape: 3302 Autochanger "loaded? drive 0", result is Slot 1.
22-Nov 13:08 btape: 3301 Issuing autochanger "loaded? drive 0" command.
22-Nov 13:08 btape: 3302 Autochanger "loaded? drive 0", result is Slot 1.
btape: btape.c:356 open device "LTO3" (/dev/nst0): OK
*test
=== Write, rewind, and re-read test ===
I'm going to write 1000 records and an EOF
then write 1000 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:813 Wrote 1000 blocks of 64412 bytes.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:829 Wrote 1000 blocks of 64412 bytes.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:838 Rewind OK.
1000 blocks re-read correctly.
Got EOF on tape.
1000 blocks re-read correctly.
=== Test Succeeded. End Write, rewind, and re-read test ===
=== Write, rewind, and position test ===
I'm going to write 1000 records and an EOF
then write 1000 records and an EOF, then rewind,
and position to a few blocks and verify that it is correct.
This is an *essential* feature ...
btape: btape.c:925 Wrote 1000 blocks of 64412 bytes.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:941 Wrote 1000 blocks of 64412 bytes.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:950 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:999
Block 1000 re-read correctly.
Reposition to file:block 1:0
Block 1001 re-read correctly.
Reposition to file:block 1:600
Block 1601 re-read correctly.
Reposition to file:block 1:999
Block 2000 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:457 Rewound "LTO3" (/dev/nst0)
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
22-Nov 13:09 btape: 3301 Issuing autochanger "loaded? drive 0" command.
22-Nov 13:09 btape: 3302 Autochanger "loaded? drive 0", result is Slot 1.
btape: btape.c:356 open device "LTO3" (/dev/nst0): OK
btape: btape.c:457 Rewound "LTO3" (/dev/nst0)
btape: btape.c:1079 Now moving to end of medium.
btape: btape.c:508 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:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:457 Rewound "LTO3" (/dev/nst0)
Done appending, there should be no I/O errors
Doing Bacula scan of blocks:
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 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:457 Rewound "LTO3" (/dev/nst0)
btape: btape.c:692 Wrote first record of 64412 bytes.
btape: btape.c:703 Wrote second record of 64412 bytes.
btape: btape.c:714 Wrote third record of 64412 bytes.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:730 Backspaced over EOF OK.
btape: btape.c:735 Backspace record OK.
btape: btape.c:753
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:457 Rewound "LTO3" (/dev/nst0)
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:1559 Wrote one record of 64412 bytes.
btape: btape.c:1561 Wrote block to device.
btape: btape.c:487 Wrote 1 EOF to "LTO3" (/dev/nst0)
btape: btape.c:457 Rewound "LTO3" (/dev/nst0)
btape: btape.c:1293 Now forward spacing 1 file.
We should be in file 1. I am at file 1. This is correct!
btape: btape.c:1305 Now forward spacing 2 files.
We should be in file 3. I am at file 3. This is correct!
btape: btape.c:457 Rewound "LTO3" (/dev/nst0)
btape: btape.c:1318 Now forward spacing 4 files.
We should be in file 4. I am at file 4. This is correct!
btape: btape.c:1336 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): y
=== Autochanger test ===
3301 Issuing autochanger "loaded" command.
Slot 1 loaded. I am going to unload it.
3302 Issuing autochanger "unload 1 0" command.
unload status=OK 0
3303 Issuing autochanger "load 1 0" command.
3303 Autochanger "load 1 0" status is OK.
22-Nov 13:11 btape: 3301 Issuing autochanger "loaded? drive 0" command.
22-Nov 13:11 btape: 3302 Autochanger "loaded? drive 0", result is Slot 1.
btape: btape.c:356 open device "LTO3" (/dev/nst0): OK
btape: btape.c:1223 Rewound "LTO3" (/dev/nst0)
btape: btape.c:1230 Wrote EOF to "LTO3" (/dev/nst0)
The test autochanger worked!!
------- fill -------
* fill
This command simulates Bacula writing to a tape.
It requires either one or two blank tapes, which it
will label and write.
If you have an autochanger configured, it will use
the tapes that are in slots 1 and 2, otherwise, you will
be prompted to insert the tapes when necessary.
It will print a status approximately
every 322 MB, and write an EOF every 3.2 GB. If you have
selected the simple test option, after writing the first tape
it will rewind it and re-read the last block written.
If you have selected the multiple tape test, when the first tape
fills, it will ask for a second, and after writing a few more
blocks, it will stop. Then it will begin re-reading the
two tapes.
This may take a long time -- hours! ...
Do you want to run the simplified test (s) with one tape
or the complete multiple tape (m) test: (s/m) m
Multiple tape test selected.
22-Nov 15:12 btape: Fatal Error at dev.c:1655 because:
dev.c:1654 Attempt to WEOF on non-appendable Volume
Wrote Volume label for volume "TestVolume1".
Wrote Start of Session label.
15:12:17 Begin writing Bacula records to first tape ...
Wrote blk_block=6605000, dev_blk_num=4966 VolBytes=320,366,592
rate=64073.3 KB/s
Wrote blk_block=6610000, dev_blk_num=9966 VolBytes=642,926,592
rate=71436.3 KB/s
Wrote blk_block=6615000, dev_blk_num=14966 VolBytes=965,486,592
rate=74268.2 KB/s
Wrote blk_block=6620000, dev_blk_num=4466 VolBytes=1,288,046,592
rate=64402.3 KB/s
15:12:40 Flush block, write EOF
Wrote blk_block=6625000, dev_blk_num=1000 VolBytes=1,610,606,592
rate=64424.3 KB/s
[--snip--]
17:13:39 Flush block, write EOF
Wrote blk_block=13185000, dev_blk_num=1000 VolBytes=424,809,326,592
rate=58304.9 KB/s
Wrote blk_block=13190000, dev_blk_num=6000 VolBytes=425,131,886,592
rate=58301.1 KB/s
22-Nov 17:13 btape: End of Volume "TestVolume1" at 618:10923 on device
"LTO3" (/dev/nst0). Write of 64512 bytes got -1.
22-Nov 17:13 btape: Re-read of last block succeeded.
btape: btape.c:2331 Last block at: 618:10922 this_dev_block_num=10923
btape: btape.c:2365 End of tape 618:0. VolumeCapacity=425,449,543,680.
Write rate = 58280.8 KB/s
22-Nov 17:13 btape: End of medium on Volume "TestVolume1"
Bytes=425,449,543,680 Blocks=6,594,890 at 22-Nov-2006 17:13.
22-Nov 17:14 btape: 3307 Issuing autochanger "unload slot 1, drive 0"
command.
22-Nov 17:15 btape: 3304 Issuing autochanger "load slot 2, drive 0" command.
22-Nov 17:15 btape: 3305 Autochanger "load slot 2, drive 0", status is OK.
22-Nov 17:15 btape: 3301 Issuing autochanger "loaded? drive 0" command.
22-Nov 17:15 btape: 3302 Autochanger "loaded? drive 0", result is Slot 2.
22-Nov 17:15 btape: Fatal Error at dev.c:1655 because:
dev.c:1654 Attempt to WEOF on non-appendable Volume
22-Nov 17:15 btape: 3301 Issuing autochanger "loaded? drive 0" command.
22-Nov 17:15 btape: 3302 Autochanger "loaded? drive 0", result is Slot 2.
Wrote Volume label for volume "TestVolume2".
22-Nov 17:15 btape: Wrote label to prelabeled Volume "TestVolume2" on
device "LTO3" (/dev/nst0)
22-Nov 17:15 btape: New volume "TestVolume2" mounted on device "LTO3"
(/dev/nst0) at 22-Nov-2006 17:15.
Done writing 0 records ...
Wrote End of Session label.
Wrote state file last_block_num1=10922 last_block_num2=11
17:15:51 Done filling tapes at 0:13. Now beginning re-read of first tape ...
22-Nov 17:15 btape: 3307 Issuing autochanger "unload slot 2, drive 0"
command.
22-Nov 17:16 btape: 3304 Issuing autochanger "load slot 1, drive 0" command.
22-Nov 17:17 btape: 3305 Autochanger "load slot 1, drive 0", status is OK.
22-Nov 17:17 btape: 3301 Issuing autochanger "loaded? drive 0" command.
22-Nov 17:17 btape: 3302 Autochanger "loaded? drive 0", result is Slot 1.
22-Nov 17:17 btape: Ready to read from volume "TestVolume1" on device
"LTO3" (/dev/nst0).
Rewinding.
Reading the first 10000 records from 0:0.
10000 records read now at 1:5084
Reposition from 1:5084 to 618:10922
Reading block 10922.
The last block of the first tape matches.
22-Nov 17:17 btape: 3307 Issuing autochanger "unload slot 1, drive 0"
command.
22-Nov 17:18 btape: 3304 Issuing autochanger "load slot 2, drive 0" command.
22-Nov 17:19 btape: 3305 Autochanger "load slot 2, drive 0", status is OK.
22-Nov 17:19 btape: 3301 Issuing autochanger "loaded? drive 0" command.
22-Nov 17:19 btape: 3302 Autochanger "loaded? drive 0", result is Slot 2.
22-Nov 17:19 btape: Ready to read from volume "TestVolume2" on device
"LTO3" (/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:11
Reading block 11.
The last block on the second tape matches. Test succeeded.
*
So, the fill and test commands are successful, but bfill fails.
And interestingly the fill command gives the same Fatal Error at beginning
as bfill does!
* weof
22-Nov 17:20 btape: Fatal Error at dev.c:1655 because:
dev.c:1654 Attempt to WEOF on non-appendable Volume
btape: btape.c:483 Bad status from weof. ERR=dev.c:1654 Attempt to WEOF on
non-appendable Volume
*cap
Configured device capabilities:
EOF BSR BSF FSR FSF FASTFSF !BSFATEOM EOM REM !RACCESS AUTOMOUNT !LABEL
ANONVOLS ALWAYSOPEN MTIOCGET
Device status:
OPENED TAPE LABEL !MALLOC !APPEND READ !EOT !WEOT !EOF !NEXTVOL !SHORT
Device parameters:
Device name: /dev/nst0
File=0 block=12
Min block=0 Max block=0
Status:
Bacula status: file=0 block=12
Device status: ONLINE IM_REP_EN file=0 block=12
btape: btape.c:1787 Device status: 641. ERR=dev.c:1654 Attempt to WEOF on
non-appendable Volume
Version: 1.39.28 (12 November 2006)
Ubuntu 6.06
Kernel 2.6.15-27-amd64-server
NEC-T40A Autochanger
IBM Ultrium 3 tape drive
Ralf
-------------------------------------------------------------------------
Take Surveys. Earn Cash. Influence the Future of IT
Join SourceForge.net's Techsay panel and you'll get the chance to share your
opinions on IT & business topics through brief surveys - and earn cash
http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
