Testing the DLT

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:

  1. removing the magazine
  2. putting physical labels onto the tapes
  3. placing the tapes into the magazine
  4. 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.

Leave a Comment

Scroll to Top