]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/stored/reserve.c
- Simplify code in askdir.c that waits for creating an appendable
[bacula/bacula] / bacula / src / stored / reserve.c
index 93a0b12f8f52b36e6076433da304ef80e3e149fe..eb10b41a11a14adee0968560ed60dfa16fc26c36 100644 (file)
@@ -48,17 +48,20 @@ public:
 /* Reserve context */
 class RCTX {
 public:
-   alist *errors;
    JCR *jcr;
    char *device_name;
    DIRSTORE *store;
    DEVRES   *device;
-   bool PreferMountedVols;
-   bool exact_match;
-   bool have_volume;
-   bool do_not_wait;
-   bool available_autochanger;
-   char VolumeName[MAX_NAME_LENGTH];
+   DEVICE *low_use_drive;             /* Low use drive candidate */
+   int num_writers;                   /* for selecting low use drive */
+   bool try_low_use_drive;            /* see if low use drive available */
+   bool any_drive;                    /* Accept any drive if set */
+   bool PreferMountedVols;            /* Prefer volumes already mounted */
+   bool exact_match;                  /* Want exact volume */
+   bool have_volume;                  /* Have DIR suggested vol name */
+   bool suitable_device;              /* at least one device is suitable */
+   bool autochanger_only;             /* look at autochangers only */
+   char VolumeName[MAX_NAME_LENGTH];  /* Vol name suggested by DIR */
 };
 
 static dlist *vol_list = NULL;
@@ -116,22 +119,35 @@ VOLRES *new_volume(DCR *dcr, const char *VolumeName)
    VOLRES *vol, *nvol;
 
    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;
+         }
+      }
+   }
    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);
    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;
       }
-      return NULL;
    }
+   V(vol_list_lock);
    return vol;
 }
 
@@ -144,11 +160,11 @@ VOLRES *new_volume(DCR *dcr, const char *VolumeName)
 VOLRES *find_volume(const char *VolumeName)
 {
    VOLRES vol, *fvol;
-   vol.vol_name = bstrdup(VolumeName);
    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;
 }
 
