]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/stored/mount.c
Backport new lock calls + debug for SD
[bacula/bacula] / bacula / src / stored / mount.c
index 4b601e07dd21c36527dd96d59fb35fa654556b2d..dc1f38bc1927d543d64b4b373caf0cdc37b9c2a8 100644 (file)
@@ -1,12 +1,12 @@
 /*
    Bacula® - The Network Backup Solution
 
-   Copyright (C) 2002-2008 Free Software Foundation Europe e.V.
+   Copyright (C) 2002-2012 Free Software Foundation Europe e.V.
 
    The main author of Bacula is Kern Sibbald, with contributions from
    many others, a complete list can be found in the file AUTHORS.
    This program is Free Software; you can redistribute it and/or
-   modify it under the terms of version two of the GNU General Public
+   modify it under the terms of version three of the GNU Affero General Public
    License as published by the Free Software Foundation and included
    in the file LICENSE.
 
    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
+   You should have received a copy of the GNU Affero General Public License
    along with this program; if not, write to the Free Software
    Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
    02110-1301, USA.
 
-   Bacula® is a registered trademark of John Walker.
+   Bacula® is a registered trademark of Kern Sibbald.
    The licensor of Bacula is the Free Software Foundation Europe
    (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
    Switzerland, email:ftf@fsfeurope.org.
  *
  *   Kern Sibbald, August MMII
  *
- *   Version $Id$
  */
 
 #include "bacula.h"                   /* pull in global headers */
 #include "stored.h"                   /* pull in Storage Deamon headers */
 
