Re: [Bacula-users] vchanger 1.0.1 says "No slots in changer to scan"

Hi Josh,

On Thu, May 5, 2016 at 8:19 PM, Josh Fisher <jfisher AT pvct DOT com> wrote:

2. I followed the vchanger documentation (vchangerHowto.html) to setup vchanger.

I have successfully configured udev and autofs. udev is able to mount the filesystems when I insert the drives. And, autofs is able to mount it to the mountpoint /mnt/vchanger

You should not configure for both autofs and udev at the same time, but rather one or the other.

To test further, I stopped autofs. And attempt to depend on udev to perform the automounting.

Questions:
==========
2a. Why did vchanger list and listmags spits out "device-enumerator" lines?

Those are generated by systemd. My best guess is that they are triggered by vchanger's use of the libudev function udev_enumerate_scan_devices() to scan for mounted filesystems by UUID. But systemd is a total enigma to me, so I am not sure why this would be the case.

2b. bconsole throws out the lines below when I issue "status slots". Did I misconfigured something?

Device "SATA-vchanger01" has 0 slots.
No slots in changer to scan.

This is very likely one of two things (or both); a race condition bug in vchanger or vchanger is incompatible with the installed version of libudev..

The vchanger bug is due to vchanger automatically issuing 'update slots' commands via bconsole when it detects a change in the volume files it has access to. Vchanger is invoking bconsole in a child process. The child bconsole process executes a 'update slots' command that in turn causes bacula-sd to invoke a few other instances of vchanger with the SLOTS and LIST commands, which is how bacula-sd queries autochangers to obtain the number of slots and current volume barcodes in those slots. Vchanger uses a lockfile to serialize the simultaneous instances, but some bug in vchanger is causing a race for the lockfile (I think).

The simple workaround to determine if the vchanger bug is causing your problem, is to change the bconsole="/usr/sbin/bconsole" line in vchanger.conf to bconsole="". This will prevent vchanger from issuing bconsole commands at all. Of course you will then have to issue the update slots command in bconsole manually whenever anything changes with the magazine drives. You may need to manually delete any leftover stale .lock files in the vchanger work directory.

Another possibility is that there has been some change in recent releases of libudev that causes vchanger to not find filesystem mountpoints by UUID. That would perhaps explain the messages from systemd. The workaround for that is to make sure the drives are mounted, either by udev or manually, and then specify the magazines as a mountpoint path in vchanger.conf, rather than as a UUID. When specified as a full path, vchanger just assumes the volumes are in that directory and does not call any libudev functions.

When I insert the drive with the filesystem UUID:1fde15be-83a4-4b67-accc-378d5fa10ea7 (at the same time, I was watching the system logs with "journalctl -f"), I do notice the following:

May 06 14:34:06 deneb systemd-udevd[2578]: LINK 'disk/by-uuid/1fde15be-83a4-4b67-accc-378d5fa10ea7' /usr/lib/udev/rules.d/60-persistent-storage.rules:69
May 06 14:34:06 deneb systemd-udevd[2578]: LINK 'disk/by-id/wwn-0x861b0a6d4ee25001-part1' /usr/lib/udev/rules.d/60-persistent-storage.rules:74
May 06 14:34:06 deneb systemd-udevd[2578]: LINK 'disk/by-partuuid/633084bd-a2f2-4d2e-8991-27e8812ccdee' /usr/lib/udev/rules.d/60-persistent-storage.rules:77
May 06 14:34:06 deneb systemd-udevd[2578]: LINK 'disk/by-partlabel/Linux\x20filesystem' /usr/lib/udev/rules.d/60-persistent-storage.rules:78
====>> May 06 14:34:06 deneb systemd-udevd[2578]: RUN '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7' /etc/udev/rules.d/96-vchanger.rules:7
^^^
^^^ Here it says that udevd is going to start running the /usr/libexec/vchanger/vchanger-launch-mount.sh script

May 06 14:34:06 deneb systemd-udevd[2578]: handling device node '/dev/sdb1', devnum=b8:17, mode=0660, uid=0, gid=6
May 06 14:34:06 deneb systemd-udevd[2578]: set permissions /dev/sdb1, 060660, uid=0, gid=6
May 06 14:34:06 deneb systemd-udevd[2578]: creating symlink '/dev/block/8:17' to '../sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating link '/dev/disk/by-id/ata-WDC_WD20NPVX-00EA4T0_WD-WX41A44L9959-part1' to '/dev/sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating symlink '/dev/disk/by-id/ata-WDC_WD20NPVX-00EA4T0_WD-WX41A44L9959-part1' to '../../sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating link '/dev/disk/by-id/wwn-0x861b0a6d4ee25001-part1' to '/dev/sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating symlink '/dev/disk/by-id/wwn-0x861b0a6d4ee25001-part1' to '../../sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating link '/dev/disk/by-partlabel/Linux\x20filesystem' to '/dev/sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating symlink '/dev/disk/by-partlabel/Linux\x20filesystem' to '../../sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating link '/dev/disk/by-partuuid/633084bd-a2f2-4d2e-8991-27e8812ccdee' to '/dev/sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating symlink '/dev/disk/by-partuuid/633084bd-a2f2-4d2e-8991-27e8812ccdee' to '../../sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating link '/dev/disk/by-uuid/1fde15be-83a4-4b67-accc-378d5fa10ea7' to '/dev/sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: creating symlink '/dev/disk/by-uuid/1fde15be-83a4-4b67-accc-378d5fa10ea7' to '../../sdb1'
May 06 14:34:06 deneb systemd-udevd[2578]: created db file '/run/udev/data/b8:17' for '/devices/pci0000:00/0000:00:16.0/0000:0b:00.0/ata1/host0/target0:0:0/0:0:0:0/block/sdb/sdb1'
====>> May 06 14:34:06 deneb systemd-udevd[2580]: starting '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'
^^^
^^^ Here it says that udevd is starting to run the /usr/libexec/vchanger/vchanger-launch-mount.sh script