@@ -162,21 +178,37 @@ bool free_volume(DEVICE *dev)
 {
    VOLRES vol, *fvol;
 
+  P(vol_list_lock);
    if (dev->VolHdr.VolumeName[0] == 0) {
-      return false;
+      /*
+       * 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);
-   P(vol_list_lock);
    fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare);
    if (fvol) {
       vol_list->remove(fvol);
       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;
 }
 
@@ -255,6 +287,17 @@ bool is_volume_in_use(DCR *dcr)
 }
 
 
+/*
+ * 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;
@@ -264,9 +307,6 @@ static bool use_storage_cmd(JCR *jcr)
    int Copy, Stripe;
    DIRSTORE *store;
    RCTX rctx;
-#ifdef implemented
-   char *error;
-#endif
 
    memset(&rctx, 0, sizeof(RCTX));
    rctx.jcr = jcr;
@@ -274,9 +314,9 @@ 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.
     */
-   Dmsg1(100, "<dird: %s", dir->msg);
    jcr->dirstore = 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;
@@ -299,6 +339,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;
@@ -332,45 +373,78 @@ static bool use_storage_cmd(JCR *jcr)
     * Wiffle through them and find one that can do the backup.
     */
    if (ok) {
-      /*
-       * First look for an exact match of Volume name as the
-       *  tape may already be mounted.
-       */
-      rctx.do_not_wait = true;
-      rctx.exact_match = true;
-      if ((ok = find_suitable_device_for_job(jcr, rctx))) {
-         goto done;
-      }
-      rctx.exact_match = false;
-
-      /* Now search if an unused autochanger slot is available */
-      rctx.available_autochanger = true;
-      if ((ok = find_suitable_device_for_job(jcr, rctx))) {
-         goto done;
-      }
-      rctx.available_autochanger = false;
-
-
-      /*
-       * 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;
-      if (!rctx.PreferMountedVols) {
-         rctx.do_not_wait = false;
-      }
-      if ((ok = find_suitable_device_for_job(jcr, rctx))) {
-         goto done;
-      }
-      if (rctx.PreferMountedVols) {
-         rctx.PreferMountedVols = false;
-         rctx.do_not_wait = false;
+      bool first = true;           /* print wait message once */
+      for ( ; !job_canceled(jcr); ) {
+         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(100, "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))) {
+               goto done;
+            }
+            /* 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))) {
+                  goto done;
+               }
+               rctx.try_low_use_drive = false;
+            }
+            rctx.autochanger_only = false;
+            Dmsg5(100, "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))) {
+               goto done;
+            }
+         }
+         /* Look for an exact match all drives */
+         rctx.PreferMountedVols = true;
+         rctx.exact_match = true;
+         rctx.autochanger_only = false;
+         Dmsg5(100, "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))) {
+            goto done;
+         }
+         /* Look for any mounted drive */
+         rctx.exact_match = false;
+         Dmsg5(100, "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))) {
             goto done;
          }
+         /* Try any drive */
+         rctx.any_drive = true;
+         Dmsg5(100, "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))) {
+            goto done;
+         }
+         if (!rctx.suitable_device || !wait_for_device(jcr, first)) {
+            break;       /* Get out, failure ... */
+         }   
+         first = false;
+         bnet_sig(dir, BNET_HEARTBEAT);  /* Inform Dir that we are alive */
       }
+
+      /*
+       * 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) {
          unbash_spaces(dir->msg);
          pm_strcpy(jcr->errmsg, dir->msg);
@@ -380,12 +454,7 @@ static bool use_storage_cmd(JCR *jcr)
          "     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", dir->msg);
    } else {
       unbash_spaces(dir->msg);
@@ -404,8 +473,7 @@ done:
    }
    delete jcr->dirstore;
 #ifdef implemented
-   for (error=(char*)rctx->errors.first(); error;
-        error=(char*)rctx->errors.next()) {
+   while (error=(char*)rctx->errors.first()) {
       free(error);
    }
 #endif
@@ -418,57 +486,43 @@ done:
  */
 bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx)
 {
-   bool first = true;
    bool ok;
-   DCR *dcr = NULL;
    DIRSTORE *store;
    char *device_name;
 
+   /* 
+    * 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);
    init_jcr_device_wait_timers(jcr);
-   for ( ;; ) {
-      int can_wait = false;
-      ok = false;
-      P(search_lock);
-      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 */
-               ok = true;
-               break;
-            } else if (stat == 0) {      /* device busy */
-               can_wait = true;
-            }
-            /* otherwise error */
-//             rctx->errors.push(bstrdup(jcr->errmsg));
-         }
-         if (ok) {
+   ok = false;
+   P(search_lock);
+   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 */
+            rctx.suitable_device = true;
+            Dmsg1(100, "Suitable device found=%s\n", device_name);
+            ok = true;
             break;
+         } else if (stat == 0) {      /* device busy */
+            Dmsg1(100, "Suitable busy device found=%s\n", device_name);
+            rctx.suitable_device = true;   /* but it is busy, so continue looking */
          }
+         /* otherwise error */
       }
-      V(search_lock);
-      /*
-       * We did not find a suitable device, so
-       *  if there is some device for which we can wait, then
-       *  wait and try again until the wait time expires
-       */
-      if (rctx.do_not_wait || !can_wait || !wait_for_device(jcr, first)) {
+      if (ok) {
          break;
       }
-      first = false;                  /* first wait complete */
-
-#ifdef implemented
-      for (error=(char*)rctx->errors.first(); error;
-           error=(char*)rctx->errors.next()) {
-         free(error);
-      }
-#endif
-   }
-   if (dcr) {
-      free_dcr(dcr);
    }
+   V(search_lock);
+
    return ok;
 }
 
@@ -484,39 +538,26 @@ static int search_res_for_device(RCTX &rctx)
    int stat;
 
    Dmsg1(100, "Search res for %s\n", rctx.device_name);
-   if (!rctx.available_autochanger) {
-      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) {
-            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 dev: %s", dir->msg);
-            return ok ? 1 : -1;
-         }
-      }
-   }
+   /* 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);
             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);
+            if (rctx.store->append == SD_APPEND) {
+               Dmsg2(100, "Device %s reserved=%d.\n", rctx.device_name,
+                  rctx.jcr->dcr->dev->reserved_device);
+            } else {
+               Dmsg2(100, "Device %s reserved=%d.\n", rctx.device_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 */
@@ -525,7 +566,26 @@ static int search_res_for_device(RCTX &rctx)
          }
       }
    }
