From bd250bd7b853e110f1aab44d7e008df8a757a858 Mon Sep 17 00:00:00 2001
From: Kern Sibbald <kern@sibbald.com>
Date: Thu, 13 Mar 2008 21:59:29 +0000
Subject: [PATCH] Reservation tweaks + more debug output

git-svn-id: https://bacula.svn.sourceforge.net/svnroot/bacula/trunk@6608 91ce42f0-d328-0410-95d8-f526ca767f89
---
 bacula/src/stored/ansi_label.c |  1 +
 bacula/src/stored/askdir.c     |  2 +-
 bacula/src/stored/label.c      |  2 ++
 bacula/src/stored/reserve.c    | 19 ++++++++++++++-----
 4 files changed, 18 insertions(+), 6 deletions(-)

diff --git a/bacula/src/stored/ansi_label.c b/bacula/src/stored/ansi_label.c
index 8796ad4823..237064b6d9 100644
--- a/bacula/src/stored/ansi_label.c
+++ b/bacula/src/stored/ansi_label.c
@@ -147,6 +147,7 @@ int read_ansi_ibm_label(DCR *dcr)
                   *q++ = *p++;
                }
                *q = 0;
+               Dmsg0(100, "Call reserve_volume\n");
                reserve_volume(dcr, dev->VolHdr.VolumeName);
                dev = dcr->dev;            /* may have changed in reserve_volume */
                Dmsg2(100, "Wanted ANSI Vol %s got %6s\n", VolName, dev->VolHdr.VolumeName);
diff --git a/bacula/src/stored/askdir.c b/bacula/src/stored/askdir.c
index b964455c7e..03a5f84c29 100644
--- a/bacula/src/stored/askdir.c
+++ b/bacula/src/stored/askdir.c
@@ -274,7 +274,7 @@ bool dir_find_next_appendable_volume(DCR *dcr)
        bool ok = do_get_volume_info(dcr);
        if (ok) {
           if (!is_volume_in_use(dcr)) {
-             Dmsg1(100, "Attempt reserve. Vol=%s\n", dcr->VolumeName);
+             Dmsg1(100, "Call reserve_volume. Vol=%s\n", dcr->VolumeName);
              if (reserve_volume(dcr, dcr->VolumeName) == 0) {
                 Dmsg2(100, "Could not reserve volume %s on %s\n", dcr->VolumeName,
                     dcr->dev->print_name());
diff --git a/bacula/src/stored/label.c b/bacula/src/stored/label.c
index 19d5630990..ccf657c5ea 100644
--- a/bacula/src/stored/label.c
+++ b/bacula/src/stored/label.c
@@ -212,6 +212,7 @@ int read_dev_volume_label(DCR *dcr)
    }
 
    dev->set_labeled();               /* set has Bacula label */
+   Dmsg0(100, "Call reserve_volume\n");
    if (reserve_volume(dcr, dev->VolHdr.VolumeName) == NULL) {
       Mmsg2(jcr->errmsg, _("Could not reserve volume %s on %s\n"),
            dev->VolHdr.VolumeName, dev->print_name());
@@ -401,6 +402,7 @@ bool write_new_volume_label_to_dev(DCR *dcr, const char *VolName,
    if (debug_level >= 20)  {
       dump_volume_label(dev);
    }
+   Dmsg0(100, "Call reserve_volume\n");
    if (reserve_volume(dcr, VolName) == NULL) {
       Mmsg2(dcr->jcr->errmsg, _("Could not reserve volume %s on %s\n"),
            dev->VolHdr.VolumeName, dev->print_name());
diff --git a/bacula/src/stored/reserve.c b/bacula/src/stored/reserve.c
index 2e21cf9bf3..7289fc3641 100644
--- a/bacula/src/stored/reserve.c
+++ b/bacula/src/stored/reserve.c
@@ -531,7 +531,7 @@ bool volume_unused(DCR *dcr)
     *  explicitly read in this drive. This allows the SD to remember
     *  where the tapes are or last were.
     */
-   Dmsg3(dbglvl, "=== mark released vol=%s num_writers=%d reserved=%d\n",
+   Dmsg3(dbglvl, "=== mark released vol=%s num_writers=%d dev_reserved=%d\n",
       dev->vol->vol_name, dev->num_writers, dev->reserved_device);
    dev->vol->released = true;
    if (dev->is_tape()) { // || dev->is_autochanger()) {
@@ -564,7 +564,8 @@ bool free_volume(DEVICE *dev)
    free_vol_item(vol);
    debug_list_volumes("free_volume");
    unlock_volumes();
-   return vol != NULL;
+// return vol != NULL;
+   return true;
 }
 
       
@@ -873,6 +874,10 @@ static bool is_vol_in_autochanger(RCTX &rctx, VOLRES *vol)
 
 /*
  * Search for a device suitable for this job.
+ * Note, this routine sets sets rctx.suitable_device if any 
+ *   device exists within the SD.  The device may not be actually
+ *   useable.
+ * It also returns if it finds a useable device.  
  */
 bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx)
 {
@@ -1003,7 +1008,7 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx)
       debug_list_volumes("=== After free temp table\n");
    }
    if (ok) {
-      Dmsg1(dbglvl, "got vol %s from in-use vols list\n", rctx.VolumeName);
+      Dmsg1(dbglvl, "Usable dev found. Vol=%s from in-use vols list\n", rctx.VolumeName);
       return true;
    }
 
@@ -1024,16 +1029,19 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx)
             ok = true;
             break;
          } else if (stat == 0) {      /* device busy */
-            Dmsg1(dbglvl, "Suitable device=%s, busy: not use\n", device_name);
+            Dmsg1(dbglvl, "No usable device=%s, busy: not use\n", device_name);
          } else {
             /* otherwise error */
-            Dmsg0(dbglvl, "No suitable device found.\n");
+            Dmsg0(dbglvl, "No usable device found.\n");
          }
       }
       if (ok) {
          break;
       }
    }
+   if (ok) {
+      Dmsg1(dbglvl, "Usable dev found. Vol=%s\n", rctx.VolumeName);
+   }
    return ok;
 }
 
@@ -1161,6 +1169,7 @@ static int reserve_device(RCTX &rctx)
       Dmsg3(dbglvl, "Vol=%s num_writers=%d, have_vol=%d\n", 
          rctx.VolumeName, dcr->dev->num_writers, rctx.have_volume);
       if (rctx.have_volume) {
+         Dmsg0(dbglvl, "Call reserve_volume\n");
          if (reserve_volume(dcr, rctx.VolumeName)) {
             Dmsg1(dbglvl, "Reserved vol=%s\n", rctx.VolumeName);
          } else {
-- 
2.39.5