]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/stored/askdir.c
This commit was manufactured by cvs2svn to create tag
[bacula/bacula] / bacula / src / stored / askdir.c
index 116a650f4d90413ed93b9fe59c5f49db66e0b736..9c40f80aa3730086d30c53d32f43be29099fe7c2 100644 (file)
@@ -7,7 +7,7 @@
  *   Version $Id$
  */
 /*
-   Copyright (C) 2000-2004 Kern Sibbald and John Walker
+   Copyright (C) 2000-2005 Kern Sibbald
 
    This program is free software; you can redistribute it and/or
    modify it under the terms of the GNU General Public License as
@@ -40,7 +40,7 @@ static char Create_job_media[] = "CatReq Job=%s CreateJobMedia"
    " FirstIndex=%u LastIndex=%u StartFile=%u EndFile=%u" 
    " StartBlock=%u EndBlock=%u\n";
 static char FileAttributes[] = "UpdCat Job=%s FileAttributes ";
-static char Job_status[]     = "3012 Job %s jobstatus %d\n";
+static char Job_status[]     = "Status Job=%s JobStatus=%d\n";
 
 
 /* Responses received from the Director */
@@ -48,13 +48,13 @@ static char OK_media[] = "1000 OK VolName=%127s VolJobs=%u VolFiles=%u"
    " VolBlocks=%u VolBytes=%" lld " VolMounts=%u VolErrors=%u VolWrites=%u"
    " MaxVolBytes=%" lld " VolCapacityBytes=%" lld " VolStatus=%20s"
    " Slot=%d MaxVolJobs=%u MaxVolFiles=%u InChanger=%d"
-   " VolReadTime=%" lld " VolWriteTime=%" lld;
+   " VolReadTime=%" lld " VolWriteTime=%" lld " EndFile=%u EndBlock=%u";
 
 
 static char OK_create[] = "1000 OK CreateJobMedia\n";
 
 /* Forward referenced functions */
-static int wait_for_sysop(JCR *jcr, DEVICE *dev);
+static int wait_for_sysop(DCR *dcr);
 
 /*
  * Send current JobStatus to Director
@@ -70,26 +70,25 @@ bool dir_send_job_status(JCR *jcr)
  * and
  *   dir_find_next_appendable_volume()
  * 
- *  Returns: true  on success and vol info in jcr->VolCatInfo
+ *  Returns: true  on success and vol info in dcr->VolCatInfo
  *          false on failure
  */
