Tape Libraries & Bacula
I am attempting to revive a long unused-tape library. I want it active so
I can go away on holiday and not worry about changing tapes. At present, I
use a single DLT-7000 drive, which needs a new tape every three or four days.
My strategy includes filling each tape, then starting a new one. This approach
may or may not be something that is applicable to your needs.
I am using Bacula 3.0.2 here. With PostgreSQL 8.3.7, and mtx
version 1.3.11. Just saying.
Connecting the device
These are my existing devices before attaching my tape library:
# camcontrol devlist <QUANTUM DLT7000 1E48> at scbus1 target 5 lun 0 (sa0,pass0) <USB 2.0 Storage Device 0100> at scbus2 target 0 lun 0 (pass1,da0) <HL-DT-ST DVDRAM GSA-H10A JL02> at scbus4 target 0 lun 0 (pass2,cd0)
That existing sa0 is used by my Bacula installation. That is important to note,
as you will see below.
With SCSI devices, it is important to use a SCSCI card and terminator that is
appropriate to the device in question. These choices are outside the scope of
this article.
I last tried using this tape library in April 2008 and I failed. The problem
was not seeing both the library and the drive at the same time. I found
my post
to the FreeBSD SCSCI mailing list. But back in 2006,
when I first bought the library, it worked just find.
Connecting the device
The standard FreeBSD tool for controlling SCSI devices is camcontrol. In this
command, I look for what is connected:
# camcontrol devlist <QUANTUM DLT7000 1E48> at scbus1 target 5 lun 0 (pass0,sa0) <USB 2.0 Storage Device 0100> at scbus2 target 0 lun 0 (pass1,da0) <HL-DT-ST DVDRAM GSA-H10A JL02> at scbus4 target 0 lun 0 (pass2,cd0)
After connecting my tape library, I ask camcontrol to scan for the new device,
and then list the devices again:
# sudo camcontrol rescan all Re-scan of bus 0 was successful Re-scan of bus 1 was successful Re-scan of bus 2 was successful Re-scan of bus 3 was successful Re-scan of bus 4 was successful Re-scan of bus 5 was successful Re-scan of bus 6 was successful # camcontrol devlist <DEC TZ89 (C) DEC 1837> at scbus0 target 1 lun 0 (pass3,sa1) <QUANTUM DLT7000 1E48> at scbus1 target 5 lun 0 (pass0,sa0) <USB 2.0 Storage Device 0100> at scbus2 target 0 lun 0 (pass1,da0) <HL-DT-ST DVDRAM GSA-H10A JL02> at scbus4 target 0 lun 0 (pass2,cd0)
As you can see, a new device has arrived, the DC TZ89. Looking back at my
original notes on this tape library, you
will see the same model number appears there. This looks good so far.
And you can also see sa0, the original tape drive, and a new sa1. But
the drive in the tape library cannot be found. This reflects the same
situation I left in 2008.
At this point (Monday), I spent time over the next two nights finding a
solution. It was on Wednesay night that I found a cable combination
that worked. The original cabling, which worked is on the left. The
new combination is on the right.
Oh the frustrations of cables.
After getting the cables right, here are my devices:
# camcontrol devlist <QUANTUM DLT7000 1E48> at scbus0 target 5 lun 0 (sa0,pass0) <DEC TL800 (C) DEC 0326> at scbus1 target 0 lun 0 (pass1,ch0) <DEC TZ89 (C) DEC 1837> at scbus1 target 5 lun 0 (sa1,pass2) <USB 2.0 Storage Device 0100> at scbus2 target 0 lun 0 (pass3,da0) <HL-DT-ST DVDRAM GSA-H10A JL02> at scbus4 target 0 lun 0 (pass4,cd0)
You may notice that some physical hardware has moved to new logical devices.
I always want the standalone DLT drive to be on sa0, and the tape library’s
drive to be on sa1, regardless of what is attached. This way, Bacula
always knows what is where. I did this with the following entries
added to /boot/device.hints:
# # hints to keep Bacula seeing consistent stuff # hint.scbus.1.at="ahc0" hint.scbus.0.at="ahc1"
The next test, writing via tar, was done before I finalized the cables.
Backing up via tar
Let’s try writing to sa1, after we first load in a tape. I did that via
the tape library front panel. Later in this article, we’ll use the command
line. For now, let us walk before we run.
Let’s try a very simple backup and restore, using tar. In my case, I have
multiple tape drives attached. Be sure to use the right one. I did something
like this:
# tar cvf /dev/nsa1 . a . a .k5login a .cshrc a .login a .profile a .history a .bashrc a .bash_profile a .bash_history a make a .rnd a .qt a .kde a .ssh a .ssh/known_hosts a .kde/share a .kde/share/config a make/Makefile a make/Makefile~ a make/NGAIO ... ... ...
Note: not all output is shown above. It was about 8GB in total.
Now for the restore:
# mkdir /usr/restore-test # cd /usr/restore-test # mt -f /dev/nsa1 rewind # tar xvf /dev/nsa1 [ lots of output here omitted]
After the restore, we need to run a diff:
# diff -ruN ~dan/ /usr/restore-test
The only difference was in ~dan/.bash_history. I call that a sucesseful
backup and restore test.
Configuring the autochanger
My autochanger configurtion is this:
Device { Name = DLTLIB0 Description = Digital DLT MiniLibrary - TL891 Media Type = DLT Archive Device = /dev/nsa1 Autochanger = YES Drive Index = 0 Offline On Unmount = no Hardware End of Medium = no BSF at EOM = yes Backward Space Record = no Fast Forward Space File = no TWO EOF = yes Spool Directory = /home/bacula/spooling-lib Maximum Spool Size = 11759496889 Maximum Job Spool Size = 11759496889 # 10GB } Autochanger { Name = TapeRobot Device = DLTLIB0 Changer Device = /dev/pass1 Changer Command = "/home/dan/rc-chio-changer %c %o %S %a %d" }
Does mtx work?
mtx is a tool for controling SCSI media changer devices. In FreeBSD, it
comes as a port at /usr/ports/misc/mtx.
Recent versions of Bacula include a wrapper for mtx.
mtx-changer is a wrapper for the mtx utility. You can use any wrapper you
want. The wrapper acts as a go-between, giving Bacula a simple interface to
mtx. There are two parts supplied with Bacula: the mtx-changer script and a
configurationfile. Sometimes you need to alter these scripts to suit your OS. If so,
I prefer not to alter the package-supplied files in place. I prefer to copy
and edit instead:
cp -i /usr/local/share/bacula/mtx-changer /usr/local/sbin/ cp -i /usr/local/share/bacula/mtx-changer.conf /usr/local/etc/
The first thing to do after copying those files: alter mtx-changer
to refer to the new configuration file.
Before we use mtx-wrapper, let us ensure mtx works.
We start with a basic simple mtx command.
# mtx -f /dev/pass1 status Storage Changer /dev/pass1:1 Drives, 10 Slots ( 0 Import/Export ) Data Transfer Element 0:Empty Storage Element 1:Full :VolumeTag=DGG472 Storage Element 2:Full :VolumeTag=DGG440 Storage Element 3:Full :VolumeTag=DGG443 Storage Element 4:Full :VolumeTag=DGG467 Storage Element 5:Full :VolumeTag=DGG469 Storage Element 6:Full :VolumeTag=DGG442 Storage Element 7:Full :VolumeTag=DGG457 Storage Element 8:Full :VolumeTag=DGG441 Storage Element 9:Full :VolumeTag=DGG471 Storage Element 10:Full :VolumeTag=DGG465 #
That is a list of the slots and which tape is in that slot.
Now, I load the tape from slot 3 into the drive (slot 0);
# /usr/local/sbin/mtx-changer /dev/pass1 load 3 /dev/sa0 0 # mtx -f /dev/pass1 status Storage Changer /dev/pass1:1 Drives, 10 Slots ( 0 Import/Export ) Data Transfer Element 0:Full (Storage Element 3 Loaded):VolumeTag = DGG443 Storage Element 1:Full :VolumeTag=DGG472 Storage Element 2:Full :VolumeTag=DGG440 Storage Element 3:Empty Storage Element 4:Full :VolumeTag=DGG467 Storage Element 5:Full :VolumeTag=DGG469 Storage Element 6:Full :VolumeTag=DGG442 Storage Element 7:Full :VolumeTag=DGG457 Storage Element 8:Full :VolumeTag=DGG441 Storage Element 9:Full :VolumeTag=DGG471 Storage Element 10:Full :VolumeTag=DGG465 #
mtx can move tapes around. Good. The basics are there.
think I have proven that my tape library and mtx can successfully
communicate. Time to start testing the mtx-changer script.
Does mtx-changer work?
mtx-changer is a wrapper script. It uses grep and awk to manipulate
the output of mtx to present Bacula with a nice simple interface.
The use of a wrapper also means that you can customize for your needs.
The use of mtx is not mandatory. You can use whatever tool you want;
you’ll have to customize mtx-changer or write your own wrapper.
Let’s use mtx-changer to get a list of the tapes:
# /usr/local/sbin/mtx-changer /dev/pass1 list 1:DGG472 2:DGG440 4:DGG467 5:DGG469 6:DGG442 7:DGG457 8:DGG441 9:DGG471 10:DGG465 3:DGG443
That works, and shows me the same information as above.
The slots aren’t sorted. That isn’t an issue.
What Volume is loaded?
# /usr/local/sbin/mtx-changer /dev/pass1 loaded 0 /dev/sa1 0 3
That tells me slot 3 is loaded. Hmmm, shouldn’t that be the Volume? No,
checking the script, it clearly says: “loaded which slot is loaded?”.
OK, next step, how many slots?
# /usr/local/sbin/mtx-changer /dev/pass1 slots 0 /dev/sa1 0 10
Yes, that’s right. Good. Let me try unloading:
# /usr/local/sbin/mtx-changer /dev/pass1 unload 3 /dev/sa1 0 Unloading drive 0 into Storage Element 3...done
Good! This all looks very good.
The btape test
btape is a Bacula utility for testing your tape. I run it on all
my drives and with each new configuration.
# btape -c /usr/local/etc/bacula-sd.conf /dev/nsa1 Tape block granularity is 1024 bytes. btape: butil.c:285 Using device: "/dev/nsa1" for writing. 30-Oct 01:05 btape JobId 0: 3301 Issuing autochanger "loaded? drive 0" command. 30-Oct 01:05 btape JobId 0: 3302 Autochanger "loaded? drive 0", result: nothing loaded. 30-Oct 01:05 btape: Fatal Error at device.c:292 because: dev open failed: dev.c:474 Unable to open device "DLTLIB0" (/dev/nsa1): ERR=Device not configured 30-Oct 01:05 btape JobId 0: Fatal error: butil.c:194 Cannot open "DLTLIB0" (/dev/nsa1)
At first, I thought I had a configuration error. No, this just means you don’t
have a tape in the drive. Let’s load one up:
# /usr/local/sbin/mtx-changer /dev/pass1 load 3 /dev/sa1 0 Loading media from Storage Element 3 into drive 0...done
And we try again:
# btape -c /usr/local/etc/bacula-sd.conf /dev/nsa1 Tape block granularity is 1024 bytes. btape: butil.c:285 Using device: "/dev/nsa1" for writing. 30-Oct 01:07 btape JobId 0: 3301 Issuing autochanger "loaded? drive 0" command. 30-Oct 01:07 btape JobId 0: 3302 Autochanger "loaded? drive 0", result: nothing loaded. 30-Oct 01:07 btape JobId 0: 3301 Issuing autochanger "loaded? drive 0" command. 30-Oct 01:07 btape JobId 0: 3302 Autochanger "loaded? drive 0", result: nothing loaded. btape: btape.c:383 open device "DLTLIB0" (/dev/nsa1): OK *
OK, now we’re in btape. But I see a problem. It thinks nothing is loaded.
And I think I know why. Yes, there it is:
Autochanger { Name = TapeRobot Device = DLTLIB0 Changer Device = /dev/pass1 Changer Command = "/home/dan/rc-chio-changer %c %o %S %a %d" }
My autochanger is using /home/dan/rc-chio-changer, not
/usr/local/sbin/mtx-changer. After making the change, you need to restart
bacula-sd:
# /usr/local/etc/rc.d/bacula-sd restart Stopping bacula_sd. Waiting for PIDS: 34563, 34563, 34563, 34563, 34563, 34563, 34563, 34563. Starting bacula_sd.
NOTE: when running btape, you must stop bacula-sd. Otherwise, btape will
be unable to access the drive.
All that waiting is waiting for the tape drive to rewind. I’m pretty sure
that is a configuration issue related to my settings. Now when I try btape:
# btape -c /usr/local/etc/bacula-sd.conf /dev/nsa1 Tape block granularity is 1024 bytes. btape: butil.c:285 Using device: "/dev/nsa1" for writing. 30-Oct 01:18 btape JobId 0: 3301 Issuing autochanger "loaded? drive 0" command. 30-Oct 01:18 btape JobId 0: 3302 Autochanger "loaded? drive 0", result is Slot 3. btape: btape.c:383 open device "DLTLIB0" (/dev/nsa1): OK *
Good. Much better. Now for the test:
*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:841 Wrote 1000 blocks of 64412 bytes. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:857 Wrote 1000 blocks of 64412 bytes. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:866 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:953 Wrote 1000 blocks of 64412 bytes. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:969 Wrote 1000 blocks of 64412 bytes. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:978 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:485 Rewound "DLTLIB0" (/dev/nsa1) btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:383 open device "DLTLIB0" (/dev/nsa1): OK btape: btape.c:485 Rewound "DLTLIB0" (/dev/nsa1) btape: btape.c:1107 Now moving to end of medium. btape: btape.c:536 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:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:485 Rewound "DLTLIB0" (/dev/nsa1) 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. Skipping read backwards test because BSR turned off. === Forward space files test === This test is essential to Bacula. I'm going to write five files then test forward spacing btape: btape.c:485 Rewound "DLTLIB0" (/dev/nsa1) btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:1587 Wrote one record of 64412 bytes. btape: btape.c:1589 Wrote block to device. btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:515 Wrote 1 EOF to "DLTLIB0" (/dev/nsa1) btape: btape.c:485 Rewound "DLTLIB0" (/dev/nsa1) btape: btape.c:1321 Now forward spacing 1 file. We should be in file 1. I am at file 1. This is correct! btape: btape.c:1333 Now forward spacing 2 files. We should be in file 3. I am at file 3. This is correct! btape: btape.c:485 Rewound "DLTLIB0" (/dev/nsa1) btape: btape.c:1346 Now forward spacing 4 files. We should be in file 4. I am at file 4. This is correct! btape: btape.c:1364 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):
All is well. Let’s test the autochanger.
Do you wish to continue with the Autochanger test? (y/n): y === Autochanger test === 3301 Issuing autochanger "loaded" command. Slot 3 loaded. I am going to unload it. 3302 Issuing autochanger "unload 3 0" command. unload status=OK 0 3303 Issuing autochanger "load 1 0" command. 3303 Autochanger "load 1 0" status is OK. btape: btape.c:383 open device "DLTLIB0" (/dev/nsa1): OK btape: btape.c:1251 Rewound "DLTLIB0" (/dev/nsa1) btape: btape.c:1258 Wrote EOF to "DLTLIB0" (/dev/nsa1) The test autochanger worked!! *
Well, that looks pretty good.
Interesting errors
While I was watching game 2 of the World Series, I tried out some tape
manipulation. I started getting some errors that drove me batty for a while.
# /usr/local/sbin/mtx-changer /dev/pass1 load 1 /dev/sa1 0 Drive 0 Full (Storage Element 1 loaded) # /usr/local/sbin/mtx-changer /dev/pass1 unload 0 /dev/sa1 0 Unloading drive 0 into Storage Element 0...mtx: Request Sense: Long Report=yes mtx: Request Sense: Valid Residual=no mtx: Request Sense: Error Code=70 (Current) mtx: Request Sense: Sense Key=Hardware Error mtx: Request Sense: FileMark=no mtx: Request Sense: EOM=no mtx: Request Sense: ILI=no mtx: Request Sense: Additional Sense Code = 15 mtx: Request Sense: Additional Sense Qualifier = 01 mtx: Request Sense: BPV=no mtx: Request Sense: Error in CDB=no mtx: Request Sense: SKSV=no MOVE MEDIUM from Element Address 240 to 0 Failed
Eh? What’s this? I can load, but I cannot unload? What’s going on?
I tried various things, even adjusting the cables. Eventually I figured it
out. I stopped bacula-sd. Then everything was fine. Just in case that
helps.
I do not know if the above events are related to these messages. I
suspect they are, but was unable to reproduce:
Nov 1 03:14:11 ngaio kernel: (sa1:ahc0:0:5:0): PREVENT ALLOW MEDIUM REMOVAL. CDB: 1e 0 0 0 0 0 Nov 1 03:14:11 ngaio kernel: (sa1:ahc0:0:5:0): CAM Status: SCSI Status Error Nov 1 03:14:11 ngaio kernel: (sa1:ahc0:0:5:0): SCSI Status: Check Condition Nov 1 03:14:11 ngaio kernel: (sa1:ahc0:0:5:0): UNIT ATTENTION asc:28,0 Nov 1 03:14:11 ngaio kernel: (sa1:ahc0:0:5:0): Not ready to ready change, medium may have changed Nov 1 03:14:11 ngaio kernel: (sa1:ahc0:0:5:0): Unretryable error Nov 1 03:14:11 ngaio kernel: (sa1:ahc0:0:5:0): removing device entry Nov 1 03:14:11 ngaio kernel: sa1 at ahc0 bus 0 target 5 lun 0 Nov 1 03:14:11 ngaio kernel: sa1: <DEC TZ89 (C) DEC 1837> Removable Sequential Access SCSI-2 device Nov 1 03:14:11 ngaio kernel: sa1: 20.000MB/s transfers (10.000MHz, offset 8, 16bit)
Labelling the barcodes
My next step is labeling the tapes in the library:
*label barcodes Automatically selected Catalog: MyCatalog Using Catalog "MyCatalog" The defined Storage resources are: 1: File 2: FileRemote 3: FileRemoteTLS 4: DLT 5: TapeLibrary 6: DLTRemote 7: DLTRemoteTLS Select Storage resource (1-7): 5 Connecting to Storage daemon TapeLibrary at bacula.unixathome.org:9103 ... 3306 Issuing autochanger "slots" command. Device "DLTLIB0" has 0 slots. No slots in changer to scan.
Well. This is annoying. It seems to be a simple problem though. No slots.
let’s try it from the command line:
# /usr/local/sbin/mtx-changer /dev/pass1 slots 10
So.. mtx-changer is putting out the right stuff. What’s wrong? I should
have guessed. But it took me putting things into debug mode to find out:
# /usr/local/sbin/bacula-sd -d 800 -u bacula -g bacula -v -c /usr/local/etc/bacula-sd.conf -f bacula-sd: lex.c:186-0 Open config file: /usr/local/etc/bacula-sd.conf bacula-sd: parse_conf.c:943-0 calling handler for name bacula-sd: parse_conf.c:943-0 calling handler for sdport bacula-sd: parse_conf.c:943-0 calling handler for workingdirectory bacula-sd: parse_conf.c:943-0 calling handler for piddirectory bacula-sd: parse_conf.c:943-0 calling handler for tlsenable [ .... lots of output omitted ... ] [ here is where I issued the command: label barcodes storage="DigitalTapeLibrary" ] bacula-sd: dircmd.c:232-0 Do command: autochanger bacula-sd: dircmd.c:596-0 Try changer device DEC TZ89 bacula-sd: dircmd.c:612-0 Found changer device DEC TZ89 bacula-sd: dircmd.c:625-0 Found device DEC TZ89 bacula-sd: block.c:133-0 Returning new block=80c12a8 bacula-sd: acquire.c:651-0 JobId=0 enter attach_dcr_to_dev bacula-sd: autochanger.c:303-0 Locking changer DEC TL800 bacula-sd: autochanger.c:678-0 omsg=/usr/local/sbin/mtx-changer /dev/pass1 slots 0 /dev/nsa1 0 bacula-sd: watchdog.c:193-0 Registered watchdog 80c1398, interval 300<NULL> bacula-sd: autochanger.c:579-0 <stored: slots=bacula-sd: bpipe.c:220-0 Wait for 38764 opt=1 bacula-sd: bpipe.c:232-0 Got wpid=0 status=-1067026034 ERR=none bacula-sd: bpipe.c:220-0 Wait for 38764 opt=1 bacula-sd: bpipe.c:228-0 Got break wpid=38764 status=51200 ERR=none bacula-sd: bpipe.c:246-0 Non-zero status 200 returned from child. bacula-sd: bpipe.c:249-0 child status=200 bacula-sd: watchdog.c:213-0 Unregistered watchdog 80c1398 bacula-sd: bpipe.c:264-0 returning stat=200,268435656 bacula-sd: autochanger.c:312-0 Unlocking changer DEC TL800 bacula-sd: acquire.c:662-0 Enter detach_dcr_from_dev bacula-sd: message.c:420-0 Close_msg jcr=80b5418 bacula-sd: message.c:420-0 Close_msg jcr=0 bacula-sd: mem_pool.c:370-0 garbage collect memory pool
I have highlighted the key lines in bold. First, you can see the correct
command being issued. Then, you can see the status being returned. That’s
when it clicked: permissions. I run bacula-sd as bacula:bacula, as you can
see above. Now, look at the permissions pm /usr/local/sbin/mtx-changer:
$ ls -l /usr/local/sbin/mtx-changer -rwxr-xr-- 1 root wheel 5221 Oct 30 00:52 /usr/local/sbin/mtx-changer
DOH! root:wheel. A quick chmod will fix that:
$ sudo chown root:operator /usr/local/sbin/mtx-changer Password: $ ls -l /usr/local/sbin/mtx-changer -rwxr-xr-- 1 root operator 5221 Oct 30 00:52 /usr/local/sbin/mtx-changer $
Why operator? On FreeBSD, tape drives are chown root:operator. And the
bacula user is a member of the operator group.
Now, let’s try that command again:
*label barcodes storage="DigitalTapeLibrary" Connecting to Storage daemon DigitalTapeLibrary at bacula.unixathome.org:9103 ... 3306 Issuing autochanger "slots" command. Device "DEC TL800" has 0 slots. No slots in changer to scan. *
Hmmm, it must be something else. Let’s see the bacula-sd debug output again:
bacula-sd: dircmd.c:232-0 Do command: autochanger bacula-sd: dircmd.c:596-0 Try changer device DEC TZ89 bacula-sd: dircmd.c:612-0 Found changer device DEC TZ89 bacula-sd: dircmd.c:625-0 Found device DEC TZ89 bacula-sd: block.c:133-0 Returning new block=80c12a8 bacula-sd: acquire.c:651-0 JobId=0 enter attach_dcr_to_dev bacula-sd: autochanger.c:303-0 Locking changer DEC TL800 bacula-sd: autochanger.c:678-0 omsg=/usr/local/sbin/mtx-changer /dev/pass1 slots 0 /dev/nsa1 0 bacula-sd: watchdog.c:193-0 Registered watchdog 80c1398, interval 300<NULL> bacula-sd: autochanger.c:579-0 <stored: slots=touch: /var/db/bacula/mtx.log: Permission denied bacula-sd: bpipe.c:220-0 Wait for 40757 opt=1 bacula-sd: bpipe.c:232-0 Got wpid=0 status=-1067026034 ERR=none bacula-sd: bpipe.c:220-0 Wait for 40757 opt=1 bacula-sd: bpipe.c:228-0 Got break wpid=40757 status=0 ERR=none bacula-sd: bpipe.c:249-0 child status=0 bacula-sd: watchdog.c:213-0 Unregistered watchdog 80c1398 bacula-sd: bpipe.c:264-0 returning stat=0,0 bacula-sd: autochanger.c:312-0 Unlocking changer DEC TL800 bacula-sd: acquire.c:662-0 Enter detach_dcr_from_dev bacula-sd: message.c:420-0 Close_msg jcr=80b5418 bacula-sd: message.c:420-0 Close_msg jcr=0 bacula-sd: mem_pool.c:370-0 garbage collect memory pool
Still a permissions problem. This time, it’s the log file, which was
created root:wheel (when I was running mtx-changer from the command line).
Now let’s change that:
$ ls -l /var/db/bacula/mtx.log -rw-r--r-- 1 root bacula 124204 Nov 1 20:44 /var/db/bacula/mtx.log $ chmod g+w /var/db/bacula/mtx.log $ ls -l /var/db/bacula/mtx.log -rw-rw-r-- 1 root bacula 124204 Nov 1 20:44 /var/db/bacula/mtx.log $
And trying again, with the exact same ouptut, I saw this error in the log output:
bacula-sd: dircmd.c:232-0 Do command: autochanger bacula-sd: dircmd.c:596-0 Try changer device DEC TZ89 bacula-sd: dircmd.c:612-0 Found changer device DEC TZ89 bacula-sd: dircmd.c:625-0 Found device DEC TZ89 bacula-sd: block.c:133-0 Returning new block=80c12a8 bacula-sd: acquire.c:651-0 JobId=0 enter attach_dcr_to_dev bacula-sd: autochanger.c:303-0 Locking changer DEC TL800 bacula-sd: autochanger.c:678-0 omsg=/usr/local/sbin/mtx-changer /dev/pass1 slots 0 /dev/nsa1 0 bacula-sd: watchdog.c:193-0 Registered watchdog 80c1398, interval 300>NULL< bacula-sd: autochanger.c:579-0 <stored: slots=cannot open SCSI device '/dev/pass1' - Permission denied bacula-sd: bpipe.c:220-0 Wait for 43030 opt=1 bacula-sd: bpipe.c:232-0 Got wpid=0 status=-1067026034 ERR=none bacula-sd: bpipe.c:220-0 Wait for 43030 opt=1 bacula-sd: bpipe.c:228-0 Got break wpid=43030 status=0 ERR=none bacula-sd: bpipe.c:249-0 child status=0 bacula-sd: watchdog.c:213-0 Unregistered watchdog 80c1398 bacula-sd: bpipe.c:264-0 returning stat=0,0 bacula-sd: autochanger.c:312-0 Unlocking changer DEC TL800 bacula-sd: acquire.c:662-0 Enter detach_dcr_from_dev bacula-sd: message.c:420-0 Close_msg jcr=80b5418 bacula-sd: message.c:420-0 Close_msg jcr=0 bacula-sd: mem_pool.c:370-0 garbage collect memory pool
OK, now another permissions issue, this time on /dev/pass1. While looking around,
I discovered I had this same issue before. Look for Permissions issues in
my previous Tape Library article. Indeed, this time,
the permissions were:
crw------- 1 root operator 0, 162 Oct 30 13:01 /dev/pass1
The operator groups has no rights whatsoever. Rather than issuing a chown on a device,
I elected to use the tools at hand.
I altered /etc/devfs.conf to contain these lines:
own pass1 root:operator perm pass1 0660
After restarting devfs (/etc/rc.d/devfs restart), I had these new permissions:
crw-rw---- 1 root operator 0, 162 Oct 30 13:01 /dev/pass1
Trying my command [yet] again:
*label barcodes storage="DigitalTapeLibrary" Connecting to Storage daemon DigitalTapeLibrary at bacula.unixathome.org:9103 ... 3306 Issuing autochanger "slots" command. Device "DEC TL800" has 10 slots. Connecting to Storage daemon DigitalTapeLibrary at bacula.unixathome.org:9103 ... 3306 Issuing autochanger "list" command. The following Volumes will be labeled: Slot Volume ============== 1 DGG472 2 DGG440 3 DGG443 4 DGG467 5 DGG469 6 DGG442 7 DGG457 8 DGG441 9 DGG471 10 DGG465 Do you want to label these Volumes? (yes|no):
Good. More progress. For completeness, here is the debug output:
bacula-sd: dircmd.c:232-0 Do command: autochanger bacula-sd: dircmd.c:596-0 Try changer device DEC TZ89 bacula-sd: dircmd.c:612-0 Found changer device DEC TZ89 bacula-sd: dircmd.c:625-0 Found device DEC TZ89 bacula-sd: block.c:133-0 Returning new block=80c12a8 bacula-sd: acquire.c:651-0 JobId=0 enter attach_dcr_to_dev bacula-sd: autochanger.c:303-0 Locking changer DEC TL800 bacula-sd: autochanger.c:678-0 omsg=/usr/local/sbin/mtx-changer /dev/pass1 list 0 /dev/nsa1 0 bacula-sd: watchdog.c:193-0 Registered watchdog 80c1398, interval 300<NULL> bacula-sd: autochanger.c:566-0 <stored: 1:DGG472 bacula-sd: autochanger.c:566-0 <stored: 2:DGG440 bacula-sd: autochanger.c:566-0 <stored: 3:DGG443 bacula-sd: autochanger.c:566-0 <stored: 4:DGG467 bacula-sd: autochanger.c:566-0 <stored: 5:DGG469 bacula-sd: autochanger.c:566-0 <stored: 6:DGG442 bacula-sd: autochanger.c:566-0 <stored: 7:DGG457 bacula-sd: autochanger.c:566-0 <stored: 8:DGG441 bacula-sd: autochanger.c:566-0 <stored: 9:DGG471 bacula-sd: autochanger.c:566-0 <stored: 10:DGG465 bacula-sd: bpipe.c:220-0 Wait for 47124 opt=1 bacula-sd: bpipe.c:228-0 Got break wpid=47124 status=0 ERR=none bacula-sd: bpipe.c:249-0 child status=0 bacula-sd: watchdog.c:213-0 Unregistered watchdog 80c1398 bacula-sd: bpipe.c:264-0 returning stat=0,0 bacula-sd: autochanger.c:312-0 Unlocking changer DEC TL800 bacula-sd: acquire.c:662-0 Enter detach_dcr_from_dev bacula-sd: message.c:420-0 Close_msg jcr=80b5418 bacula-sd: message.c:420-0 Close_msg jcr=0 bacula-sd: mem_pool.c:370-0 garbage collect memory pool
Ahh, good, now, let’s reply yes and let Bacula do the labelling for me.
Do you want to label these Volumes? (yes|no): yes Defined Pools: 1: Default 2: FilePool Select the Pool (1-2): 1 Connecting to Storage daemon DigitalTapeLibrary at bacula.unixathome.org:9103 ... Sending label command for Volume "DGG472" Slot 1 ... 3301 Issuing autochanger "loaded? drive 0" command. 3302 Autochanger "loaded? drive 0", result: nothing loaded. 3304 Issuing autochanger "load slot 1, drive 0" command. 3305 Autochanger "load slot 1, drive 0", status is OK. 3000 OK label. VolBytes=64512 DVD=0 Volume="DGG472" Device="DEC TZ89" (/dev/nsa1) Catalog record for Volume "DGG472", Slot 1 successfully created. Sending label command for Volume "DGG440" Slot 2 ... 3307 Issuing autochanger "unload slot 1, drive 0" command. 3304 Issuing autochanger "load slot 2, drive 0" command. 3305 Autochanger "load slot 2, drive 0", status is OK. 3920 Cannot label Volume because it is already labeled: "DGG440" Label command failed for Volume DGG440. Sending label command for Volume "DGG443" Slot 3 ... 3307 Issuing autochanger "unload slot 2, drive 0" command. 3304 Issuing autochanger "load slot 3, drive 0" command. 3305 Autochanger "load slot 3, drive 0", status is OK. 3000 OK label. VolBytes=64512 DVD=0 Volume="DGG443" Device="DEC TZ89" (/dev/nsa1) Catalog record for Volume "DGG443", Slot 3 successfully created. Sending label command for Volume "DGG467" Slot 4 ... 3307 Issuing autochanger "unload slot 3, drive 0" command. 3304 Issuing autochanger "load slot 4, drive 0" command. 3305 Autochanger "load slot 4, drive 0", status is OK. 3920 Cannot label Volume because it is already labeled: "DGG467" Label command failed for Volume DGG467. Sending label command for Volume "DGG469" Slot 5 ... 3307 Issuing autochanger "unload slot 4, drive 0" command. 3304 Issuing autochanger "load slot 5, drive 0" command. 3305 Autochanger "load slot 5, drive 0", status is OK. 3920 Cannot label Volume because it is already labeled: "DGG469" Label command failed for Volume DGG469. Sending label command for Volume "DGG442" Slot 6 ... 3307 Issuing autochanger "unload slot 5, drive 0" command. 3304 Issuing autochanger "load slot 6, drive 0" command. 3305 Autochanger "load slot 6, drive 0", status is OK. 3920 Cannot label Volume because it is already labeled: "DGG442" Label command failed for Volume DGG442. Sending label command for Volume "DGG457" Slot 7 ... 3307 Issuing autochanger "unload slot 6, drive 0" command. 3304 Issuing autochanger "load slot 7, drive 0" command. 3305 Autochanger "load slot 7, drive 0", status is OK. 3920 Cannot label Volume because it is already labeled: "DGG457" Label command failed for Volume DGG457. Sending label command for Volume "DGG441" Slot 8 ... 3307 Issuing autochanger "unload slot 7, drive 0" command. 3304 Issuing autochanger "load slot 8, drive 0" command. 3305 Autochanger "load slot 8, drive 0", status is OK. 3920 Cannot label Volume because it is already labeled: "DGG441" Label command failed for Volume DGG441. Sending label command for Volume "DGG471" Slot 9 ... 3307 Issuing autochanger "unload slot 8, drive 0" command. 3304 Issuing autochanger "load slot 9, drive 0" command. 3305 Autochanger "load slot 9, drive 0", status is OK. 3920 Cannot label Volume because it is already labeled: "DGG471" Label command failed for Volume DGG471. Sending label command for Volume "DGG465" Slot 10 ... 3307 Issuing autochanger "unload slot 9, drive 0" command. 3304 Issuing autochanger "load slot 10, drive 0" command. 3305 Autochanger "load slot 10, drive 0", status is OK. block.c:275 Volume data error at 0:0! Wanted ID: "BB02", got "". Buffer discarded. 3000 OK label. VolBytes=64512 DVD=0 Volume="DGG465" Device="DEC TZ89" (/dev/nsa1) Catalog record for Volume "DGG465", Slot 10 successfully created. *
That is an interesting line near the end. I’m not sure at all what that
error relates to. Not to mention all the tapes which already had labels.
These labels were most likely added years ago during my previous testing
with this library.
I will remove those labels and start with them blank. This will be a good
exercise in shell scriping and a good workout for the tape libary.
Deleting the barcodes
When you wish to remove the labels from a Bacula labelled tape, the process is pretty fast.
It is described in the Bacula FAQ
under the heading My Catalog is Full of Test Runs, How Can I Start Over?. The short answer is:
write an EOF marker to the tape. All you need to do is insert the tape, and issue these commands,
where /dev/sa1 is your tape drive:
mt -f /dev/sa1 rewind mt -f /dev/sa1 weof
Since I have a tape library, I will write a short shell script to cycle through the tapes.
$ cat ~/bin/erase-tapes #!/bin/sh NUMSLOTS=10 FIRSTSLOT=1 CHANGER=/dev/pass4 TAPEDRIVE=/dev/sa1 MTXCHANGER=/usr/local/sbin/mtx-changer MT=/usr/bin/mt SLOTS=`jot ${NUMSLOTS} ${FIRSTSLOT} ${NUMSLOTS}` # or you could this: provided by Marcin Haba # SLOTS=`${MTXCHANGER} ${CHANGER} list | awk -F ':' '{print $1}'` # unload any existing tape for slot in ${SLOTS} do echo ${slot} # load ${MTXCHANGER} ${CHANGER} load ${slot} ${TAPEDRIVE} 0 # erase ${MT} -f ${TAPEDRIVE} rewind ${MT} -f ${TAPEDRIVE} weof # unload ${MTXCHANGER} ${CHANGER} unload ${slot} ${TAPEDRIVE} 0 done
Some details:
- NUMSLOTS=10 – this is the number of slots in my tape library.
- FIRSTSLOT=1 – the first slot to deal with
- CHANGER=/dev/pass4 – the device for the tape changer
- TAPEDRIVE=/dev/sa1 – the device for the tape drive
- MTXCHANGER=/usr/local/sbin/mtx-changer – the path to my mtx-changer script
- MT=/usr/bin/mt – the path to the mt(1) binary
- SLOTS=`jot ${NUMSLOTS} ${FIRSTSLOT} ${NUMSLOTS}` – this generates a sequence of 1..10 (for my ten slots)
The output looks like this:
[dan@ngaio:~/bin] $ sudo ~/bin/erase-tapes Password: 1 Loading media from Storage Element 1 into drive 0...done Unloading drive 0 into Storage Element 1...done 2 Loading media from Storage Element 2 into drive 0...done Unloading drive 0 into Storage Element 2...done 3 Loading media from Storage Element 3 into drive 0...done Unloading drive 0 into Storage Element 3...done 4 Loading media from Storage Element 4 into drive 0...done Unloading drive 0 into Storage Element 4...done 5 Loading media from Storage Element 5 into drive 0...done Unloading drive 0 into Storage Element 5...done 6 Loading media from Storage Element 6 into drive 0...done Unloading drive 0 into Storage Element 6...done 7 Loading media from Storage Element 7 into drive 0...done Unloading drive 0 into Storage Element 7...done 8 Loading media from Storage Element 8 into drive 0...done Unloading drive 0 into Storage Element 8...done 9 Loading media from Storage Element 9 into drive 0...done Unloading drive 0 into Storage Element 9...done 10 Loading media from Storage Element 10 into drive 0...done Unloading drive 0 into Storage Element 10...done [dan@ngaio:~/bin] $
That’s it for now!
That’s it for now. This is a fairly length article. It dealt mainly with getting mtx-changer working
properly and outlines some of the problems you may encounter. Hopefully, it will help you get your
tape changing up and running. My next goal: get this tape library working with Bacula. That is what
I will work on next. Best wishes and have fun.