]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/stored/reserve.c
This commit was manufactured by cvs2svn to create tag
[bacula/bacula] / bacula / src / stored / reserve.c
index ebcb77c038f8a0cbd0dbeca2076b79c5a19aee0e..1859001811d71f83d6269eef9d0cf38acd600c92 100644 (file)
@@ -9,7 +9,7 @@
  *
  */
 /*
-   Copyright (C) 2000-2005 Kern Sibbald
+   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
 #include "bacula.h"
 #include "stored.h"
 
-/*
- *   Use Device command from Director
- *   He tells is what Device Name to use, the Media Type,
- *      the Pool Name, and the Pool Type.
- *
- *    Ensure that the device exists and is opened, then store
- *      the media and pool info in the JCR.  This class is used
- *      only temporarily in this file.
- */
-class DIRSTORE {
-public:
-   alist *device;
-   bool append;
-   char name[MAX_NAME_LENGTH];
-   char media_type[MAX_NAME_LENGTH];
-   char pool_name[MAX_NAME_LENGTH];
-   char pool_type[MAX_NAME_LENGTH];
-};
-
-/* Reserve context */
-class RCTX {
-public:
-   alist *errors;
-   JCR *jcr;
-   char *device_name;
-   DIRSTORE *store;
-   DEVRES   *device;
-   bool PreferMountedVols;
-};
-
 static dlist *vol_list = NULL;
 static pthread_mutex_t vol_list_lock = PTHREAD_MUTEX_INITIALIZER;
 
 /* Forward referenced functions */
-static int can_reserve_drive(DCR *dcr, bool PerferMountedVols);
-static int search_res_for_device(RCTX &rctx);
+static int can_reserve_drive(DCR *dcr, RCTX &rctx);
 static int reserve_device(RCTX &rctx);
 static bool reserve_device_for_read(DCR *dcr);
-static bool reserve_device_for_append(DCR *dcr, bool PreferMountedVols);
+static bool reserve_device_for_append(DCR *dcr, RCTX &rctx);
 static bool use_storage_cmd(JCR *jcr);
-bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx);
+static void queue_reserve_message(JCR *jcr);
 
 /* Requests from the Director daemon */
 static char use_storage[]  = "use storage=%127s media_type=%127s "
@@ -96,6 +65,45 @@ static int my_compare(void *item1, void *item2)
    return strcmp(((VOLRES *)item1)->vol_name, ((VOLRES *)item2)->vol_name);
 }
 
+static brwlock_t reservation_lock;
+
+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.strerror(errstat));
+   }
+
+}
+
+void term_reservations_lock()
+{
+   rwl_destroy(&reservation_lock);
+}
+
+/* This applies to a drive and to Volumes */
+void lock_reservations()
+{
+   int errstat;
+   if ((errstat=rwl_writelock(&reservation_lock)) != 0) {
+      berrno be;
+      Emsg2(M_ABORT, 0, "rwl_writelock failure. stat=%d: ERR=%s\n",
+           errstat, be.strerror(errstat));
+   }
+}
+
+void unlock_reservations()
+{
+   int errstat;
+   if ((errstat=rwl_writeunlock(&reservation_lock)) != 0) {
+      berrno be;
+      Emsg2(M_ABORT, 0, "rwl_writeunlock failure. stat=%d: ERR=%s\n",
+           errstat, be.strerror(errstat));
+   }
+}
+
 
 /*
  * Put a new Volume entry in the Volume list. This
@@ -108,22 +116,54 @@ static int my_compare(void *item1, void *item2)
 VOLRES *new_volume(DCR *dcr, const char *VolumeName)
 {
    VOLRES *vol, *nvol;
+
+   Dmsg1(400, "new_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_reservations();
+   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;
+         }
+      }
+   }
    vol = (VOLRES *)malloc(sizeof(VOLRES));
    memset(vol, 0, sizeof(VOLRES));
    vol->vol_name = bstrdup(VolumeName);
    vol->dev = dcr->dev;
    vol->dcr = dcr;
-   P(vol_list_lock);
+   Dmsg2(100, "New Vol=%s dev=%s\n", VolumeName, dcr->dev->print_name());
    nvol = (VOLRES *)vol_list->binary_insert(vol, my_compare);
-   V(vol_list_lock);
    if (nvol != vol) {
       free(vol->vol_name);
       free(vol);
+      vol = NULL;
       if (dcr->dev) {
-         nvol->dev = dcr->dev;
+         DEVICE *dev = nvol->dev;
+         if (!dev->is_busy()) {
+            Dmsg3(100, "Swap vol=%s from dev=%s to %s\n", VolumeName,
+               dev->print_name(), dcr->dev->print_name());
+            nvol->dev = dcr->dev;
+            dev->VolHdr.VolumeName[0] = 0;
+         } else {
+            Dmsg3(100, "!!!! could not swap vol=%s from dev=%s to %s\n", VolumeName,
+               dev->print_name(), dcr->dev->print_name());
+         }
       }
-      return NULL;
    }
+   V(vol_list_lock);
+   unlock_reservations();
    return vol;
 }
 
@@ -136,11 +176,12 @@ VOLRES *new_volume(DCR *dcr, const char *VolumeName)
 VOLRES *find_volume(const char *VolumeName)
 {
    VOLRES vol, *fvol;
-   vol.vol_name = bstrdup(VolumeName);
+   /* Do not lock reservations here */
    P(vol_list_lock);
