Please help - cannot label a tape

[George A.]

Hi,

I was getting a message that Bareos is waiting for an appendable volume when running a backup job. No matter what I tried I couldn't run the job successfully and the 'cancel jobid' hung the bconsole (I had to press CTRL+C). Actually though bat I purged the volume but that didn't help either.

/var/log/bareos/bareos.log:

16-Dec 04:19 i7-dir JobId 4083: No prior Full backup Job record found.
16-Dec 04:19 i7-dir JobId 4083: No prior or suitable Full backup found in catalog. Doing FULL backup.
16-Dec 04:19 i7-dir JobId 4083: Start Backup JobId 4083, Job=i7_Backup.2015-12-16_04.19.22_34
16-Dec 04:19 i7-dir JobId 4083: Recycled current volume "BackupTape1"
16-Dec 04:19 i7-dir JobId 4083: Using Device "LTO-2" to write.
16-Dec 04:21 i7-sd JobId 4083: Error: block.c:630 Write error at 0:0 on device "LTO-2" (/dev/nst0). ERR=Invalid argument.
16-Dec 04:21 i7-sd JobId 4083: Error: block.c:644 Write error on fd=6 at file:blk 0:0 on device "LTO-2" (/dev/nst0). ERR=Invalid argument.
16-Dec 04:25 i7-sd JobId 4083: Error: Backspace record at EOT failed. ERR=Input/output error
16-Dec 04:25 i7-sd JobId 4083: Error: label.c:562 Unable to write device "LTO-2" (/dev/nst0): ERR=generic_tape_device.c:726 ioctl MTBSR error on "LTO-2" (/dev/nst0). ERR=Input/output error.

16-Dec 04:25 i7-sd JobId 4083: Marking Volume "BackupTape1" in Error in Catalog.
16-Dec 04:25 i7-sd JobId 4083: Job i7_Backup.2015-12-16_04.19.22_34 is waiting. Cannot find any appendable volumes.
Please use the "label" command to create a new Volume for:
Storage: "LTO-2" (/dev/nst0)
Pool: DailyPool
Media type: LTO-2

So I decided to delete that volume and relabel it. So here is what I did:

# dd if=/dev/urandom of=/dev/st0 bs=16384 count=1024; mt -f /dev/nst0 weof; mt weof
1024+0 records in
1024+0 records out
16777216 bytes (17 MB) copied, 19.4806 s, 861 kB/s

# bconsole
Connecting to Director i7:9101
1000 OK: i7-dir Version: 15.2.2 (16 November 2015)
Enter a period to cancel a command.

*list volumes pool=DailyPool
No results to list.
*label volume=BackupTape1 pool=DailyPool
barcodes encrypt pool= slot= storage= volume=
*label volume=BackupTape1 pool=DailyPool
Using Catalog "MyCatalog"
Automatically selected Storage: LTO-2
Connecting to Storage daemon LTO-2 at i7:9103 ...
Sending label command for Volume "BackupTape1" Slot 0 ...
block.c:630 Write error at 0:0 on device "LTO-2" (/dev/nst0). ERR=Invalid argument.
block.c:644 Write error on fd=5 at file:blk 0:0 on device "LTO-2" (/dev/nst0). ERR=Invalid argument.
Backspace record at EOT failed. ERR=Input/output error
3912 Failed to label Volume: ERR=generic_tape_device.c:726 ioctl MTBSR error on "LTO-2" (/dev/nst0). ERR=Input/output error.

Label command failed for Volume BackupTape1.
Do not forget to mount the drive!!!
*

The configuration is fine. All filesets have been tested, communication between DIR, FD and SD works. But the actual backup doesn't. (the tape is healthy, as well as the device)

I hope someone can help.

[Philipp Storz]

Please use "btape test" to check your drive outside of the sd.

Do not forget to shutdown the sd first.

