On 3/21/24 16:36, Marco Gaiarin wrote:
Mandi! Josh Fisher via Bacula-users
   In chel di` si favelave...

'Log Level = LOG_DEBUG' in the vchanger.conf file. That will log everything
'log level = 7', do you mean, right?
Yes. The configuration parser will also understand "LOG_DEBUG" (same as 7)


I've found an installation where i've forgot a log level = 7, so, last
friday:

...

Mar 15 07:00:06:  [6778]: bconsole output:
Connecting to Director bacula.lnf.it:9101
1000 OK: 103 lnfbacula-dir Version: 9.4.2 (04 February 2019)
Enter a period to cancel a command.
update slots storage="SDPVE2RDX" drive="0"
Automatically selected Catalog: BaculaLNF
Using Catalog "BaculaLNF"
Connecting to Storage daemon SDPVE2RDX at sdpve2.sd.lnf.it:9103 ...
3306 Issuing autochanger "slots" command.
Device "RDXAutochanger" has 10 slots.
Connecting to Storage daemon SDPVE2RDX at sdpve2.sd.lnf.it:9103 ...
3306 Issuing autochanger "list" command.
No Volumes found to label, or no barcodes.
You have messages.

Mar 15 07:00:06:  [6778]: bconsole update slots command success
...

OK. That looks correct. I wish we knew what Bacula thought was in-changer at this point in time. The 'update slots' command succeeded and the LIST command that Bacula sent to vchanger suceeded and listed no volumes. Bacula should show that no volumes are in changer at this point and the slot number of every volume should be zero.


And then the operator insert the new cartdrige:

Mar 15 11:01:59:  [31055]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 has 
udev assigned device /dev/sdc1
Mar 15 11:01:59:  [31055]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 
(device /dev/sdc1) mounted at /mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4
Mar 15 11:01:59:  [31055]: magazine 0 has 10 volumes on 
/mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4
Mar 15 11:01:59:  [31055]: update slots needed. magazine 0 has 10 volumes, 
previously had 0
Mar 15 11:01:59:  [31055]: magazine 1 is not mounted
Mar 15 11:01:59:  [31055]: magazine 2 is not mounted
Mar 15 11:01:59:  [31055]: 10 volumes on magazine 0 assigned slots 1-10
Mar 15 11:01:59:  [31055]: saved state of magazine 0
Mar 15 11:01:59:  [31055]: saved dynamic configuration (max used slot: 10)
Mar 15 11:01:59:  [31055]: drive 0 previously unloaded
Mar 15 11:01:59:  [31055]: ==== preforming REFRESH command
Mar 15 11:01:59:  [31055]: running '/usr/sbin/bconsole -n -u 30'
Mar 15 11:01:59:  [31055]: popen: child stdin uses pipe (4 -> 5)
Mar 15 11:01:59:  [31055]: popen: child stdout uses pipe (6 -> 7)
Mar 15 11:01:59:  [31055]: popen: forking now
Mar 15 11:01:59:  [31055]: popen: parent closing pipe ends 4,7,-1 used by child
Mar 15 11:01:59:  [31055]: popen: parent writes child's stdin to 5
Mar 15 11:01:59:  [31055]: popen: parent reads child's stdout from 6
Mar 15 11:01:59:  [31055]: popen: parent returning pid=31056 of child
Mar 15 11:01:59:  [31055]: sending bconsole command 'update slots storage="SDPVE2RDX" 
drive="0"'
Mar 15 11:01:59:  [31056]: popen: child closing pipe ends 5,6,-1 used by parent
Mar 15 11:01:59:  [31056]: popen: child will read stdin from 4
Mar 15 11:01:59:  [31056]: popen: child will write stdout to 7
Mar 15 11:01:59:  [31056]: popen: child executing '/usr/sbin/bconsole'
Mar 15 11:02:00:  [31076]: restored state of magazine 0
Mar 15 11:02:00:  [31076]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 has 
udev assigned device /dev/sdc1
Mar 15 11:02:00:  [31076]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 
(device /dev/sdc1) mounted at /mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4
Mar 15 11:02:00:  [31076]: magazine 0 has 10 volumes on 
/mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4
Mar 15 11:02:00:  [31076]: 10 volumes on magazine 0 assigned slots 1-10
Mar 15 11:02:00:  [31076]: magazine 1 is not mounted
Mar 15 11:02:00:  [31076]: magazine 2 is not mounted
Mar 15 11:02:00:  [31076]: saved state of magazine 0
Mar 15 11:02:00:  [31076]: saved dynamic configuration (max used slot: 10)
Mar 15 11:02:00:  [31076]: drive 0 previously unloaded
Mar 15 11:02:00:  [31076]: ==== preforming SLOTS command
Mar 15 11:02:00:  [31076]:   SUCCESS reporting 10 slots
Mar 15 11:02:00:  [31078]: restored state of magazine 0
Mar 15 11:02:00:  [31078]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 has 
udev assigned device /dev/sdc1
Mar 15 11:02:00:  [31078]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 
(device /dev/sdc1) mounted at /mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4
Mar 15 11:02:00:  [31078]: magazine 0 has 10 volumes on 
/mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4
Mar 15 11:02:00:  [31078]: 10 volumes on magazine 0 assigned slots 1-10
Mar 15 11:02:00:  [31078]: magazine 1 is not mounted
Mar 15 11:02:00:  [31078]: magazine 2 is not mounted
Mar 15 11:02:00:  [31078]: saved state of magazine 0
Mar 15 11:02:00:  [31078]: saved dynamic configuration (max used slot: 10)
Mar 15 11:02:00:  [31078]: drive 0 previously unloaded
Mar 15 11:02:00:  [31078]: ==== preforming LOADED command
Mar 15 11:02:00:  [31078]:   SUCCESS reporting drive 0 loaded from slot 0
Mar 15 11:02:00:  [31079]: restored state of magazine 0
Mar 15 11:02:01:  [31079]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 has 
udev assigned device /dev/sdc1
Mar 15 11:02:01:  [31079]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 
(device /dev/sdc1) mounted at /mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4
Mar 15 11:02:01:  [31079]: magazine 0 has 10 volumes on 
/mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4
Mar 15 11:02:01:  [31079]: 10 volumes on magazine 0 assigned slots 1-10
Mar 15 11:02:01:  [31079]: magazine 1 is not mounted
Mar 15 11:02:01:  [31079]: magazine 2 is not mounted
Mar 15 11:02:01:  [31079]: saved state of magazine 0
Mar 15 11:02:01:  [31079]: saved dynamic configuration (max used slot: 10)
Mar 15 11:02:01:  [31079]: drive 0 previously unloaded
Mar 15 11:02:01:  [31079]: ==== preforming LIST command
Mar 15 11:02:01:  [31079]:   SUCCESS sent list to stdout
Mar 15 11:02:01:  [31055]: bconsole: bconsole terminated normally
Mar 15 11:02:01:  [31055]: bconsole output:
Connecting to Director bacula.lnf.it:9101
1000 OK: 103 lnfbacula-dir Version: 9.4.2 (04 February 2019)
Enter a period to cancel a command.
update slots storage="SDPVE2RDX" drive="0"
Automatically selected Catalog: BaculaLNF
Using Catalog "BaculaLNF"
Connecting to Storage daemon SDPVE2RDX at sdpve2.sd.lnf.it:9103 ...
3306 Issuing autochanger "slots" command.
Device "RDXAutochanger" has 10 slots.
Connecting to Storage daemon SDPVE2RDX at sdpve2.sd.lnf.it:9103 ...
3306 Issuing autochanger "list" command.
Catalog record for Volume "SDPVE2RDX_0000_0000" updated to reference slot 1.
Catalog record for Volume "SDPVE2RDX_0000_0001" updated to reference slot 2.
Catalog record for Volume "SDPVE2RDX_0000_0002" updated to reference slot 3.
Catalog record for Volume "SDPVE2RDX_0000_0003" updated to reference slot 4.
Catalog record for Volume "SDPVE2RDX_0000_0004" updated to reference slot 5.
Catalog record for Volume "SDPVE2RDX_0000_0005" updated to reference slot 6.
Catalog record for Volume "SDPVE2RDX_0000_0006" updated to reference slot 7.
Catalog record for Volume "SDPVE2RDX_0000_0007" updated to reference slot 8.
Catalog record for Volume "SDPVE2RDX_0000_0008" updated to reference slot 9.
Catalog record for Volume "SDPVE2RDX_0000_0009" updated to reference slot 10.
You have messages.

Mar 15 11:02:01:  [31055]: bconsole update slots command success

Also correct. It does look like udev is trigerring vchanger, vchanger is invoking the update slots command, and that the update slots command is successful.

that vchanger does. The udev script will run vchanger with the REFRESH
command.
If you don't see a REFRESH command being logged in the vchanger log file
when
the cartridge is removed, then Bill is correct, the RDX device is not
generating an ACTION="remove" event in udev when the cartridge is removed.


Simply they are not purgeable, so bacula start to purge volumes in cartdrige
1 (right) and mount them (wrong), puting them on error.

I can't explain that, unless the volumes that are in changer, those assigned to a slot > 0, are not getting their current slot set to zero when the magazine is ejected.


     [-- text/html, encoding 8bit, charset: UTF-8, 66 lines --]

[-- text/plain, encoding 7bit, charset: us-ascii, 1 lines --]


[-- text/plain, encoding 7bit, charset: us-ascii, 5 lines --]

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

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

Reply via email to