btape multivolume fill test fails on 7.4.4 but succeeds on 5.2.13

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

btape multivolume fill test fails on 7.4.4 but succeeds on 5.2.13

Caribe Schreiber
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.  I've got an HP
1/8 G2 Autoloader with an LTO-6 SAS drive running under gentoo linux
with kernel 4.4.39 and the linux st drivers.  The firmware on both the
drive and the autoloader are relatively recent.

I'm able to successfully run the batpe test command on a single tape
with the invocation 'btape -c /etc/bacula/bacula-sd.conf /dev/nst0' as
is outlined in the docs and all the autochanger tests function happily
at the end of the normal test cycle and correctly swap tapes between
slots perfectly (output included below).

I'm running into a somewhat odd issue where I'm not able to get the
btape multivolume fill test to complete successfully under 7.4.4, but I
am able to use the exact same bacula-sd.conf file under a build of
5.2.13 which succeeds (in fact, on the same boot with the same device
files and same default st configs).

I've included a copy of the output from the failed multivolume fill run
under 7.4.4 and the successful multivolume fill run under 5.2.13.  I've
also included the pertinent sections from the bacula-sd.conf that I've
been using for both runs.  Additionally, I've included the output from
sginfo in case there's something in the way the st kernel driver is
configured by default that's incorrect and I'm just not seeing it.

I'm relatively new to bacula and linux tape management in general, so
I'm hoping I've just done something silly and a sage old hand can point
out my obvious mistake.

I did note that there was another user that posted about this exact
problem several months ago on a very similar IBM LTO-6 configuration,
but there wasn't a posted resolution.  Here's the relevant thread:
http://www.backupcentral.com/forum/19/271519?sid=e1ed71be5d24670fea367324f317339f
.

The only thing that I see obviously different from the two versions'
btape runs is that 5.2.13 writes the last block at block_num 26144 for
the first tape and 7.4.4 writes its last block at block_num 26147 for
the first tape, which to me signals a possible change in end of tape
management between the two versions (again...I'm not steeped in the
bacula code, but it seems weird to have two different finishing points
on the same hardware and configuration...especially when the successful
one is a couple of blocks shorter).

Any help would be greatly appreciated.  Thank You in advance!

~Caribe


-------------------------------------------begin
bacula-sd.conf--------------------------------------------------------------

#
# An HP 1/8 autochanger device with one drive
#
Autochanger {
  Name = AutochangerHP
  Device = Drive-1
  Changer Command = "/usr/libexec/bacula/mtx-changer %c %o %S %a %d"
  Changer Device = /dev/sg3
}

Device {
  Name = Drive-1                      #
  Media Type = LTO-6
  Archive Device = /dev/nst0
  AutomaticMount = yes;               # when device opened, read it
  AlwaysOpen = yes;
  RemovableMedia = yes;
  RandomAccess = no;
  AutoChanger = yes
  Maximum File Size = 5GB
  #
  # 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'"
}


-------------------------------------------end
bacula-sd.conf----------------------------------------------------------------



--------------------------------------------begin successful 5.2.13
btape output----------------------------------------

Wrote block=38770000, file,blk=126,17624 VolBytes=2,501,130,175,488
rate=151.5 MB/s
Wrote block=38775000, file,blk=126,22624 VolBytes=2,501,452,735,488
rate=151.5 MB/s
25-Jan 22:31 btape JobId 0: End of Volume "TestVolume1" at 126:26144 on
device "Drive-1" (/dev/nst0). Write of 64512 bytes got -1.
25-Jan 22:31 btape JobId 0: Re-read of last block succeeded.
btape: btape.c:2714-0 Last block at: 126:26143 this_dev_block_num=26144
btape: btape.c:2749-0 End of tape 126:0. Volume Bytes=2,501,679,817,728.
Write rate = 151.5 MB/s
25-Jan 22:31 btape JobId 0: End of medium on Volume "TestVolume1"
Bytes=2,501,679,817,728 Blocks=38,778,519 at 25-Jan-2017 22:31.
25-Jan 22:31 btape JobId 0: 3307 Issuing autochanger "unload slot 1,
drive 0" command.
25-Jan 22:32 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive
0" command.
25-Jan 22:33 btape JobId 0: 3305 Autochanger "load slot 2, drive 0",
status is OK.
Wrote Volume label for volume "TestVolume2".
25-Jan 22:33 btape JobId 0: Wrote label to prelabeled Volume
"TestVolume2" on device "Drive-1" (/dev/nst0)
25-Jan 22:33 btape JobId 0: New volume "TestVolume2" mounted on device
"Drive-1" (/dev/nst0) at 25-Jan-2017 22:33.
btape: btape.c:2320-0 Wrote 1000 blocks on second tape. Done.
Done writing 0 records ...
Wrote End of Session label.
btape: btape.c:2389-0 Wrote state file last_block_num1=26143
last_block_num2=1001
btape: btape.c:2407-0

