[Bacula-bugs] [Bacula Bug Reports 0002174]: Race condition in the selection of the volume for two jobs

[Mantis B. T. <no...@bu...>]

The following issue has been SUBMITTED. 
====================================================================== 
http://bugs.bacula.org/view.php?id=2174 
====================================================================== 
Reported By:                wonko
Assigned To:                
====================================================================== 
Project:                    Bacula Bug Reports
Issue ID:                   2174
Category:                   Director
Reproducibility:            always
Severity:                   major
Priority:                   normal
Status:                     new
====================================================================== 
Date Submitted:             2015-10-06 09:24 BST
Last Modified:              2015-10-06 09:24 BST
====================================================================== 
Summary:                    Race condition in the selection of the volume for
two jobs
Description: 
Bacula 7.2.0, vchanger autochanger, scratch-pool, full-pool, diff-pool and
incr-pool. 1 job per volume.

When starting two new jobs at the same time, the first jobs selects a volume,
issues a mount request, marks the volume in use and starts the backup.

The second job selects the same volume, purges it (does no harm, as no entries
are yet in the database), issues a mount, and then hangs.

This is the correspondent log snippet:

05-Oct 17:02 bacula-director JobId 507457: Start Backup JobId 507457,
Job=webnode-004.2015-10-05_17.02.17_01
05-Oct 17:02 bacula-director JobId 507457: There are no more Jobs associated
with Volume "changer2_0001_6551". Marking it purged.
05-Oct 17:02 bacula-director JobId 507457: All records pruned from Volume
"changer2_0001_6551"; marking it "Purged"
05-Oct 17:02 bacula-director JobId 507457: Recycled volume "changer2_0001_6551"
05-Oct 17:02 bacula-director JobId 507458: Start Backup JobId 507458,
Job=webnode-005.2015-10-05_17.02.18_02
05-Oct 17:02 bacula-director JobId 507457: Using Device "changer2-drive-0" to
write.
05-Oct 17:02 bacula-director JobId 507458: Using Device "changer2-drive-2" to
write.
05-Oct 17:02 bacula-sd JobId 507457: 3304 Issuing autochanger "load slot 6551,
drive 0" command.
05-Oct 17:02 bacula-sd JobId 507457: 3305 Autochanger "load slot 6551, drive 0",
status is OK.
05-Oct 17:02 bacula-sd JobId 507457: Recycled volume "changer2_0001_6551" on
file device "changer2-drive-0" (/var/lib/bacula/changer2/0/drive0), all previous
data lost.
05-Oct 17:02 bacula-director JobId 507457: Max Volume jobs=1 exceeded. Marking
Volume "changer2_0001_6551" as Used.
05-Oct 17:02 bacula-director JobId 507458: There are no more Jobs associated
with Volume "changer2_0001_6551". Marking it purged.
05-Oct 17:02 bacula-director JobId 507458: All records pruned from Volume
"changer2_0001_6551"; marking it "Purged"
05-Oct 17:02 bacula-director JobId 507458: Recycled volume "changer2_0001_6551"
05-Oct 17:02 bacula-sd JobId 507458: Job webnode-005.2015-10-05_17.02.18_02 is
waiting. Cannot find any appendable volumes.
Please use the "label" command to create a new Volume for:
    Storage:      "changer2-drive-2" (/var/lib/bacula/changer2/2/drive2)
    Pool:         changer2-full
    Media type:   File

I observed when a backup is started, there are no references in the JobMedia
table to link the volume to the job (I assume these get inserted at the end of
the backup). As such, there is no way for a job to know that the volume it
selects is in fact already being used by another currently running job. 

I tried the Prefer Mounted Volumes = no directive, and this helps for jobs that
start later. However, starting two jobs simultaneous triggers this race
condition. 

Steps to Reproduce: 
Starting two jobs at exactly the same time.

Additional Information: 
I could not select version 7.2.0 in the bug reporting tool - you might want to
update the report to reflect the correct version. 
====================================================================== 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2015-10-06 09:24 wonko          New Issue                                    
======================================================================