-static bool do_get_volume_info(JCR *jcr)
+static bool do_get_volume_info(DCR *dcr)
 {
+    JCR *jcr = dcr->jcr;
     BSOCK *dir = jcr->dir_bsock;
-    DCR *dcr = jcr->dcr;
     VOLUME_CAT_INFO vol;
     int n;
     int InChanger;
 
-    jcr->VolumeName[0] = 0;          /* No volume */
     dcr->VolumeName[0] = 0;          /* No volume */
     if (bnet_recv(dir) <= 0) {
        Dmsg0(200, "getvolname error bnet_recv\n");
-       Mmsg(&jcr->errmsg, _("Network error on bnet_recv in req_vol_info.\n"));
+       Mmsg(jcr->errmsg, _("Network error on bnet_recv in req_vol_info.\n"));
        return false;
     }
     memset(&vol, 0, sizeof(vol));
-    Dmsg1(200, "Get vol info=%s\n", dir->msg);
+    Dmsg1(300, "Get vol info=%s", dir->msg);
     n = sscanf(dir->msg, OK_media, vol.VolCatName, 
               &vol.VolCatJobs, &vol.VolCatFiles,
               &vol.VolCatBlocks, &vol.VolCatBytes,
@@ -97,20 +96,19 @@ static bool do_get_volume_info(JCR *jcr)
               &vol.VolCatWrites, &vol.VolCatMaxBytes,
               &vol.VolCatCapacityBytes, vol.VolCatStatus,
               &vol.Slot, &vol.VolCatMaxJobs, &vol.VolCatMaxFiles,
-              &InChanger, &vol.VolReadTime, &vol.VolWriteTime);
-    if (n != 17) {
+              &InChanger, &vol.VolReadTime, &vol.VolWriteTime,
+              &vol.EndFile, &vol.EndBlock);
+    if (n != 19) {
        Dmsg2(100, "Bad response from Dir fields=%d: %s\n", n, dir->msg);
-       Mmsg(&jcr->errmsg, _("Error getting Volume info: %s\n"), dir->msg);
+       Mmsg(jcr->errmsg, _("Error getting Volume info: %s\n"), dir->msg);
        return false;
     }
     vol.InChanger = InChanger;       /* bool in structure */
     unbash_spaces(vol.VolCatName);
-    pm_strcpy(&jcr->VolumeName, vol.VolCatName); /* set desired VolumeName */
     bstrncpy(dcr->VolumeName, vol.VolCatName, sizeof(dcr->VolumeName));
-    memcpy(&jcr->VolCatInfo, &vol, sizeof(jcr->VolCatInfo));
     memcpy(&dcr->VolCatInfo, &vol, sizeof(dcr->VolCatInfo));
     
-    Dmsg2(200, "do_reqest_vol_info got slot=%d Volume=%s\n", 
+    Dmsg2(300, "do_reqest_vol_info got slot=%d Volume=%s\n", 
          vol.Slot, vol.VolCatName);
     return true;
 }
@@ -126,16 +124,17 @@ static bool do_get_volume_info(JCR *jcr)
  *
  *         Volume information returned in jcr
  */
-bool dir_get_volume_info(JCR *jcr, enum get_vol_info_rw writing)
+bool dir_get_volume_info(DCR *dcr, enum get_vol_info_rw writing)
 {
+    JCR *jcr = dcr->jcr;
     BSOCK *dir = jcr->dir_bsock;
 
-    bstrncpy(jcr->VolCatInfo.VolCatName, jcr->VolumeName, sizeof(jcr->VolCatInfo.VolCatName));
-    Dmsg1(200, "dir_get_volume_info=%s\n", jcr->VolCatInfo.VolCatName);
-    bash_spaces(jcr->VolCatInfo.VolCatName);
-    bnet_fsend(dir, Get_Vol_Info, jcr->Job, jcr->VolCatInfo.VolCatName, 
+    bstrncpy(dcr->VolCatInfo.VolCatName, dcr->VolumeName, sizeof(dcr->VolCatInfo.VolCatName));
+    Dmsg1(300, "dir_get_volume_info=%s\n", dcr->VolCatInfo.VolCatName);
+    bash_spaces(dcr->VolCatInfo.VolCatName);
+    bnet_fsend(dir, Get_Vol_Info, jcr->Job, dcr->VolCatInfo.VolCatName, 
        writing==GET_VOL_INFO_FOR_WRITE?1:0);
-    return do_get_volume_info(jcr);
+    return do_get_volume_info(dcr);
 }
 
 
@@ -145,19 +144,25 @@ bool dir_get_volume_info(JCR *jcr, enum get_vol_info_rw writing)
  * Returns: true  on success
  *         false on failure
  *
- *         Volume information returned in jcr
+ *         Volume information returned in dcr
  *
  */
-bool dir_find_next_appendable_volume(JCR *jcr)
+bool dir_find_next_appendable_volume(DCR *dcr)
 {
+    JCR *jcr = dcr->jcr;
     BSOCK *dir = jcr->dir_bsock;
     JCR *njcr;
 
     Dmsg0(200, "dir_find_next_appendable_volume\n");
+    /*
+     * Try the three oldest or most available volumes. Note,
+     *  the most available could already be mounted on another
+     *  drive, so we continue looking for a not in use Volume.
+     */
     for (int vol_index=1;  vol_index < 3; vol_index++) {
        bnet_fsend(dir, Find_media, jcr->Job, vol_index);
-       if (do_get_volume_info(jcr)) {
-          Dmsg2(200, "JobId=%d got possible Vol=%s\n", jcr->JobId, jcr->VolumeName);
+       if (do_get_volume_info(dcr)) {
+          Dmsg2(300, "JobId=%d got possible Vol=%s\n", jcr->JobId, dcr->VolumeName);
          bool found = false;
          /* 
           * Walk through all jobs and see if the volume is   
@@ -171,10 +176,10 @@ bool dir_find_next_appendable_volume(JCR *jcr)
                free_locked_jcr(njcr);
                continue;             /* us */
             }
-             Dmsg2(200, "Compare to JobId=%d using Vol=%s\n", njcr->JobId, njcr->VolumeName);
-            if (strcmp(jcr->VolumeName, njcr->VolumeName) == 0) {
+             Dmsg2(300, "Compare to JobId=%d using Vol=%s\n", njcr->JobId, njcr->dcr->VolumeName);
+            if (njcr->dcr && strcmp(dcr->VolumeName, njcr->dcr->VolumeName) == 0) {
                found = true;
-                Dmsg1(200, "Vol in use by JobId=%u\n", njcr->JobId);
+                Dmsg1(400, "Vol in use by JobId=%u\n", njcr->JobId);
                free_locked_jcr(njcr);
                break;
             }
@@ -182,7 +187,7 @@ bool dir_find_next_appendable_volume(JCR *jcr)
          }
          unlock_jcr_chain();
          if (!found) {
-             Dmsg0(200, "dir_find_next_appendable_volume return true\n");
+             Dmsg0(400, "dir_find_next_appendable_volume return true\n");
             return true;             /* Got good Volume */
          }
        } else {
@@ -190,7 +195,7 @@ bool dir_find_next_appendable_volume(JCR *jcr)
          return false;
        }
     }
-    Dmsg0(200, "dir_find_next_appendable_volume return true\n");
+    Dmsg0(400, "dir_find_next_appendable_volume return true\n");
     return true; 
 }
 
@@ -200,25 +205,28 @@ bool dir_find_next_appendable_volume(JCR *jcr)
  * back to the director. The information comes from the
  * dev record.    
  */
-bool dir_update_volume_info(JCR *jcr, bool label)
+bool dir_update_volume_info(DCR *dcr, bool label)
 {
+   JCR *jcr = dcr->jcr;
    BSOCK *dir = jcr->dir_bsock;
-   DEVICE *dev = jcr->dcr->dev;
+   DEVICE *dev = dcr->dev;
    time_t LastWritten = time(NULL);
    char ed1[50], ed2[50], ed3[50], ed4[50];
    VOLUME_CAT_INFO *vol = &dev->VolCatInfo;
    int InChanger;
 
    if (vol->VolCatName[0] == 0) {
-      Jmsg0(jcr, M_ERROR, 0, _("NULL Volume name. This shouldn't happen!!!\n"));
+      Jmsg0(jcr, M_FATAL, 0, _("NULL Volume name. This shouldn't happen!!!\n"));
+      Dmsg0(000, "NULL Volume name. This shouldn't happen!!!\n");
       return false;
    }
    if (dev_state(dev, ST_READ)) {
-      Jmsg0(jcr, M_ERROR, 0, _("Attempt to update_volume_info in read mode!!!\n"));
+      Jmsg0(jcr, M_FATAL, 0, _("Attempt to update_volume_info in read mode!!!\n"));
+      Dmsg0(000, "Attempt to update_volume_info in read mode!!!\n");
       return false;
    }
 
-   Dmsg1(100, "Update cat VolFiles=%d\n", dev->file);
+   Dmsg1(300, "Update cat VolFiles=%d\n", dev->file);
    /* Just labeled or relabeled the tape */
    if (label) {
       bstrncpy(vol->VolCatStatus, "Append", sizeof(vol->VolCatStatus));
@@ -236,26 +244,27 @@ bool dir_update_volume_info(JCR *jcr, bool label)
       edit_uint64(vol->VolReadTime, ed3), 
       edit_uint64(vol->VolWriteTime, ed4) );
 
-   Dmsg1(120, "update_volume_info(): %s", dir->msg);
+   Dmsg1(300, "update_volume_info(): %s", dir->msg);
    unbash_spaces(vol->VolCatName);
 
-   if (!do_get_volume_info(jcr)) {
-      Jmsg(jcr, M_ERROR, 0, "%s", jcr->errmsg);
+   if (!do_get_volume_info(dcr)) {
+      Jmsg(jcr, M_FATAL, 0, "%s", jcr->errmsg);
+      Dmsg1(000, "Didn't get vol info: %s", jcr->errmsg);
       return false;
    }
-   Dmsg1(120, "get_volume_info(): %s", dir->msg);
+   Dmsg1(420, "get_volume_info(): %s", dir->msg);
    /* Update dev Volume info in case something changed (e.g. expired) */
-   memcpy(&dev->VolCatInfo, &jcr->VolCatInfo, sizeof(dev->VolCatInfo));
+   memcpy(&dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dev->VolCatInfo));
    return true;
 }
 
 /*
  * After writing a Volume, create the JobMedia record.
  */
-bool dir_create_jobmedia_record(JCR *jcr)
+bool dir_create_jobmedia_record(DCR *dcr)
 {
+   JCR *jcr = dcr->jcr;
    BSOCK *dir = jcr->dir_bsock;
-   DCR *dcr = jcr->dcr;
 
    if (!dcr->WroteVol) {
       return true;                   /* nothing written to tape */
@@ -266,17 +275,17 @@ bool dir_create_jobmedia_record(JCR *jcr)
       dcr->VolFirstIndex, dcr->VolLastIndex,
       dcr->StartFile, dcr->EndFile,
       dcr->StartBlock, dcr->EndBlock);
-   Dmsg1(100, "create_jobmedia(): %s", dir->msg);
+   Dmsg1(400, "create_jobmedia(): %s", dir->msg);
    if (bnet_recv(dir) <= 0) {
       Dmsg0(190, "create_jobmedia error bnet_recv\n");
-      Jmsg(jcr, M_ERROR, 0, _("Error creating JobMedia record: ERR=%s\n"), 
+      Jmsg(jcr, M_FATAL, 0, _("Error creating JobMedia record: ERR=%s\n"), 
           bnet_strerror(dir));
       return false;
    }
-   Dmsg1(120, "Create_jobmedia: %s", dir->msg);
+   Dmsg1(400, "Create_jobmedia: %s", dir->msg);
    if (strcmp(dir->msg, OK_create) != 0) {
       Dmsg1(130, "Bad response from Dir: %s\n", dir->msg);
-      Jmsg(jcr, M_ERROR, 0, _("Error creating JobMedia record: %s\n"), dir->msg);
+      Jmsg(jcr, M_FATAL, 0, _("Error creating JobMedia record: %s\n"), dir->msg);
       return false;
    }
    return true;
@@ -286,8 +295,9 @@ bool dir_create_jobmedia_record(JCR *jcr)
 /* 
  * Update File Attribute data
  */
-bool dir_update_file_attributes(JCR *jcr, DEV_RECORD *rec)
+bool dir_update_file_attributes(DCR *dcr, DEV_RECORD *rec)
 {
+   JCR *jcr = dcr->jcr;
    BSOCK *dir = jcr->dir_bsock;
    ser_declare;
 
@@ -316,7 +326,7 @@ bool dir_update_file_attributes(JCR *jcr, DEV_RECORD *rec)
  *           false on failure
  *             Note, must create dev->errmsg on error return.
  *
- *    On success, jcr->VolumeName and jcr->VolCatInfo contain
+ *    On success, dcr->VolumeName and dcr->VolCatInfo contain
  *     information on suggested volume, but this may not be the
  *     same as what is actually mounted.
  *
@@ -324,25 +334,26 @@ bool dir_update_file_attributes(JCR *jcr, DEV_RECORD *rec)
  *     actually be mounted. The calling routine must read it and
  *     verify the label.
  */
-bool dir_ask_sysop_to_create_appendable_volume(JCR *jcr)
+bool dir_ask_sysop_to_create_appendable_volume(DCR *dcr)
 {
    int stat = 0, jstat;
    bool unmounted;
    bool first = true;
-   DEVICE *dev = jcr->dcr->dev;
+   DEVICE *dev = dcr->dev;
+   JCR *jcr = dcr->jcr;
 
-   Dmsg0(130, "enter dir_ask_sysop_to_create_appendable_volume\n");
+   Dmsg0(400, "enter dir_ask_sysop_to_create_appendable_volume\n");
    ASSERT(dev->dev_blocked);
    for ( ;; ) {
       if (job_canceled(jcr)) {
-        Mmsg(&dev->errmsg,
+        Mmsg(dev->errmsg,
               _("Job %s canceled while waiting for mount on Storage Device \"%s\".\n"), 
-             jcr->Job, jcr->dev_name);
+             jcr->Job, dcr->dev_name);
          Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
         return false;
       }
       /* First pass, we *know* there are no appendable volumes, so no need to call */
-      if (!first && dir_find_next_appendable_volume(jcr)) { /* get suggested volume */
+      if (!first && dir_find_next_appendable_volume(dcr)) { /* get suggested volume */
         unmounted = (dev->dev_blocked == BST_UNMOUNTED) ||
                     (dev->dev_blocked == BST_UNMOUNTED_WAITING_FOR_SYSOP);
         /*
@@ -351,10 +362,10 @@ bool dir_ask_sysop_to_create_appendable_volume(JCR *jcr)
          *   Slot for an autochanger, otherwise wait
          *   for the operator to mount the media.
          */
-        if (!unmounted && ((jcr->VolumeName[0] && !dev_cap(dev, CAP_REM) && 
+        if (!unmounted && ((dcr->VolumeName[0] && !dev_cap(dev, CAP_REM) && 
                dev_cap(dev, CAP_LABEL)) ||
-                (jcr->VolumeName[0] && jcr->VolCatInfo.Slot))) {
-            Dmsg0(100, "Return 1 from mount without wait.\n");
+                (dcr->VolumeName[0] && dcr->VolCatInfo.Slot))) {
+            Dmsg0(400, "Return 1 from mount without wait.\n");
            return true;
         }
         jstat = JS_WaitMount;
@@ -362,9 +373,9 @@ bool dir_ask_sysop_to_create_appendable_volume(JCR *jcr)
            Jmsg(jcr, M_MOUNT, 0, _(
 "Please mount Volume \"%s\" on Storage Device \"%s\" for Job %s\n"
 "Use \"mount\" command to release Job.\n"),
-             jcr->VolumeName, jcr->dev_name, jcr->Job);
-            Dmsg3(190, "Mount %s on %s for Job %s\n",
-                 jcr->VolumeName, jcr->dev_name, jcr->Job);
+             dcr->VolumeName, dcr->dev_name, jcr->Job);
+            Dmsg3(400, "Mount %s on %s for Job %s\n",
+                 dcr->VolumeName, dcr->dev_name, jcr->Job);
         }
       } else {
         jstat = JS_WaitMedia;
@@ -376,9 +387,9 @@ Please use the \"label\"  command to create a new Volume for:\n\
     Media type:   %s\n\
     Pool:         %s\n"),
               jcr->Job, 
-              jcr->dev_name, 
-              jcr->media_type,
-              jcr->pool_name);
+              dcr->dev_name, 
+              dcr->media_type,
+              dcr->pool_name);
         }
       }
       first = false;
@@ -386,37 +397,39 @@ Please use the \"label\"  command to create a new Volume for:\n\
       jcr->JobStatus = jstat;
       dir_send_job_status(jcr);
 
-      stat = wait_for_sysop(jcr, dev);
+      stat = wait_for_sysop(dcr);
       if (dev->poll) {
-         Dmsg1(200, "Poll timeout in create append vol on device %s\n", dev_name(dev));
+         Dmsg1(400, "Poll timeout in create append vol on device %s\n", dev_name(dev));
         continue;
       }
 
       if (stat == ETIMEDOUT) {
         if (!double_dev_wait_time(dev)) {
-            Mmsg(&dev->errmsg, _("Gave up waiting to mount Storage Device \"%s\" for Job %s\n"), 
+            Mmsg(dev->errmsg, _("Max time exceeded waiting to mount Storage Device \"%s\" for Job %s\n"), 
               dev_name(dev), jcr->Job);
             Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
-            Dmsg1(190, "Gave up waiting on device %s\n", dev_name(dev));
+            Dmsg1(400, "Gave up waiting on device %s\n", dev_name(dev));
            return false;             /* exceeded maximum waits */
         }
         continue;
       }
       if (stat == EINVAL) {
-         Mmsg2(&dev->errmsg, _("pthread error in mount_next_volume stat=%d ERR=%s\n"),
-              stat, strerror(stat));
+        berrno be;
+         Mmsg2(dev->errmsg, _("pthread error in mount_next_volume stat=%d ERR=%s\n"),
+              stat, be.strerror(stat));
          Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
         return false;
       }
       if (stat != 0) {
+        berrno be;
          Jmsg(jcr, M_WARNING, 0, _("pthread error in mount_next_volume stat=%d ERR=%s\n"), stat,
-           strerror(stat));
+           be.strerror(stat));
       }
-      Dmsg1(190, "Someone woke me for device %s\n", dev_name(dev));
+      Dmsg1(400, "Someone woke me for device %s\n", dev_name(dev));
 
       /* If no VolumeName, and cannot get one, try again */
-      if (jcr->VolumeName[0] == 0 && !job_canceled(jcr) &&
-         !dir_find_next_appendable_volume(jcr)) {
+      if (dcr->VolumeName[0] == 0 && !job_canceled(jcr) &&
+         !dir_find_next_appendable_volume(dcr)) {
         Jmsg(jcr, M_MOUNT, 0, _(
 "Someone woke me up, but I cannot find any appendable\n\
 volumes for Job=%s.\n"), jcr->Job);
@@ -437,92 +450,95 @@ volumes for Job=%s.\n"), jcr->Job);
    }
    set_jcr_job_status(jcr, JS_Running);
    dir_send_job_status(jcr);
-   Dmsg0(130, "leave dir_ask_sysop_to_mount_create_appendable_volume\n");
+   Dmsg0(400, "leave dir_ask_sysop_to_mount_create_appendable_volume\n");
    return true;
 }
 
 /*
  *   Request to mount specific Volume
  *
- *   Entered with device blocked and jcr->VolumeName is desired
+ *   Entered with device blocked and dcr->VolumeName is desired
  *     volume.
  *   Leaves with device blocked.
  *
- *   Returns: 1 on success (operator issues a mount command)
- *           0 on failure
- *             Note, must create dev->errmsg on error return.
+ *   Returns: true  on success (operator issues a mount command)
+ *           false on failure
+ *                 Note, must create dev->errmsg on error return.
  *
  */
-bool dir_ask_sysop_to_mount_volume(JCR *jcr)
+bool dir_ask_sysop_to_mount_volume(DCR *dcr)
 {
    int stat = 0;
    const char *msg;
-   DEVICE *dev = jcr->dcr->dev;
+   DEVICE *dev = dcr->dev;
+   JCR *jcr = dcr->jcr;
 
-   Dmsg0(130, "enter dir_ask_sysop_to_mount_volume\n");
-   if (!jcr->VolumeName[0]) {
-      Mmsg0(&dev->errmsg, _("Cannot request another volume: no volume name given.\n"));
-      return 0;
+   Dmsg0(400, "enter dir_ask_sysop_to_mount_volume\n");
+   if (!dcr->VolumeName[0]) {
+      Mmsg0(dev->errmsg, _("Cannot request another volume: no volume name given.\n"));
+      return false;
    }
    ASSERT(dev->dev_blocked);
    for ( ;; ) {
       if (job_canceled(jcr)) {
-         Mmsg(&dev->errmsg, _("Job %s canceled while waiting for mount on Storage Device \"%s\".\n"), 
-             jcr->Job, jcr->dev_name);
+         Mmsg(dev->errmsg, _("Job %s canceled while waiting for mount on Storage Device \"%s\".\n"), 
+             jcr->Job, dcr->dev_name);
         return false;
       }
 
       if (!dev->poll) {
          msg = _("Please mount");
          Jmsg(jcr, M_MOUNT, 0, _("%s Volume \"%s\" on Storage Device \"%s\" for Job %s\n"),
-             msg, jcr->VolumeName, jcr->dev_name, jcr->Job);
-         Dmsg3(190, "Mount %s on %s for Job %s\n",
-              jcr->VolumeName, jcr->dev_name, jcr->Job);
+             msg, dcr->VolumeName, dcr->dev_name, jcr->Job);
+         Dmsg3(400, "Mount \"%s\" on device \"%s\" for Job %s\n",
+              dcr->VolumeName, dcr->dev_name, jcr->Job);
       }
 
       jcr->JobStatus = JS_WaitMount;
       dir_send_job_status(jcr);
 
-      stat = wait_for_sysop(jcr, dev);    /* wait on device */
+      stat = wait_for_sysop(dcr);    ;    /* wait on device */
       if (dev->poll) {
-         Dmsg1(200, "Poll timeout in mount vol on device %s\n", dev_name(dev));
-         Dmsg1(200, "Blocked=%d\n", dev->dev_blocked);
+         Dmsg1(400, "Poll timeout in mount vol on device %s\n", dev_name(dev));
+         Dmsg1(400, "Blocked=%s\n", edit_blocked_reason(dev));
         return true;
       }
 
       if (stat == ETIMEDOUT) {
         if (!double_dev_wait_time(dev)) {
-            Mmsg(&dev->errmsg, _("Gave up waiting to mount Storage Device \"%s\" for Job %s\n"), 
+            Mmsg(dev->errmsg, _("Max time exceeded waiting to mount Storage Device \"%s\" for Job %s\n"), 
               dev_name(dev), jcr->Job);
             Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
-            Dmsg1(190, "Gave up waiting on device %s\n", dev_name(dev));
+            Dmsg1(400, "Gave up waiting on device %s\n", dev_name(dev));
            return false;             /* exceeded maximum waits */
         }
         continue;
       }
       if (stat == EINVAL) {
-         Mmsg2(&dev->errmsg, _("pthread error in mount_volume stat=%d ERR=%s\n"),
-              stat, strerror(stat));
+        berrno be;
+         Mmsg2(dev->errmsg, _("pthread error in mount_volume stat=%d ERR=%s\n"),
+              stat, be.strerror(stat));
          Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
         return false;
       }
       if (stat != 0) {
-         Jmsg(jcr, M_ERROR, 0, _("pthread error in mount_next_volume stat=%d ERR=%s\n"), stat,
-           strerror(stat));
+        berrno be;
+         Jmsg(jcr, M_FATAL, 0, _("pthread error in mount_next_volume stat=%d ERR=%s\n"), stat,
+           be.strerror(stat));
       }
-      Dmsg1(190, "Someone woke me for device %s\n", dev_name(dev));
+      Dmsg1(400, "Someone woke me for device %s\n", dev_name(dev));
       break;
    }
    set_jcr_job_status(jcr, JS_Running);
    dir_send_job_status(jcr);
-   Dmsg0(130, "leave dir_ask_sysop_to_mount_volume\n");
+   Dmsg0(400, "leave dir_ask_sysop_to_mount_volume\n");
    return true;
 }
 
 /*
  * Wait for SysOp to mount a tape
  */
-static int wait_for_sysop(JCR *jcr, DEVICE *dev)
+static int wait_for_sysop(DCR *dcr)
 {
    struct timeval tv;
    struct timezone tz;
@@ -532,6 +548,8 @@ static int wait_for_sysop(JCR *jcr, DEVICE *dev)
    int stat = 0;
    int add_wait;
    bool unmounted;
+   DEVICE *dev = dcr->dev;
+   JCR *jcr = dcr->jcr;
    
    P(dev->mutex);
    unmounted = (dev->dev_blocked == BST_UNMOUNTED) ||
@@ -548,6 +566,9 @@ static int wait_for_sysop(JCR *jcr, DEVICE *dev)
    if (me->heartbeat_interval && add_wait > me->heartbeat_interval) {
       add_wait = me->heartbeat_interval;
    }
+   /* If the user did not unmount the tape and we are polling, ensure
+    *  that we poll at the correct interval. 
+    */
    if (!unmounted && dev->vol_poll_interval && add_wait > dev->vol_poll_interval) {
       add_wait = dev->vol_poll_interval;
    }
@@ -563,11 +584,12 @@ static int wait_for_sysop(JCR *jcr, DEVICE *dev)
    for ( ; !job_canceled(jcr); ) {
       time_t now, start;
 
-      Dmsg3(100, "I'm going to sleep on device %s. HB=%d wait=%d\n", dev_name(dev),
+      Dmsg3(400, "I'm going to sleep on device %s. HB=%d wait=%d\n", dev_name(dev),
         (int)me->heartbeat_interval, dev->wait_sec);
       start = time(NULL);
+      /* Wait required time */
       stat = pthread_cond_timedwait(&dev->wait_next_vol, &dev->mutex, &timeout);
-      Dmsg1(100, "Wokeup from sleep on device stat=%d\n", stat);
+      Dmsg1(400, "Wokeup from sleep on device stat=%d\n", stat);
 
       now = time(NULL);
       dev->rem_wait_sec -= (now - start);
@@ -578,7 +600,7 @@ static int wait_for_sysop(JCR *jcr, DEVICE *dev)
            /* send heartbeats */
            if (jcr->file_bsock) {
               bnet_sig(jcr->file_bsock, BNET_HEARTBEAT);
-               Dmsg0(100, "Send heartbeat to FD.\n");
+               Dmsg0(400, "Send heartbeat to FD.\n");
            }
            if (jcr->dir_bsock) {
               bnet_sig(jcr->dir_bsock, BNET_HEARTBEAT);
@@ -597,14 +619,14 @@ static int wait_for_sysop(JCR *jcr, DEVICE *dev)
         break;                    /* on error return */
       }
       if (dev->rem_wait_sec <= 0) {  /* on exceeding wait time return */
-         Dmsg0(100, "Exceed wait time.\n");
+         Dmsg0(400, "Exceed wait time.\n");
         break;
       }
       
       if (!unmounted && dev->vol_poll_interval &&      
          (now - first_start >= dev->vol_poll_interval)) {
-         Dmsg1(200, "In wait blocked=%d\n", dev->dev_blocked);
-        dev->poll = true;
+         Dmsg1(400, "In wait blocked=%s\n", edit_blocked_reason(dev));
+        dev->poll = true;            /* returning a poll event */
         break;
       }
       /*
@@ -625,7 +647,7 @@ static int wait_for_sysop(JCR *jcr, DEVICE *dev)
       gettimeofday(&tv, &tz);
       timeout.tv_nsec = tv.tv_usec * 1000;
       timeout.tv_sec = tv.tv_sec + add_wait; /* additional wait */
-      Dmsg1(100, "Additional wait %d sec.\n", add_wait);
+      Dmsg1(400, "Additional wait %d sec.\n", add_wait);
    }
 
    if (!unmounted) {