22:33:21 Done filling tapes at 0:1003. Now beginning re-read of first
tape ...
btape: btape.c:2485-0 Enter do_unfill
25-Jan 22:33 btape JobId 0: 3307 Issuing autochanger "unload slot 2,
drive 0" command.
25-Jan 22:34 btape JobId 0: 3304 Issuing autochanger "load slot 1, drive
0" command.
25-Jan 22:35 btape JobId 0: 3305 Autochanger "load slot 1, drive 0",
status is OK.
25-Jan 22:35 btape JobId 0: Ready to read from volume "TestVolume1" on
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 126:26143
Reading block 26143.

The last block of the first tape matches.

25-Jan 22:36 btape JobId 0: 3307 Issuing autochanger "unload slot 1,
drive 0" command.
25-Jan 22:37 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive
0" command.
25-Jan 22:38 btape JobId 0: 3305 Autochanger "load slot 2, drive 0",
status is OK.
25-Jan 22:38 btape JobId 0: Ready to read from volume "TestVolume2" on
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.


--------------------------------------------end successful 5.2.13 btape
output------------------------------------------


--------------------------------------------begin failed 7.4.4 btape
output----------------------------------------
Wrote block=38770000, file,blk=501,17999 VolBytes=2,501,130,175,488
rate=127.2 MB/s
Wrote block=38775000, file,blk=501,22999 VolBytes=2,501,452,735,488
rate=127.2 MB/s
26-Jan 17:38 btape JobId 0: End of Volume "TestVolume1" at 501:26148 on
device "Drive-1" (/dev/nst0). Write of 64512 bytes got -1.
26-Jan 17:38 btape JobId 0: Re-read of last block succeeded.
btape: btape.c:2712-0 Last block at: 501:26147 this_dev_block_num=26148
btape: btape.c:2747-0 End of tape 501:0. Volume Bytes=2,501,655,883,776.
Write rate = 127.1 MB/s
26-Jan 17:38 btape JobId 0: End of medium on Volume "TestVolume1"
Bytes=2,501,655,883,776 Blocks=38,778,148 at 26-Jan-2017 17:38.
26-Jan 17:38 btape JobId 0: 3307 Issuing autochanger "unload slot 1,
drive 0" command for vol TestVolume1.
26-Jan 17:39 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive
0" command for vol TestVolume2.
26-Jan 17:40 btape JobId 0: 3305 Autochanger "load slot 2, drive 0",
status is OK for vol TestVolume2.
Wrote Volume label for volume "TestVolume2".
26-Jan 17:40 btape JobId 0: Wrote label to prelabeled Volume
"TestVolume2" on tape device "Drive-1" (/dev/nst0)
26-Jan 17:40 btape JobId 0: New volume "TestVolume2" mounted on device
"Drive-1" (/dev/nst0) at 26-Jan-2017 17:40.
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=26147
last_block_num2=1001
btape: btape.c:2402-0