+   vol.vol_name = bstrdup(VolumeName);
    fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare);
-   V(vol_list_lock);
    free(vol.vol_name);
+   V(vol_list_lock);
    return fvol;
 }
 
@@ -154,20 +195,40 @@ bool free_volume(DEVICE *dev)
 {
    VOLRES vol, *fvol;
 
+   P(vol_list_lock);
    if (dev->VolHdr.VolumeName[0] == 0) {
-      return false;
+      Dmsg1(100, "free_volume: no vol on dev %s\n", dev->print_name());
+      /*
+       * 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) {
+               Dmsg2(100, "free_volume %s dev=%s\n", fvol->vol_name, dev->print_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);
-   P(vol_list_lock);
    fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare);
    if (fvol) {
       vol_list->remove(fvol);
+      Dmsg2(100, "free_volume %s dev=%s\n", fvol->vol_name, dev->print_name());
       free(fvol->vol_name);
       free(fvol);
    }
-   V(vol_list_lock);
    free(vol.vol_name);
    dev->VolHdr.VolumeName[0] = 0;
+bail_out:
+   V(vol_list_lock);
    return fvol != NULL;
 }
 
@@ -175,11 +236,13 @@ bool free_volume(DEVICE *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);
+         Dmsg1(100, "free_unused_olume %s\n", vol->vol_name);
          free(vol->vol_name);
          free(vol);
          break;
@@ -194,9 +257,15 @@ void free_unused_volume(DCR *dcr)
 void list_volumes(BSOCK *user)  
 {
    VOLRES *vol;
+   P(vol_list_lock);
    for (vol=(VOLRES *)vol_list->first(); vol; vol=(VOLRES *)vol_list->next(vol)) {
-      bnet_fsend(user, "%s\n", vol->vol_name);
+      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);
+      }
    }
+   V(vol_list_lock);
 }
       
 /* Create the Volume list */
@@ -215,33 +284,51 @@ void free_volume_list()
    if (!vol_list) {
       return;
    }
+   P(vol_list_lock);
    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);
    }
    delete vol_list;
    vol_list = NULL;
+   V(vol_list_lock);
 }
 
 bool is_volume_in_use(DCR *dcr)
 {
    VOLRES *vol = find_volume(dcr->VolumeName);
    if (!vol) {
+      Dmsg1(100, "Vol=%s not in use.\n", dcr->VolumeName);
       return false;                   /* vol not in list */
    }
    if (!vol->dev) {                   /* vol not attached to device */
+      Dmsg1(100, "Vol=%s has no dev.\n", dcr->VolumeName);
       return false;
    }
    if (dcr->dev == vol->dev) {        /* same device OK */
+      Dmsg1(100, "Vol=%s on same dev.\n", dcr->VolumeName);
       return false;
    }
    if (!vol->dev->is_busy()) {
+      Dmsg2(100, "Vol=%s dev=%s not busy.\n", dcr->VolumeName, vol->dev->print_name());
       return false;
    }
+   Dmsg2(100, "Vol=%s used by %s.\n", dcr->VolumeName, vol->dev->print_name());
    return true;
 }
 
 
