Last night, I managed to install new (but used) SAS cables for my Dell TL4000 on the tape01 server.
I managed to get bacula-sd running, but I was unable to communicate with it from bacula-dir, via bconsole on my laptop. Eventually, I ran bacula-sd from the command line in the foreground and with debugging and saw things which needed to be corrected.
In this post, I will
- adjust permissions on devices
- get bacula-dir : bacula-sd communications working
- do some mtx-changer testing
- run some simple backup tests with tar
The errors
This is the debugging output I saw. Feel free to skip to the next section.
# /usr/local/sbin/bacula-sd -u bacula -g bacula -v -c /usr/local/etc/bacula/bacula-sd.conf -d 99 -f bacula-sd: address_conf.c:274-0 Initaddr 0.0.0.0:9103 bacula-sd: stored_conf.c:698-0 Inserting Device res: LTO_1 tape01-sd: bnet_server.c:86-0 Addresses 0.0.0.0:9103 tape01-sd: stored.c:572-0 calling init_dev /dev/nsa0 tape01-sd: stored.c:574-0 SD init done /dev/nsa0 tape01-sd: autochanger.c:322-0 Locking changer tape01 tape01-sd: autochanger.c:278-0 Run program=/usr/local/sbin/mtx-changer /dev/pass1 loaded 0 /dev/nsa0 0 tape01-sd: autochanger.c:280-0 run_prog: /usr/local/sbin/mtx-changer /dev/pass1 loaded 0 /dev/nsa0 0 stat=268435457 result=cannot open SCSI device '/dev/pass1' - Permission denied tape01-sd: autochanger.c:308-0 Error: autochanger loaded? drive 0 ERR=Child exited with code 1. Results=cannot open SCSI device '/dev/pass1' - Permission denied tape01-sd: autochanger.c:336-0 Unlocking changer tape01 tape01-sd: stored.c:588-0 calling first_open_device "LTO_0" (/dev/nsa0) tape01-sd: autochanger.c:322-0 Locking changer tape01 tape01-sd: autochanger.c:278-0 Run program=/usr/local/sbin/mtx-changer /dev/pass1 loaded 0 /dev/nsa0 0 tape01-sd: autochanger.c:280-0 run_prog: /usr/local/sbin/mtx-changer /dev/pass1 loaded 0 /dev/nsa0 0 stat=268435457 result=cannot open SCSI device '/dev/pass1' - Permission denied tape01-sd: autochanger.c:308-0 Error: autochanger loaded? drive 0 ERR=Child exited with code 1. Results=cannot open SCSI device '/dev/pass1' - Permission denied tape01-sd: autochanger.c:336-0 Unlocking changer tape01 ^C^C
Yes, a few things to change there. Things I should have known needed to be changed.
Permissions
On FreeBSD, bacula-sd is configured, by default, to run with UID bacula and GID bacula:
$ grep bacula /etc/passwd /etc/group /etc/passwd:bacula:*:910:910:Bacula Daemon:/var/db/bacula:/usr/sbin/nologin /etc/group:bacula:*:910:
Accordingly, we need to let bacula-sd access the tape library (i.e. the tape drives and the tape changer). From this command, we can locate those devices:
$ sudo camcontrol devlist <IBM ULT3580-HH4 C7Q1> at scbus0 target 0 lun 0 (pass0,sa0) <IBM 3573-TL B.60> at scbus0 target 0 lun 1 (pass1,ch0) <IBM ULT3580-HH4 C7Q1> at scbus0 target 1 lun 0 (pass2,sa1) <IBM 3573-TL B.60> at scbus0 target 1 lun 1 (pass3,ch1) <CT480BX200SSD1 MU01.4> at scbus1 target 0 lun 0 (ada0,pass4) <CT480BX200SSD1 MU01.4> at scbus3 target 0 lun 0 (ada1,pass5)
bacula-sd will need access to the following devices:
$ ls -l /dev/pass0 /dev/sa0 /dev/pass1 /dev/ch0 /dev/pass2 /dev/sa1 crw------- 1 root operator 0x63 Feb 4 23:48 /dev/ch0 crw------- 1 root operator 0x65 Feb 4 23:48 /dev/pass0 crw------- 1 root operator 0x66 Feb 4 23:48 /dev/pass1 crw------- 1 root operator 0x67 Feb 4 23:48 /dev/pass2 crw-rw---- 1 root operator 0x5c Feb 4 23:48 /dev/sa0 crw-rw---- 1 root operator 0x60 Feb 4 23:48 /dev/sa1
By default, these defaults are chgrp operator and you will notice that the tape drives are already writable by members of that group. I want to take advantage of that by adding bacula to the operator group. I altered this line in /etc/group:
operator:*:5:root,bacula
You can confirm this change with the following command:
$ id bacula uid=910(bacula) gid=910(bacula) groups=910(bacula),5(operator)
To alter the device permissions, I will use /etc/devfs.conf. At the end of that file, I will add these entries:
perm ch0 0660 perm pass0 0660 perm pass1 0660 perm pass2 0660
After any such changes, you can invoke them by restarting the service: /etc/rc.d/devfs restart
Now the permission look like this:
$ ls -l /dev/pass0 /dev/sa0 /dev/pass1 /dev/ch0 /dev/pass2 /dev/sa1 crw-rw---- 1 root operator 0x63 Feb 4 23:48 /dev/ch0 crw-rw---- 1 root operator 0x65 Feb 4 23:48 /dev/pass0 crw-rw---- 1 root operator 0x66 Feb 4 23:48 /dev/pass1 crw-rw---- 1 root operator 0x67 Feb 4 23:48 /dev/pass2 crw-rw---- 1 root operator 0x5c Feb 4 23:48 /dev/sa0 crw-rw---- 1 root operator 0x60 Feb 4 23:48 /dev/sa1
Starting bacula-sd
This time when I started bacula-sd in debug mode, those original error messages did not appear:
# /usr/local/sbin/bacula-sd -u bacula -g bacula -v -c /usr/local/etc/bacula/bacula-sd.conf -d 99 -f bacula-sd: address_conf.c:274-0 Initaddr 0.0.0.0:9103 bacula-sd: stored_conf.c:698-0 Inserting Device res: LTO_1 tape01-sd: bnet_server.c:86-0 Addresses 0.0.0.0:9103 tape01-sd: stored.c:572-0 calling init_dev /dev/nsa0 tape01-sd: stored.c:574-0 SD init done /dev/nsa0 tape01-sd: autochanger.c:322-0 Locking changer tape01 tape01-sd: autochanger.c:278-0 Run program=/usr/local/sbin/mtx-changer /dev/pass1 loaded 0 /dev/nsa0 0 tape01-sd: autochanger.c:280-0 run_prog: /usr/local/sbin/mtx-changer /dev/pass1 loaded 0 /dev/nsa0 0 stat=0 result=1 tape01-sd: autochanger.c:336-0 Unlocking changer tape01 tape01-sd: stored.c:588-0 calling first_open_device "LTO_0" (/dev/nsa0) tape01-sd: autochanger.c:260-0 Return cached slot=1 tape01-sd: stored.c:613-0 Could not mount device "LTO_0" (/dev/nsa0) tape01-sd: stored.c:572-0 calling init_dev /dev/nsa1 tape01-sd: stored.c:574-0 SD init done /dev/nsa1 tape01-sd: autochanger.c:322-0 Locking changer tape01 tape01-sd: autochanger.c:278-0 Run program=/usr/local/sbin/mtx-changer /dev/pass1 loaded 0 /dev/nsa1 0 tape01-sd: autochanger.c:280-0 run_prog: /usr/local/sbin/mtx-changer /dev/pass1 loaded 0 /dev/nsa1 0 stat=0 result=1 tape01-sd: autochanger.c:336-0 Unlocking changer tape01 tape01-sd: stored.c:588-0 calling first_open_device "LTO_1" (/dev/nsa1) tape01-sd: autochanger.c:260-0 Return cached slot=1 tape01-sd: Fatal Error at device.c:300 because: dev open failed: tape_dev.c:164 Unable to open device "LTO_1" (/dev/nsa1): ERR=Device not configured tape01-sd: stored.c:595-0 Could not open device "LTO_1" (/dev/nsa1) tape01-sd: stored.c:596-0 Could not open device "LTO_1" (/dev/nsa1)
Notes on the above:
- Device not configured: there is no tape in the drive
- Could not mount: it is not a Bacula Volume
status storage=tape01-sd
Let’s try a status storage on that bacula-sd. If successful, this will confirm that bacula-dir and bacula-sd agree on the credentials and that communications are functional.
*st st
The defined Storage resources are:
1: CreyFile
2: tape01-sd
Select Storage resource (1-2): 2
Connecting to Storage daemon tape01-sd at tape01.int.unixathome.org:9103
tape01-sd Version: 7.4.0 (16 January 2016) amd64-portbld-freebsd10.2 freebsd 10.2-RELEASE-p8
Daemon started 05-Feb-16 23:32. Jobs: run=0, running=0.
Heap: heap=0 smbytes=29,151 max_bytes=117,679 bufs=89 max_bufs=90
Sizes: boffset_t=8 size_t=8 int32_t=4 int64_t=8 mode=0,0
Running Jobs:
No Jobs running.
====
Jobs waiting to reserve a drive:
====
Terminated Jobs:
====
Device status:
Autochanger "tape01" with devices:
"LTO_0" (/dev/nsa0)
"LTO_1" (/dev/nsa1)
Device tape: "LTO_0" (/dev/nsa0) open but no Bacula volume is currently mounted.
Slot 1 is loaded in drive 0.
Configured device capabilities:
EOF BSR BSF FSR FSF !EOM REM !RACCESS AUTOMOUNT !LABEL !ANONVOLS ALWAYSOPEN
Device state:
OPENED TAPE !LABEL !MALLOC !APPEND !READ !EOT !WEOT !EOF !NEXTVOL !SHORT !MOUNTED
num_writers=0 reserves=0 block=0 enabled=1
Attached JobIds:
Device parameters:
Archive name: /dev/nsa0 Device name: LTO_0
File=0 block=0
Min block=0 Max block=0
Total Bytes Read=0 Blocks Read=0 Bytes/block=0
Positioned at File=0 Block=0
==
Device tape: "LTO_1" (/dev/nsa1) is not open.
Slot 1 was last loaded in drive 0.
Configured device capabilities:
EOF !BSR BSF FSR FSF !EOM REM !RACCESS AUTOMOUNT !LABEL !ANONVOLS ALWAYSOPEN
Device state:
!OPENED TAPE !LABEL !MALLOC !APPEND !READ !EOT !WEOT !EOF !NEXTVOL !SHORT !MOUNTED
num_writers=0 reserves=0 block=0 enabled=1
Attached JobIds:
Device parameters:
Archive name: /dev/nsa1 Device name: LTO_1
File=0 block=0
Min block=0 Max block=0
==
====
Used Volume status:
====
====
*
Great! Now, let’s move tapes around!
mtx-changer
I covered my mtx-changer configuartion in a previous post, so I will not be repeating that here.
Let’s start with listing the tapes:
$ sudo /usr/local/sbin/mtx-changer /dev/pass1 list 2:000001L4 3:000003L4 4:000004L4 5:000005L4 6:000006L4 7:000007L4 8:000008L4 9:000009L4 10:000010L4 11:000011L4 12:000012L4 13:000013L4 14:000014L4 15:000015L4 16:000016L4 17:000017L4 18:000018L4 19:000019L4 20:000020L4 21:000021L4 22:000022L4 23:000023L4 24:000024L4 25:000025L4 26:000026L4 27:000027L4 28:000028L4 29:000029L4 30:000030L4 31:000031L4 32:000032L4 33:000033L4 34:000034L4 35:000035L4 36:000036L4 37:000037L4 38:000038L4 39:000039L4 41:000041L4 42:000042L4 43:000043L4 44:000044L4 45:000045L4 46:000046L4 47:000048L4 1:000002L4
Compare the above with the output from this:
$ sudo mtx -f /dev/pass1 status
Storage Changer /dev/pass1:2 Drives, 47 Slots ( 0 Import/Export )
Data Transfer Element 0:Full (Storage Element 1 Loaded):VolumeTag = 000002L4
Data Transfer Element 1:Empty
Storage Element 1:Empty
Storage Element 2:Full :VolumeTag=000001L4
Storage Element 3:Full :VolumeTag=000003L4
Storage Element 4:Full :VolumeTag=000004L4
Storage Element 5:Full :VolumeTag=000005L4
Storage Element 6:Full :VolumeTag=000006L4
Storage Element 7:Full :VolumeTag=000007L4
Storage Element 8:Full :VolumeTag=000008L4
Storage Element 9:Full :VolumeTag=000009L4
Storage Element 10:Full :VolumeTag=000010L4
Storage Element 11:Full :VolumeTag=000011L4
Storage Element 12:Full :VolumeTag=000012L4
Storage Element 13:Full :VolumeTag=000013L4
Storage Element 14:Full :VolumeTag=000014L4
Storage Element 15:Full :VolumeTag=000015L4
Storage Element 16:Full :VolumeTag=000016L4
Storage Element 17:Full :VolumeTag=000017L4
Storage Element 18:Full :VolumeTag=000018L4
Storage Element 19:Full :VolumeTag=000019L4
Storage Element 20:Full :VolumeTag=000020L4
Storage Element 21:Full :VolumeTag=000021L4
Storage Element 22:Full :VolumeTag=000022L4
Storage Element 23:Full :VolumeTag=000023L4
Storage Element 24:Full :VolumeTag=000024L4
Storage Element 25:Full :VolumeTag=000025L4
Storage Element 26:Full :VolumeTag=000026L4
Storage Element 27:Full :VolumeTag=000027L4
Storage Element 28:Full :VolumeTag=000028L4
Storage Element 29:Full :VolumeTag=000029L4
Storage Element 30:Full :VolumeTag=000030L4
Storage Element 31:Full :VolumeTag=000031L4
Storage Element 32:Full :VolumeTag=000032L4
Storage Element 33:Full :VolumeTag=000033L4
Storage Element 34:Full :VolumeTag=000034L4
Storage Element 35:Full :VolumeTag=000035L4
Storage Element 36:Full :VolumeTag=000036L4
Storage Element 37:Full :VolumeTag=000037L4
Storage Element 38:Full :VolumeTag=000038L4
Storage Element 39:Full :VolumeTag=000039L4
Storage Element 40:Empty
Storage Element 41:Full :VolumeTag=000041L4
Storage Element 42:Full :VolumeTag=000042L4
Storage Element 43:Full :VolumeTag=000043L4
Storage Element 44:Full :VolumeTag=000044L4
Storage Element 45:Full :VolumeTag=000045L4
Storage Element 46:Full :VolumeTag=000046L4
Storage Element 47:Full :VolumeTag=000048L4
We already have a tape in drive 0. Let’s put a tape into drive 1.
$ sudo /usr/local/sbin/mtx-changer /dev/pass1 load 47 x 1 Loading media from Storage Element 47 into drive 1...done
There’s a trick in there… Usually the 4th parameter is the archive device (i.e. tape drive), but the 5th parameter is the drive index. In the above case, I supplied ‘x’ as the 4th parameter because I have noticed that it does not affect the outcome, at least for me. I have supplied sa0 when I meant sa1 but had the 5th parameter set to 1. The tape was loaded into sa1.
Writing stuff to the tape
What follow is mostly a repeat of what I have done for other tape libraries.
This is a destructive test. Anything on the tape before this test will be lost.
$ cd /bin $ sudo tar -cvf /dev/nsa0 . a . a ./expr a ./realpath a ./hostname a ./ps a ./red a ./date a ./sh a ./tcsh a ./uuidgen a ./[ a ./mkdir a ./freebsd-version a ./csh a ./rmail a ./cat a ./df a ./pkill a ./test a ./pax a ./domainname a ./link a ./rcp a ./mv a ./rmdir a ./cp a ./echo a ./pgrep a ./ln a ./chflags a ./sync a ./dd a ./kill a ./chio a ./rm a ./getfacl a ./setfacl a ./chmod a ./sleep a ./stty a ./ls a ./unlink a ./pwd a ./ed a ./pwait a ./kenv
Now it’s time for a restore and a diff:
$ mkdir -p ~/tmp/bin $ cd ~/tmp/bin $ sudo tar -xvf /dev/nsa0 x ./ x ./expr x ./realpath x ./hostname x ./ps x ./red x ./date x ./sh x ./tcsh x ./uuidgen x ./[ x ./mkdir x ./freebsd-version x ./csh x ./rmail x ./cat x ./df x ./pkill x ./test x ./pax x ./domainname x ./link x ./rcp x ./mv x ./rmdir x ./cp x ./echo x ./pgrep x ./ln x ./chflags x ./sync x ./dd x ./kill x ./chio x ./rm x ./getfacl x ./setfacl x ./chmod x ./sleep x ./stty x ./ls x ./unlink x ./pwd x ./ed x ./pwait x ./kenv $ diff -ruN /bin ~/tmp/bin $
Remember to do that diff. There should be no output.
Now, let’s write some more
Let’s backup a bit more data. The drives in this system are 2x Crucial BX200 480GB SATA 2.5 Inch Internal Solid State Drive – CT480BX200SSD1 in a ZFS mirror. That explains the fast speeds.
$ time sudo tar -cf /dev/nsa0 /usr/ports tar: Removing leading '/' from member names real 0m17.442s user 0m2.621s sys 0m6.222s
And now we do the restore:
$ mkdir PORTS $ cd PORTS $ time sudo tar -xf /dev/sa0 real 0m18.635s user 0m1.951s sys 0m11.296s $ diff -ruN /usr/ports/ ./usr/ports/ $
Good. As good as it gets.
Next time, on Bacula Adventures…
I’m too late with these tests to make the full backups which are running as I type this on Sunday morning. My next post will deal with the Bacula configuration (in bacula-dir.conf) and creation of new Jobs to use this tape library.
