I would not worry too much about btape errors trying to switch
volumes. Some of the older btapes had a bug that caused such
problems. I don't believe that they are related to your problem.
You can avoid those problems by running btape fill using a single
volume.
On 05.02.2018 21:07, Tom Plancon wrote:
I ran btape Fill and it did fill a tape with 1.5TB in about 3
hours. Btape asked for a new tape, put it in, wrote OK then
asked for the first tape. I put it in but now I'm getting this
error:
Wrote block=23680000, file,blk=62,41035
VolBytes=1,527,644,095,488 rate=133.7 MB/s
05-Feb 14:31 btape JobId 0: End of Volume "TestVolume1" at
62:41848 on device "LTO-5" (/dev/st0). Write of 64512 bytes got
-1.
05-Feb 14:31 btape JobId 0: Re-read of last block succeeded.
btape: btape.c:2708-0 Last block at: 62:41847
this_dev_block_num=41848
btape: btape.c:2743-0 End of tape 62:0. Volume
Bytes=1,527,696,543,744. Write rate = 133.6 MB/s
05-Feb 14:31 btape JobId 0: End of medium on Volume
"TestVolume1" Bytes=1,527,696,543,744 Blocks=23,680,812 at
05-Feb-2018 14:31.
btape: btape.c:3068-0 Autochanger returned: 0
Mount blank Volume on device "LTO-5" (/dev/st0) and press return
when ready:
btape: btape.c:3073-0
Wrote Volume label for volume "TestVolume2".
05-Feb 14:35 btape JobId 0: Wrote label to prelabeled Volume
"TestVolume2" on tape device "LTO-5" (/dev/st0)
05-Feb 14:35 btape JobId 0: New volume "TestVolume2" mounted on
device "LTO-5" (/dev/st0) at 05-Feb-2018 14:35.
btape: btape.c:2313-0 Wrote 1000 blocks on second tape. Done.
Done writing 0 records ...
Wrote End of Session label.
btape: btape.c:2382-0 Wrote state file last_block_num1=41847
last_block_num2=1001
btape: btape.c:2400-0
14:35:52 Done filling tapes at 0:1003. Now beginning re-read of
first tape ...
btape: btape.c:2478-0 Enter do_unfill
btape: btape.c:2516-0 Autochanger returned: 0
Mount first tape. Press enter when ready:
btape: btape.c:2519-0
05-Feb 14:37 btape JobId 0: Warning: acquire.c:276 Read acquire:
vol_mgr.c:382 Could not reserve volume "TestVolume1" for append,
because it will be read.
Mount Volume "TestVolume1" on device "LTO-5" (/dev/st0) and
press return when ready:
05-Feb 14:37 btape JobId 0: Error: mount.c:834 Hey!!!!! WroteVol
non-zero !!!!!
btape: mount.c:835-0 Hey!!!!! WroteVol non-zero !!!!!
Mount Volume "TestVolume1" on device "LTO-5" (/dev/st0) and
press return when ready:
05-Feb 14:41 btape JobId 0: Error: mount.c:834 Hey!!!!! WroteVol
non-zero !!!!!
btape: mount.c:835-0 Hey!!!!! WroteVol non-zero !!!!!
05-Feb 14:41 btape JobId 0: Warning: acquire.c:276 Read acquire:
Wrong Volume mounted on tape device "LTO-5" (/dev/st0): Wanted
TestVolume1 have TestVolume2
Mount Volume "TestVolume1" on device "LTO-5" (/dev/st0) and
press return when ready:
05-Feb 14:42 btape JobId 0: Error: mount.c:834 Hey!!!!! WroteVol
non-zero !!!!!
btape: mount.c:835-0 Hey!!!!! WroteVol non-zero !!!!!
05-Feb 14:42 btape JobId 0: Warning: acquire.c:276 Read acquire:
vol_mgr.c:382 Could not reserve volume "TestVolume1" for append,
because it will be read.
>>>>>>>>I did put in the 2nd tape again,
thinking something didn't complete that needed to, but it
doesn't look like that was the case! Does the fact that btape
called my device an "autochanger" have any meaning? Tried it a
couple more times then got this:
Mount Volume "TestVolume1" on device "LTO-5" (/dev/st0) and
press return when ready: 05-Feb 14:56 btape JobId 0: Error:
mount.c:834 Hey!!!!! WroteVol non-zero !!!!!
btape: mount.c:835-0 Hey!!!!! WroteVol non-zero !!!!!
Mount Volume "TestVolume1" on device "LTO-5" (/dev/st0) and
press return when ready:
05-Feb 14:56 btape JobId 0: Fatal error: acquire.c:325 Too many
errors trying to mount tape device "LTO-5" (/dev/st0) for
reading.
Bacula interrupted by signal 11: Segmentation violation
Kaboom! btape, btape got signal 11 - Segmentation violation at
05-Feb-2018 14:56:56. Attempting traceback.
Kaboom! exepath=/root
Calling: /root/btraceback /root/btape 11510 /tmp
Any thoughts on what this means greatly appreciated! Thanks!
On 2/5/2018 11:41 AM, Tom Plancon
wrote:
Hi Kern,
Yes, this has happened on several tapes at this point. They
are all brand new HP LTO-5 tapes.
No, I'm not using the Windows SD. The SD is running on the
Centos 7 machine which runs the tape drive.
So this AM I'm running the btape Fill routine. It it still
running and it's over 130Gb at this time, that's 6 times the
21Gb I was getting on the backup. Is it safe to say that the
controller is not the issue?
Thanks again for your help!
On 2/3/2018 3:58 AM, Kern Sibbald
wrote:
Hello,
In this case, Bacula received an EOT marker, so it stopped
writing. My best guess is that the tape is defective or has
a misplaced EOT marker. Does this happen on all your
tapes? If so, then there might be something wrong with your
tape controller.
You are not by any chance using the Windows SD are you?
(pretty unlikely, but just checking).
Another thing to do is to point btape at the volume
(assuming you can afford to overwrite the data) and give it
the "fill" command and see how much data btape can write.
Then try btape on a different tape to see what it does.
Best regards,
Kern
On 02.02.2018 22:53, Tom Plancon
wrote:
Kern,
Thanks much for the response! Here is the job output from
Bacula, there was nothing in /var/log/messages for the
time period.
01-Feb 17:01 godwit-bacula-dir JobId 33: No prior Full
backup Job record found.
01-Feb 17:01 godwit-bacula-dir JobId 33: No prior or
suitable Full backup found in catalog. Doing FULL backup.
01-Feb 17:01 godwit-bacula-dir JobId 33: Start Backup
JobId 33, Job=HomeTape.2018-02-01_17.01.01_03
01-Feb 17:01 godwit-bacula-dir JobId 33: Using Device
"LTO-5" to write.
01-Feb 17:01 bacula-sd JobId 33: Wrote label to prelabeled
Volume "001" on tape device "LTO-5" (/dev/st0)
01-Feb 17:01 bka-design-fd JobId 33: Generate VSS
snapshots. Driver="Win64 VSS"
01-Feb 17:01 bka-design-fd JobId 33: Snapshot mount
point: E:\
01-Feb 17:45 bacula-sd JobId 33: Re-read of last block
succeeded.
01-Feb 17:45 bacula-sd JobId 33: End of medium on Volume
"001" Bytes=21,474,819,072 Blocks=332,880 at 01-Feb-2018
17:45.
01-Feb 17:47 godwit-bacula-dir JobId 33: Created new
Volume="Hme-0002", Pool="HomePool", MediaType="LTO-5" in
catalog.
01-Feb 17:47 bacula-sd JobId 33: Please mount append
Volume "Hme-0002" or label a new one for:
Job: HomeTape.2018-02-01_17.01.01_03
Storage: "LTO-5" (/dev/st0)
Pool: HomePool
Media type: LTO-5
<....tape request repeated....>
02-Feb 09:48 bacula-sd JobId 33: Fatal error: Job 33
canceled.
02-Feb 09:48 bacula-sd JobId 33: Elapsed time=16:47:45,
Transfer rate=354.8 K Bytes/second
02-Feb 09:48 bacula-sd JobId 33: Fatal error: askdir.c:355
NULL Volume name. This shouldn't happen!!!
02-Feb 09:48 godwit-bacula-dir JobId 33: Bacula
godwit-bacula-dir 7.0.5 (28Jul14):
Build OS: x86_64-redhat-linux-gnu redhat
Enterprise release
JobId: 33
Job: HomeTape.2018-02-01_17.01.01_03
Backup Level: Full (upgraded from Incremental)
Client: "bka-design-fd" 7.0.5 (04Aug14)
Microsoft Windows Server 2008 R2 Standard Edition Service
Pack 1 (build 76
01), 64-bit,Cross-compile,Win64
FileSet: "Home Set" 2018-02-01 17:01:01
Pool: "HomePool" (>From Job resource)
Catalog: "MyCatalog" (From Client
resource)
Storage: "LTO-5" (From Job resource)
Scheduled time: 01-Feb-2018 17:00:55
Start time: 01-Feb-2018 17:01:03
End time: 02-Feb-2018 09:48:54
Elapsed time: 16 hours 47 mins 51 secs
Priority: 10
FD Files Written: 19,340
SD Files Written: 19,373
FD Bytes Written: 21,301,085,904 (21.30 GB)
SD Bytes Written: 21,457,844,820 (21.45 GB)
Rate: 352.3 KB/s
Software Compression: None
VSS: no
Encryption: no
Accurate: no
Volume name(s): 001
Volume Session Id: 1
Volume Session Time: 1517515212
Last Volume Bytes: 0 (0 B)
Non-fatal FD errors: 0
SD Errors: 1
FD termination status: Canceled
SD termination status: Canceled
Termination: Backup Canceled
:
Thanks again.
On 2/2/2018 4:16 PM, Kern
Sibbald wrote:
Hello,
Unfortunately without the *complete* job output from
Bacula when "Bacula called the tape full", we cannot do
much for you.
You should also look and see if there are any messages in
the OS log at the time the tape was declared full. If
there are any please include them too.
Best regards,
Kern
On 02.02.2018 20:42, Tom Plancon wrote:
Hi folks,
Setting up Bacula 7.0.5 on Centos 7, backing up to a HPE
LTO-5 Ultrium 3000 external SAS drive. Everything going
fairly smoothly; bacula-sd finds the drive and
btape-test reports full success. However, tried doing a
test backup from a Win client using a directory of
134Gb. Backup started and appeared to run normally, then
after about 21Gb written to tape, Bacula called tape
full and requested a new tape be mounted!
I've seen discussions re: block sizes on LTO-5 devices,
but much of it a bit over my head. This is the first
LT0-5 device I've used although had great success with
LT0-4 devices. Here it the output of Tapeinfo:
Product Type: Tape Drive
Vendor ID: 'HP '
Product ID: 'Ultrium 5-SCSI '
Revision: 'Z6ED'
Attached Changer API: No
SerialNumber: 'HUJ6326M2G'
MinBlock: 1
MaxBlock: 16777215
SCSI ID: 0
SCSI LUN: 0
Ready: yes
BufferedMode: yes
Medium Type: Not Loaded -------?!?!?
Density Code: 0x58
BlockSize: 0
DataCompEnabled: yes
DataCompCapable: yes
DataDeCompEnabled: yes
CompType: 0x1
DeCompType: 0x1
BOP: yes
Block Position: 0
Partition 0 Remaining Kbytes: 1470031
Partition 0 Size in Kbytes: 1470031
ActivePartition: 0
EarlyWarningSize: 0
NumPartitions: 0
MaxPartitions: 1
"Medium type - not loaded", there was a tape in the
drive, so not sure what that means.
And the resource definitions from the conf files:
------------resource def. from
bacula-dir-------------------------------------------------
# Definition of LTO-5 tape device
Storage {
Name = LTO-5
##Do not use "localhost" here
Address = godwit.domus-bka.local # N.B.
Use a fully qualified name here
SDPort = 9103
Password = "godwitBackup" # password for
Storage daemon
Device = LTO-5 # must be same as
Device in Storage daemon
Media Type = LTO-5 # must be same as
MediaType in Storage daemon
Maximum Concurrent Jobs = 10
}
------------resource def. from
bacula-sd-------------------------------------------------
# A Linux or Solaris LTO-5 tape drive
Device {
Name = LTO-5
Media Type = LTO-5
Archive Device = /dev/st0
AutomaticMount = yes; # when device
opened, read it
AlwaysOpen = yes;
RemovableMedia = yes;
RandomAccess = no;
AutoChanger = no
Maximum File Size = 25GB
## Changer Command = "/usr/libexec/bacula/mtx-changer %c
%o %S %a %d"
## Changer Device = /dev/sg0
## AutoChanger = yes
# # Enable the Alert command only if you have the mtx
package loaded
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-------------------------------------------------------------------------
Any insight as to what may be happening here, or config
items I've left out would be greatly appreciated!
Thanks much!
|