]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/stored/reserve.c
kes Implement algorithm to handle only one appendable volume with
[bacula/bacula] / bacula / src / stored / reserve.c
index 362eccac70fcde422a4a69fec4f8430f305a107a..3fb60b4340e81299579d7ebd4470078d0af20ef6 100644 (file)
@@ -1,3 +1,30 @@
+/*
+   Bacula® - The Network Backup Solution
+
+   Copyright (C) 2000-2007 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 two of the GNU General Public
+   License as published by the Free Software Foundation plus additions
+   that are listed 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 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 John Walker.
+   The licensor of Bacula is the Free Software Foundation Europe
+   (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
+   Switzerland, email:ftf@fsfeurope.org.
+*/
 /*
  *   Drive reservation functions for Storage Daemon
  *
  *   Version $Id$
  *
  */
-/*
-   Copyright (C) 2000-2006 Kern Sibbald
-
-   This program is free software; you can redistribute it and/or
-   modify it under the terms of the GNU General Public License
-   version 2 as amended with additional clauses defined in the
-   file LICENSE in the main source directory.
-
-   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 
-   the file LICENSE for additional details.
-
- */
 
 #include "bacula.h"
 #include "stored.h"
 
+const int dbglvl =  50;
 
 static dlist *vol_list = NULL;
-static pthread_mutex_t vol_list_lock = PTHREAD_MUTEX_INITIALIZER;
-static pthread_mutex_t search_lock = PTHREAD_MUTEX_INITIALIZER;
+static brwlock_t reservation_lock;
+static brwlock_t vol_list_lock;
 
 /* Forward referenced functions */
 static int can_reserve_drive(DCR *dcr, RCTX &rctx);
-static int search_res_for_device(RCTX &rctx);
 static int reserve_device(RCTX &rctx);
 static bool reserve_device_for_read(DCR *dcr);
 static bool reserve_device_for_append(DCR *dcr, RCTX &rctx);
 static bool use_storage_cmd(JCR *jcr);
 static void queue_reserve_message(JCR *jcr);
-static void release_msgs(JCR *jcr);
 
 /* Requests from the Director daemon */
 static char use_storage[]  = "use storage=%127s media_type=%127s "
@@ -70,48 +82,303 @@ static int my_compare(void *item1, void *item2)
 }
 
 
+void init_reservations_lock()
+{
+   int errstat;
+   if ((errstat=rwl_init(&reservation_lock)) != 0) {
+      berrno be;
+      Emsg1(M_ABORT, 0, _("Unable to initialize reservation lock. ERR=%s\n"),
+            be.bstrerror(errstat));
+   }
+
+   if ((errstat=rwl_init(&vol_list_lock)) != 0) {
+      berrno be;
+      Emsg1(M_ABORT, 0, _("Unable to initialize volume list lock. ERR=%s\n"),
+            be.bstrerror(errstat));
+   }
+}
+
+void term_reservations_lock()
+{
+   rwl_destroy(&reservation_lock);
+   rwl_destroy(&vol_list_lock);
+}
+
+int reservations_lock_count = 0;
+
+/* This applies to a drive and to Volumes */
+void _lock_reservations()
+{
+   int errstat;
+   reservations_lock_count++;
+   if ((errstat=rwl_writelock(&reservation_lock)) != 0) {
+      berrno be;
+      Emsg2(M_ABORT, 0, "rwl_writelock failure. stat=%d: ERR=%s\n",
+           errstat, be.bstrerror(errstat));
+   }
+}
+
+void _unlock_reservations()
+{
+   int errstat;
+   reservations_lock_count--;
+   if ((errstat=rwl_writeunlock(&reservation_lock)) != 0) {
+      berrno be;
+      Emsg2(M_ABORT, 0, "rwl_writeunlock failure. stat=%d: ERR=%s\n",
+           errstat, be.bstrerror(errstat));
+   }
+}
+
+int vol_list_lock_count = 0;
+
+void _lock_volumes()
+{
+   int errstat;
+   vol_list_lock_count++;
+   if ((errstat=rwl_writelock(&vol_list_lock)) != 0) {
+      berrno be;
+      Emsg2(M_ABORT, 0, "rwl_writelock failure. stat=%d: ERR=%s\n",
+           errstat, be.bstrerror(errstat));
+   }
+}
+
+void _unlock_volumes()
+{
+   int errstat;
+   vol_list_lock_count--;
+   if ((errstat=rwl_writeunlock(&vol_list_lock)) != 0) {
+      berrno be;
+      Emsg2(M_ABORT, 0, "rwl_writeunlock failure. stat=%d: ERR=%s\n",
+           errstat, be.bstrerror(errstat));
+   }
+}
+
+
+/*
+ * List Volumes -- this should be moved to status.c
+ */
+enum {
+   debug_lock = true,
+   debug_nolock = false
+};
+
+static void debug_list_volumes(const char *imsg)
+{
+   VOLRES *vol;
+   POOL_MEM msg(PM_MESSAGE);
+
+   lock_volumes();
+   foreach_dlist(vol, vol_list) {
+      if (vol->dev) {
+         Mmsg(msg, "List from %s: %s at %p on device %s\n", imsg, 
+              vol->vol_name, vol->vol_name, vol->dev->print_name());
+      } else {
+         Mmsg(msg, "List from %s: %s at %p no dev\n", imsg, vol->vol_name, vol->vol_name);
+      }
+      Dmsg1(dbglvl, "%s", msg.c_str());
+   }
+
+#ifdef xxx
+   DEVICE *dev = NULL;
+   foreach_dlist(vol, vol_list) {
+      if (vol->dev == dev) {
+         Dmsg0(000, "Two Volumes on same device.\n");
+         ASSERT(0);
+         dev = vol->dev;
+      }
+   }
+#endif
+
+// Dmsg2(dbglvl, "List from %s: %d volumes\n", imsg, count);
+   unlock_volumes();
+}
+
+
+/*
+ * List Volumes -- this should be moved to status.c
+ */
+void list_volumes(void sendit(const char *msg, int len, void *sarg), void *arg)
+{
+   VOLRES *vol;
+   POOL_MEM msg(PM_MESSAGE);
+   int len;
+
+   lock_volumes();
+   foreach_dlist(vol, vol_list) {
+      if (vol->dev) {
+         len = Mmsg(msg, "%s on device %s\n", vol->vol_name, vol->dev->print_name());
+         sendit(msg.c_str(), len, arg);
+      } else {
+         len = Mmsg(msg, "%s no dev\n", vol->vol_name);
+         sendit(msg.c_str(), len, arg);
+      }
+   }
+   unlock_volumes();
+}
+
+/*
+ * Create a Volume item to put in the Volume list
+ *   Ensure that the device points to it.
+ */
+static VOLRES *new_vol_item(DCR *dcr, const char *VolumeName)
+{
+   VOLRES *vol;
+   vol = (VOLRES *)malloc(sizeof(VOLRES));
+   memset(vol, 0, sizeof(VOLRES));
+   vol->vol_name = bstrdup(VolumeName);
+   vol->dev = dcr->dev;
+   Dmsg4(dbglvl, "JobId=%u new Vol=%s at %p dev=%s\n", (int)dcr->jcr->JobId,
+         VolumeName, vol->vol_name, vol->dev->print_name());
+   return vol;
+}
+
+static void free_vol_item(VOLRES *vol)
+{
+   free(vol->vol_name);
+   if (vol->dev) {
+      vol->dev->vol = NULL;
+   }
+   free(vol);
+}
+
+
 /*
  * Put a new Volume entry in the Volume list. This
  *  effectively reserves the volume so that it will
  *  not be mounted again.
  *
+ * 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" 
+ *       the volume (reserved, 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.  
+ *
+ *  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
+ *       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 
+ *      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 
+ *  counts are always very tricky.
+ *
+ *  The old code had a concept of "reserving" a Volume, but it needs to be 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 has the job (dcr) owning the volume (more or less).  The job is 
+ *  to change the insertion and removal of the volumes from the list to be based 
+ *  on the drive rather than the job.  
+ *
  *  Return: VOLRES entry on success
- *          NULL if the Volume is already in the list
+ *          NULL volume busy on another drive
  */