17:40:25 Done filling tapes at 0:1003. Now beginning re-read of first
tape ...
btape: btape.c:2480-0 Enter do_unfill
26-Jan 17:40 btape JobId 0: 3307 Issuing autochanger "unload slot 2,
drive 0" command for vol TestVolume1.
26-Jan 17:41 btape JobId 0: 3304 Issuing autochanger "load slot 1, drive
0" command for vol TestVolume1.
26-Jan 17:42 btape JobId 0: 3305 Autochanger "load slot 1, drive 0",
status is OK for vol TestVolume1.
26-Jan 17:42 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 501:26147
Reading block 26147.




The blocks differ at byte 0


!!!! The last block written and the block
that was read back differ. The test FAILED !!!!
This must be corrected before you use Bacula
to write multi-tape Volumes.!!!!
26-Jan 17:43 btape JobId 0: 3307 Issuing autochanger "unload slot 1,
drive 0" command for vol TestVolume2.
26-Jan 17:44 btape JobId 0: 3304 Issuing autochanger "load slot 2, drive
0" command for vol TestVolume2.
26-Jan 17:44 btape JobId 0: 3305 Autochanger "load slot 2, drive 0",
status is OK for vol TestVolume2.
26-Jan 17:45 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 blocks differ at byte 0


!!!! The last block written and the block
that was read back differ. The test FAILED !!!!
This must be corrected before you use Bacula
to write multi-tape Volumes.!!!!
btape: btape.c:2407-0 do_unfill failed.
--------------------------------------------end failed 7.4.4 btape
output------------------------------------------


--------------------------------------------begin sginfo
output------------------------------------------
backup ~ # sginfo -a /dev/nst0
INQUIRY response (cmd: 0x12)
----------------------------
Device Type                        1
Vendor:                    HP
Product:                   Ultrium 6-SCSI
Revision level:            35JW

Serial Number 'G0-F15h'

Read-Write Error Recovery mode page (0x1)
-----------------------------------------
AWRE                               0
ARRE                               0
TB                                 0
RC                                 0
EER                                1
PER                                0
DTE                                0
DCR                                0
Read Retry Count                   21
Correction Span                    0
Head Offset Count                  0
Data Strobe Offset Count           0
Write Retry Count                  10
Recovery Time Limit (ms)           0

Disconnect-Reconnect mode page (0x2)
------------------------------------
Buffer full ratio                  0
Buffer empty ratio                 0
Bus Inactivity Limit (SAS: 100us)  1
Disconnect Time Limit              0
Connect Time Limit (SAS: 100us)    0
Maximum Burst Size                 0
EMDP                               0
Fair Arbitration (fcp:faa,fab,fac) 0
DIMM                               0
DTDC                               0
First Burst Size                   0

Control mode page (0xa)
-----------------------
TST                                1
TMF_ONLY                           0
D_SENSE                            0
GLTSD                              0
RLEC                               0
Queue Algorithm Modifier           0
QErr                               0
DQue [obsolete]                    0
TAS                                0
RAC                                0
UA_INTLCK_CTRL                     0
SWP                                0
RAERP [obs.]                       0
UAAERP [obs.]                      0
EAERP [obs.]                       0
ATO                                0
TAS                                1
AUTOLOAD MODE                      2
Ready AER Holdoff Period [obs.]    0
Busy Timeout Period                0
Extended self-test completion time 0

Data compression mode page (0xf)
----------------------------------------------------
DCE                                1
DCC                                1
DDE                                1
RED                                0
Compression algorithm              1
Decompression algorithm            1

Device configuration mode page (0x10)
----------------------------------------------------
CAF                                0
Active format                      0
Active partition                   0
Write object cbuffer full ratio    0
Read object cbuffer full ratio     0
Wire delay time                    300
OBR                                0
LOIS                               1
RSMK                               0
AVC                                1
SOCF                               0
ROBO                               0
REW                                0
Gap size                           0
EOD defined                        0
EEG                                1
SEW                                0
SWP                                0
BAML                               0
BAM                                0
Object cbuffer size at early warning0
Select data compression algorithm  1
ASOCWP                             0
PERSWO                             0
PRMWP                              0