-   return 0;                    /* nothing found */
+
+   /* 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;
+            }
+            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 -1;                    /* nothing found */
 }
 
 /*
@@ -546,6 +606,7 @@ static int reserve_device(RCTX &rctx)
       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);
    }
@@ -561,7 +622,9 @@ static int reserve_device(RCTX &rctx)
       }
       return -1;  /* no use waiting */
    }  
-   Dmsg1(100, "Found device %s\n", rctx.device->hdr.name);
+
+   Dmsg2(100, "Try reserve %s jobid=%d\n", rctx.device->hdr.name,
+         rctx.jcr->JobId);
    dcr = new_dcr(rctx.jcr, rctx.device->dev);
    if (!dcr) {
       BSOCK *dir = rctx.jcr->dir_bsock;
@@ -569,7 +632,6 @@ static int reserve_device(RCTX &rctx)
       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);
@@ -578,21 +640,33 @@ static int reserve_device(RCTX &rctx)
       if (rctx.exact_match && !rctx.have_volume) {
          dcr->any_volume = true;
          if (dir_find_next_appendable_volume(dcr)) {
-            Dmsg1(200, "Looking for Volume=%s\n", dcr->VolumeName);
+            Dmsg1(100, "Looking for Volume=%s\n", dcr->VolumeName);
             bstrncpy(rctx.VolumeName, dcr->VolumeName, sizeof(rctx.VolumeName));
             rctx.have_volume = true;
          } else {
-            Dmsg0(200, "No next volume found\n");
+            Dmsg0(100, "No next volume found\n");
             rctx.VolumeName[0] = 0;
         }
       }
       ok = reserve_device_for_append(dcr, rctx);
-      Dmsg3(200, "dev_name=%s mediatype=%s ok=%d\n", dcr->dev_name, dcr->media_type, ok);
+      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(100, "Not OK.\n");
       return 0;
    }
    return 1;
@@ -612,7 +686,7 @@ static bool reserve_device_for_read(DCR *dcr)
 
    ASSERT(dcr);
 
-   dev->block(BST_DOING_ACQUIRE);
+   P(dev->mutex);
 
    if (is_device_unmounted(dev)) {             
       Dmsg1(200, "Device %s is BLOCKED due to user unmount.\n", dev->print_name());
@@ -634,7 +708,7 @@ static bool reserve_device_for_read(DCR *dcr)
    ok = true;
 
 bail_out:
-   dev->unblock();
+   V(dev->mutex);
    return ok;
 }
 
@@ -662,68 +736,105 @@ static bool reserve_device_for_append(DCR *dcr, RCTX &rctx)
 
    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);
       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);
       goto bail_out;
    }
 
-   Dmsg1(190, "reserve_append device is %s\n", dev->is_tape()?"tape":"disk");
+   Dmsg1(100, "reserve_append device is %s\n", dev->is_tape()?"tape":"disk");
 