-VOLRES *new_volume(DCR *dcr, const char *VolumeName)
+VOLRES *reserve_volume(DCR *dcr, const char *VolumeName)
 {
    VOLRES *vol, *nvol;
+   DEVICE *dev = dcr->dev;
 
-   Dmsg1(400, "new_volume %s\n", VolumeName);
-   P(vol_list_lock);
-   if (dcr->dev) {
-again:
-      foreach_dlist(vol, vol_list) {
-         if (vol && vol->dev == dcr->dev) {
-            vol_list->remove(vol);
-            if (vol->vol_name) {
-               free(vol->vol_name);
-            }
-            free(vol);
-            goto again;
-         }
+   ASSERT(dev != NULL);
+
+   Dmsg1(dbglvl, "reserve_volume %s\n", VolumeName);
+   /* 
+    * 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.
+    */
+   if (dev->vol) {
+      vol = dev->vol;
+      /*
+       * Make sure we don't remove the current volume we are inserting
+       *  because it was probably inserted by another job.
+       */
+      if (strcmp(vol->vol_name, VolumeName) == 0) {
+         goto get_out;                  /* Volume already on this device */
+      } else {
+         Dmsg3(dbglvl, "reserve_vol free vol=%s at %p JobId=%u\n", vol->vol_name,
+               vol->vol_name, (int)dcr->jcr->JobId);
+         debug_list_volumes("reserve_vol free");
+         vol_list->remove(vol);
+         free_vol_item(vol);
       }
    }
-   vol = (VOLRES *)malloc(sizeof(VOLRES));
-   memset(vol, 0, sizeof(VOLRES));
-   vol->vol_name = bstrdup(VolumeName);
-   vol->dev = dcr->dev;
-   vol->dcr = dcr;
-   nvol = (VOLRES *)vol_list->binary_insert(vol, my_compare);
-   if (nvol != vol) {
-      free(vol->vol_name);
-      free(vol);
-      vol = NULL;
-      if (dcr->dev) {
-         nvol->dev = dcr->dev;
+
+   /* Create a new Volume entry */
+   nvol = new_vol_item(dcr, VolumeName);
+
+   /*
+    * Now try to insert the new Volume
+    */
+   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.
+       */
+      Dmsg3(dbglvl, "reserve_vol free-tmp vol=%s at %p JobId=%u\n", vol->vol_name,
+            vol->vol_name, (int)dcr->jcr->JobId);
+      /*
+       * 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);
+
+      /* Check if we are trying to use the Volume on a different drive */
+      if (dev != vol->dev) {
+         /* Caller wants to switch Volume to another device */
+         if (!vol->dev->is_busy()) {
+            /* OK to move it -- I'm not sure this will work */
+            Dmsg3(dbglvl, "==== Swap vol=%s from dev=%s to %s\n", VolumeName,
+               vol->dev->print_name(), dev->print_name());
+            vol->dev->vol = NULL;         /* take vol from old drive */
+            vol->dev->VolHdr.VolumeName[0] = 0;
+            vol->dev = dev;               /* point vol at new drive */
+            dev->vol = vol;               /* point dev at vol */
+            dev->VolHdr.VolumeName[0] = 0;
+         } else {
+            Dmsg3(dbglvl, "Volume busy could not swap vol=%s from dev=%s to %s\n", VolumeName,
+               vol->dev->print_name(), dev->print_name());
+            vol = NULL;                /* device busy */
+         }
       }
    }
-   V(vol_list_lock);
+   dev->vol = vol;
+
+get_out:
+   debug_list_volumes("end new volume");
+   unlock_volumes();
    return vol;
 }
 
@@ -121,99 +388,101 @@ again:
  *  Returns: VOLRES entry on success
  *           NULL if the Volume is not in the list
  */
-VOLRES *find_volume(const char *VolumeName)
+VOLRES *find_volume(DCR *dcr)
 {
    VOLRES vol, *fvol;
-   P(vol_list_lock);
-   vol.vol_name = bstrdup(VolumeName);
+   /* Do not lock reservations here */
+   lock_volumes();
+   vol.vol_name = bstrdup(dcr->VolumeName);
    fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare);
    free(vol.vol_name);
-   V(vol_list_lock);
+   Dmsg2(dbglvl, "find_vol=%s found=%d\n", dcr->VolumeName, fvol!=NULL);
+   debug_list_volumes("find_volume");
+   unlock_volumes();
    return fvol;
 }
 
+/* 
+ * Remove any reservation from a drive and tell the system
+ *  that the volume is unused at least by us.
+ */
+void unreserve_device(DCR *dcr)
+{
+   DEVICE *dev = dcr->dev;
+   dev->dlock();
+   if (dcr->reserved_device) {
+      dcr->reserved_device = false;
+      dev->reserved_device--;
+      Dmsg2(dbglvl, "Dec reserve=%d dev=%s\n", dev->reserved_device, dev->print_name());
+      dcr->reserved_device = false;
+      /* If we set read mode in reserving, remove it */
+      if (dev->can_read()) {
+         dev->clear_read();
+      }
+      if (dev->num_writers < 0) {
+         Jmsg1(dcr->jcr, M_ERROR, 0, _("Hey! num_writers=%d!!!!\n"), dev->num_writers);
+         dev->num_writers = 0;
+      }
+   }
+
+   volume_unused(dcr);
+   dev->dunlock();
+}
+
 /*  
- * Free a Volume from the Volume list
+ * Free a Volume from the Volume list if it is no longer used
  *
  *  Returns: true if the Volume found and removed from the list
- *           false if the Volume is not in the list
+ *           false if the Volume is not in the list or is in use
  */
-bool free_volume(DEVICE *dev)
+bool volume_unused(DCR *dcr)
 {
-   VOLRES vol, *fvol;
+   DEVICE *dev = dcr->dev;
 
-  P(vol_list_lock);
-   if (dev->VolHdr.VolumeName[0] == 0) {
-      /*
-       * Our device has no VolumeName listed, but
-       *  search the list for any Volume attached to
-       *  this device and remove it.
-       */
-      foreach_dlist(fvol, vol_list) {
-         if (fvol && fvol->dev == dev) {
-            vol_list->remove(fvol);
-            if (fvol->vol_name) {
-               free(fvol->vol_name);
-            }
-            free(fvol);
-            break;
-         }
-      }
-      goto bail_out;
-   }
-   Dmsg1(400, "free_volume %s\n", dev->VolHdr.VolumeName);
-   vol.vol_name = bstrdup(dev->VolHdr.VolumeName);
-   fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare);
-   if (fvol) {
-      vol_list->remove(fvol);
-      free(fvol->vol_name);
-      free(fvol);
+   if (dev->vol == NULL) {
+      Dmsg2(dbglvl, "JobId=%u vol_unused: no vol on %s\n", (int)dcr->jcr->JobId, dev->print_name());
+      debug_list_volumes("null vol cannot unreserve_volume");
+      return false;
    }
-   free(vol.vol_name);
-   dev->VolHdr.VolumeName[0] = 0;
-bail_out:
-   V(vol_list_lock);
-   return fvol != NULL;
-}
 
-/* Free volume reserved by this dcr but not attached to a dev */
-void free_unused_volume(DCR *dcr)
-{
-   VOLRES *vol;
-   P(vol_list_lock);
-   for (vol=(VOLRES *)vol_list->first(); vol; vol=(VOLRES *)vol_list->next(vol)) {
-      if (vol->dcr == dcr && (vol->dev == NULL || 
-          strcmp(vol->vol_name, vol->dev->VolHdr.VolumeName) != 0)) {
-         vol_list->remove(vol);
-         free(vol->vol_name);
-         free(vol);
-         break;
-      }
+   if (dev->is_busy()) {
+      Dmsg2(dbglvl, "JobId=%u vol_unused: no vol on %s\n", (int)dcr->jcr->JobId, dev->print_name());
+      debug_list_volumes("dev busy cannot unreserve_volume");
+      return false;
    }
-   V(vol_list_lock);
+
+   return free_volume(dev);
 }
 
 /*
- * List Volumes -- this should be moved to status.c
+ * Unconditionally release the volume
  */
-void list_volumes(BSOCK *user)  
+bool free_volume(DEVICE *dev)
 {
    VOLRES *vol;
-   for (vol=(VOLRES *)vol_list->first(); vol; vol=(VOLRES *)vol_list->next(vol)) {
-      if (vol->dev) {
-         bnet_fsend(user, "%s on device %s\n", vol->vol_name, vol->dev->print_name());
-      } else {
-         bnet_fsend(user, "%s\n", vol->vol_name);
-      }
+
+   if (dev->vol == NULL) {
+      Dmsg1(dbglvl, "No vol on dev %s\n", dev->print_name());
+      return false;
    }
+   lock_volumes();
+   vol = dev->vol;
+   dev->vol = NULL;
+   vol_list->remove(vol);
+   Dmsg2(dbglvl, "free_volume %s dev=%s\n", vol->vol_name, dev->print_name());
+   free_vol_item(vol);
+   debug_list_volumes("free_volume");
+   unlock_volumes();
+   return vol != NULL;
 }
+
       
 /* Create the Volume list */
-void init_volume_list()
+void create_volume_list()
 {
-   VOLRES *dummy = NULL;
+   VOLRES *vol = NULL;
    if (vol_list == NULL) {
-      vol_list = New(dlist(dummy, &dummy->link));
+      vol_list = New(dlist(vol, &vol->link));
    }
 }
 
@@ -224,29 +493,40 @@ void free_volume_list()
    if (!vol_list) {
       return;
    }
-   for (vol=(VOLRES *)vol_list->first(); vol; vol=(VOLRES *)vol_list->next(vol)) {
-      Dmsg3(000, "Unreleased Volume=%s dcr=0x%x dev=0x%x\n", vol->vol_name,
-         vol->dcr, vol->dev);
+   lock_volumes();
+   foreach_dlist(vol, vol_list) {
+      Dmsg2(dbglvl, "Unreleased Volume=%s dev=%p\n", vol->vol_name, vol->dev);
+      free(vol->vol_name);
+      vol->vol_name = NULL;
    }
    delete vol_list;
    vol_list = NULL;
+   unlock_volumes();
 }
 
 bool is_volume_in_use(DCR *dcr)
 {
-   VOLRES *vol = find_volume(dcr->VolumeName);
+   VOLRES *vol = find_volume(dcr);
    if (!vol) {
+      Dmsg1(dbglvl, "Vol=%s not in use.\n", dcr->VolumeName);
       return false;                   /* vol not in list */
    }
-   if (!vol->dev) {                   /* vol not attached to device */
-      return false;
-   }
+   ASSERT(vol->dev != NULL);
+
    if (dcr->dev == vol->dev) {        /* same device OK */
+      Dmsg1(dbglvl, "Vol=%s on same dev.\n", dcr->VolumeName);
       return false;
+   } else {
+      Dmsg3(dbglvl, "Vol=%s on %s we have %s\n", dcr->VolumeName,
+            vol->dev->print_name(), dcr->dev->print_name());
    }
    if (!vol->dev->is_busy()) {
+      Dmsg2(dbglvl, "Vol=%s dev=%s not busy.\n", dcr->VolumeName, vol->dev->print_name());
       return false;
+   } else {
+      Dmsg2(dbglvl, "Vol=%s dev=%s busy.\n", dcr->VolumeName, vol->dev->print_name());
    }
+   Dmsg2(dbglvl, "Vol=%s in use by %s.\n", dcr->VolumeName, vol->dev->print_name());
    return true;
 }
 
@@ -273,6 +553,7 @@ static bool use_storage_cmd(JCR *jcr)
    RCTX rctx;
    char *msg;
    alist *msgs;
+   alist *dirstore;
 
    memset(&rctx, 0, sizeof(RCTX));
    rctx.jcr = jcr;
@@ -280,22 +561,28 @@ static bool use_storage_cmd(JCR *jcr)
     * If there are multiple devices, the director sends us
     *   use_device for each device that it wants to use.
     */
-   jcr->dirstore = New(alist(10, not_owned_by_alist));
+   dirstore = New(alist(10, not_owned_by_alist));
    msgs = jcr->reserve_msgs = New(alist(10, not_owned_by_alist));  
    do {
-      Dmsg1(100, "<dird: %s", dir->msg);
+      Dmsg1(dbglvl, "<dird: %s", dir->msg);
       ok = sscanf(dir->msg, use_storage, store_name.c_str(), 
                   media_type.c_str(), pool_name.c_str(), 
                   pool_type.c_str(), &append, &Copy, &Stripe) == 7;
       if (!ok) {
          break;
       }
+      if (append) {
+         jcr->write_store = dirstore;
+      } else {
+         jcr->read_store = dirstore;
+      }
+      rctx.append = append;
       unbash_spaces(store_name);
       unbash_spaces(media_type);
       unbash_spaces(pool_name);
       unbash_spaces(pool_type);
       store = new DIRSTORE;
-      jcr->dirstore->append(store);
+      dirstore->append(store);
       memset(store, 0, sizeof(DIRSTORE));
       store->device = New(alist(10));
       bstrncpy(store->name, store_name, sizeof(store->name));
@@ -305,8 +592,8 @@ static bool use_storage_cmd(JCR *jcr)
       store->append = append;
 
       /* Now get all devices */
-      while (bnet_recv(dir) >= 0) {
-         Dmsg1(100, "<dird device: %s", dir->msg);
+      while (dir->recv() >= 0) {
+         Dmsg1(dbglvl, "<dird device: %s", dir->msg);
          ok = sscanf(dir->msg, use_device, dev_name.c_str()) == 1;
          if (!ok) {
             break;
@@ -314,21 +601,21 @@ static bool use_storage_cmd(JCR *jcr)
          unbash_spaces(dev_name);
          store->device->append(bstrdup(dev_name.c_str()));
       }
-   }  while (ok && bnet_recv(dir) >= 0);
+   }  while (ok && dir->recv() >= 0);
 
-#ifdef DEVELOPER
-   /* This loop is debug code and can be removed */
-   /* ***FIXME**** remove after 1.38 release */
+   /* Developer debug code */
    char *device_name;
-   foreach_alist(store, jcr->dirstore) {
-      Dmsg5(100, "Storage=%s media_type=%s pool=%s pool_type=%s append=%d\n", 
-         store->name, store->media_type, store->pool_name, 
-         store->pool_type, store->append);
-      foreach_alist(device_name, store->device) {
-         Dmsg1(100, "   Device=%s\n", device_name);
+   if (debug_level >= dbglvl) {
+      foreach_alist(store, dirstore) {
+         Dmsg6(dbglvl, "JobId=%u Storage=%s media_type=%s pool=%s pool_type=%s append=%d\n", 
+            (int)rctx.jcr->JobId,
+            store->name, store->media_type, store->pool_name, 
+            store->pool_type, store->append);
+         foreach_alist(device_name, store->device) {
+            Dmsg1(dbglvl, "   Device=%s\n", device_name);
+         }
       }
    }
-#endif
 
    init_jcr_device_wait_timers(jcr);
    /*                    
@@ -341,14 +628,18 @@ static bool use_storage_cmd(JCR *jcr)
     * Wiffle through them and find one that can do the backup.
     */
    if (ok) {
-      bool first = true;           /* print wait message once */
-      for ( ; !job_canceled(jcr); ) {
-         P(search_lock);           /* only one thread at a time */
+      int wait_for_device_retries = 0;  
+      int repeat = 0;
+      bool fail = false;
+      rctx.notify_dir = true;
+      lock_reservations();
+      for ( ; !fail && !job_canceled(jcr); ) {
          while ((msg = (char *)msgs->pop())) {
             free(msg);
          }
          rctx.suitable_device = false;
          rctx.have_volume = false;
+         rctx.VolumeName[0] = 0;
          rctx.any_drive = false;
          if (!jcr->PreferMountedVols) {
             /* Look for unused drives in autochangers */
@@ -357,7 +648,8 @@ static bool use_storage_cmd(JCR *jcr)
             rctx.PreferMountedVols = false;                
             rctx.exact_match = false;
             rctx.autochanger_only = true;
-            Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+            Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+               (int)rctx.jcr->JobId,
                rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
                rctx.autochanger_only, rctx.any_drive);
             if ((ok = find_suitable_device_for_job(jcr, rctx))) {
@@ -372,7 +664,8 @@ static bool use_storage_cmd(JCR *jcr)
                rctx.try_low_use_drive = false;
             }
             rctx.autochanger_only = false;
-            Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+            Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+               (int)rctx.jcr->JobId,
                rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
                rctx.autochanger_only, rctx.any_drive);
             if ((ok = find_suitable_device_for_job(jcr, rctx))) {
@@ -383,7 +676,8 @@ static bool use_storage_cmd(JCR *jcr)
          rctx.PreferMountedVols = true;
          rctx.exact_match = true;
          rctx.autochanger_only = false;
-         Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+         Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+            (int)rctx.jcr->JobId,
             rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
             rctx.autochanger_only, rctx.any_drive);
          if ((ok = find_suitable_device_for_job(jcr, rctx))) {
@@ -391,7 +685,8 @@ static bool use_storage_cmd(JCR *jcr)
          }
          /* Look for any mounted drive */
          rctx.exact_match = false;
-         Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+         Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+            (int)rctx.jcr->JobId,
             rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
             rctx.autochanger_only, rctx.any_drive);
          if ((ok = find_suitable_device_for_job(jcr, rctx))) {
@@ -399,69 +694,77 @@ static bool use_storage_cmd(JCR *jcr)
          }
          /* Try any drive */
          rctx.any_drive = true;
-         Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+         Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+            (int)rctx.jcr->JobId,
             rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
             rctx.autochanger_only, rctx.any_drive);
          if ((ok = find_suitable_device_for_job(jcr, rctx))) {
             break;
          }
-         /* Unlock before possible wait */
-         V(search_lock);
-         if (!rctx.suitable_device || !wait_for_device(jcr, first)) {
-            break;       /* Get out, failure ... */
+         /* Keep reservations locked *except* during wait_for_device() */
+         unlock_reservations();
+         /*     
+          * The idea of looping on repeat a few times it to ensure
+          * that if there is some subtle timing problem between two
+          * jobs, we will simply try again, and most likely succeed.
+          * This can happen if one job reserves a drive or finishes using
+          * a drive at the same time a second job wants it.
+          */
+         if (repeat++ > 1) {              /* try algorithm 3 times */
+            bmicrosleep(30, 0);           /* wait a bit */
+            Dmsg1(dbglvl, "JobId=%u repeat reserve algorithm\n", (int)rctx.jcr->JobId);
+         } else if (!rctx.suitable_device || !wait_for_device(jcr, wait_for_device_retries)) {
+            Dmsg1(dbglvl, "JobId=%u Fail. !suitable_device || !wait_for_device\n",
+                 (int)rctx.jcr->JobId);
+            fail = true;
          }   
-         first = false;
-         bnet_sig(dir, BNET_HEARTBEAT);  /* Inform Dir that we are alive */
+         lock_reservations();
+         dir->signal(BNET_HEARTBEAT);  /* Inform Dir that we are alive */
       }
-      /* Note if !ok then search_lock is already cleared */
-      if (ok) {
-         V(search_lock);
-         goto all_done;
-      } 
-
-      /*
-       * If we get here, there are no suitable devices available, which
-       *  means nothing configured.  If a device is suitable but busy
-       *  with another Volume, we will not come here.
-       */
-      if (verbose) {
+      unlock_reservations();
+      if (!ok) {
+         /*
+          * If we get here, there are no suitable devices available, which
+          *  means nothing configured.  If a device is suitable but busy
+          *  with another Volume, we will not come here.
+          */
          unbash_spaces(dir->msg);
          pm_strcpy(jcr->errmsg, dir->msg);
          Jmsg(jcr, M_INFO, 0, _("Failed command: %s\n"), jcr->errmsg);
-      }
-      Jmsg(jcr, M_FATAL, 0, _("\n"
-         "     Device \"%s\" with MediaType \"%s\" requested by DIR not found in SD Device resources.\n"),
-           dev_name.c_str(), media_type.c_str());
-      bnet_fsend(dir, NO_device, dev_name.c_str());
+         Jmsg(jcr, M_FATAL, 0, _("\n"
+            "     Device \"%s\" with MediaType \"%s\" requested by DIR not found in SD Device resources.\n"),
+              dev_name.c_str(), media_type.c_str());
+         dir->fsend(NO_device, dev_name.c_str());
 
-      Dmsg1(100, ">dird: %s", dir->msg);
+         Dmsg1(dbglvl, ">dird: %s", dir->msg);
+      }
    } else {
       unbash_spaces(dir->msg);
       pm_strcpy(jcr->errmsg, dir->msg);
-      if (verbose) {
-         Jmsg(jcr, M_INFO, 0, _("Failed command: %s\n"), jcr->errmsg);
-      }
-      bnet_fsend(dir, BAD_use, jcr->errmsg);
-      Dmsg1(100, ">dird: %s", dir->msg);
+      Jmsg(jcr, M_FATAL, 0, _("Failed command: %s\n"), jcr->errmsg);
+      dir->fsend(BAD_use, jcr->errmsg);
+      Dmsg1(dbglvl, ">dird: %s", dir->msg);
    }
 
-all_done:
    release_msgs(jcr);
    return ok;
 }
 
-static void release_msgs(JCR *jcr)
+void release_msgs(JCR *jcr)
 {
    alist *msgs = jcr->reserve_msgs;
    char *msg;
 
-   P(search_lock);
+   if (!msgs) {
+      return;
+   }
+   lock_reservations();
    while ((msg = (char *)msgs->pop())) {
       free(msg);
    }
    delete msgs;
    jcr->reserve_msgs = NULL;
-   V(search_lock);
+   unlock_reservations();
 }
 
 /*
@@ -469,40 +772,131 @@ static void release_msgs(JCR *jcr)
  */
 bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx)
 {
-   bool ok;
+   bool ok = false;
    DIRSTORE *store;
    char *device_name;
+   alist *dirstore;
+
+   if (rctx.append) {
+      dirstore = jcr->write_store;
+   } else {
+      dirstore = jcr->read_store;
+   }
+   Dmsg5(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d\n",
+      (int)rctx.jcr->JobId,
+      rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
+      rctx.autochanger_only);
+
+   if (!vol_list->empty() && rctx.append && rctx.PreferMountedVols) {
+      dlist *temp_vol_list, *save_vol_list;
+      VOLRES *vol = NULL;
+      lock_volumes();
+
+      /*  
+       * 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 
+       *   search at least a few times).
+       */
+      temp_vol_list = New(dlist(vol, &vol->link));
+      foreach_dlist(vol, vol_list) {
+         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);
+         if (tvol != nvol) {
+            tvol->dev = NULL;                   /* don't zap dev entry */
+            free_vol_item(tvol);
+            Pmsg0(000, "Logic error. Duplicating vol list hit duplicate.\n");
+            Jmsg(jcr, M_WARNING, 0, "Logic error. Duplicating vol list hit duplicate.\n");
+         }
+      }
+      unlock_volumes();
+
+      /* Look through reserved volumes for one we can use */
+      foreach_dlist(vol, temp_vol_list) {
+         if (!vol->dev) {
+            continue;
+         }
+         foreach_alist(store, dirstore) {
+            rctx.store = store;
+            foreach_alist(device_name, store->device) {
+               int stat;
+               if (strcmp(device_name, vol->dev->device->hdr.name) != 0) {
+                  continue;
+               }
+               rctx.device_name = device_name;
+               rctx.device = vol->dev->device;
+               bstrncpy(rctx.VolumeName, vol->vol_name, sizeof(rctx.VolumeName));
+               rctx.have_volume = true;
+               /* Try reserving this device and volume */
+               Dmsg3(dbglvl, "JobId=%u try vol=%s on device=%s\n", (int)rctx.jcr->JobId, 
+                     rctx.VolumeName, device_name);
+               stat = reserve_device(rctx);
+               if (stat == 1) {             /* found available device */
+                  Dmsg2(dbglvl, "JobId=%u Suitable device found=%s\n", (int)rctx.jcr->JobId, 
+                        device_name);
+                  ok = true;
+                  break;
+               } else if (stat == 0) {      /* device busy */
+                  Dmsg2(dbglvl, "JobId=%u Suitable device=%s, busy: not use\n", 
+                        (int)rctx.jcr->JobId, device_name);
+               } else {
+                  /* otherwise error */
+                  Dmsg1(dbglvl, "JobId=%u No suitable device found.\n", (int)rctx.jcr->JobId);
+               }
+               rctx.have_volume = false;
+            }
+            if (ok) {
+               break;
+            }
+         }
+      } /* end for loop over reserved volumes */
+      lock_volumes();
+      save_vol_list = vol_list;
+      vol_list = temp_vol_list;
+      free_volume_list();                  /* release temp_vol_list */
+      vol_list = save_vol_list;
+      unlock_volumes();
+   }
+   if (ok) {
+      return true;
+   }
 
    /* 
+    * No reserved volume we can use, so now search for an available device.  
+    *
     * For each storage device that the user specified, we
     *  search and see if there is a resource for that device.
     */
-   Dmsg4(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d\n",
-      rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
-      rctx.autochanger_only);
-   ok = false;
-   foreach_alist(store, jcr->dirstore) {
+   foreach_alist(store, dirstore) {
       rctx.store = store;
       foreach_alist(device_name, store->device) {
          int stat;
          rctx.device_name = device_name;
          stat = search_res_for_device(rctx); 
          if (stat == 1) {             /* found available device */
-            Dmsg1(100, "Suitable device found=%s\n", device_name);
+            Dmsg2(dbglvl, "JobId=%u available device found=%s\n", (int)rctx.jcr->JobId, 
+                  device_name);
             ok = true;
             break;
          } else if (stat == 0) {      /* device busy */
-            Dmsg1(100, "Suitable device found=%s, not used: busy\n", device_name);
+            Dmsg2(dbglvl, "JobId=%u Suitable device=%s, busy: not use\n", 
+                  (int)rctx.jcr->JobId, device_name);
          } else {
             /* otherwise error */
-            Dmsg0(100, "No suitable device found.\n");
+            Dmsg1(dbglvl, "JobId=%u No suitable device found.\n", (int)rctx.jcr->JobId);
          }
       }
       if (ok) {
          break;
       }
    }
-
    return ok;
 }
 
@@ -510,39 +904,36 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx)
  * Search for a particular storage device with particular storage
  *  characteristics (MediaType).
  */
-static int search_res_for_device(RCTX &rctx) 
+int search_res_for_device(RCTX &rctx) 
 {
    AUTOCHANGER *changer;
-   BSOCK *dir = rctx.jcr->dir_bsock;
-   bool ok;
    int stat;
 
-   Dmsg1(100, "Search res for %s\n", rctx.device_name);
+   Dmsg2(dbglvl, "JobId=%u search res for %s\n", (int)rctx.jcr->JobId, rctx.device_name);
    /* Look through Autochangers first */
    foreach_res(changer, R_AUTOCHANGER) {
-      Dmsg1(150, "Try match changer res=%s\n", changer->hdr.name);
+      Dmsg2(150, "JobId=%u Try match changer res=%s\n", (int)rctx.jcr->JobId, changer->hdr.name);
       /* Find resource, and make sure we were able to open it */
       if (fnmatch(rctx.device_name, changer->hdr.name, 0) == 0) {
          /* Try each device in this AutoChanger */
          foreach_alist(rctx.device, changer->device) {
-            Dmsg1(100, "Try changer device %s\n", rctx.device->hdr.name);
+            Dmsg2(dbglvl, "JobId=%u Try changer device %s\n", (int)rctx.jcr->JobId, 
+                  rctx.device->hdr.name);
             stat = reserve_device(rctx);
             if (stat != 1) {             /* try another device */
                continue;
             }
-            POOL_MEM dev_name;
+            /* Debug code */
             if (rctx.store->append == SD_APPEND) {
-               Dmsg2(100, "Device %s reserved=%d for append.\n", rctx.device->hdr.name,
+               Dmsg3(dbglvl, "JobId=%u Device %s reserved=%d for append.\n", 
+                  (int)rctx.jcr->JobId, rctx.device->hdr.name,
                   rctx.jcr->dcr->dev->reserved_device);
             } else {
-               Dmsg2(100, "Device %s reserved=%d for read.\n", rctx.device->hdr.name,
+               Dmsg3(dbglvl, "JobId=%u Device %s reserved=%d for read.\n", 
+                  (int)rctx.jcr->JobId, rctx.device->hdr.name,
                   rctx.jcr->read_dcr->dev->reserved_device);
             }
-            pm_strcpy(dev_name, rctx.device->hdr.name);
-            bash_spaces(dev_name);
-            ok = bnet_fsend(dir, OK_device, dev_name.c_str());  /* Return real device name */
-            Dmsg1(100, ">dird changer: %s", dir->msg);
-            return ok ? 1 : -1;
+            return stat;
          }
       }
    }
@@ -550,18 +941,24 @@ static int search_res_for_device(RCTX &rctx)
    /* Now if requested look through regular devices */
    if (!rctx.autochanger_only) {
       foreach_res(rctx.device, R_DEVICE) {
-         Dmsg1(150, "Try match res=%s\n", rctx.device->hdr.name);
+         Dmsg2(150, "JobId=%u Try match res=%s\n", (int)rctx.jcr->JobId, rctx.device->hdr.name);
          /* Find resource, and make sure we were able to open it */
          if (fnmatch(rctx.device_name, rctx.device->hdr.name, 0) == 0) {
             stat = reserve_device(rctx);
-            if (stat != 1) {
-               return stat;
+            if (stat != 1) {             /* try another device */
+               continue;
+            }
+            /* Debug code */
+            if (rctx.store->append == SD_APPEND) {
+               Dmsg3(dbglvl, "JobId=%u Device %s reserved=%d for append.\n", 
+                  (int)rctx.jcr->JobId, rctx.device->hdr.name,
+                  rctx.jcr->dcr->dev->reserved_device);
+            } else {
+               Dmsg3(dbglvl, "JobId=%u Device %s reserved=%d for read.\n", 
+                  (int)rctx.jcr->JobId, rctx.device->hdr.name,
+                  rctx.jcr->read_dcr->dev->reserved_device);
             }
-            Dmsg1(220, "Got: %s", dir->msg);
-            bash_spaces(rctx.device_name);
-            ok = bnet_fsend(dir, OK_device, rctx.device_name);
-            Dmsg1(100, ">dird dev: %s", dir->msg);
-            return ok ? 1 : -1;
+            return stat;
          }
       }
    }
@@ -582,7 +979,8 @@ static int reserve_device(RCTX &rctx)
    const int name_len = MAX_NAME_LENGTH;
 
    /* Make sure MediaType is OK */
-   Dmsg2(100, "MediaType device=%s request=%s\n",
+   Dmsg3(dbglvl, "JobId=%u MediaType device=%s request=%s\n",
+         (int)rctx.jcr->JobId,
          rctx.device->media_type, rctx.store->media_type);
    if (strcmp(rctx.device->media_type, rctx.store->media_type) != 0) {
       return -1;
@@ -606,13 +1004,12 @@ static int reserve_device(RCTX &rctx)
    }  
 
    rctx.suitable_device = true;
-   Dmsg2(100, "Try reserve %s JobId=%u\n", rctx.device->hdr.name,
-         rctx.jcr->JobId);
+   Dmsg2(dbglvl, "JobId=%u try reserve %s\n", rctx.jcr->JobId, rctx.device->hdr.name);
    dcr = new_dcr(rctx.jcr, rctx.device->dev);
    if (!dcr) {
       BSOCK *dir = rctx.jcr->dir_bsock;
-      bnet_fsend(dir, _("3926 Could not get dcr for device: %s\n"), rctx.device_name);
-      Dmsg1(100, ">dird: %s", dir->msg);
+      dir->fsend(_("3926 Could not get dcr for device: %s\n"), rctx.device_name);
+      Dmsg1(dbglvl, ">dird: %s", dir->msg);
       return -1;
    }
    bstrncpy(dcr->pool_name, rctx.store->pool_name, name_len);
@@ -620,21 +1017,36 @@ static int reserve_device(RCTX &rctx)
    bstrncpy(dcr->media_type, rctx.store->media_type, name_len);
    bstrncpy(dcr->dev_name, rctx.device_name, name_len);
    if (rctx.store->append == SD_APPEND) {
-      if (rctx.exact_match && !rctx.have_volume) {
+      Dmsg3(dbglvl, "JobId=%u have_vol=%d vol=%s\n", (int)rctx.jcr->JobId,
+          rctx.have_volume, rctx.VolumeName);                                   
+      if (!rctx.have_volume) {
          dcr->any_volume = true;
          if (dir_find_next_appendable_volume(dcr)) {
             bstrncpy(rctx.VolumeName, dcr->VolumeName, sizeof(rctx.VolumeName));
-            Dmsg2(100, "JobId=%u looking for Volume=%s\n", rctx.jcr->JobId, rctx.VolumeName);
+            Dmsg2(dbglvl, "JobId=%u looking for Volume=%s\n", (int)rctx.jcr->JobId, rctx.VolumeName);
             rctx.have_volume = true;
          } else {
-            Dmsg0(100, "No next volume found\n");
+            Dmsg1(dbglvl, "JobId=%u No next volume found\n", (int)rctx.jcr->JobId);
+            rctx.have_volume = false;
             rctx.VolumeName[0] = 0;
-        }
+            /*
+             * If there is at least one volume that is valid and in use,
+             *   but we get here, check if we are running with prefers
+             *   non-mounted drives.  In that case, we have selected a
+             *   non-used drive and our one and only volume is mounted
+             *   elsewhere, so we bail out and retry using that drive.
+             */
+            if (dcr->volume_in_use && !rctx.PreferMountedVols) {
+               rctx.PreferMountedVols = true;
+               goto bail_out;
+            }
+         }
       }
       ok = reserve_device_for_append(dcr, rctx);
       if (ok) {
          rctx.jcr->dcr = dcr;
-         Dmsg5(100, "Reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n",
+         Dmsg6(dbglvl, "JobId=%u Reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n",
+               (int)rctx.jcr->JobId,
                dcr->dev->reserved_device,
                dcr->dev_name, dcr->media_type, dcr->pool_name, ok);
       }
@@ -642,17 +1054,32 @@ static int reserve_device(RCTX &rctx)
       ok = reserve_device_for_read(dcr);
       if (ok) {
          rctx.jcr->read_dcr = dcr;
-         Dmsg5(100, "Read reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n",
+         Dmsg6(dbglvl, "JobId=%u Read reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n",
+               (int)rctx.jcr->JobId,
                dcr->dev->reserved_device,
                dcr->dev_name, dcr->media_type, dcr->pool_name, ok);
       }
    }
    if (!ok) {
-      free_dcr(dcr);
-      Dmsg0(100, "Not OK.\n");
-      return 0;
+      goto bail_out;
    }
-   return 1;
+   if (rctx.notify_dir) {
+      POOL_MEM dev_name;
+      BSOCK *dir = rctx.jcr->dir_bsock;
+      pm_strcpy(dev_name, rctx.device->hdr.name);
+      bash_spaces(dev_name);
+      ok = dir->fsend(OK_device, dev_name.c_str());  /* Return real device name */
+      Dmsg1(dbglvl, ">dird changer: %s", dir->msg);
+   } else {
+      ok = true;
+   }
+   return ok ? 1 : -1;
+
+bail_out:
+   rctx.have_volume = false;
+   free_dcr(dcr);
+   Dmsg1(dbglvl, "JobId=%u Not OK.\n", (int)rctx.jcr->JobId);
+   return 0;
 }
 
 /*
@@ -669,10 +1096,11 @@ static bool reserve_device_for_read(DCR *dcr)
 
    ASSERT(dcr);
 
-   P(dev->mutex);
+   dev->dlock();  
 
    if (is_device_unmounted(dev)) {             
-      Dmsg1(200, "Device %s is BLOCKED due to user unmount.\n", dev->print_name());
+      Dmsg2(dbglvl, "JobId=%u Device %s is BLOCKED due to user unmount.\n", 
+         (int)jcr->JobId, dev->print_name());
       Mmsg(jcr->errmsg, _("3601 JobId=%u device %s is BLOCKED due to user unmount.\n"),
            jcr->JobId, dev->print_name());
       queue_reserve_message(jcr);
@@ -680,7 +1108,8 @@ static bool reserve_device_for_read(DCR *dcr)
    }
 
    if (dev->is_busy()) {
-      Dmsg4(200, "Device %s is busy ST_READ=%d num_writers=%d reserved=%d.\n", dev->print_name(),
+      Dmsg5(dbglvl, "JobId=%u Device %s is busy ST_READ=%d num_writers=%d reserved=%d.\n", 
+         (int)jcr->JobId, dev->print_name(),
          dev->state & ST_READ?1:0, dev->num_writers, dev->reserved_device);
       Mmsg(jcr->errmsg, _("3602 JobId=%u device %s is busy (already reading/writing).\n"),
             jcr->JobId, dev->print_name());
@@ -692,12 +1121,12 @@ static bool reserve_device_for_read(DCR *dcr)
    dev->set_read();
    ok = true;
    dev->reserved_device++;
-   Dmsg3(100, "Inc reserve=%d dev=%s %p\n", dev->reserved_device, 
-      dev->print_name(), dev);
+   Dmsg4(dbglvl, "JobId=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId,
+      dev->reserved_device, dev->print_name(), dev);
    dcr->reserved_device = true;
 
 bail_out:
-   V(dev->mutex);
+   dev->dunlock();
    return ok;
 }
 
@@ -725,13 +1154,13 @@ static bool reserve_device_for_append(DCR *dcr, RCTX &rctx)
 
    ASSERT(dcr);
 
-   P(dev->mutex);
+   dev->dlock();
 
    /* If device is being read, we cannot write it */
    if (dev->can_read()) {
       Mmsg(jcr->errmsg, _("3603 JobId=%u device %s is busy reading.\n"), 
          jcr->JobId, dev->print_name());
-      Dmsg1(100, "%s", jcr->errmsg);
+      Dmsg1(dbglvl, "%s", jcr->errmsg);
       queue_reserve_message(jcr);
       goto bail_out;
    }
@@ -740,27 +1169,28 @@ static bool reserve_device_for_append(DCR *dcr, RCTX &rctx)
    if (is_device_unmounted(dev)) {
       Mmsg(jcr->errmsg, _("3604 JobId=%u device %s is BLOCKED due to user unmount.\n"), 
          jcr->JobId, dev->print_name());
-      Dmsg1(100, "%s", jcr->errmsg);
+      Dmsg1(dbglvl, "%s", jcr->errmsg);
       queue_reserve_message(jcr);
       goto bail_out;
    }
 
-   Dmsg1(100, "reserve_append device is %s\n", dev->is_tape()?"tape":"disk");
+   Dmsg2(dbglvl, "JobId=%u reserve_append device is %s\n", 
+       (int)jcr->JobId, dev->print_name());
 
    /* Now do detailed tests ... */
    if (can_reserve_drive(dcr, rctx) != 1) {
-      Dmsg0(100, "can_reserve_drive!=1\n");
+      Dmsg1(dbglvl, "JobId=%u can_reserve_drive!=1\n", (int)jcr->JobId);
       goto bail_out;
    }
 
    dev->reserved_device++;
-   Dmsg3(100, "Inc reserve=%d dev=%s %p\n", dev->reserved_device, 
+   Dmsg4(dbglvl, "JobId=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId, dev->reserved_device, 
       dev->print_name(), dev);
    dcr->reserved_device = true;
    ok = true;
 
 bail_out:
-   V(dev->mutex);
+   dev->dunlock();
    return ok;
 }
 
@@ -774,7 +1204,8 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
    DEVICE *dev = dcr->dev;
    JCR *jcr = dcr->jcr;
 
-   Dmsg5(100, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+   Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+         (int)jcr->JobId,
          rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
          rctx.autochanger_only, rctx.any_drive);
 
@@ -787,7 +1218,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
        *  helps spread the load to the least used drives.  
        */
       if (rctx.try_low_use_drive && dev == rctx.low_use_drive) {
-         Dmsg3(100, "OK dev=%s == low_drive=%s. JobId=%u\n",
+         Dmsg3(dbglvl, "OK dev=%s == low_drive=%s. JobId=%u\n",
             dev->print_name(), rctx.low_use_drive->print_name(), jcr->JobId);
          return 1;
       }
@@ -797,13 +1228,13 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
          if ((dev->num_writers + dev->reserved_device) < rctx.num_writers) {
             rctx.num_writers = dev->num_writers + dev->reserved_device;
             rctx.low_use_drive = dev;
-            Dmsg2(100, "set low use drive=%s num_writers=%d\n", dev->print_name(),
-               rctx.num_writers);
+            Dmsg3(dbglvl, "JobId=%u set low use drive=%s num_writers=%d\n", 
+               (int)jcr->JobId, dev->print_name(), rctx.num_writers);
          } else {
-            Dmsg1(100, "not low use num_writers=%d\n", dev->num_writers+ 
-               dev->reserved_device);
+            Dmsg2(dbglvl, "JobId=%u not low use num_writers=%d\n", 
+               (int)jcr->JobId, dev->num_writers+dev->reserved_device);
          }
-         Dmsg1(100, "failed: !prefMnt && busy. JobId=%u\n", jcr->JobId);
+         Dmsg1(dbglvl, "failed: !prefMnt && busy. JobId=%u\n", jcr->JobId);
          Mmsg(jcr->errmsg, _("3605 JobId=%u wants free drive but device %s is busy.\n"), 
             jcr->JobId, dev->print_name());
          queue_reserve_message(jcr);
@@ -811,32 +1242,51 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
       }
 
       /* Check for prefer mounted volumes */
-      if (rctx.PreferMountedVols && !dev->VolHdr.VolumeName[0] && dev->is_tape()) {
-         Mmsg(jcr->errmsg, _("3606 JobId=%u wants mounted, but drive %s has no Volume.\n"), 
+//    if (rctx.PreferMountedVols && !dev->VolHdr.VolumeName[0] && dev->is_tape()) {
+      if (rctx.PreferMountedVols && !dev->vol && dev->is_tape()) {
+         Mmsg(jcr->errmsg, _("3606 JobId=%u prefers mounted drives, but drive %s has no Volume.\n"), 
             jcr->JobId, dev->print_name());
          queue_reserve_message(jcr);
-         Dmsg1(100, "failed: want mounted -- no vol JobId=%u\n", jcr->JobId);
+         Dmsg1(dbglvl, "failed: want mounted -- no vol JobId=%u\n", (uint32_t)jcr->JobId);
          return 0;                 /* No volume mounted */
       }
 
       /* Check for exact Volume name match */
-      if (rctx.exact_match && rctx.have_volume &&
-          strcmp(dev->VolHdr.VolumeName, rctx.VolumeName) != 0) {
-         Mmsg(jcr->errmsg, _("3607 JobId=%u wants Vol=\"%s\" drive has Vol=\"%s\" on drive %s.\n"), 
-            jcr->JobId, rctx.VolumeName, dev->VolHdr.VolumeName, 
-            dev->print_name());
-         queue_reserve_message(jcr);
-         Dmsg2(100, "failed: Not exact match have=%s want=%s\n",
-               dev->VolHdr.VolumeName, rctx.VolumeName);
-         return 0;
+      /* ***FIXME*** for Disk, we can accept any volume that goes with this
+       *    drive.
+       */
+      if (rctx.exact_match && rctx.have_volume) {
+         bool ok;
+         Dmsg6(dbglvl, "JobId=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+               (int)jcr->JobId,
+               rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
+               rctx.autochanger_only, rctx.any_drive);
+         Dmsg5(dbglvl, "JobId=%u have_vol=%d have=%s resvol=%s want=%s\n",
+                  (int)jcr->JobId, rctx.have_volume, dev->VolHdr.VolumeName, 
+                  dev->vol?dev->vol->vol_name:"*none*", rctx.VolumeName);
+         ok = strcmp(dev->VolHdr.VolumeName, rctx.VolumeName) == 0 ||
+                 (dev->vol && strcmp(dev->vol->vol_name, rctx.VolumeName) == 0);
+         if (!ok) {
+            Mmsg(jcr->errmsg, _("3607 JobId=%u wants Vol=\"%s\" drive has Vol=\"%s\" on drive %s.\n"), 
+               jcr->JobId, rctx.VolumeName, dev->VolHdr.VolumeName, 
+               dev->print_name());
+            queue_reserve_message(jcr);
+            Dmsg4(dbglvl, "JobId=%u failed: dev have=%s resvol=%s want=%s\n",
+                  (int)jcr->JobId, dev->VolHdr.VolumeName, 
+                  dev->vol?dev->vol->vol_name:"*none*", rctx.VolumeName);
+            return 0;
+         }
+         if (is_volume_in_use(dcr)) {
+            return 0;              /* fail if volume on another drive */
+         }
       }
    }
 
    /* Check for unused autochanger drive */
-   if (rctx.autochanger_only && dev->num_writers == 0 &&
+   if (rctx.autochanger_only && !dev->is_busy() &&
        dev->VolHdr.VolumeName[0] == 0) {
       /* Device is available but not yet reserved, reserve it for us */
-      Dmsg2(100, "OK Res Unused autochanger %s JobId=%u.\n",
+      Dmsg2(dbglvl, "OK Res Unused autochanger %s JobId=%u.\n",
          dev->print_name(), jcr->JobId);
       bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name));
       bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type));
@@ -853,34 +1303,37 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
          if (strcmp(dev->pool_name, dcr->pool_name) == 0 &&
              strcmp(dev->pool_type, dcr->pool_type) == 0) {
             /* OK, compatible device */
-            Dmsg2(100, "OK dev: %s num_writers=0, reserved, pool matches JobId=%u\n",
+            Dmsg2(dbglvl, "OK dev: %s num_writers=0, reserved, pool matches JobId=%u\n",
                dev->print_name(), jcr->JobId);
             return 1;
          } else {
             /* Drive Pool not suitable for us */
-            Mmsg(jcr->errmsg, _("3608 JobId=%u wants Pool=\"%s\" but have Pool=\"%s\" on drive %s.\n"), 
-                  jcr->JobId, dcr->pool_name, dev->pool_name, dev->print_name());
+            Mmsg(jcr->errmsg, _(
+"3608 JobId=%u wants Pool=\"%s\" but have Pool=\"%s\" nreserve=%d on drive %s.\n"), 
+                  jcr->JobId, dcr->pool_name, dev->pool_name,
+                  dev->reserved_device, dev->print_name());
             queue_reserve_message(jcr);
-            Dmsg2(100, "failed: busy num_writers=0, reserved, pool=%s wanted=%s\n",
-               dev->pool_name, dcr->pool_name);
+            Dmsg3(dbglvl, "JobId=%u failed: busy num_writers=0, reserved, pool=%s wanted=%s\n",
+               (int)jcr->JobId, dev->pool_name, dcr->pool_name);
             return 0;                 /* wait */
          }
       } else if (dev->can_append()) {
          /* Device in append mode, check if changing pool */
          if (strcmp(dev->pool_name, dcr->pool_name) == 0 &&
              strcmp(dev->pool_type, dcr->pool_type) == 0) {
-            Dmsg2(100, "OK dev: %s num_writers=0, can_append, pool matches. JobId=%u\n",
+            Dmsg2(dbglvl, "OK dev: %s num_writers=0, can_append, pool matches. JobId=%u\n",
                dev->print_name(), jcr->JobId);
             /* OK, compatible device */
             return 1;
          } else {
             /* Changing pool, unload old tape if any in drive */
-            Dmsg0(100, "OK dev: num_writers=0, not reserved, pool change, unload changer\n");
+            Dmsg1(dbglvl, "JobId=%u OK dev: num_writers=0, not reserved, pool change, unload changer\n",
+                (int)jcr->JobId);
             unload_autochanger(dcr, 0);
          }
       }
       /* Device is available but not yet reserved, reserve it for us */
-      Dmsg2(100, "OK Dev avail reserved %s JobId=%u\n", dev->print_name(),
+      Dmsg2(dbglvl, "OK Dev avail reserved %s JobId=%u\n", dev->print_name(),
          jcr->JobId);
       bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name));
       bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type));
@@ -895,21 +1348,21 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
       /* Yes, now check if we want the same Pool and pool type */
       if (strcmp(dev->pool_name, dcr->pool_name) == 0 &&
           strcmp(dev->pool_type, dcr->pool_type) == 0) {
-         Dmsg2(100, "OK dev: %s num_writers>=0, can_append, pool matches. JobId=%u\n",
+         Dmsg2(dbglvl, "OK dev: %s num_writers>=0, can_append, pool matches. JobId=%u\n",
             dev->print_name(), jcr->JobId);
          /* OK, compatible device */
          return 1;
       } else {
          /* Drive Pool not suitable for us */
-         Mmsg(jcr->errmsg, _("3609 JobId=%u wants Pool=\"%s\" but have Pool=\"%s\" on drive %s.\n"), 
+         Mmsg(jcr->errmsg, _("3609 JobId=%u wants Pool=\"%s\" but has Pool=\"%s\" on drive %s.\n"), 
                jcr->JobId, dcr->pool_name, dev->pool_name, dev->print_name());
          queue_reserve_message(jcr);
-         Dmsg2(100, "failed: busy num_writers>0, can_append, pool=%s wanted=%s\n",
-            dev->pool_name, dcr->pool_name);
+         Dmsg3(dbglvl, "JobId=%u failed: busy num_writers>0, can_append, pool=%s wanted=%s\n",
+            (int)jcr->JobId, dev->pool_name, dcr->pool_name);
          return 0;                    /* wait */
       }
    } else {
-      Pmsg0(000, _("Logic error!!!! Should not get here.\n"));
+      Pmsg1(000, _("Logic error!!!! JobId=%u Should not get here.\n"), (int)jcr->JobId);
       Mmsg(jcr->errmsg, _("3910 JobId=%u Logic error!!!! drive %s Should not get here.\n"),
             jcr->JobId, dev->print_name());
       queue_reserve_message(jcr);
@@ -919,7 +1372,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
    Mmsg(jcr->errmsg, _("3911 JobId=%u failed reserve drive %s.\n"), 
          jcr->JobId, dev->print_name());
    queue_reserve_message(jcr);
-   Dmsg2(100, "failed: No reserve %s JobId=%u\n", dev->print_name(), jcr->JobId);
+   Dmsg2(dbglvl, "failed: No reserve %s JobId=%u\n", dev->print_name(), jcr->JobId);
    return 0;
 }
 
@@ -956,25 +1409,27 @@ static void queue_reserve_message(JCR *jcr)
 /*
  * Send any reservation messages queued for this jcr
  */
-void send_drive_reserve_messages(JCR *jcr, BSOCK *user)
+void send_drive_reserve_messages(JCR *jcr, void sendit(const char *msg, int len, void *sarg), void *arg)
 {
    int i;
    alist *msgs;
    char *msg;
 
-   P(search_lock);
+   lock_reservations();
    msgs = jcr->reserve_msgs;
    if (!msgs || msgs->size() == 0) {
-      V(search_lock);
-      return;
+      goto bail_out;
    }
    for (i=msgs->size()-1; i >= 0; i--) {
       msg = (char *)msgs->get(i);
       if (msg) {
-         bnet_fsend(user, "   %s", msg);
+         sendit("   ", 3, arg);
+         sendit(msg, strlen(msg), arg);
       } else {
          break;
       }
    }
-   V(search_lock);
+
+bail_out:
+   unlock_reservations();
 }