+/*
+ * We get the following type of information:
+ *
+ * use storage=xxx media_type=yyy pool_name=xxx pool_type=yyy append=1 copy=0 strip=0
+ *  use device=zzz
+ *  use device=aaa
+ *  use device=bbb
+ * use storage=xxx media_type=yyy pool_name=xxx pool_type=yyy append=0 copy=0 strip=0
+ *  use device=bbb
+ *
+ */
 static bool use_storage_cmd(JCR *jcr)
 {
    POOL_MEM store_name, dev_name, media_type, pool_name, pool_type;
@@ -251,18 +338,19 @@ static bool use_storage_cmd(JCR *jcr)
    int Copy, Stripe;
    DIRSTORE *store;
    RCTX rctx;
-   rctx.jcr = jcr;
-#ifdef implemented
-   char *error;
-#endif
+   char *msg;
+   alist *msgs;
 
+   memset(&rctx, 0, sizeof(RCTX));
+   rctx.jcr = jcr;
    /*
     * If there are multiple devices, the director sends us
     *   use_device for each device that it wants to use.
     */
-   Dmsg1(100, "<dird: %s", dir->msg);
    jcr->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);
       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;
@@ -285,6 +373,7 @@ static bool use_storage_cmd(JCR *jcr)
 
       /* Now get all devices */
       while (bnet_recv(dir) >= 0) {
+         Dmsg1(100, "<dird device: %s", dir->msg);
          ok = sscanf(dir->msg, use_device, dev_name.c_str()) == 1;
          if (!ok) {
             break;
@@ -299,15 +388,16 @@ static bool use_storage_cmd(JCR *jcr)
    /* ***FIXME**** remove after 1.38 release */
    char *device_name;
    foreach_alist(store, jcr->dirstore) {
-      Dmsg4(100, "Storage=%s media_type=%s pool=%s pool_type=%s\n", 
+      Dmsg5(110, "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->pool_type, store->append);
       foreach_alist(device_name, store->device) {
-         Dmsg1(100, "   Device=%s\n", device_name);
+         Dmsg1(110, "   Device=%s\n", device_name);
       }
    }
 #endif
 
+   init_jcr_device_wait_timers(jcr);
    /*                    
     * At this point, we have a list of all the Director's Storage
     *  resources indicated for this Job, which include Pool, PoolType,
@@ -318,114 +408,165 @@ static bool use_storage_cmd(JCR *jcr)
     * Wiffle through them and find one that can do the backup.
     */
    if (ok) {
-      /*
-       * Make up to two passes. The first with PreferMountedVols possibly
-       *   set to true.  In that case, we look only for an available 
-       *   drive with something mounted. If that fails, then we
-       *   do a second pass with PerferMountedVols set false.
-       */
-      rctx.PreferMountedVols = jcr->PreferMountedVols;
-      ok = find_suitable_device_for_job(jcr, rctx);
-      if (ok) {
-         goto done;
-      }
-      if (rctx.PreferMountedVols) {
-         rctx.PreferMountedVols = false;
-         ok = find_suitable_device_for_job(jcr, rctx);
-         if (ok) {
-            goto done;
+      bool first = true;           /* print wait message once */
+      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.any_drive = false;
+         if (!jcr->PreferMountedVols) {
+            /* Look for unused drives in autochangers */
+            rctx.num_writers = 20000000;   /* start with impossible number */
+            rctx.low_use_drive = NULL;
+            rctx.PreferMountedVols = false;                
+            rctx.exact_match = false;
+            rctx.autochanger_only = true;
+            Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+               rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
+               rctx.autochanger_only, rctx.any_drive);
+            if ((ok = find_suitable_device_for_job(jcr, rctx))) {
+               break;
+            }
+            /* Look through all drives possibly for low_use drive */
+            if (rctx.low_use_drive) {
+               rctx.try_low_use_drive = true;
+               if ((ok = find_suitable_device_for_job(jcr, rctx))) {
+                  break;
+               }
+               rctx.try_low_use_drive = false;
+            }
+            rctx.autochanger_only = false;
+            Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+               rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
+               rctx.autochanger_only, rctx.any_drive);
+            if ((ok = find_suitable_device_for_job(jcr, rctx))) {
+               break;
+            }
+         }
+         /* Look for an exact match all drives */
+         rctx.PreferMountedVols = true;
+         rctx.exact_match = true;
+         rctx.autochanger_only = false;
+         Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+            rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
+            rctx.autochanger_only, rctx.any_drive);
+         if ((ok = find_suitable_device_for_job(jcr, rctx))) {
+            break;
+         }
+         /* Look for any mounted drive */
+         rctx.exact_match = false;
+         Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+            rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
+            rctx.autochanger_only, rctx.any_drive);
+         if ((ok = find_suitable_device_for_job(jcr, rctx))) {
+            break;
+         }
+         /* Try any drive */
+         rctx.any_drive = true;
+         Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+            rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
+            rctx.autochanger_only, rctx.any_drive);
+         if ((ok = find_suitable_device_for_job(jcr, rctx))) {
+            break;
+         }
+         /* Keep reservations locked *except* during wait_for_device() */
+         unlock_reservations();
+         if (!rctx.suitable_device || !wait_for_device(jcr, first)) {
+            Dmsg0(100, "Fail. !suitable_device || !wait_for_device\n");
+            fail = true;
+         }   
+         lock_reservations();
+         first = false;
+         bnet_sig(dir, BNET_HEARTBEAT);  /* Inform Dir that we are alive */
       }
-      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());
+
+         Dmsg1(100, ">dird: %s", dir->msg);
       }