Medium partition(1) mode page (0x11)
----------------------------------------------------
Maximum additional partitions      3
Additional partitions defined      0
FDP                                0
SDP                                0
IDP                                1
PSUM                               3
POFM                               1
CLEAR                              0
ADDP                               0
Medium format recognition          3
Partition units                    9
Partition size                     2620
Partition size                     0
Partition size                     0
Partition size                     0

SAS logical unit mode page (0x18)
----------------------------------------------------
Transport Layer Retries            1

SAS SSP port control mode page (0x19)
-------------------------------------
Ready LED meaning                  0
I_T Nexus Loss time                2000
Initiator response time-out        1000

Power Condition mode page (0x1a)
--------------------------------
Idle                               1
Standby                            0
Idle Condition counter (100ms)     0
Standby Condition counter (100ms)  0

Informational Exceptions mode page (0x1c)
-----------------------------------------
PERF                               0
EBF                                0
EWASC                              0
DEXCPT                             1
TEST                               0
EBACKERR                           0
LOGERR                             0
MRIE                               3
Interval Timer                     0
Report Count                       1

mode page: 0x1d   [Medium configuration]
---------------
0x02                               0x00
0x03                               0x00
0x04                               0x01
0x05                               0x02
0x06                               0x00
0x07                               0x00
0x08                               0x00
0x09                               0x00
0x0a                               0x00
0x0b                               0x00
0x0c                               0x00
0x0d                               0x00
0x0e                               0x00
0x0f                               0x00
0x10                               0x00
0x11                               0x00
0x12                               0x00
0x13                               0x00
0x14                               0x00
0x15                               0x00
0x16                               0x00
0x17                               0x00
0x18                               0x00
0x19                               0x00
0x1a                               0x00
0x1b                               0x00
0x1c                               0x00
0x1d                               0x00
0x1e                               0x00
0x1f                               0x00

mode page: 0x3b
---------------
0x02                               0x01
0x03                               0x00
0x04                               0x00
0x05                               0x00
0x06                               0x48
0x07                               0x55
0x08                               0x4a
0x09                               0x35
0x0a                               0x34
0x0b                               0x31
0x0c                               0x34
0x0d                               0x54
0x0e                               0x47
0x0f                               0x48

mode page: 0x3c
---------------
0x02                               0x07
0x03                               0x00
0x04                               0x00
0x05                               0x06
0x06                               0x00
0x07                               0x14
0x08                               0x00
0x09                               0x07
0x0a                               0x8a
0x0b                               0x6f
0x0c                               0x01
0x0d                               0x06
0x0e                               0x00
0x0f                               0x00
0x10                               0x58
0x11                               0x89
0x12                               0xe0
0x13                               0xdd
0x14                               0x10
0x15                               0x06
0x16                               0x00
0x17                               0x0b
0x18                               0x2b
0x19                               0x19
0x1a                               0x00
0x1b                               0x00
0x1c                               0x18
0x1d                               0x06
0x1e                               0x00
0x1f                               0x00
0x20                               0x00
0x21                               0x08
0x22                               0x52
0x23                               0x8f

mode page: 0x3d
---------------
0x02                               0x00
0x03                               0x00

--------------------------------------------end sginfo
output------------------------------------------

--------------------------------------------begin successful btape test
output--------------------

backup ~ # btape -c /etc/bacula/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
*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: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: btape.c:471-0 open device "Drive-1" (/dev/nst0): OK
btape: btape.c:576-0 Rewound "Drive-1" (/dev/nst0)
btape: btape.c:1422-0 Now moving to end of medium.
btape: btape.c:627-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: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:576-0 Rewound "Drive-1" (/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:576-0 Rewound "Drive-1" (/dev/nst0)
btape: btape.c:813-0 Wrote first record of 64412 bytes.
btape: btape.c:824-0 Wrote second record of 64412 bytes.
btape: btape.c:835-0 Wrote third record of 64412 bytes.
btape: btape.c:606-0 Wrote 1 EOF to "Drive-1" (/dev/nst0)
btape: btape.c:851-0 Backspaced over EOF OK.
btape: btape.c:856-0 Backspace record OK.
btape: btape.c:873-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: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: 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:606-0 Wrote 1 EOF to "Drive-1" (/dev/nst0)
btape: btape.c:576-0 Rewound "Drive-1" (/dev/nst0)
btape: btape.c:1636-0 Now forward spacing 1 file.
We should be in file 1. I am at file 1. This is correct!
btape: btape.c:1648-0 Now forward spacing 2 files.
We should be in file 3. I am at file 3. This is correct!
btape: btape.c:576-0 Rewound "Drive-1" (/dev/nst0)
btape: btape.c:1661-0 Now forward spacing 4 files.
We should be in file 4. I am at file 4. This is correct!

btape: btape.c:1679-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): y