May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(out) 'checking dev'
May 06 14:34:06 deneb kernel: EXT4-fs (sdb1): recovery complete
====>> May 06 14:34:06 deneb kernel: EXT4-fs (sdb1): mounted filesystem with ordered data mode. Opts: (null)
^^^
^^^ At this point, kernel reports that it's mounted the filesystem (/dev/sdb1)

May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) 'device-enumerator: scan all dirs'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) ' device-enumerator: scanning /sys/bus'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) ' device-enumerator: scanning /sys/class'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) 'device-enumerator: scan all dirs'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) ' device-enumerator: scanning /sys/bus'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) ' device-enumerator: scanning /sys/class'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) 'device-enumerator: scan all dirs'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) ' device-enumerator: scanning /sys/bus'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) ' device-enumerator: scanning /sys/class'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) 'device-enumerator: scan all dirs'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) ' device-enumerator: scanning /sys/bus'
May 06 14:34:06 deneb systemd-udevd[2578]: '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7'(err) ' device-enumerator: scanning /sys/class'
====>> May 06 14:34:06 deneb systemd-udevd[2578]: Process '/usr/libexec/vchanger/vchanger-launch-mount.sh 1fde15be-83a4-4b67-accc-378d5fa10ea7' succeeded.
^^^
^^^ Here, udevd says that /usr/libexec/vchanger/vchanger-launch-mount.sh script has completed running successfully.

A point to note about the kernel reporting that it has mounted the filesystem. When I checked with mount command, the filesystem was not mounted.

[root@deneb ~]# mount | grep vchanger
[root@deneb ~]#

Don't know why. Did /usr/libexec/vchanger/vchanger-launch-mount.sh actually mounts it?

Anyway, to test further, I manually mount it:

[root@deneb ~]# mount /dev/disk/by-uuid/1fde15be-83a4-4b67-accc-378d5fa10ea7 /mnt/vchanger/1fde15be-83a4-4b67-accc-378d5fa10ea7/
[root@deneb ~]# mount | grep vchanger
/dev/sdb1 on /mnt/vchanger/1fde15be-83a4-4b67-accc-378d5fa10ea7 type ext4 (rw,relatime,data="">[root@deneb ~]#

Then, I did what you mentioned:- I modified /etc/vchanger/vchanger01.conf and changed the bconsole="/usr/sbin/bconsole" line to bconsole = "".

Then I tried the following again.

[root@deneb ~]# vchanger /etc/vchanger/vchanger01.conf listmags
device-enumerator: scan all dirs
device-enumerator: scanning /sys/bus
device-enumerator: scanning /sys/class
device-enumerator: scan all dirs
device-enumerator: scanning /sys/bus
device-enumerator: scanning /sys/class
device-enumerator: scan all dirs
device-enumerator: scanning /sys/bus
device-enumerator: scanning /sys/class
device-enumerator: scan all dirs
device-enumerator: scanning /sys/bus
device-enumerator: scanning /sys/class
0:18:1:/mnt/vchanger/1fde15be-83a4-4b67-accc-378d5fa10ea7
1:::
2:::
3:::
[root@deneb ~]# vchanger /etc/vchanger/vchanger01.conf list
device-enumerator: scan all dirs
device-enumerator: scanning /sys/bus
device-enumerator: scanning /sys/class
device-enumerator: scan all dirs
device-enumerator: scanning /sys/bus
device-enumerator: scanning /sys/class
device-enumerator: scan all dirs
device-enumerator: scanning /sys/bus
device-enumerator: scanning /sys/class
device-enumerator: scan all dirs
device-enumerator: scanning /sys/bus
device-enumerator: scanning /sys/class
1:vchanger01_0_0
2:vchanger01_0_1
3:vchanger01_0_10
4:vchanger01_0_11
5:vchanger01_0_12
6:vchanger01_0_13
7:vchanger01_0_14
8:vchanger01_0_15
9:vchanger01_0_16
10:vchanger01_0_17
11:vchanger01_0_2
12:vchanger01_0_3
13:vchanger01_0_4
14:vchanger01_0_5
15:vchanger01_0_6
16:vchanger01_0_7
17:vchanger01_0_8
18:vchanger01_0_9
19:
20:
21:
22:
23:
24:
25:
26:
27:
28:
29:
30:
31:
32:
33:
34:
35:
36:
37:
[root@deneb ~]# bconsole
Connecting to Director deneb.chuakt.local:9101
1000 OK: 102 bacula-dir Version: 7.4.0 (16 January 2016)
Enter a period to cancel a command.
*update slots
Automatically selected Catalog: MyCatalog
Using Catalog "MyCatalog"
Automatically selected Storage: vchanger01
Connecting to Storage daemon vchanger01 at deneb.chuakt.local:9103 ...
3306 Issuing autochanger "slots" command.
Device "SATA-vchanger01" has 0 slots.
No slots in changer to scan.
*

In the end, I'm still getting the error in bconsole:

Device "SATA-vchanger01" has 0 slots.
No slots in changer to scan.

By any chance I may have misconfigured something within bacula-dir.conf and bacula-sd.conf?

Thanks again,

Pann

------------------------------------------------------------------------------
Find and fix application performance issues faster with Applications Manager
Applications Manager provides deep performance insights into multiple tiers of
your business applications. It resolves application problems quickly and
reduces your MTTR. Get your free trial!
https://ad.doubleclick.net/ddm/clk/302982198;130105516;z

_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users