Testing the DLT
Now that my tape labels have arrived, it’s time to run
those tapes through Bacula. In this article, you’ll see:
- a list slots command fail
- a command line mtx-changer command fail
- the fix via device permissions
- a label barcodes fail
- a script to test tapes
Oh, that script isn’t actually in this article. It’s in the tape testing article.
But I do use it below to determine that my tape drive and my tapes are all in very good condition.
Not bad for used gear.
Permission is everything
After:
- removing the magazine
- putting physical labels onto the tapes
- placing the tapes into the magazine
- putting the magazine back into the library
I sought to see the list of labels I had. I failed:
$ bconsole Connecting to Director bacula.example.org:9101 1000 OK: bacula-dir Version: 5.0.3 (04 August 2010) Enter a period to cancel a command. *update slots Automatically selected Catalog: MyCatalog Using Catalog "MyCatalog" The defined Storage resources are: 1: File 2: MegaFile 3: MegaFile-catalog 4: MegaFile-bast 5: MegaFile-dbclone 6: MegaFile-kraken 7: MegaFile-laptop-freebsd 8: MegaFile-laptop-vista 9: MegaFile-latens 10: MegaFile-ngaio 11: MegaFile-nyi 12: MegaFile-polo 13: MegaFile-supernews 14: MegaFile-wocker 15: FileRemote 16: FileRemoteTLS 17: DLT 18: DigitalTapeLibrary 19: DLTRemote 20: DLTRemoteTLS Select Storage resource (1-20): 18 Connecting to Storage daemon DigitalTapeLibrary at kraken.example.org:9103 ... 3306 Issuing autochanger "slots" command. Device "DTL01" has 0 slots. No slots in changer to scan.
What? No Slots? What’s up with that? let’s try something else:
# /usr/local/sbin/mtx-changer /dev/pass10 list 2:ETU010 3:ETU009 4:ETU008 5:ETU007 6:ETU006 7:ETU005 8:ETU004 9:ETU003 10:ETU002 1:DGG472
OK. That works. Let’s try something else:
# su -m bacula -c '/usr/local/sbin/mtx-changer /dev/pass10 slots' cannot open SCSI device '/dev/pass10' - Permission denied
Clearly a permissions issue:
# ls -l /usr/local/sbin/mtx-changer /dev/pass10 crw------- 1 root operator 0, 125 Nov 15 18:29 /dev/pass10 -rwxr-xr-- 1 root operator 5699 Aug 29 17:20 /usr/local/sbin/mtx-changer # id bacula uid=910(bacula) gid=910(bacula) groups=910(bacula),5(operator)
Ahh. Bacula does not have permission on /dev/pass10, clearly. However, I found the following
in /etc/devfs.conf (this is FreeBSD 8.1). Thus, I just restart devfs:
# /etc/rc.d/devfs restart # ls -l /usr/local/sbin/mtx-changer /dev/pass10 crw-rw---- 1 root operator 0, 125 Nov 15 18:29 /dev/pass10 -rwxr-xr-- 1 root operator 5699 Aug 29 17:20 /usr/local/sbin/mtx-changer
And now I try again:
# su -m bacula -c '/usr/local/sbin/mtx-changer /dev/pass10 slots' 10
Much better. Now back to bconsole:
*update slots The defined Storage resources are: 1: File 2: MegaFile 3: MegaFile-catalog 4: MegaFile-bast 5: MegaFile-dbclone 6: MegaFile-kraken 7: MegaFile-laptop-freebsd 8: MegaFile-laptop-vista 9: MegaFile-latens 10: MegaFile-ngaio 11: MegaFile-nyi 12: MegaFile-polo 13: MegaFile-supernews 14: MegaFile-wocker 15: FileRemote 16: FileRemoteTLS 17: DLT 18: DigitalTapeLibrary 19: DLTRemote 20: DLTRemoteTLS Select Storage resource (1-20): 18 Connecting to Storage daemon DigitalTapeLibrary at kraken.example.org:9103 ... 3306 Issuing autochanger "slots" command. Device "DTL01" has 10 slots.
OK, good. The slots command works. Now for the rest of the output:
Connecting to Storage daemon DigitalTapeLibrary at kraken.example.org:9103 ... 3306 Issuing autochanger "list" command. Catalog record for Volume "DGG472" updated to reference slot 1. Volume "ETU010" not found in catalog. Slot=2 InChanger set to zero. Volume "ETU009" not found in catalog. Slot=3 InChanger set to zero. Volume "ETU008" not found in catalog. Slot=4 InChanger set to zero. Volume "ETU007" not found in catalog. Slot=5 InChanger set to zero. Volume "ETU006" not found in catalog. Slot=6 InChanger set to zero. Volume "ETU005" not found in catalog. Slot=7 InChanger set to zero. Volume "ETU004" not found in catalog. Slot=8 InChanger set to zero. Volume "ETU003" not found in catalog. Slot=9 InChanger set to zero. Volume "ETU002" not found in catalog. Slot=10 InChanger set to zero. *
Now on to the label barcodes command.
label barcodes
In this section, we’ll [attempt & fail] to label the tapes according to the barcodes on the tapes.
This puts a label on the physical tape.
*label barcodes The defined Storage resources are: 1: File 2: MegaFile 3: MegaFile-catalog 4: MegaFile-bast 5: MegaFile-dbclone 6: MegaFile-kraken 7: MegaFile-laptop-freebsd 8: MegaFile-laptop-vista 9: MegaFile-latens 10: MegaFile-ngaio 11: MegaFile-nyi 12: MegaFile-polo 13: MegaFile-supernews 14: MegaFile-wocker 15: FileRemote 16: FileRemoteTLS 17: DLT 18: DigitalTapeLibrary 19: DLTRemote 20: DLTRemoteTLS Select Storage resource (1-20): 18 Connecting to Storage daemon DigitalTapeLibrary at kraken.example.org:9103 ... 3306 Issuing autochanger "slots" command. Device "DTL01" has 10 slots. Connecting to Storage daemon DigitalTapeLibrary at kraken.example.org:9103 ... 3306 Issuing autochanger "list" command. The following Volumes will be labeled: Slot Volume ============== 1 DGG472 2 ETU010 3 ETU009 4 ETU008 5 ETU007 6 ETU006 7 ETU005 8 ETU004 9 ETU003 10 ETU002 Do you want to label these Volumes? (yes|no): yes Defined Pools: 1: MegaFile-ngaio 2: MegaFile-supernews 3: FullsFile 4: Default 5: MegaFile-w2k 6: Fulls 7: Incrementals 8: Differentials 9: FilePool 10: MegaFilePool 11: MegaFile-bast 12: MegaFile-catalog 13: MegaFile-dbclone 14: MegaFile-kraken 15: MegaFile-laptop-freebsd 16: MegaFile-laptop-vista 17: MegaFile-latens 18: MegaFile-nyi 19: MegaFile-polo 20: MegaFile-wocker Select the Pool (1-20): 6
These new tapes will be used for FULL backups. This command will only assign tapes into a single
pool. The rest of the output follows:
Media record for Slot 1 Volume "DGG472" already exists. Connecting to Storage daemon DigitalTapeLibrary at kraken.example.org:9103 ... Sending label command for Volume "ETU010" Slot 2 ... 3301 Issuing autochanger "loaded? drive 0" command. 3302 Autochanger "loaded? drive 0", result is Slot 1. 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: "StorageElement25:Full"
DOH! I know what’s happened. The tapes still contains labels. This was part of his erase
process. I’ll just write a script to write an EOF to each of these tapes.
By the way, DGG472 was already in the tape drive when I pulled the magazine. That’s why it
‘already exists’.
FYI, there’s more output:
Label command failed for Volume ETU010. Sending label command for Volume "ETU009" 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. 3920 Cannot label Volume because it is already labeled: "StorageElement20:Full" Label command failed for Volume ETU009. Sending label command for Volume "ETU008" 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: "StorageElement88:Full" Label command failed for Volume ETU008. Sending label command for Volume "ETU007" 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: "StorageElement55:Full" Label command failed for Volume ETU007. Sending label command for Volume "ETU006" 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: "StorageElement25:Full" Label command failed for Volume ETU006. Sending label command for Volume "ETU005" 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: "StorageElement53:Full" Label command failed for Volume ETU005. Sending label command for Volume "ETU004" 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: "StorageElement57:Full" Label command failed for Volume ETU004. Sending label command for Volume "ETU003" 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: "StorageElement60:Full" Label command failed for Volume ETU003. Sending label command for Volume "ETU002" 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. 3920 Cannot label Volume because it is already labeled: "StorageElement19:Full" Label command failed for Volume ETU002. *
On to the script!
The script
I need a script that will wipe the label from each of the tapes. In short, it will write an EOF
mark to the start of the tape, thereby allowing Bacula to write a new label. After the above
failure, I went downstairs and remove the one valid tape from the magazine and replaced it with
one of the new tapes. The following script will lose all data. Technically, the data
is still there, but unless you’re good, highly experienced, the data will be as good as gone.
Let’s see what’s in there now:
# /usr/local/sbin/mtx-changer /dev/pass10 list mtx: Request Sense: Long Report=yes mtx: Request Sense: Valid Residual=no mtx: Request Sense: Error Code=70 (Current) mtx: Request Sense: Sense Key=Unit Attention mtx: Request Sense: FileMark=no mtx: Request Sense: EOM=no mtx: Request Sense: ILI=no mtx: Request Sense: Additional Sense Code = 28 mtx: Request Sense: Additional Sense Qualifier = 00 mtx: Request Sense: BPV=no mtx: Request Sense: Error in CDB=no mtx: Request Sense: SKSV=no Mode sense (0x1A) for Page 0x1D failed 1:ETU001 2:ETU010 3:ETU009 4:ETU008 5:ETU007 6:ETU006 7:ETU005 8:ETU004 9:ETU003 10:ETU002
I’m not sure why those Request Sense messages appear. It happened earlier tonight, but
I didn’t include it in the output.
In a previous article, I created a script to test the tapes for
errors. I think I’ll run that program now, then alter the script to just write the EOF.
The output from that script is:
# sh ./test-tapes.sh pass10 nsa0 /usr/local/sbin/mtx-changer /dev/pass10 list nsa0 loading 1 Loading media from Storage Element 1 into drive 0...done tar: Removing leading '/' from member names unloading 1 Unloading drive 0 into Storage Element 1...done loading 2 Loading media from Storage Element 2 into drive 0...done tar: Removing leading '/' from member names unloading 2 Unloading drive 0 into Storage Element 2...done loading 3 Loading media from Storage Element 3 into drive 0...done tar: Removing leading '/' from member names unloading 3 Unloading drive 0 into Storage Element 3...done loading 4 Loading media from Storage Element 4 into drive 0...done tar: Removing leading '/' from member names unloading 4 Unloading drive 0 into Storage Element 4...done loading 5 Loading media from Storage Element 5 into drive 0...done tar: Removing leading '/' from member names unloading 5 Unloading drive 0 into Storage Element 5...done loading 6 Loading media from Storage Element 6 into drive 0...done tar: Removing leading '/' from member names unloading 6 Unloading drive 0 into Storage Element 6...
Meanwhile, in /var/log/messages, I see:
Nov 16 21:14:43 kraken dan: TapeTesting: /dev/pass10 : ETU010 - Total corrected errors / GB : 0 Total corrected errors / GB : 3 - Total uncorrected errors : 0 Total uncorrected errors : 0 Nov 16 21:23:01 kraken dan: TapeTesting: /dev/pass10 : ETU009 - Total corrected errors / GB : N/A Total corrected errors / GB : 7 - Total uncorrected errors : 0 Total uncorrected errors : 0 Nov 16 21:31:12 kraken dan: TapeTesting: /dev/pass10 : ETU008 - Total corrected errors / GB : 0 Total corrected errors / GB : 4 - Total uncorrected errors : 0 Total uncorrected errors : 0
I’ll let that run overnight. But those error rates are pretty good. Anything under 10 correctable
errors per GB is like a brand new tape in a very good drive.
Oh. The script. I guess I’ll write that tomorrow night.