=== Autochanger test ===

3301 Issuing autochanger "loaded" command.
Slot 2 loaded. I am going to unload it.
3302 Issuing autochanger "unload 2 0" command.
unload status=OK 0
3303 Issuing autochanger "load 1 0" command.
3303 Autochanger "load 1 0" status is OK.
btape: btape.c:471-0 open device "Drive-1" (/dev/nst0): OK
btape: btape.c:1566-0 Rewound "Drive-1" (/dev/nst0)
btape: btape.c:1573-0 Wrote EOF to "Drive-1" (/dev/nst0)

The test autochanger worked!!

--------------------------------------------end successful btape test
output----------------------



------------------------------------------------------------------------------
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
[hidden email]
https://lists.sourceforge.net/lists/listinfo/bacula-users
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: btape multivolume fill test fails on 7.4.4 but succeeds on 5.2.13

Alan Brown
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
[hidden email]
https://lists.sourceforge.net/lists/listinfo/bacula-users
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: btape multivolume fill test fails on 7.4.4 but succeeds on 5.2.13

Caribe Schreiber
That's sad to hear, but I'm glad to know that it's got a known issue
that's being worked on.

I've tried the single volume test with similar results (see below). Is
the breakage only in the multivolume test, or is the btape fill facility
just plain broken in 7.4.4?

Thanks for your help!




-------begin single volume fill breakage-----------
Wrote block=38770000, file,blk=251,17749 VolBytes=2,501,130,175,488
rate=142.2 MB/s
Wrote block=38775000, file,blk=251,22749 VolBytes=2,501,452,735,488
rate=142.2 MB/s
27-Jan 11:30 btape JobId 0: End of Volume "TestVolume1" at 251:26146 on
device "Drive-1" (/dev/nst0). Write of 64512 bytes got -1.
27-Jan 11:31 btape JobId 0: Re-read of last block succeeded.
btape: btape.c:2712-0 Last block at: 251:26145 this_dev_block_num=26146
btape: btape.c:2747-0 End of tape 251:0. Volume Bytes=2,501,671,882,752.
Write rate = 142.1 MB/s
btape: btape.c:2315-0 Wrote 1000 blocks on second tape. Done.
Done writing 0 records ...
btape: btape.c:2384-0 Wrote state file last_block_num1=26145
last_block_num2=0
btape: btape.c:2399-0

11:31:02 Done filling tape at 251:0. Now beginning re-read of tape ...
btape: btape.c:2480-0 Enter do_unfill
27-Jan 11:31 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:26145
Reading block 26145.




The blocks differ at byte 0


!!!! The last block written and the block
that was read back differ. The test FAILED !!!!
This must be corrected before you use Bacula
to write multi-tape Volumes.!!!!
btape: btape.c:2407-0 do_unfill failed.

-------end single volume fill breakage-------------



On 01/27/17 11:04, 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
[hidden email]
https://lists.sourceforge.net/lists/listinfo/bacula-users
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: btape multivolume fill test fails on 7.4.4 but succeeds on 5.2.13

Kern Sibbald
In reply to this post by Alan Brown
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
> [hidden email]
> 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
[hidden email]
https://lists.sourceforge.net/lists/listinfo/bacula-users
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: btape multivolume fill test fails on 7.4.4 but succeeds on 5.2.13

Kern Sibbald
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
>> [hidden email]
>> 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
> [hidden email]
> 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
[hidden email]
https://lists.sourceforge.net/lists/listinfo/bacula-users
Loading...