-      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());
-#ifdef implemented
-      for (error=(char*)rctx->errors.first(); error;
-           error=(char*)rctx->errors.next()) {
-         Jmsg(jcr, M_INFO, 0, "%s", error);
-      }
-#endif
-      Dmsg1(100, ">dird: %s\n", 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);
-      }
+      Jmsg(jcr, M_FATAL, 0, _("Failed command: %s\n"), jcr->errmsg);
       bnet_fsend(dir, BAD_use, jcr->errmsg);
-      Dmsg1(100, ">dird: %s\n", dir->msg);
+      Dmsg1(100, ">dird: %s", dir->msg);
    }
 
-done:
-   foreach_alist(store, jcr->dirstore) {
-      delete store->device;
-      delete store;
-   }
-   delete jcr->dirstore;
-#ifdef implemented
-   for (error=(char*)rctx->errors.first(); error;
-        error=(char*)rctx->errors.next()) {
-      free(error);
-   }
-#endif
+   release_msgs(jcr);
    return ok;
 }
 
+void release_msgs(JCR *jcr)
+{
+   alist *msgs = jcr->reserve_msgs;
+   char *msg;
+
+   if (!msgs) {
+      return;
+   }
+   lock_reservations();
+   while ((msg = (char *)msgs->pop())) {
+      free(msg);
+   }
+   delete msgs;
+   jcr->reserve_msgs = NULL;
+   unlock_reservations();
+}
 
 /*
  * Search for a device suitable for this job.
  */
 bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx)
 {
-   bool first = true;
-   bool ok = false;
-   DCR *dcr = NULL;
+   bool ok;
    DIRSTORE *store;
    char *device_name;
 
-   init_jcr_device_wait_timers(jcr);
-   for ( ;; ) {
-      int need_wait = false;
-      foreach_alist(store, jcr->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 */
-               dcr = jcr->dcr;
-               ok = true;
-               break;
-            } else if (stat == 0) {      /* device busy */
-               need_wait = true;
-            }
+   /* 
+    * For each storage device that the user specified, we
+    *  search and see if there is a resource for that device.
+    */
+   Dmsg4(110, "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) {
+      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);
+            ok = true;
+            break;
+         } else if (stat == 0) {      /* device busy */
+            Dmsg1(110, "Suitable device found=%s, not used: busy\n", device_name);
+         } else {
             /* otherwise error */
-//             rctx->errors.push(bstrdup(jcr->errmsg));
+            Dmsg0(110, "No suitable device found.\n");
          }
       }
