]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/stored/vol_mgr.c
Add some additional tape slot debug code
[bacula/bacula] / bacula / src / stored / vol_mgr.c
index a89584d137b1aee409f48045279c6a06925a2c0e..f4c9cdf6e6a520de5c4a928da4054b01074ca0ca 100644 (file)
@@ -1,29 +1,20 @@
 /*
-   Bacula® - The Network Backup Solution
-
-   Copyright (C) 2000-2012 Free Software Foundation Europe e.V.
-
-   The main author of Bacula is Kern Sibbald, with contributions from
-   many others, a complete list can be found in the file AUTHORS.
-   This program is Free Software; you can redistribute it and/or
-   modify it under the terms of version three of the GNU Affero General Public
-   License as published by the Free Software Foundation and included
-   in the file LICENSE.
-
-   This program is distributed in the hope that it will be useful, but
-   WITHOUT ANY WARRANTY; without even the implied warranty of
-   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
-   General Public License for more details.
-
-   You should have received a copy of the GNU Affero General Public License
-   along with this program; if not, write to the Free Software
-   Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
-   02110-1301, USA.
-
-   Bacula® is a registered trademark of Kern Sibbald.
-   The licensor of Bacula is the Free Software Foundation Europe
-   (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
-   Switzerland, email:ftf@fsfeurope.org.
+   Bacula(R) - The Network Backup Solution
+
+   Copyright (C) 2000-2016 Kern Sibbald
+
+   The original author of Bacula is Kern Sibbald, with contributions
+   from many others, a complete list can be found in the file AUTHORS.
+
+   You may use this file and others of this release according to the
+   license defined in the LICENSE file, which includes the Affero General
+   Public License, v3.0 ("AGPLv3") and some additional permissions and
+   terms pursuant to its AGPLv3 Section 7.
+
+   This notice must be preserved when any source code is 
+   conveyed and/or propagated.
+
+   Bacula(R) is a registered trademark of Kern Sibbald.
 */
 /*
  *   Volume management functions for Storage Daemon
@@ -52,7 +43,7 @@ static void debug_list_volumes(const char *imsg);
 /*
  * For append volumes the key is the VolumeName.
  */
-static int my_compare(void *item1, void *item2)
+static int name_compare(void *item1, void *item2)
 {
    return strcmp(((VOLRES *)item1)->vol_name, ((VOLRES *)item2)->vol_name);
 }
@@ -74,8 +65,7 @@ static int read_compare(void *item1, void *item2)
    return 1;
 }
 
-
-bool is_vol_list_empty() 
+bool is_vol_list_empty()
 {
    return vol_list->empty();
 }
@@ -100,7 +90,7 @@ void term_vol_list_lock()
    rwl_destroy(&vol_list_lock);
 }
 
-/* 
+/*
  * This allows a given thread to recursively call to lock_volumes()
  */
 void _lock_volumes(const char *file, int line)
@@ -125,12 +115,13 @@ void _unlock_volumes()
    }
 }
 
-void lock_read_volumes(const char *file="**Unknown", int line=0)
+#define lock_read_volumes() lock_read_volumes_p(__FILE__, __LINE__)
+static void lock_read_volumes_p(const char *file="**Unknown", int line=0)
 {
    bthread_mutex_lock_p(&read_vol_lock, file, line);
 }
 
-void unlock_read_volumes()
+static void unlock_read_volumes()
 {
    bthread_mutex_unlock(&read_vol_lock);
 }
@@ -140,7 +131,7 @@ void unlock_read_volumes()
  * Note, we use VOLRES because it simplifies the code
  *   even though, the only part of VOLRES that we need is
  *   the volume name.  The same volume may be in the list
- *   multiple times, but each one is distinguished by the 
+ *   multiple times, but each one is distinguished by the
  *   JobId.  We use JobId, VolumeName as the key.
  * We can get called multiple times for the same volume because
  *   when parsing the bsr, the volume name appears multiple times.