-
 enum {
    try_next_vol = 1,
    try_read_vol,
@@ -64,6 +62,9 @@ enum {
  * This routine returns a 0 only if it is REALLY
  *  impossible to get the requested Volume.
  *
+ * This routine is entered with the device blocked, but not
+ *   locked.
+ *
  */
 bool DCR::mount_next_write_volume()
 {
@@ -72,72 +73,55 @@ bool DCR::mount_next_write_volume()
    int mode;
    DCR *dcr = this;
 
-   Dmsg2(150, "Enter mount_next_volume(release=%d) dev=%s\n", unload_device,
+   Dmsg2(150, "Enter mount_next_volume(release=%d) dev=%s\n", dev->must_unload(),
       dev->print_name());
 
    init_device_wait_timers(dcr);
-   lock_volumes();
    
    /*
     * Attempt to mount the next volume. If something non-fatal goes
     *  wrong, we come back here to re-try (new op messages, re-read
     *  Volume, ...)
     */
+   lock_volumes();
+
 mount_next_vol:
    Dmsg1(150, "mount_next_vol retry=%d\n", retry);
    /* Ignore retry if this is poll request */
-   if (!dev->poll && retry++ > 4) {
+   if (retry++ > 4) {
       /* Last ditch effort before giving up, force operator to respond */
       VolCatInfo.Slot = 0;
+      unlock_volumes();
       if (!dir_ask_sysop_to_mount_volume(dcr, ST_APPEND)) {
          Jmsg(jcr, M_FATAL, 0, _("Too many errors trying to mount device %s.\n"),
               dev->print_name());
-         goto bail_out;
+         goto no_lock_bail_out;
       }
+      lock_volumes();
+      Dmsg1(150, "Continue after dir_ask_sysop_to_mount. must_load=%d\n", dev->must_load());
    }
    if (job_canceled(jcr)) {
       Jmsg(jcr, M_FATAL, 0, _("Job %d canceled.\n"), jcr->JobId);
       goto bail_out;
    }
    recycle = false;
-   if (unload_device) {
-      Dmsg0(150, "mount_next_volume release=1\n");
-      release_volume(dcr);
-      unload_autochanger(dcr, -1);
-      unload_device = false;
+
+   if (dev->must_unload()) {
       ask = true;                     /* ask operator to mount tape */
    }
+   do_unload();
+   do_swapping(true /*is_writing*/);
+   do_load(true /*is_writing*/);
 
-   /*
-    * See if we are asked to swap the Volume from another device
-    *  if so, unload the other device here, and attach the
-    *  volume to our drive.
-    */
-   if (swap_dev) {
-      dev->vol = swap_dev->vol;      /* take its volume */
-      swap_dev->vol = NULL;
-      unload_dev(dcr, swap_dev);
-      swap_dev = NULL;
-   }
-   if (!is_suitable_volume_mounted()) {
-      /*
-       * Get Director's idea of what tape we should have mounted.
-       *    in dcr->VolCatInfo
-       */
-      Dmsg0(200, "Before dir_find_next_appendable_volume.\n");
-      while (!dir_find_next_appendable_volume(dcr)) {
-         Dmsg0(200, "not dir_find_next\n");
-         if (!dir_ask_sysop_to_create_appendable_volume(dcr)) {
-            goto bail_out;
-          }
-          Dmsg0(200, "Again dir_find_next_append...\n");
-      }
+   if (!find_a_volume()) {
+      goto bail_out;
    }
+
    if (job_canceled(jcr)) {
       goto bail_out;
    }
    Dmsg3(150, "After find_next_append. Vol=%s Slot=%d Parts=%d\n",
-         VolCatInfo.VolCatName, VolCatInfo.Slot, VolCatInfo.VolCatParts);
+         getVolCatName(), VolCatInfo.Slot, VolCatInfo.VolCatParts);
    
    /*
     * Get next volume and ready it for append
@@ -150,35 +134,41 @@ mount_next_vol:
     * and move the tape to the end of data.
     *
     */
-   if (autoload_device(dcr, 1, NULL) > 0) {
+   dcr->setVolCatInfo(false);   /* out of date when Vols unlocked */
+   if (autoload_device(dcr, true/*writing*/, NULL) > 0) {
       autochanger = true;
       ask = false;
    } else {
       autochanger = false;
       VolCatInfo.Slot = 0;
+      ask = retry >= 2;
    }
-   Dmsg1(200, "autoload_dev returns %d\n", autochanger);
+   Dmsg1(150, "autoload_dev returns %d\n", autochanger);
    /*
     * If we autochanged to correct Volume or (we have not just
     *   released the Volume AND we can automount) we go ahead
     *   and read the label. If there is no tape in the drive,
     *   we will fail, recurse and ask the operator the next time.
     */
-   if (!unload_device && dev->is_tape() && dev->has_cap(CAP_AUTOMOUNT)) {
-      Dmsg0(150, "(1)Ask=0\n");
+   if (!dev->must_unload() && dev->is_tape() && dev->has_cap(CAP_AUTOMOUNT)) {
+      Dmsg0(250, "(1)Ask=0\n");
       ask = false;                 /* don't ask SYSOP this time */
    }
    /* Don't ask if not removable */
    if (!dev->is_removable()) {
-      Dmsg0(150, "(2)Ask=0\n");
+      Dmsg0(250, "(2)Ask=0\n");
       ask = false;
    }
-   Dmsg2(150, "Ask=%d autochanger=%d\n", ask, autochanger);
-   unload_device = true;     /* release next time if we "recurse" */
+   Dmsg2(250, "Ask=%d autochanger=%d\n", ask, autochanger);
 
-   if (ask && !dir_ask_sysop_to_mount_volume(dcr, ST_APPEND)) {
-      Dmsg0(150, "Error return ask_sysop ...\n");
-      goto bail_out;          /* error return */
+   if (ask) {
+      unlock_volumes();
+      dcr->setVolCatInfo(false);   /* out of date when Vols unlocked */
+      if (!dir_ask_sysop_to_mount_volume(dcr, ST_APPEND)) {
+         Dmsg0(150, "Error return ask_sysop ...\n");
+         goto no_lock_bail_out;
+      }
+      lock_volumes();
    }
    if (job_canceled(jcr)) {
       goto bail_out;
@@ -188,6 +178,7 @@ mount_next_vol:
 
    if (dev->poll && dev->has_cap(CAP_CLOSEONPOLL)) {
       dev->close();
+      free_volume(dev);
    }
 
    /* Ensure the device is open */
@@ -197,10 +188,10 @@ mount_next_vol:
       mode = OPEN_READ_WRITE;
    }
    /* Try autolabel if enabled */
-   if (dev->open(dcr, mode) < 0) {
+   if (!dev->open(dcr, mode)) {
       try_autolabel(false);      /* try to create a new volume label */
    }
-   while (dev->open(dcr, mode) < 0) {
+   while (!dev->open(dcr, mode)) {
       Dmsg1(150, "open_device failed: ERR=%s\n", dev->bstrerror());
       if ((dev->is_file() && dev->is_removable()) || dev->is_dvd()) {
          bool ok = true;
@@ -211,7 +202,7 @@ mount_next_vol:
             }
          }
          if (ok && dev->scan_dir_for_volume(dcr)) {
-            if (dev->open(dcr, mode) >= 0) {
+            if (dev->open(dcr, mode)) {
                break;                    /* got a valid volume */
             }
          }
@@ -222,24 +213,24 @@ mount_next_vol:
       if (try_autolabel(false) == try_read_vol) {
          break;                       /* created a new volume label */
       }
-      /* If DVD, ignore the error, very often you cannot open the device
-       * (when there is no DVD, or when the one inserted is a wrong one) */
-      if (dev->poll || dev->is_dvd() || dev->is_removable()) {
-         goto mount_next_vol;
-      } else {
-         Jmsg(jcr, M_ERROR, 0, _("Could not open device %s: ERR=%s\n"),
-            dev->print_name(), dev->print_errmsg());
-         goto bail_out;
-      }
+      Jmsg3(jcr, M_WARNING, 0, _("Open device %s Volume \"%s\" failed: ERR=%s\n"),
+            dev->print_name(), dcr->VolumeName, dev->bstrerror());
+      Dmsg0(50, "set_unload\n");
+      dev->set_unload();              /* force ask sysop */
+      ask = true;
+      Dmsg0(150, "goto mount_next_vol\n");
+      goto mount_next_vol;
    }
 
    /*
     * Now check the volume label to make sure we have the right tape mounted
     */
 read_volume:
-
    switch (check_volume_label(ask, autochanger)) {
    case check_next_vol:
+      Dmsg0(50, "set_unload\n");
+      dev->set_unload();                 /* want a different Volume */
+      Dmsg0(150, "goto mount_next_vol\n");
       goto mount_next_vol;
    case check_read_vol:
       goto read_volume;
@@ -248,6 +239,16 @@ read_volume:
    case check_ok:
       break;
    }
+   /*
+    * Check that volcatinfo is good   
+    */
+   if (!dev->haveVolCatInfo()) {
+      Dmsg0(210, "Do not have volcatinfo\n");
+      if (!find_a_volume()) {
+         goto mount_next_vol;
+      }
+      dev->VolCatInfo = VolCatInfo;      /* structure assignment */
+   }
 
    /*
     * See if we have a fresh tape or a tape with data.
@@ -264,7 +265,7 @@ read_volume:
     */
    recycle = strcmp(dev->VolCatInfo.VolCatStatus, "Recycle") == 0;
    if (dev->VolHdr.LabelType == PRE_LABEL || recycle) {
-      if (!rewrite_volume_label(dcr, recycle)) {
+      if (!dcr->rewrite_volume_label(recycle)) {
          mark_volume_in_error();
          goto mount_next_vol;
       }
@@ -274,17 +275,21 @@ read_volume:
        * we need to position to the end of the volume, since we are
        * just now putting it into append mode.
        */
-      Dmsg0(200, "Device previously written, moving to end of data\n");
+      Dmsg1(100, "Device previously written, moving to end of data. Expect %lld bytes\n",
+           dev->VolCatInfo.VolCatBytes);
       Jmsg(jcr, M_INFO, 0, _("Volume \"%s\" previously written, moving to end of data.\n"),
          VolumeName);
 
       if (!dev->eod(dcr)) {
+         Dmsg2(050, "Unable to position to end of data on device %s: ERR=%s\n", 
+            dev->print_name(), dev->bstrerror());
          Jmsg(jcr, M_ERROR, 0, _("Unable to position to end of data on device %s: ERR=%s\n"),
             dev->print_name(), dev->bstrerror());
          mark_volume_in_error();
          goto mount_next_vol;
       }
       if (!is_eod_valid()) {
+         Dmsg0(100, "goto mount_next_vol\n");
          goto mount_next_vol;
       }
 
@@ -306,9 +311,58 @@ read_volume:
 
 bail_out:
    unlock_volumes();
+
+no_lock_bail_out:
    return false;
 }
 
+/*
+ * This routine is meant to be called once the first pass
+ *   to ensure that we have a candidate volume to mount.
+ *   Otherwise, we ask the sysop to created one.
+ * Note, the the Volumes are locked on entry and exit.
+ */
+bool DCR::find_a_volume()
+{
+   DCR *dcr = this;
+
+   if (!is_suitable_volume_mounted()) {
+      bool have_vol = false;
+      /* Do we have a candidate volume? */
+      if (dev->vol) {
+         bstrncpy(VolumeName, dev->vol->vol_name, sizeof(VolumeName));
+         have_vol = dir_get_volume_info(this, GET_VOL_INFO_FOR_WRITE);
+      }
+      /*
+       * Get Director's idea of what tape we should have mounted.
+       *    in dcr->VolCatInfo
+       */
+      if (!have_vol) {
+         Dmsg0(200, "Before dir_find_next_appendable_volume.\n");
+         while (!dir_find_next_appendable_volume(dcr)) {
+            Dmsg0(200, "not dir_find_next\n");
+            if (job_canceled(jcr)) {
+               return false;
+            }
+            unlock_volumes();
+            if (!dir_ask_sysop_to_create_appendable_volume(dcr)) {
+               lock_volumes();
+               return false;
+             }
+             lock_volumes();
+             if (job_canceled(jcr)) {
+                return false;
+             }
+             Dmsg0(150, "Again dir_find_next_append...\n");
+         }
+      }
+   }
+   if (dcr->haveVolCatInfo()) {
+      return true;
+   }
+   return dir_get_volume_info(dcr, GET_VOL_INFO_FOR_WRITE);
+}
+
 int DCR::check_volume_label(bool &ask, bool &autochanger)
 {
    int vol_label_status;
@@ -329,18 +383,25 @@ int DCR::check_volume_label(bool &ask, bool &autochanger)
 
    Dmsg2(150, "Want dirVol=%s dirStat=%s\n", VolumeName,
       VolCatInfo.VolCatStatus);
+
    /*
     * At this point, dev->VolCatInfo has what is in the drive, if anything,
     *          and   dcr->VolCatInfo has what the Director wants.
     */
    switch (vol_label_status) {
    case VOL_OK:
-      Dmsg1(150, "Vol OK name=%s\n", VolumeName);
+      Dmsg1(150, "Vol OK name=%s\n", dev->VolHdr.VolumeName);
       dev->VolCatInfo = VolCatInfo;       /* structure assignment */
       break;                    /* got a Volume */
    case VOL_NAME_ERROR:
       VOLUME_CAT_INFO dcrVolCatInfo, devVolCatInfo;
-      char VolumeName[MAX_NAME_LENGTH];
+      char saveVolumeName[MAX_NAME_LENGTH];
+
+      Dmsg2(150, "Vol NAME Error Have=%s, want=%s\n", dev->VolHdr.VolumeName, VolumeName);
+      if (dev->is_volume_to_unload()) {
+         ask = true;
+         goto check_next_volume;
+      }
 
       /* If not removable, Volume is broken */
       if (!dev->is_removable()) {
@@ -350,13 +411,6 @@ int DCR::check_volume_label(bool &ask, bool &autochanger)
          goto check_next_volume;
       }
 
-      Dmsg1(150, "Vol NAME Error Name=%s\n", VolumeName);
-      /* If polling and got a previous bad name, ignore it */
-      if (dev->poll && strcmp(dev->BadVolName, dev->VolHdr.VolumeName) == 0) {
-         ask = true;
-         Dmsg1(200, "Vol Name error supress due to poll. Name=%s\n", VolumeName);
-         goto check_next_volume;
-      }
       /*
        * OK, we got a different volume mounted. First save the
        *  requested Volume info (dcr) structure, then query if
@@ -366,7 +420,7 @@ int DCR::check_volume_label(bool &ask, bool &autochanger)
       dcrVolCatInfo = VolCatInfo;      /* structure assignment */
       devVolCatInfo = dev->VolCatInfo;      /* structure assignment */
       /* Check if this is a valid Volume in the pool */
-      bstrncpy(VolumeName, VolumeName, sizeof(VolumeName));
+      bstrncpy(saveVolumeName, VolumeName, sizeof(saveVolumeName));
       bstrncpy(VolumeName, dev->VolHdr.VolumeName, sizeof(VolumeName));
       if (!dir_get_volume_info(this, GET_VOL_INFO_FOR_WRITE)) {
          POOL_MEM vol_info_msg;
@@ -383,7 +437,7 @@ int DCR::check_volume_label(bool &ask, bool &autochanger)
             mark_volume_not_inchanger();
          }
          dev->VolCatInfo = devVolCatInfo;    /* structure assignment */
-         bstrncpy(dev->BadVolName, dev->VolHdr.VolumeName, sizeof(dev->BadVolName));
+         dev->set_unload();                  /* unload this volume */
          Jmsg(jcr, M_WARNING, 0, _("Director wanted Volume \"%s\".\n"
               "    Current Volume \"%s\" not acceptable because:\n"
               "    %s"),
@@ -391,7 +445,7 @@ int DCR::check_volume_label(bool &ask, bool &autochanger)
              vol_info_msg.c_str());
          ask = true;
          /* Restore saved DCR before continuing */
-         bstrncpy(VolumeName, VolumeName, sizeof(VolumeName));
+         bstrncpy(VolumeName, saveVolumeName, sizeof(VolumeName));
          VolCatInfo = dcrVolCatInfo;  /* structure assignment */
          goto check_next_volume;
       }
@@ -399,8 +453,17 @@ int DCR::check_volume_label(bool &ask, bool &autochanger)
        * This was not the volume we expected, but it is OK with
        * the Director, so use it.
        */
-      Dmsg1(150, "want new name=%s\n", VolumeName);
+      Dmsg1(150, "Got new Volume name=%s\n", VolumeName);
       dev->VolCatInfo = VolCatInfo;   /* structure assignment */
+      Dmsg1(100, "Call reserve_volume=%s\n", dev->VolHdr.VolumeName);
+      if (reserve_volume(this, dev->VolHdr.VolumeName) == NULL) {
+         Jmsg2(jcr, M_WARNING, 0, _("Could not reserve volume %s on %s\n"),
+            dev->VolHdr.VolumeName, dev->print_name());
+         ask = true;
+         dev->setVolCatInfo(false);
+         setVolCatInfo(false);
+         goto check_next_volume;
+      }
       break;                /* got a Volume */
    /*
     * At this point, we assume we have a blank tape mounted.
@@ -423,7 +486,6 @@ int DCR::check_volume_label(bool &ask, bool &autochanger)
       case try_default:
          break;
       }
-
       /* NOTE! Fall-through wanted. */
    case VOL_NO_MEDIA:
    default:
@@ -437,12 +499,15 @@ int DCR::check_volume_label(bool &ask, bool &autochanger)
       /* Needed, so the medium can be changed */
       if (dev->requires_mount()) {
          dev->close();
+         free_volume(dev);
       }
       goto check_next_volume;
    }
    return check_ok;
 
 check_next_volume:
+   dev->setVolCatInfo(false);
+   setVolCatInfo(false);
    return check_next_vol;
 
 check_bail_out:
@@ -456,15 +521,71 @@ check_read_volume:
 
 bool DCR::is_suitable_volume_mounted()
 {
-
    /* Volume mounted? */
-   if (dev->VolHdr.VolumeName[0] == 0 || swap_dev || unload_device) {
+   if (dev->VolHdr.VolumeName[0] == 0 || dev->swap_dev || dev->must_unload()) {
       return false;                      /* no */
    }
    bstrncpy(VolumeName, dev->VolHdr.VolumeName, sizeof(VolumeName));
    return dir_get_volume_info(this, GET_VOL_INFO_FOR_WRITE);
 }
 
+bool DCR::do_unload()
+{
+   if (dev->must_unload()) {
+      Dmsg1(100, "must_unload release %s\n", dev->print_name());
+      release_volume();
+   }
+   return false;
+}
+
+bool DCR::do_load(bool is_writing)
+{
+   if (dev->must_load()) {
+      Dmsg1(100, "Must load %s\n", dev->print_name());
+      if (autoload_device(this, is_writing, NULL) > 0) {
+         dev->clear_load();
+         return true;
+      }
+      return false;
+   }
+   return true;
+}
+
+void DCR::do_swapping(bool is_writing)
+{
+   /*
+    * See if we are asked to swap the Volume from another device
+    *  if so, unload the other device here, and attach the
+    *  volume to our drive.
+    */
+   if (dev->swap_dev) {
+      if (dev->swap_dev->must_unload()) {
+         if (dev->vol) {
+            dev->swap_dev->set_slot(dev->vol->get_slot());
+         }
+         Dmsg2(100, "Swap unloading slot=%d %s\n", dev->swap_dev->get_slot(),
+               dev->swap_dev->print_name());
+         unload_dev(this, dev->swap_dev);
+      }
+      if (dev->vol) {
+         dev->vol->clear_swapping();
+         Dmsg1(100, "=== set in_use vol=%s\n", dev->vol->vol_name);
+         dev->vol->set_in_use();
+         dev->VolHdr.VolumeName[0] = 0;  /* don't yet have right Volume */
+      } else {
+         Dmsg1(100, "No vol on dev=%s\n", dev->print_name());
+      }
+      if (dev->swap_dev->vol) {
+         Dmsg2(100, "Vol=%s on dev=%s\n", dev->swap_dev->vol->vol_name,
+              dev->swap_dev->print_name());
+      }
+      Dmsg2(100, "Set swap_dev=NULL for dev=%s swap_dev=%s\n",
+         dev->print_name(), dev->swap_dev->print_name());
+      dev->swap_dev = NULL;
+   } else {
+      Dmsg0(100, "No swap_dev set\n");
+   }
+}
 
 
 /*
@@ -496,6 +617,18 @@ bool DCR::is_eod_valid()
       if (dev->VolCatInfo.VolCatFiles == dev->get_file()) {
          Jmsg(jcr, M_INFO, 0, _("Ready to append to end of Volume \"%s\" at file=%d.\n"),
               VolumeName, dev->get_file());
+      } else if (dev->get_file() > dev->VolCatInfo.VolCatFiles) {
+         Jmsg(jcr, M_WARNING, 0, _("For Volume \"%s\":\n"
+              "The number of files mismatch! Volume=%u Catalog=%u\n"
+              "Correcting Catalog\n"),
+              VolumeName, dev->get_file(), dev->VolCatInfo.VolCatFiles);
+         dev->VolCatInfo.VolCatFiles = dev->get_file();
+         dev->VolCatInfo.VolCatBlocks = dev->get_block_num();
+         if (!dir_update_volume_info(this, false, true)) {
+            Jmsg(jcr, M_WARNING, 0, _("Error updating Catalog\n"));
+            mark_volume_in_error();
+            return false;
+         }
       } else {
          Jmsg(jcr, M_ERROR, 0, _("Bacula cannot write on tape Volume \"%s\" because:\n"
               "The number of files mismatch! Volume=%u Catalog=%u\n"),
@@ -511,12 +644,27 @@ bool DCR::is_eod_valid()
          Jmsg(jcr, M_INFO, 0, _("Ready to append to end of Volume \"%s\""
               " size=%s\n"), VolumeName, 
               edit_uint64(dev->VolCatInfo.VolCatBytes, ed1));
+      } else if ((uint64_t)pos > dev->VolCatInfo.VolCatBytes) {
+         Jmsg(jcr, M_WARNING, 0, _("For Volume \"%s\":\n"
+              "The sizes do not match! Volume=%s Catalog=%s\n"
+              "Correcting Catalog\n"),
+              VolumeName, edit_uint64(pos, ed1), 
+              edit_uint64(dev->VolCatInfo.VolCatBytes, ed2));
+         dev->VolCatInfo.VolCatBytes = (uint64_t)pos;
+         dev->VolCatInfo.VolCatFiles = (uint32_t)(pos >> 32);
+         if (!dir_update_volume_info(this, false, true)) {
+            Jmsg(jcr, M_WARNING, 0, _("Error updating Catalog\n"));
+            mark_volume_in_error();
+            return false;
+         }
       } else {
-         Jmsg(jcr, M_ERROR, 0, _("Bacula cannot write on disk Volume \"%s\" because: "
+         Mmsg(jcr->errmsg, _("Bacula cannot write on disk Volume \"%s\" because: "
               "The sizes do not match! Volume=%s Catalog=%s\n"),
               VolumeName,
               edit_uint64(pos, ed1),
               edit_uint64(dev->VolCatInfo.VolCatBytes, ed2));
+         Jmsg(jcr, M_ERROR, 0, jcr->errmsg);
+         Dmsg0(050, jcr->errmsg);
          mark_volume_in_error();
          return false;
       }
@@ -560,7 +708,8 @@ int DCR::try_autolabel(bool opened)
       /* Create a new Volume label and write it to the device */
       if (!write_new_volume_label_to_dev(dcr, VolumeName,
              pool_name, false, /* no relabel */ false /* defer DVD label */)) {
-         Dmsg0(150, "!write_vol_label\n");
+         Dmsg2(150, "write_vol_label failed. vol=%s, pool=%s\n",
+           VolumeName, pool_name);
          if (opened) { 
             mark_volume_in_error();
          }
@@ -598,11 +747,13 @@ void DCR::mark_volume_in_error()
 {
    Jmsg(jcr, M_INFO, 0, _("Marking Volume \"%s\" in Error in Catalog.\n"),
         VolumeName);
-   dev->VolCatInfo = VolCatInfo;     /* structure assignment */
+   dev->VolCatInfo = VolCatInfo;       /* structure assignment */
    bstrncpy(dev->VolCatInfo.VolCatStatus, "Error", sizeof(dev->VolCatInfo.VolCatStatus));
    Dmsg0(150, "dir_update_vol_info. Set Error.\n");
    dir_update_volume_info(this, false, false);
    volume_unused(this);
+   Dmsg0(50, "set_unload\n");
+   dev->set_unload();                 /* must get a new volume */
 }
 
 /*
@@ -613,7 +764,7 @@ void DCR::mark_volume_not_inchanger()
 {
    Jmsg(jcr, M_ERROR, 0, _("Autochanger Volume \"%s\" not found in slot %d.\n"
 "    Setting InChanger to zero in catalog.\n"),
-        VolCatInfo.VolCatName, VolCatInfo.Slot);
+        getVolCatName(), VolCatInfo.Slot);
    dev->VolCatInfo = VolCatInfo;    /* structure assignment */
    VolCatInfo.InChanger = false;
    dev->VolCatInfo.InChanger = false;
@@ -625,13 +776,13 @@ void DCR::mark_volume_not_inchanger()
  * Either because we are going to hang a new volume, or because
  *  of explicit user request, we release the current volume.
  */
-void release_volume(DCR *dcr)
+void DCR::release_volume()
 {
-   JCR *jcr = dcr->jcr;
-   DEVICE *dev = dcr->dev;
-   if (dcr->WroteVol) {
+   unload_autochanger(this, -1);
+
+   if (WroteVol) {
       Jmsg0(jcr, M_ERROR, 0, _("Hey!!!!! WroteVol non-zero !!!!!\n"));
-      Dmsg0(190, "Hey!!!!! WroteVol non-zero !!!!!\n");
+      Pmsg0(190, "Hey!!!!! WroteVol non-zero !!!!!\n");
    }
    /*
     * First erase all memory of the current volume
@@ -640,14 +791,13 @@ void release_volume(DCR *dcr)
    dev->block_num = dev->file = 0;
    dev->EndBlock = dev->EndFile = 0;
    memset(&dev->VolCatInfo, 0, sizeof(dev->VolCatInfo));
-// memset(&dcr->VolCatInfo, 0, sizeof(dcr->VolCatInfo));
    dev->clear_volhdr();
    /* Force re-read of label */
    dev->clear_labeled();
    dev->clear_read();
    dev->clear_append();
    dev->label_type = B_BACULA_LABEL;
-// dcr->VolumeName[0] = 0;
+   VolumeName[0] = 0;
 
    if (dev->is_open() && (!dev->is_tape() || !dev->has_cap(CAP_ALWAYSOPEN))) {
       dev->close();
@@ -660,6 +810,44 @@ void release_volume(DCR *dcr)
    Dmsg0(190, "release_volume\n");
 }
 
+/*
+ *      Insanity check 
+ *
+ * Check to see if the tape position as defined by the OS is
+ *  the same as our concept.  If it is not, 
+ *  it means the user has probably manually rewound the tape.
+ * Note, we check only if num_writers == 0, but this code will
+ *  also work fine for any number of writers. If num_writers > 0,
+ *  we probably should cancel all jobs using this device, or 
+ *  perhaps even abort the SD, or at a minimum, mark the tape
+ *  in error.  Another strategy with num_writers == 0, would be
+ *  to rewind the tape and do a new eod() request.
+ */
+bool DCR::is_tape_position_ok()
+{
+   if (dev->is_tape() && dev->num_writers == 0) {
+      int32_t file = dev->get_os_tape_file();
+      if (file >= 0 && file != (int32_t)dev->get_file()) {
+         Jmsg(jcr, M_ERROR, 0, _("Invalid tape position on volume \"%s\"" 
+              " on device %s. Expected %d, got %d\n"), 
+              dev->VolHdr.VolumeName, dev->print_name(), dev->get_file(), file);
+         /* 
+          * If the current file is greater than zero, it means we probably
+          *  have some bad count of EOF marks, so mark tape in error.  Otherwise
+          *  the operator might have moved the tape, so we just release it
+          *  and try again.
+          */
+         if (file > 0) {
+            mark_volume_in_error();
+         }
+         release_volume();
+         return false;
+      }
+   }
+   return true;
+}
+
+
 /*
  * If we are reading, we come here at the end of the tape
  *  and see if there are more volumes to be mounted.
@@ -675,7 +863,11 @@ bool mount_next_read_volume(DCR *dcr)
     * End Of Tape -- mount next Volume (if another specified)
     */
    if (jcr->NumReadVolumes > 1 && jcr->CurReadVolume < jcr->NumReadVolumes) {
+      dev->Lock();
       dev->close();
+      dev->set_read();
+      dcr->set_reserved();
+      dev->Unlock();
       if (!acquire_device_for_read(dcr)) {
          Jmsg2(jcr, M_FATAL, 0, _("Cannot open Dev=%s, Vol=%s\n"), dev->print_name(),
                dcr->VolumeName);