(see http://doc.bareos.org/master/html/bareos-manual-main-reference.html#TapeDrive)

--
Mit freundlichen Grüßen

Philipp Storz philip...@bareos.com
Bareos GmbH & Co. KG Phone: +49 221 63 06 93-92
http://www.bareos.com Fax: +49 221 63 06 93-10

Sitz der Gesellschaft: Köln | Amtsgericht Köln: HRA 29646
Geschäftsführer: Stephan Dühr, M. Außendorf,
J. Steffens, P. Storz, M. v. Wieringen

[George Anchev]

Thanks for the tip. I am attaching the result. It seems there are no errors or problems.

Also before running "btape test" I was able to restore a file from an older tape (a different pool) which was backed up using Bacula. So I believe the hardware is fine.

But why can't I label and add to a pool the very same tape which shows no problems with "btape test"?

[George Anchev]

I really hope someone can help me with that. Practically I can't backup now because of this :(

[George Anchev]

I think this might be a bug Philipp.

I succeeded to boot my older VM system which is running Bacula 5.2.13 and the same tape was labeled successfully there. I am sending a screenshot as PNG file.

After that I booted back to the new system and started Bareos's bconsole. I have attached my result as TXT file so you can see everything. Each time I issue a 'mount' command the tape spins but backup doesn't start and keeps waiting for a mountable volume. No matter how many times I try it is still the same. In the end I decided to try another label and it took me back from where I started.

[Philipp Storz]

Have you altered the tape blocksize ?

If you look at the dmesg output, you might get a hint form the st driver.

[George Anchev]

I don't even know how to do what you are saying. I have simply copied the exact same parameters from my Bacula config. These settings have been working in Bacula for years without issues:

In bareos-sd.conf I have:

Device { 

 Name = LTO-2 

 Media Type = LTO-2 

 Archive Device = /dev/nst0 

 AutomaticMount = yes;

 AlwaysOpen = yes; 

 RemovableMedia = yes; 

 RandomAccess = no; 

 Maximum File Size = 100GB 

 Maximum Network Buffer Size = 65536

}

And in bareos-dir.conf I have:

Pool {

  Name = DailyPool

  Pool Type = Backup

  Recycle = yes

  AutoPrune = yes

  Volume Retention = 1 year

  Maximum Volume Bytes = 400G

  Maximum Volumes = 10

}

Searching through dmesg gives:

# dmesg | grep -E "block|blocksize|st0"

[    0.273511] ACPI: Executed 1 blocks of module-level executable AML code

[    0.330337] ACPI: Enabled 4 GPEs in block 00 to 3F

[    1.213746] scsi host0: ahci

[    1.537730] sd 0:0:0:0: [sda] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)

[    1.538229] sd 1:0:0:0: [sdb] 976773168 512-byte logical blocks: (500 GB/465 GiB)

[    1.539734] sd 2:0:0:0: [sdc] 321672960 512-byte logical blocks: (164 GB/153 GiB)

[    1.545964] sd 4:0:0:0: [sdd] 468862128 512-byte logical blocks: (240 GB/223 GiB)

[    1.545968] sd 4:0:0:0: [sdd] 4096-byte physical blocks

[    1.546372] sd 5:0:0:0: [sde] 7814037168 512-byte logical blocks: (4.00 TB/3.63 TiB)

[    2.185458] random: nonblocking pool is initialized

[   11.762276] st 8:0:3:0: Attached scsi tape st0

[   11.762279] st 8:0:3:0: st0: try direct i/o: yes (alignment 4 B)

[   86.339750] st 8:0:3:0: [st0] Block limits 256 - 524288 bytes.

What should I do?

[George Anchev]

Happy new year.

I still hope to get help on this.

[George Anchev]

Digging into the code of block.c I found this difference between Bacula's code and that of Bareos. Looking at those 2 files:

http://www.bacula.org/git/cgit.cgi/bacula/tree/bacula/src/stored/block.c (lines 613-617)

lacks the else statement which is visible in Bareos code (line 639-645) and according to the error lines it seems the problem is happening exactly there:

https://github.com/bareos/bareos/blob/master/src/stored/block.c#L639-L645

However I still don't know how to fix the problem.

Desperately waiting for some help.

[Marco van Wieringen]

On 01/ 6/16 06:30 PM, George Anchev wrote:
> Digging into the code of block.c I found this difference between Bacula's code and that of Bareos. Looking at those 2 files:
>
> http://www.bacula.org/git/cgit.cgi/bacula/tree/bacula/src/stored/block.c (lines 613-617)
>

> lacks the *else* statement which is visible in Bareos code (line 639-645) and according to the error lines it seems the problem is happening exactly there:

>
> https://github.com/bareos/bareos/blob/master/src/stored/block.c#L639-L645
>
> However I still don't know how to fix the problem.
>
> Desperately waiting for some help.
>

> --
> You received this message because you are subscribed to the Google Groups "bareos-users" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to bareos-users...@googlegroups.com <mailto:bareos-users...@googlegroups.com>.
> To post to this group, send email to bareos...@googlegroups.com <mailto:bareos...@googlegroups.com>.
> For more options, visit https://groups.google.com/d/optout.

That particular change has nothing to do with your actual problem. It seems your
tape drive refuses to write the label block to the tape and throws an EINVAL error.
Looking at the way you truncate your tapes I would try a default truncate which is
something like mt -f /dev/nst0 rewind; mt -f /dev/nst0 weof; mt -f /dev/nst0 rewind

In your other truncate you write random data which is kind of useless when you
write a EOF marker on the tape the drive will not pass that anyway.

For whatever reason your tape drive is not happy to write a label block and until
you fix that nothing else is going to work.

--
Marco van Wieringen marco.van...@bareos.com
Bareos GmbH & Co. KG Phone: +49-221-63069389
http://www.bareos.com

Sitz der Gesellschaft: Köln | Amtsgericht Köln: HRA 29646

Komplementär: Bareos Verwaltungs-GmbH

[George Anchev]

Thanks for your attention Marco.

I have been truncating all my tapes this way for years and never had such issues with Bacula (as I showed in an earlier message the same tape was successfully labeled in Bacula).

However I tried what you suggest. It seems I am getting the same unfortunate result:

# mt -f /dev/nst0 rewind; mt -f /dev/nst0 weof; mt -f /dev/nst0 rewind

# bconsole 

Connecting to Director i7:9101

1000 OK: i7-dir Version: 15.2.2 (16 November 2015)

Enter a period to cancel a command.

*list volumes pool=DailyPool

Automatically selected Catalog: MyCatalog

Using Catalog "MyCatalog"

No results to list.

*label storage=LTO-2 volume=BackupTape1 pool=DailyPool

Using Catalog "MyCatalog"

Connecting to Storage daemon LTO-2 at i7:9103 ...

Sending label command for Volume "BackupTape1" Slot 0 ...

block.c:630 Write error at 0:0 on device "LTO-2" (/dev/nst0). ERR=Invalid argument.

block.c:644 Write error on fd=5 at file:blk 0:0 on device "LTO-2" (/dev/nst0). ERR=Invalid argument.

Backspace record at EOT failed. ERR=Input/output error

3912 Failed to label Volume: ERR=generic_tape_device.c:726 ioctl MTBSR error on "LTO-2" (/dev/nst0). ERR=Input/output error.

Label command failed for Volume BackupTape1.

Do not forget to mount the drive!!!

*

What should I try next?

[George Anchev]

To triple check my own sanity:

I just installed Bacula 5.2.13 on this new system, stopped Bareos services and copied all config from /etc/bareos/*.conf to /etc/bacula/*.conf (modifying only db credentials, paths which were pointing to /var/lib/bareos and so on). Then I started Bacula services, truncated the tape and the labeling with Bacula was successful.

So: same system, same config, same device and same tape - labeling in Bacula works, in Bareos - not.

Unfortunately I am not an expert and I hope some of you knows what is going on.

[Marco van Wieringen]

As I already said in my previous mail it seems we get an EINVAL from the
tape write. Your only last resort option is to make sure NO SD plugins are
loaded and run the bareos-sd with debug e.g.

su - bareos -s /bin/bash
bareos-sd -f -d 200

Its probably easier to open a bug report on bugs.bareos.org and attach
your debug log there instead of dumping big logs on mailinglist. If nothing
else works then I'm afraid you are stuck on using Bacula on this particular
hardware. We use the same code on lots of tape installs where it works well
so it must be some strange bug or feature of this particular install. Then
again I think we only run things on LTO4 or higher these days.

[George Anchev]

Thanks Marco.

I don't know what EINVAL means and unfortunately I don't have an LTO-4 device.

Following your advice I filed a bug report with full info from the debug log and what we discussed here:

https://bugs.bareos.org/view.php?id=592