-      /*
-       * If there is some device for which we can wait, then
-       *  wait and try again until the wait time expires
-       */
-      if (!need_wait || !wait_for_device(jcr, first)) {
+      if (ok) {
          break;
       }
-      first = false;
-#ifdef implemented
-      for (error=(char*)rctx->errors.first(); error;
-           error=(char*)rctx->errors.next()) {
-         free(error);
-      }
-#endif
-   }
-   if (!ok && dcr) {
-      free_dcr(dcr);
    }
 
    return ok;
@@ -435,55 +576,69 @@ 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);
-   foreach_res(rctx.device, R_DEVICE) {
-      Dmsg1(100, "Try res=%s\n", 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 &&
-          strcmp(rctx.device->media_type, rctx.store->media_type) == 0) {
-         stat = reserve_device(rctx);
-         if (stat != 1) {
-            return stat;
-         }
-         Dmsg1(220, "Got: %s", dir->msg);
-         bash_spaces(rctx.device_name);
-         ok = bnet_fsend(dir, OK_device, rctx.device_name);
-         Dmsg1(100, ">dird: %s\n", dir->msg);
-         return ok ? 1 : -1;
-      }
-   }
+   Dmsg1(110, "Search res for %s\n", rctx.device_name);
+   /* Look through Autochangers first */
    foreach_res(changer, R_AUTOCHANGER) {
-      Dmsg1(100, "Try changer res=%s\n", changer->hdr.name);
+      Dmsg1(150, "Try match changer res=%s\n", 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);
+            Dmsg1(110, "Try changer device %s\n", rctx.device->hdr.name);
             stat = reserve_device(rctx);
-            if (stat == -1) {            /* hard error */
-               return -1;
-            }
-            if (stat == 0) {             /* must wait, try next one */
+            if (stat != 1) {             /* try another device */
                continue;
             }
             POOL_MEM dev_name;
-            Dmsg1(100, "Device %s opened.\n", rctx.device_name);
-            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: %s\n", dir->msg);
+            if (rctx.store->append == SD_APPEND) {
+               Dmsg2(100, "Device %s reserved=%d for append.\n", rctx.device->hdr.name,
+                  rctx.jcr->dcr->dev->reserved_device);
+            } else {
+               Dmsg2(100, "Device %s reserved=%d for read.\n", rctx.device->hdr.name,
+                  rctx.jcr->read_dcr->dev->reserved_device);
+            }
+            if (rctx.notify_dir) {
+               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);
+            } else {
+               ok = true;
+            }
+            return ok ? 1 : -1;
+         }
+      }
+   }
+
+   /* 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);
+         /* 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 (rctx.notify_dir) {
+               bash_spaces(rctx.device_name);
+               ok = bnet_fsend(dir, OK_device, rctx.device_name);
+               Dmsg1(100, ">dird dev: %s", dir->msg);
+            } else {
+               ok = true;
+            }
             return ok ? 1 : -1;
          }
       }
    }
-   return 0;                    /* nothing found */
+   return -1;                    /* nothing found */
 }
 
 /*
@@ -498,6 +653,15 @@ static int reserve_device(RCTX &rctx)
    bool ok;
    DCR *dcr;
    const int name_len = MAX_NAME_LENGTH;
+
+   /* Make sure MediaType is OK */
+   Dmsg2(110, "MediaType device=%s request=%s\n",
+         rctx.device->media_type, rctx.store->media_type);
+   if (strcmp(rctx.device->media_type, rctx.store->media_type) != 0) {
+      return -1;
+   }
+
+   /* Make sure device exists -- i.e. we can stat() it */
    if (!rctx.device->dev) {
       rctx.device->dev = init_dev(rctx.jcr, rctx.device);
    }
@@ -513,27 +677,52 @@ static int reserve_device(RCTX &rctx)
       }
       return -1;  /* no use waiting */
    }  
-   Dmsg1(100, "Found device %s\n", rctx.device->hdr.name);
+
+   rctx.suitable_device = true;
+   Dmsg2(110, "Try reserve %s JobId=%u\n", rctx.device->hdr.name,
+         rctx.jcr->JobId);
    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\n", dir->msg);
+      Dmsg1(100, ">dird: %s", dir->msg);
       return -1;
    }