+   /* Now do detailed tests ... */
    if (can_reserve_drive(dcr, rctx) != 1) {
-      Dmsg1(100, "%s", jcr->errmsg);
+      Dmsg0(100, "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, RCTX &rctx) 
 {
    DEVICE *dev = dcr->dev;
    JCR *jcr = dcr->jcr;
 
-   /* Check for prefer mounted volumes */
-   if (rctx.PreferMountedVols && !dev->VolHdr.VolumeName[0] && dev->is_tape()) {
-      Mmsg0(jcr->errmsg, _("Want mounted Volume, drive is empty\n"));
-      Dmsg0(200, "want mounted -- no vol\n");
-      return 0;                 /* No volume mounted */
-   }
+   Dmsg5(100, "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);
 
-   /* Check for exact Volume name match */
-   if (rctx.exact_match && rctx.have_volume &&
-       strcmp(dev->VolHdr.VolumeName, rctx.VolumeName) != 0) {
-      Mmsg2(jcr->errmsg, _("Not exact match have=%s want=%s\n"),
-            dev->VolHdr.VolumeName, rctx.VolumeName);
-      Dmsg2(200, "Not exact match have=%s want=%s\n",
-            dev->VolHdr.VolumeName, rctx.VolumeName);
-      return 0;
+   /* 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(100, "OK dev=%s == low_drive=%s. JobId=%d\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(100, "set low use drive=%s num_writers=%d\n", dev->print_name(),
+               rctx.num_writers);
+         } else {
+            Dmsg1(100, "not low use num_writers=%d\n", dev->num_writers+ 
+               dev->reserved_device);
+         }
+         Dmsg1(100, "failed: !prefMnt && busy. JobId=%d\n", jcr->JobId);
+         return 0;
+      }
+
+      /* Check for prefer mounted volumes */
+      if (rctx.PreferMountedVols && !dev->VolHdr.VolumeName[0] && dev->is_tape()) {
+         Dmsg1(100, "failed: want mounted -- no vol JobId=%d\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) {
+         Dmsg2(100, "failed: Not exact match have=%s want=%s\n",
+               dev->VolHdr.VolumeName, rctx.VolumeName);
+         return 0;
+      }
    }
 
    /* Check for unused autochanger drive */
-   if (rctx.available_autochanger && dev->num_writers == 0 &&
+   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=%d.\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 */
@@ -739,13 +850,12 @@ 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 */
-            Dmsg0(200, "got dev: num_writers=0, reserved, pool matches\n");
+            Dmsg2(100, "OK dev: %s num_writers=0, reserved, pool matches JobId=%d\n",
+               dev->print_name(), jcr->JobId);
             return 1;
          } else {
             /* Drive not suitable for us */
-            Mmsg2(jcr->errmsg, _("Drive busy wrong pool: num_writers=0, reserved, pool=%s wanted=%s\n"),
-               dev->pool_name, dcr->pool_name);
-            Dmsg2(200, "busy: num_writers=0, reserved, pool=%s wanted=%s\n",
+            Dmsg2(100, "failed: busy num_writers=0, reserved, pool=%s wanted=%s\n",
                dev->pool_name, dcr->pool_name);
             return 0;                 /* wait */
          }
@@ -753,16 +863,19 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
          /* 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) {
-            Dmsg0(200, "got dev: num_writers=0, can_append, pool matches\n");
+            Dmsg2(100, "OK dev: %s num_writers=0, can_append, pool matches. JobId=%d\n",
+               dev->print_name(), jcr->JobId);
             /* OK, compatible device */
             return 1;
          } else {
             /* Changing pool, unload old tape if any in drive */
-            Dmsg0(200, "got dev: num_writers=0, reserved, pool change\n");
+            Dmsg0(100, "OK dev: num_writers=0, not reserved, pool change, unload changer\n");
             unload_autochanger(dcr, 0);
          }
       }
       /* Device is available but not yet reserved, reserve it for us */
+      Dmsg2(100, "OK Dev avail reserved %s JobId=%d\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 */
@@ -773,18 +886,16 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
     *  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) {
-         Dmsg0(200, "got dev: num_writers>=0, can_append, pool matches\n");
+         Dmsg2(100, "OK dev: %s num_writers>=0, can_append, pool matches. JobId=%d\n",
+            dev->print_name(), jcr->JobId);
          /* OK, compatible device */
          return 1;
       } else {
          /* Drive not suitable for us */
-         Mmsg(jcr->errmsg, _("Wanted Pool \"%s\", but device %s is using Pool \"%s\" .\n"), 
-                 dcr->pool_name, dev->print_name(), dev->pool_name);
-         Dmsg2(200, "busy: num_writers>0, can_append, pool=%s wanted=%s\n",
+         Dmsg2(100, "failed: busy num_writers>0, can_append, pool=%s wanted=%s\n",
             dev->pool_name, dcr->pool_name);
          return 0;                    /* wait */
       }
@@ -793,6 +904,6 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx)
       Jmsg0(jcr, M_FATAL, 0, _("Logic error!!!! Should not get here.\n"));
       return -1;                      /* error, should not get here */
    }
-
+   Dmsg2(100, "failed: No reserve %s JobId=%d\n", dev->print_name(), jcr->JobId);
    return 0;
 }