@@ -149,9 +140,10 @@ void add_read_volume(JCR *jcr, const char *VolumeName)
 {
    VOLRES *nvol, *vol;
 
-   lock_read_volumes();
    nvol = new_vol_item(NULL, VolumeName);
    nvol->set_jobid(jcr->JobId);
+   nvol->set_reading();
+   lock_read_volumes();
    vol = (VOLRES *)read_vol_list->binary_insert(nvol, read_compare);
    if (vol != nvol) {
       free_vol_item(nvol);
@@ -162,6 +154,20 @@ void add_read_volume(JCR *jcr, const char *VolumeName)
    unlock_read_volumes();
 }
 
+/*
+ * Check if volume name is in the read list.
+ */
+bool is_read_volume(JCR *jcr, const char *VolumeName)
+{
+   VOLRES vol, *fvol;
+   lock_read_volumes();
+   vol.vol_name = bstrdup(VolumeName);
+   fvol = (VOLRES *)read_vol_list->binary_search(&vol, name_compare);
+   free(vol.vol_name);
+   unlock_read_volumes();
+   return fvol != NULL;
+}
+
 /*
  * Remove a given volume name from the read list.
  */
@@ -197,19 +203,23 @@ static void debug_list_volumes(const char *imsg)
    VOLRES *vol;
    POOL_MEM msg(PM_MESSAGE);
 
-   lock_volumes();
-   foreach_dlist(vol, vol_list) {
+   if (debug_level < dbglvl) {
+      return;
+   }
+
+   foreach_vol(vol) {
       if (vol->dev) {
-         Mmsg(msg, "List %s: %s in_use=%d swap=%d on device %s\n", imsg, 
-              vol->vol_name, vol->is_in_use(), vol->is_swapping(), vol->dev->print_name());
+         Mmsg(msg, "List %s: %s in_use=%d swap=%d slot=%d on %s device %s\n", imsg,
+              vol->vol_name, vol->is_in_use(), vol->is_swapping(),
+              vol->get_slot(),
+              vol->dev->print_type(), vol->dev->print_name());
       } else {
-         Mmsg(msg, "List %s: %s in_use=%d swap=%d no dev\n", imsg, vol->vol_name, 
-              vol->is_in_use(), vol->is_swapping());
+         Mmsg(msg, "List %s: %s in_use=%d swap=%d slot=%d no dev\n", imsg, vol->vol_name,
+              vol->is_in_use(), vol->is_swapping(), vol->get_slot());
       }
       Dmsg1(dbglvl, "%s", msg.c_str());
    }
-
-   unlock_volumes();
+   endeach_vol(vol);
 }
 
 
@@ -222,32 +232,42 @@ void list_volumes(void sendit(const char *msg, int len, void *sarg), void *arg)
    POOL_MEM msg(PM_MESSAGE);
    int len;
 
-   lock_volumes();
-   foreach_dlist(vol, vol_list) {
+   foreach_vol(vol) {
       DEVICE *dev = vol->dev;
       if (dev) {
-         len = Mmsg(msg, "%s on device %s\n", vol->vol_name, dev->print_name());
+         len = Mmsg(msg, "Reserved volume: %s on %s device %s\n", vol->vol_name,
+                  dev->print_type(), dev->print_name());
          sendit(msg.c_str(), len, arg);
-         len = Mmsg(msg, "    Reader=%d writers=%d devres=%d volinuse=%d\n", 
-            dev->can_read()?1:0, dev->num_writers, dev->num_reserved(),   
+         len = Mmsg(msg, "    Reader=%d writers=%d reserves=%d volinuse=%d\n",
+            dev->can_read()?1:0, dev->num_writers, dev->num_reserved(),
             vol->is_in_use());
          sendit(msg.c_str(), len, arg);
       } else {
-         len = Mmsg(msg, "%s no device. volinuse= %d\n", vol->vol_name, 
+         len = Mmsg(msg, "Volume %s no device. volinuse=%d\n", vol->vol_name,
             vol->is_in_use());
          sendit(msg.c_str(), len, arg);
       }
    }
-   unlock_volumes();
+   endeach_vol(vol);
 
    lock_read_volumes();
    foreach_dlist(vol, read_vol_list) {
-      len = Mmsg(msg, "%s read volume JobId=%d\n", vol->vol_name, 
-            vol->get_jobid());
-      sendit(msg.c_str(), len, arg);
+      DEVICE *dev = vol->dev;
+      if (dev) {
+         len = Mmsg(msg, "Read volume: %s on %s device %s\n", vol->vol_name,
+                  dev->print_type(), dev->print_name());
+         sendit(msg.c_str(), len, arg);
+         len = Mmsg(msg, "    Reader=%d writers=%d reserves=%d volinuse=%d JobId=%d\n",
+            dev->can_read()?1:0, dev->num_writers, dev->num_reserved(),
+            vol->is_in_use(), vol->get_jobid());
+         sendit(msg.c_str(), len, arg);
+      } else {
+         len = Mmsg(msg, "Volume: %s no device. volinuse=%d\n", vol->vol_name,
+            vol->is_in_use());
+         sendit(msg.c_str(), len, arg);
+      }
    }
    unlock_read_volumes();
-
 }
 
 /*
@@ -262,9 +282,11 @@ static VOLRES *new_vol_item(DCR *dcr, const char *VolumeName)
    vol->vol_name = bstrdup(VolumeName);
    if (dcr) {
       vol->dev = dcr->dev;
-      Dmsg3(dbglvl, "new Vol=%s at %p dev=%s\n",
-            VolumeName, vol->vol_name, vol->dev->print_name());
+      Dmsg4(dbglvl, "new Vol=%s slot=%d at %p dev=%s\n",
+            VolumeName, vol->get_slot(), vol->vol_name, vol->dev->print_name());
    }
+   vol->init_mutex();
+   vol->inc_use_count();
    return vol;
 }
 
@@ -272,10 +294,18 @@ static void free_vol_item(VOLRES *vol)
 {
    DEVICE *dev = NULL;
 
+   vol->dec_use_count();
+   vol->vLock();
+   if (vol->use_count() > 0) {
+      vol->vUnlock();
+      return;
+   }
+   vol->vUnlock();
    free(vol->vol_name);
    if (vol->dev) {
       dev = vol->dev;
    }
+   vol->destroy_mutex();
    free(vol);
    if (dev) {
       dev->vol = NULL;
@@ -290,72 +320,81 @@ static void free_vol_item(VOLRES *vol)
  * If the device has any current volume associated with it,
  *  and it is a different Volume, and the device is not busy,
  *  we release the old Volume item and insert the new one.
- * 
+ *
  * It is assumed that the device is free and locked so that
  *  we can change the device structure.
  *
  * Some details of the Volume list handling:
  *
- *  1. The Volume list entry must be attached to the drive (rather than 
- *       attached to a job as it currently is. I.e. the drive that "owns" 
+ *  1. The Volume list entry is attached to the drive (rather than
+ *       attached to a job as it was previously. I.e. the drive that "owns"
  *       the volume (in use, mounted)
  *       must point to the volume (still to be maintained in a list).
  *
- *  2. The Volume is entered in the list when a drive is reserved.  
+ *  2. The Volume is entered in the list when a drive is reserved.
  *
  *  3. When a drive is in use, the device code must appropriately update the
- *      volume name as it changes (currently the list is static -- an entry is
- *      removed when the Volume is no longer reserved, in use or mounted).  
- *      The new code must keep the same list entry as long as the drive
+ *       volume name as it changes.
+  *      This code keeps the same list entry as long as the drive
  *       has any volume associated with it but the volume name in the list
  *       must be updated when the drive has a different volume mounted.
  *
- *  4. A job that has reserved a volume, can un-reserve the volume, and if the 
+ *  4. A job that has reserved a volume, can un-reserve the volume, and if the
  *      volume is not mounted, and not reserved, and not in use, it will be
  *      removed from the list.
  *
  *  5. If a job wants to reserve a drive with a different Volume from the one on
  *      the drive, it can re-use the drive for the new Volume.
- *
+
  *  6. If a job wants a Volume that is in a different drive, it can either use the
  *      other drive or take the volume, only if the other drive is not in use or
  *      not reserved.
  *
- *  One nice aspect of this is that the reserve use count and the writer use count 
- *  already exist and are correctly programmed and will need no changes -- use 
+ *  One nice aspect of this is that the reserve use count and the writer use count
+ *  already exist and are correctly programmed and will need no changes -- use
  *  counts are always very tricky.
  *
- *  The old code had a concept of "reserving" a Volume, but was changed 
- *  to reserving and using a drive.  A volume is must be attached to (owned by) a 
- *  drive and can move from drive to drive or be unused given certain specific 
- *  conditions of the drive.  The key is that the drive must "own" the Volume.  
- *  The old code had the job (dcr) owning the volume (more or less).  The job was
- *  to change the insertion and removal of the volumes from the list to be based 
- *  on the drive rather than the job.  
+ *  The old code had a concept of "reserving" a Volume, but was changed
+ *  to reserving and using a drive.  A volume is must be attached to (owned by) a
+ *  drive and can move from drive to drive or be unused given certain specific
+ *  conditions of the drive.  The key is that the drive must "own" the Volume.
  *
  *  Return: VOLRES entry on success
  *          NULL volume busy on another drive
+ *               jcr->errmsg has details
  */
 VOLRES *reserve_volume(DCR *dcr, const char *VolumeName)
 {
    VOLRES *vol, *nvol;
    DEVICE * volatile dev = dcr->dev;
+   JCR *jcr = dcr->jcr;
 
+   jcr->errmsg[0] = 0;
    if (job_canceled(dcr->jcr)) {
+      Mmsg1(jcr->errmsg, _("Could not reserve volume \"%s\", because job canceled.\n"),
+         dev->VolHdr.VolumeName);
       return NULL;
    }
-   ASSERT(dev != NULL);
+   ASSERT2(dev != NULL, "No device in reserve_volume!");
 
-   Dmsg2(dbglvl, "enter reserve_volume=%s drive=%s\n", VolumeName, 
+   Dmsg2(dbglvl, "enter reserve_volume=%s drive=%s\n", VolumeName,
       dcr->dev->print_name());
-   /* 
+
+   /* If acquiring to write, don't accept a Volume in read list */
+   if (dcr->is_writing() && is_read_volume(dcr->jcr, VolumeName)) {
+      Mmsg1(jcr->errmsg, _("Could not reserve volume \"%s\" for append, because it will be read.\n"),
+         dev->VolHdr.VolumeName);
+      return NULL;
+   }
+
+   /*
     * We lock the reservations system here to ensure
     *  when adding a new volume that no newly scheduled
     *  job can reserve it.
     */
    lock_volumes();
    debug_list_volumes("begin reserve_volume");
-   /* 
+   /*
     * First, remove any old volume attached to this device as it
     *  is no longer used.
     */
@@ -369,20 +408,23 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName)
        *  is not being used and is marked as not reserved.
        */
       if (strcmp(vol->vol_name, VolumeName) == 0) {
-         Dmsg2(dbglvl, "=== set reserved vol=%s dev=%s\n", VolumeName,
-               vol->dev->print_name());
+         Dmsg3(dbglvl, "set reserved vol=%s slot=%d dev=%s\n", VolumeName,
+               vol->get_slot(), vol->dev->print_name());
          goto get_out;                  /* Volume already on this device */
       } else {
          /* Don't release a volume if it was reserved by someone other than us */
-         if (vol->is_in_use() && !dcr->reserved_volume) { 
-            Dmsg1(dbglvl, "Cannot free vol=%s. It is reserved.\n", vol->vol_name);
+         if (vol->is_in_use() && !dcr->reserved_volume) {
+            Dmsg2(dbglvl, "Set wait(). Cannot free vol=%s for %s. It is reserved.\n", vol->vol_name, VolumeName);
+            Mmsg1(dcr->jcr->errmsg, _("Cannot free Volume \"%s\", because it is reserved by someone else.\n"),
+               vol->vol_name);
+            dev->set_wait();
             vol = NULL;                  /* vol in use */
             goto get_out;
          }
          Dmsg2(dbglvl, "reserve_vol free vol=%s at %p\n", vol->vol_name, vol->vol_name);
          /* If old Volume is still mounted, must unload it */
          if (strcmp(vol->vol_name, dev->VolHdr.VolumeName) == 0) {
-            Dmsg0(50, "set_unload\n");
+            Dmsg2(50, "set_unload vol=%s slot=%d\n", vol->vol_name, vol->get_slot());
             dev->set_unload();          /* have to unload current volume */
          }
          free_volume(dev);              /* Release old volume entry */
@@ -394,21 +436,40 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName)
    nvol = new_vol_item(dcr, VolumeName);
 
    /*
-    * Now try to insert the new Volume
+    * Handle request for read volume for file
+    *  device, for which we assume we can open multiple
+    *  devices to read the Volume.
+    *
+    * Note: when doing multiple simultaneous reads
+    *  of the same volume, the volume names are not
+    *  inserted into the write volume list.
+    */
+   if (dcr->is_reading() && dev->is_file()) {
+      nvol->set_jobid(dcr->jcr->JobId);
+      nvol->set_reading();
+      vol = nvol;
+      dev->vol = vol;
+      goto get_out;
+   } else {
+      vol = (VOLRES *)vol_list->binary_insert(nvol, name_compare);
+   }
+
+   /*
+    * This part handles any write volumes or read volumes that
+    *  cannot be simultaneously on multiple devices.
     */
-   vol = (VOLRES *)vol_list->binary_insert(nvol, my_compare);
    if (vol != nvol) {
-      Dmsg2(dbglvl, "Found vol=%s dev-same=%d\n", vol->vol_name, dev==vol->dev);
       /*
        * At this point, a Volume with this name already is in the list,
        *   so we simply release our new Volume entry. Note, this should
        *   only happen if we are moving the volume from one drive to another.
        */
-      Dmsg2(dbglvl, "reserve_vol free-tmp vol=%s at %p\n", 
+      Dmsg2(dbglvl, "Found vol=%s dev-same=%d\n", vol->vol_name, dev==vol->dev);
+      Dmsg2(dbglvl, "reserve_vol free-tmp vol=%s at %p\n",
             vol->vol_name, vol->vol_name);
       /*
-       * Clear dev pointer so that free_vol_item() doesn't 
-       *  take away our volume. 
+       * Clear dev pointer so that free_vol_item() doesn't
+       *  take away our volume.
        */
       nvol->dev = NULL;                  /* don't zap dev entry */
       free_vol_item(nvol);
@@ -416,7 +477,7 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName)
       if (vol->dev) {
          Dmsg2(dbglvl, "dev=%s vol->dev=%s\n", dev->print_name(), vol->dev->print_name());
       }
-         
+
       /*
        * Check if we are trying to use the Volume on a different drive
        *  dev      is our device
@@ -426,10 +487,11 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName)
          /* Caller wants to switch Volume to another device */
          if (!vol->dev->is_busy() && !vol->is_swapping()) {
             int32_t slot;
-            Dmsg3(dbglvl, "==== Swap vol=%s from dev=%s to %s\n", 
+            Dmsg3(dbglvl, "==== Swap vol=%s from dev=%s to %s\n",
                VolumeName, vol->dev->print_name(), dev->print_name());
             free_volume(dev);            /* free any volume attached to our drive */
-            Dmsg1(50, "set_unload dev=%s\n", dev->print_name());
+            Dmsg3(50, "set_unload vol=%s slot=%d dev=%s\n", vol->vol_name,
+               vol->get_slot(), dev->print_name());
             dev->set_unload();           /* Unload any volume that is on our drive */
             dcr->set_dev(vol->dev);      /* temp point to other dev */
             slot = get_autochanger_loaded_slot(dcr);  /* get slot on other drive */
@@ -443,19 +505,30 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName)
             vol->dev = dev;              /* point the Volume at our drive */
             dev->vol = vol;              /* point our drive at the Volume */
          } else {
-            Jmsg8(jcr, M_WARNING, 0, "Need volume for %s from other drive, "
-               "but swap not possible. Status: read=%d num_writers=%d "
-               "num_reserve=%d swap=%d vol=%s from dev=%s to %s\n", 
-               dcr->is_write_acquire()?"write":"read",
-               vol->dev->can_read(), vol->dev->num_writers,
-               vol->dev->num_reserved(), vol->is_swapping(),
-               VolumeName, vol->dev->print_name(), dev->print_name());
-            if (vol->is_swapping() && dev->swap_dev) {
-               Dmsg3(dbglvl, "Swap failed vol=%s from=%s to dev=%s\n", 
-                 vol->vol_name, dev->swap_dev->print_name(), dev->print_name());
+            if (dev) {
+               Jmsg8(jcr, M_WARNING, 0, "Need volume for %s from other drive, "
+                  "but swap not possible. Status: reader=%d writers=%d "
+                  "reserves=%d swap=%d vol=%s from dev=%s to %s\n",
+                  dcr->is_writing()?"write":"read",
+                  vol->dev->can_read(), vol->dev->num_writers,
+                  vol->dev->num_reserved(), vol->is_swapping(),
+                  VolumeName, vol->dev->print_name(), dev->print_name());
+            }
+            if (vol->is_swapping()) {
+               DEVICE *swapdev = dev->swap_dev;
+               if (vol && dev && swapdev) {
+                  Mmsg3(jcr->errmsg, _("Volume %s is busy swapping from %s to %s\n"),
+                     NPRT(vol->vol_name), dev->print_name(), swapdev->print_name());
+               } else {
+                  Mmsg1(jcr->errmsg, _("Volume %s is busy swapping.\n"),
+                     NPRT(vol->vol_name));
+               }
+            } else if (vol->dev) {
+               Mmsg2(jcr->errmsg, _("%s device %s is busy.\n"),
+                  vol->dev->print_type(), vol->dev->print_name());
             } else {
-               Dmsg3(dbglvl, "Swap failed vol=%s from=%p to dev=%s\n", 
-                  vol->vol_name, dev->swap_dev, dev->print_name());
+               Mmsg1(jcr->errmsg, _("Volume %s is busy swapping.\n"),
+                  NPRT(vol->vol_name));
             }
             debug_list_volumes("failed swap");
             vol = NULL;                  /* device busy */
@@ -470,7 +543,7 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName)
 
 get_out:
    if (vol) {
-      Dmsg2(dbglvl, "=== set in_use. vol=%s dev=%s\n", vol->vol_name,
+      Dmsg2(dbglvl, "set in_use. vol=%s dev=%s\n", vol->vol_name,
             vol->dev->print_name());
       vol->set_in_use();
       dcr->reserved_volume = true;
@@ -481,13 +554,78 @@ get_out:
    return vol;
 }
 
+/*
+ * Start walk of vol chain
+ * The proper way to walk the vol chain is:
+ *    VOLRES *vol;
+ *    foreach_vol(vol) {
+ *      ...
+ *    }
+ *    endeach_vol(vol);
+ *
+ *  It is possible to leave out the endeach_vol(vol), but
+ *   in that case, the last vol referenced must be explicitly
+ *   released with:
+ *
+ *    free_vol_item(vol);
+ *
+ */
+VOLRES *vol_walk_start()
+{
+   VOLRES *vol;
+   lock_volumes();
+   vol = (VOLRES *)vol_list->first();
+   if (vol) {
+      vol->inc_use_count();
+      Dmsg2(dbglvl, "Inc walk_start use_count=%d volname=%s\n",
+            vol->use_count(), vol->vol_name);
+   }
+   unlock_volumes();
+   return vol;
+}
+
+/*
+ * Get next vol from chain, and release current one
+ */
+VOLRES *vol_walk_next(VOLRES *prev_vol)
+{
+   VOLRES *vol;
+
+   lock_volumes();
+   vol = (VOLRES *)vol_list->next(prev_vol);
+   if (vol) {
+      vol->inc_use_count();
+      Dmsg2(dbglvl, "Inc walk_next use_count=%d volname=%s\n",
+            vol->use_count(), vol->vol_name);
+   }
+   if (prev_vol) {
+      free_vol_item(prev_vol);
+   }
+   unlock_volumes();
+   return vol;
+}
+
+/*
+ * Release last vol referenced
+ */
+void vol_walk_end(VOLRES *vol)
+{
+   if (vol) {
+      lock_volumes();
+      Dmsg2(dbglvl, "Free walk_end use_count=%d volname=%s\n",
+            vol->use_count(), vol->vol_name);
+      free_vol_item(vol);
+      unlock_volumes();
+   }
+}
+
 /*
  * Search for a Volume name in the Volume list.
  *
  *  Returns: VOLRES entry on success
  *           NULL if the Volume is not in the list
  */
-VOLRES *find_volume(const char *VolumeName) 
+static VOLRES *find_volume(const char *VolumeName)
 {
    VOLRES vol, *fvol;
 
@@ -497,7 +635,7 @@ VOLRES *find_volume(const char *VolumeName)
    /* Do not lock reservations here */
    lock_volumes();
    vol.vol_name = bstrdup(VolumeName);
-   fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare);
+   fvol = (VOLRES *)vol_list->binary_search(&vol, name_compare);
    free(vol.vol_name);
    Dmsg2(dbglvl, "find_vol=%s found=%d\n", VolumeName, fvol!=NULL);
    debug_list_volumes("find_volume");
@@ -511,7 +649,7 @@ VOLRES *find_volume(const char *VolumeName)
  *  Returns: VOLRES entry on success
  *           NULL if the Volume is not in the list
  */
-static VOLRES *find_read_volume(const char *VolumeName) 
+static VOLRES *find_read_volume(const char *VolumeName)
 {
    VOLRES vol, *fvol;
 
@@ -522,8 +660,8 @@ static VOLRES *find_read_volume(const char *VolumeName)
    /* Do not lock reservations here */
    lock_read_volumes();
    vol.vol_name = bstrdup(VolumeName);
-   /* Note, we do want a simple my_compare on volume name only here */
-   fvol = (VOLRES *)read_vol_list->binary_search(&vol, my_compare);
+   /* Note, we do want a simple name_compare on volume name only here */
+   fvol = (VOLRES *)read_vol_list->binary_search(&vol, name_compare);
    free(vol.vol_name);
    Dmsg2(dbglvl, "find_read_vol=%s found=%d\n", VolumeName, fvol!=NULL);
    unlock_read_volumes();
@@ -531,7 +669,7 @@ static VOLRES *find_read_volume(const char *VolumeName)
 }
 
 
-/*  
+/*
  * Free a Volume from the Volume list if it is no longer used
  *   Note, for tape drives we want to remember where the Volume
  *   was when last used, so rather than free the volume entry,
@@ -551,7 +689,8 @@ bool volume_unused(DCR *dcr)
       return false;
    }
 
-   Dmsg1(dbglvl, "=== clear in_use vol=%s\n", dev->vol->vol_name);
+   Dmsg2(dbglvl, "Clear in_use vol=%s slot=%d\n", dev->vol->vol_name,
+         dev->vol->get_slot());
    dev->vol->clear_in_use();
 
    if (dev->vol->is_swapping()) {
@@ -560,19 +699,20 @@ bool volume_unused(DCR *dcr)
       return false;
    }
 
-   /*  
+   /*
     * If this is a tape, we do not free the volume, rather we wait
     *  until the autoloader unloads it, or until another tape is
     *  explicitly read in this drive. This allows the SD to remember
     *  where the tapes are or last were.
     */
-   Dmsg4(dbglvl, "=== set not reserved vol=%s num_writers=%d dev_reserved=%d dev=%s\n",
-      dev->vol->vol_name, dev->num_writers, dev->num_reserved(), dev->print_name());
+   Dmsg5(dbglvl, "set not reserved vol=%s slot=%d writers=%d reserves=%d dev=%s\n",
+      dev->vol->vol_name, dev->vol->get_slot(), dev->num_writers, 
+      dev->num_reserved(), dev->print_name());
    if (dev->is_tape() || dev->is_autochanger()) {
       return true;
    } else {
       /*
-       * Note, this frees the volume reservation entry, but the 
+       * Note, this frees the volume reservation entry, but the
        *   file descriptor remains open with the OS.
        */
       return free_volume(dev);
@@ -581,6 +721,8 @@ bool volume_unused(DCR *dcr)
 
 /*
  * Unconditionally release the volume entry
+ * Note: read volumes are not in the list, so
+ *   do not attempt to remove them.
  */
 bool free_volume(DEVICE *dev)
 {
@@ -595,21 +737,23 @@ bool free_volume(DEVICE *dev)
    }
    /* Don't free a volume while it is being swapped */
    if (!vol->is_swapping()) {
-      Dmsg1(dbglvl, "=== clear in_use vol=%s\n", vol->vol_name);
+      Dmsg2(dbglvl, "Clear in_use vol=%s slot=%d\n", vol->vol_name, vol->get_slot());
       dev->vol = NULL;
-      vol_list->remove(vol);
-      Dmsg2(dbglvl, "=== remove volume %s dev=%s\n", vol->vol_name, dev->print_name());
+      if (vol->is_writing()) {
+         vol_list->remove(vol);
+      }
+      Dmsg3(dbglvl, "Remove volume %s slot=%d dev=%s\n", vol->vol_name, 
+         vol->get_slot(), dev->print_name());
       free_vol_item(vol);
       debug_list_volumes("free_volume");
    } else {
-      Dmsg1(dbglvl, "=== cannot clear swapping vol=%s\n", vol->vol_name);
+      Dmsg1(dbglvl, "=== Cannot clear. Swapping vol=%s\n", vol->vol_name);
    }
    unlock_volumes();
-// pthread_cond_broadcast(&wait_next_vol);
    return true;
 }
 
-      
+
 /* Create the Volume list */
 void create_volume_lists()
 {
@@ -638,6 +782,7 @@ static void free_volume_list()
          }
          free(vol->vol_name);
          vol->vol_name = NULL;
+         vol->destroy_mutex();
       }
       delete vol_list;
       vol_list = NULL;
@@ -662,6 +807,7 @@ void free_volume_lists()
          }
          free(vol->vol_name);
          vol->vol_name = NULL;
+         vol->destroy_mutex();
       }
       delete read_vol_list;
       read_vol_list = NULL;
@@ -669,8 +815,9 @@ void free_volume_lists()
    }
 }
 
-/* 
- * Determine if caller can write on volume
+/*
+ * Determine if caller can write on volume.
+ *  If not, return reason in jcr->errmsg
  */
 bool DCR::can_i_write_volume()
 {
@@ -678,6 +825,7 @@ bool DCR::can_i_write_volume()
 
    vol = find_read_volume(VolumeName);
    if (vol) {
+      Mmsg(jcr->errmsg, "Found in read list; cannot write vol=%s\n", VolumeName);
       Dmsg1(100, "Found in read list; cannot write vol=%s\n", VolumeName);
       return false;
    }
@@ -685,7 +833,8 @@ bool DCR::can_i_write_volume()
 }
 
 /*
- * Determine if caller can read or write volume
+ * Determine if caller can read or write volume.
+ *  If not, return reason in jcr->errmsg
  */
 bool DCR::can_i_use_volume()
 {
@@ -693,6 +842,7 @@ bool DCR::can_i_use_volume()
    VOLRES *vol;
 
    if (job_canceled(jcr)) {
+      Mmsg(jcr->errmsg, "Job is canceled\n");
       return false;
    }
    lock_volumes();
@@ -701,7 +851,7 @@ bool DCR::can_i_use_volume()
       Dmsg1(dbglvl, "Vol=%s not in use.\n", VolumeName);
       goto get_out;                   /* vol not in list */
    }
-   ASSERT(vol->dev != NULL);
+   ASSERT2(vol->dev != NULL, "No device in can_i_use_volume!");
 
    if (dev == vol->dev) {        /* same device OK */
       Dmsg1(dbglvl, "Vol=%s on same dev.\n", VolumeName);
@@ -717,7 +867,8 @@ bool DCR::can_i_use_volume()
    } else {
       Dmsg2(dbglvl, "Vol=%s dev=%s busy.\n", VolumeName, vol->dev->print_name());
    }
-   Dmsg2(dbglvl, "Vol=%s in use by %s.\n", VolumeName, vol->dev->print_name());
+   Mmsg(jcr->errmsg, "Volume=%s in use on another device %s.\n", VolumeName, vol->dev->print_name());
+   Dmsg2(dbglvl, "Volume=%s in use on another device %s.\n", VolumeName, vol->dev->print_name());
    rtn = false;
 
 get_out:
@@ -726,13 +877,13 @@ get_out:
 
 }
 
-/*  
+/*
  * Create a temporary copy of the volume list.  We do this,
  *   to avoid having the volume list locked during the
  *   call to reserve_device(), which would cause a deadlock.
  * Note, we may want to add an update counter on the vol_list
  *   so that if it is modified while we are traversing the copy
- *   we can take note and act accordingly (probably redo the 
+ *   we can take note and act accordingly (probably redo the
  *   search at least a few times).
  */
 dlist *dup_vol_list(JCR *jcr)
@@ -740,18 +891,17 @@ dlist *dup_vol_list(JCR *jcr)
    dlist *temp_vol_list;
    VOLRES *vol = NULL;
 
-   lock_volumes();
-   Dmsg0(dbglvl, "lock volumes\n");                           
+   Dmsg0(dbglvl, "lock volumes\n");
 
    Dmsg0(dbglvl, "duplicate vol list\n");
    temp_vol_list = New(dlist(vol, &vol->link));
-   foreach_dlist(vol, vol_list) {
+   foreach_vol(vol) {
       VOLRES *nvol;
       VOLRES *tvol = (VOLRES *)malloc(sizeof(VOLRES));
       memset(tvol, 0, sizeof(VOLRES));
       tvol->vol_name = bstrdup(vol->vol_name);
       tvol->dev = vol->dev;
-      nvol = (VOLRES *)temp_vol_list->binary_insert(tvol, my_compare);
+      nvol = (VOLRES *)temp_vol_list->binary_insert(tvol, name_compare);
       if (tvol != nvol) {
          tvol->dev = NULL;                   /* don't zap dev entry */
          free_vol_item(tvol);
@@ -759,8 +909,8 @@ dlist *dup_vol_list(JCR *jcr)
          Jmsg(jcr, M_WARNING, 0, "Logic error. Duplicating vol list hit duplicate.\n");
       }
    }
+   endeach_vol(vol);
    Dmsg0(dbglvl, "unlock volumes\n");
-   unlock_volumes();
    return temp_vol_list;
 }
 
@@ -770,7 +920,7 @@ dlist *dup_vol_list(JCR *jcr)
 void free_temp_vol_list(dlist *temp_vol_list)
 {
    dlist *save_vol_list;
-   
+
    lock_volumes();
    save_vol_list = vol_list;
    vol_list = temp_vol_list;