-   rctx.jcr->dcr = dcr;
    bstrncpy(dcr->pool_name, rctx.store->pool_name, name_len);
    bstrncpy(dcr->pool_type, rctx.store->pool_type, name_len);
    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) {
-      ok = reserve_device_for_append(dcr, rctx.PreferMountedVols);
-      Dmsg3(200, "dev_name=%s mediatype=%s ok=%d\n", dcr->dev_name, dcr->media_type, ok);
+      if (rctx.exact_match && !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);
+            rctx.have_volume = true;
+         } else {
+            Dmsg0(100, "No next volume found\n");
+            rctx.VolumeName[0] = 0;
+        }
+      }
+      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",
+               dcr->dev->reserved_device,
+               dcr->dev_name, dcr->media_type, dcr->pool_name, ok);
+      }
    } else {
       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",
+               dcr->dev->reserved_device,
+               dcr->dev_name, dcr->media_type, dcr->pool_name, ok);
+      }
    }
    if (!ok) {
-      free_dcr(rctx.jcr->dcr);
+      free_dcr(dcr);
+      Dmsg0(110, "Not OK.\n");
       return 0;
    }
    return 1;
@@ -553,29 +742,38 @@ static bool reserve_device_for_read(DCR *dcr)
 
    ASSERT(dcr);
 
-   dev->block(BST_DOING_ACQUIRE);
+   /* Get locks in correct order */
+   unlock_reservations();
+   P(dev->mutex);
+   lock_reservations();
 
    if (is_device_unmounted(dev)) {             
       Dmsg1(200, "Device %s is BLOCKED due to user unmount.\n", dev->print_name());
-      Mmsg(jcr->errmsg, _("Device %s is BLOCKED due to user unmount.\n"),
-           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);
       goto bail_out;
    }
 
    if (dev->is_busy()) {
       Dmsg4(200, "Device %s is busy ST_READ=%d num_writers=%d reserved=%d.\n", dev->print_name(),
          dev->state & ST_READ?1:0, dev->num_writers, dev->reserved_device);
-      Mmsg1(jcr->errmsg, _("Device %s is busy.\n"),
-            dev->print_name());
+      Mmsg(jcr->errmsg, _("3602 JobId=%u device %s is busy (already reading/writing).\n"),
+            jcr->JobId, dev->print_name());
+      queue_reserve_message(jcr);
       goto bail_out;
    }
 
    dev->clear_append();
    dev->set_read();
    ok = true;
+   dev->reserved_device++;
+   Dmsg3(100, "Inc reserve=%d dev=%s %p\n", dev->reserved_device, 
+      dev->print_name(), dev);
+   dcr->reserved_device = true;
 
 bail_out:
-   dev->unblock();
+   V(dev->mutex);
    return ok;
 }
 
@@ -595,7 +793,7 @@ bail_out:
  *  the first tor reserve the device, we put the pool
  *  name and pool type in the device record.
  */
-static bool reserve_device_for_append(DCR *dcr, bool PreferMountedVols) 
+static bool reserve_device_for_append(DCR *dcr, RCTX &rctx)
 {
    JCR *jcr = dcr->jcr;
    DEVICE *dev = dcr->dev;
@@ -603,105 +801,256 @@ static bool reserve_device_for_append(DCR *dcr, bool PreferMountedVols)
 
    ASSERT(dcr);
 
-   dev->block(BST_DOING_ACQUIRE);
+   P(dev->mutex);
 
+   /* If device is being read, we cannot write it */
    if (dev->can_read()) {
-      Mmsg1(jcr->errmsg, _("Device %s is busy reading.\n"), dev->print_name());
-      Dmsg1(100, "%s", jcr->errmsg);
+      Mmsg(jcr->errmsg, _("3603 JobId=%u device %s is busy reading.\n"), 
+         jcr->JobId, dev->print_name());
+      Dmsg1(110, "%s", jcr->errmsg);
+      queue_reserve_message(jcr);
       goto bail_out;
    }
 
+   /* If device is unmounted, we are out of luck */
    if (is_device_unmounted(dev)) {
-      Mmsg(jcr->errmsg, _("Device %s is BLOCKED due to user unmount.\n"), dev->print_name());
-      Dmsg1(100, "%s", jcr->errmsg);
+      Mmsg(jcr->errmsg, _("3604 JobId=%u device %s is BLOCKED due to user unmount.\n"), 
+         jcr->JobId, dev->print_name());
+      Dmsg1(110, "%s", jcr->errmsg);
+      queue_reserve_message(jcr);
       goto bail_out;
    }
 
-   Dmsg1(190, "reserve_append device is %s\n", dev->is_tape()?"tape":"disk");
+   Dmsg1(110, "reserve_append device is %s\n", dev->is_tape()?"tape":"disk");
 
-   if (can_reserve_drive(dcr, PreferMountedVols) != 1) {
-      Mmsg1(jcr->errmsg, _("Device %s is busy writing on another Volume.\n"), dev->print_name());
-      Dmsg1(100, "%s", jcr->errmsg);
+   /* Now do detailed tests ... */
+   if (can_reserve_drive(dcr, rctx) != 1) {
+      Dmsg0(110, "can_reserve_drive!=1\n");
       goto bail_out;
    }
 
    dev->reserved_device++;
-   Dmsg1(200, "Inc reserve=%d\n", dev->reserved_device);
+   Dmsg3(100, "Inc reserve=%d dev=%s %p\n", dev->reserved_device, 
+      dev->print_name(), dev);
    dcr->reserved_device = true;
    ok = true;
 
 bail_out:
-   dev->unblock();
+   V(dev->mutex);
    return ok;
 }
 
 /*
  * Returns: 1 if drive can be reserved
  *          0 if we should wait
- *         -1 on error
+ *         -1 on error or impossibility
  */
-static int can_reserve_drive(DCR *dcr, bool PreferMountedVols
+static int can_reserve_drive(DCR *dcr, RCTX &rctx
 {
    DEVICE *dev = dcr->dev;
    JCR *jcr = dcr->jcr;
 
-   if (PreferMountedVols && !dev->VolHdr.VolumeName[0] &&
-       dev->is_tape() && !dev->is_autochanger()) {
-      return 0;                 /* No volume mounted */
+   Dmsg5(110, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n",
+         rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device,
+         rctx.autochanger_only, rctx.any_drive);
+
+   /* setting any_drive overrides PreferMountedVols flag */
+   if (!rctx.any_drive) {
+      /*
+       * When PreferMountedVols is set, we keep track of the 
+       *  drive in use that has the least number of writers, then if
+       *  no unmounted drive is found, we try that drive. This   
+       *  helps spread the load to the least used drives.  
+       */
+      if (rctx.try_low_use_drive && dev == rctx.low_use_drive) {
+         Dmsg3(110, "OK dev=%s == low_drive=%s. JobId=%u\n",
+            dev->print_name(), rctx.low_use_drive->print_name(), jcr->JobId);
+         return 1;
+      }
+      /* If he wants a free drive, but this one is busy, no go */
+      if (!rctx.PreferMountedVols && dev->is_busy()) {
+         /* Save least used drive */
+         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(110, "set low use drive=%s num_writers=%d\n", dev->print_name(),
+               rctx.num_writers);
+         } else {
+            Dmsg1(110, "not low use num_writers=%d\n", dev->num_writers+ 
+               dev->reserved_device);
+         }
+         Dmsg1(110, "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);
+         return 0;
+      }
+
+      /* 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"), 
+            jcr->JobId, dev->print_name());
+         queue_reserve_message(jcr);
+         Dmsg1(110, "failed: want mounted -- no vol JobId=%u\n", 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(110, "failed: Not exact match have=%s want=%s\n",
+               dev->VolHdr.VolumeName, rctx.VolumeName);
+         return 0;
+      }
+   }
+
+   /* Check for unused autochanger drive */
+   if (rctx.autochanger_only && dev->num_writers == 0 &&
+       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",
+         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));
+      return 1;                       /* reserve drive */
    }
 
    /*
-    * Handle the case that the drive is not yet in append mode
+    * Handle the case that there are no writers
     */
-   if (!dev->can_append() && dev->num_writers == 0) {
+   if (dev->num_writers == 0) {
       /* Now check if there are any reservations on the drive */
       if (dev->reserved_device) {           
-         /* Yes, now check if we want the same Pool and pool type */
+         /* 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) {
             /* OK, compatible device */
+            Dmsg2(100, "OK dev: %s num_writers=0, reserved, pool matches JobId=%u\n",
+               dev->print_name(), jcr->JobId);
+            return 1;
          } else {
-            /* Drive not suitable for us */
+            /* 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());
+            queue_reserve_message(jcr);
+            Dmsg2(110, "failed: busy num_writers=0, reserved, pool=%s wanted=%s\n",
+               dev->pool_name, dcr->pool_name);
             return 0;                 /* wait */
          }
-      } else {
-         /* Device is available but not yet reserved, reserve it for us */
-         bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name));
-         bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type));
+      } 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",
+               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");
+            unload_autochanger(dcr, 0);
+         }
       }
-      return 1;                       /* reserve drive */
-   }
-
-   /*
-    * Check if device in append mode with no writers (i.e. available)
-    */
-   if (dev->can_append() && dev->num_writers == 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(),
+         jcr->JobId);
       bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name));
       bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type));
-      return 1;
+      return 1;                       /* reserve drive */
    }
+
    /*
     * Check if the device is in append mode with writers (i.e.
     *  available if pool is the same).
     */
    if (dev->can_append() || dev->num_writers > 0) {
-      Dmsg0(190, "device already in append.\n");
       /* 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",
+            dev->print_name(), jcr->JobId);
          /* OK, compatible device */
          return 1;
       } else {
-         /* Drive not suitable for us */
-         Jmsg(jcr, M_WARNING, 0, _("Device %s is busy writing on another Volume.\n"), dev->print_name());
+         /* Drive Pool not suitable for us */
+         Mmsg(jcr->errmsg, _("3609 JobId=%u wants Pool=\"%s\" but have Pool=\"%s\" on drive %s.\n"), 
+               jcr->JobId, dcr->pool_name, dev->pool_name, dev->print_name());
+         queue_reserve_message(jcr);
+         Dmsg2(110, "failed: busy num_writers>0, can_append, pool=%s wanted=%s\n",
+            dev->pool_name, dcr->pool_name);
          return 0;                    /* wait */
       }
    } else {
-      Pmsg0(000, "Logic error!!!! Should not get here.\n");
+      Pmsg0(000, _("Logic error!!!! Should not get here.\n"));
+      Mmsg(jcr->errmsg, _("3910 JobId=%u Logic error!!!! drive %s Should not get here.\n"),
+            jcr->JobId, dev->print_name());
+      queue_reserve_message(jcr);
       Jmsg0(jcr, M_FATAL, 0, _("Logic error!!!! Should not get here.\n"));
       return -1;                      /* error, should not get here */
    }
-
+   Mmsg(jcr->errmsg, _("3911 JobId=%u failed reserve drive %s.\n"), 
+         jcr->JobId, dev->print_name());
+   queue_reserve_message(jcr);
+   Dmsg2(110, "failed: No reserve %s JobId=%u\n", dev->print_name(), jcr->JobId);
    return 0;
 }
+
+/*
+ * search_lock is already set on entering this routine 
+ */
+static void queue_reserve_message(JCR *jcr)
+{
+   int i;   
+   alist *msgs = jcr->reserve_msgs;
+   char *msg;
+
+   if (!msgs) {
+      return;
+   }
+   /*
+    * Look for duplicate message.  If found, do
+    * not insert
+    */
+   for (i=msgs->size()-1; i >= 0; i--) {
+      msg = (char *)msgs->get(i);
+      if (!msg) {
+         return;
+      }
+      /* Comparison based on 4 digit message number */
+      if (strncmp(msg, jcr->errmsg, 4) == 0) {
+         return;
+      }
+   }      
+   /* Message unique, so insert it */
+   jcr->reserve_msgs->push(bstrdup(jcr->errmsg));
+}
+
+/*
+ * Send any reservation messages queued for this jcr
+ */
+void send_drive_reserve_messages(JCR *jcr, BSOCK *user)
+{
+   int i;
+   alist *msgs;
+   char *msg;
+
+   lock_reservations();
+   msgs = jcr->reserve_msgs;
+   if (!msgs || msgs->size() == 0) {
+      unlock_reservations();
+      return;
+   }
+   for (i=msgs->size()-1; i >= 0; i--) {
+      msg = (char *)msgs->get(i);
+      if (msg) {
+         bnet_fsend(user, "   %s", msg);
+      } else {
+         break;
+      }
+   }
+   unlock_reservations();
+}