From: Kern Sibbald <kern@sibbald.com>
Date: Mon, 27 Sep 2004 07:01:38 +0000 (+0000)
Subject: - Correct buffer length passed to inet_ntop() in address_conf.c
X-Git-Tag: Release-1.35.6~11
X-Git-Url: https://git.sur5r.net/?a=commitdiff_plain;h=5c5a7a4abbd563746ed836d8e817222a7a5a9d31;p=bacula%2Fbacula

- Correct buffer length passed to inet_ntop() in address_conf.c
- Increase the debug level of a lot of messages to reduce the
  debugging noise.
- Modify how ST_APPEND is handled so that nothing is written
  to the Volume if it is not set. It is now set only when
  the Volume label is verified, and released when the volume
  is released. This required a number of minor but rather
  critical and fundamental changes.
- Improve quickly terminating a job in the SD when it errs.
  More status checking and a few additional checks on
  job_canceled() and check more error return statuses.
- Added a number of debug statements (to be removed later) that
  check the VolCatName for a name.
- Create a single subroutine that handles terminating writing
  on a Volume at the end of the volume (or after an error).
- Continued to add use of the berrno classs for strerror().


git-svn-id: https://bacula.svn.sourceforge.net/svnroot/bacula/trunk@1619 91ce42f0-d328-0410-95d8-f526ca767f89
---

diff --git a/bacula/src/lib/address_conf.c b/bacula/src/lib/address_conf.c
index 49629b3579..f67c470434 100644
--- a/bacula/src/lib/address_conf.c
+++ b/bacula/src/lib/address_conf.c
@@ -540,8 +540,7 @@ int  sockaddr_to_ascii(const struct sockaddr *sa, char *buf, int len)
 	     sa->sa_family == AF_INET ? 
 		 (void*)&(((struct sockaddr_in*)sa)->sin_addr) :
 		 (void*)&(((struct sockaddr_in6*)sa)->sin6_addr),
-	     buf,
-	     sizeof(buf));
+	     buf, len);
 #else
    bstrncpy(buf, inet_ntoa(((struct sockaddr_in *)sa)->sin_addr), len);
 #endif
diff --git a/bacula/src/lib/bget_msg.c b/bacula/src/lib/bget_msg.c
index a1a366c056..7451424e8f 100644
--- a/bacula/src/lib/bget_msg.c
+++ b/bacula/src/lib/bget_msg.c
@@ -32,7 +32,7 @@
 extern char OK_msg[];
 extern char TERM_msg[];
 
-#define msglvl 200
+#define msglvl 500
 
 /*	 
  * This routine does a bnet_recv(), then if a signal was
diff --git a/bacula/src/lib/message.c b/bacula/src/lib/message.c
index cb0e0613a9..af87bed48f 100755
--- a/bacula/src/lib/message.c
+++ b/bacula/src/lib/message.c
@@ -108,7 +108,7 @@ static int exit_on_error = 1;
 void my_name_is(int argc, char *argv[], const char *name)
 {
    char *l, *p, *q;
-   char cpath[400], npath[400];
+   char cpath[1024], npath[1024];
    int len;
 
    bstrncpy(my_name, name, sizeof(my_name));
@@ -414,7 +414,7 @@ void close_msg(JCR *jcr)
    POOLMEM *cmd, *line;
    int len, stat;
    
-   Dmsg1(050, "Close_msg jcr=0x%x\n", jcr);
+   Dmsg1(350, "Close_msg jcr=0x%x\n", jcr);
 
    if (jcr == NULL) {		     /* NULL -> global chain */
       msgs = daemon_msgs;
@@ -426,7 +426,7 @@ void close_msg(JCR *jcr)
    if (msgs == NULL) {
       return;
    }
-   Dmsg1(150, "===Begin close msg resource at 0x%x\n", msgs);
+   Dmsg1(350, "===Begin close msg resource at 0x%x\n", msgs);
    cmd = get_pool_memory(PM_MESSAGE);
    for (d=msgs->dest_chain; d; ) {
       if (d->fd) {
@@ -439,7 +439,7 @@ void close_msg(JCR *jcr)
 	    break;
 	 case MD_MAIL:
 	 case MD_MAIL_ON_ERROR:
-            Dmsg0(150, "Got MD_MAIL or MD_MAIL_ON_ERROR\n");
+            Dmsg0(350, "Got MD_MAIL or MD_MAIL_ON_ERROR\n");
 	    if (!d->fd) {
 	       break;
 	    }
@@ -452,7 +452,7 @@ void close_msg(JCR *jcr)
                Pmsg0(000, "open mail pipe failed.\n");
 	       goto rem_temp_file;
 	    }
-            Dmsg0(150, "Opened mail pipe\n");
+            Dmsg0(350, "Opened mail pipe\n");
 	    len = d->max_len+10;
 	    line = get_memory(len);
 	    rewind(d->fd);
@@ -479,7 +479,7 @@ void close_msg(JCR *jcr)
 	    if (stat != 0 && msgs != daemon_msgs) {
 	       berrno be;
 	       be.set_errno(stat);
-               Dmsg1(150, "Calling emsg. CMD=%s\n", cmd);
+               Dmsg1(350, "Calling emsg. CMD=%s\n", cmd);
                Jmsg2(jcr, M_ERROR, 0, _("Mail program terminated in error.\n"
                                         "CMD=%s\n"
                                         "ERR=%s\n"), cmd, be.strerror());
@@ -491,7 +491,7 @@ rem_temp_file:
 	    unlink(d->mail_filename);
 	    free_pool_memory(d->mail_filename);
 	    d->mail_filename = NULL;
-            Dmsg0(150, "end mail or mail on error\n");
+            Dmsg0(350, "end mail or mail on error\n");
 	    break;
 	 default:
 	    break;
@@ -501,14 +501,14 @@ rem_temp_file:
       d = d->next;		      /* point to next buffer */
    }
    free_pool_memory(cmd);
-   Dmsg0(150, "Done walking message chain.\n");
+   Dmsg0(350, "Done walking message chain.\n");
    if (jcr) {
       free_msgs_res(msgs);
       msgs = NULL;
    } else {
       V(mutex);
    }
-   Dmsg0(150, "===End close msg resource\n");
+   Dmsg0(350, "===End close msg resource\n");
 }
 
 /*
@@ -544,7 +544,7 @@ void free_msgs_res(MSGS *msgs)
  */
 void term_msg()
 {
-   Dmsg0(100, "Enter term_msg\n");
+   Dmsg0(300, "Enter term_msg\n");
    close_msg(NULL);		      /* close global chain */
    free_msgs_res(daemon_msgs);	      /* free the resources */
    daemon_msgs = NULL;
diff --git a/bacula/src/lib/workq.c b/bacula/src/lib/workq.c
index 01c9307cb1..efc41bbe8b 100755
--- a/bacula/src/lib/workq.c
+++ b/bacula/src/lib/workq.c
@@ -149,7 +149,7 @@ int workq_add(workq_t *wq, void *element, workq_ele_t **work_item, int priority)
    workq_ele_t *item;
    pthread_t id;
     
-   Dmsg0(200, "workq_add\n");
+   Dmsg0(400, "workq_add\n");
    if (wq->valid != WORKQ_VALID) {
       return EINVAL;
    }
@@ -164,7 +164,7 @@ int workq_add(workq_t *wq, void *element, workq_ele_t **work_item, int priority)
       return stat;
    }
 
-   Dmsg0(200, "add item to queue\n");
+   Dmsg0(400, "add item to queue\n");
    if (priority) {
       /* Add to head of queue */
       if (wq->first == NULL) {
@@ -186,13 +186,13 @@ int workq_add(workq_t *wq, void *element, workq_ele_t **work_item, int priority)
 
    /* if any threads are idle, wake one */
    if (wq->idle_workers > 0) {
-      Dmsg0(200, "Signal worker\n");
+      Dmsg0(400, "Signal worker\n");
       if ((stat = pthread_cond_signal(&wq->work)) != 0) {
 	 pthread_mutex_unlock(&wq->mutex);
 	 return stat;
       }
    } else if (wq->num_workers < wq->max_workers) {
-      Dmsg0(200, "Create worker thread\n");
+      Dmsg0(400, "Create worker thread\n");
       /* No idle threads so create a new one */
       set_thread_concurrency(wq->max_workers + 1);
       if ((stat = pthread_create(&id, &wq->attr, workq_server, (void *)wq)) != 0) {
@@ -202,7 +202,7 @@ int workq_add(workq_t *wq, void *element, workq_ele_t **work_item, int priority)
       wq->num_workers++;
    }
    pthread_mutex_unlock(&wq->mutex);
-   Dmsg0(200, "Return workq_add\n");
+   Dmsg0(400, "Return workq_add\n");
    /* Return work_item if requested */
    if (work_item) {
       *work_item = item;
@@ -225,7 +225,7 @@ int workq_remove(workq_t *wq, workq_ele_t *work_item)
    pthread_t id;
    workq_ele_t *item, *prev;
     
-   Dmsg0(200, "workq_remove\n");
+   Dmsg0(400, "workq_remove\n");
    if (wq->valid != WORKQ_VALID) {
       return EINVAL;
    }
@@ -257,13 +257,13 @@ int workq_remove(workq_t *wq, workq_ele_t *work_item)
 
    /* if any threads are idle, wake one */
    if (wq->idle_workers > 0) {
-      Dmsg0(200, "Signal worker\n");
+      Dmsg0(400, "Signal worker\n");
       if ((stat = pthread_cond_signal(&wq->work)) != 0) {
 	 pthread_mutex_unlock(&wq->mutex);
 	 return stat;
       }
    } else {
-      Dmsg0(200, "Create worker thread\n");
+      Dmsg0(400, "Create worker thread\n");
       /* No idle threads so create a new one */
       set_thread_concurrency(wq->max_workers + 1);
       if ((stat = pthread_create(&id, &wq->attr, workq_server, (void *)wq)) != 0) {
@@ -273,7 +273,7 @@ int workq_remove(workq_t *wq, workq_ele_t *work_item)
       wq->num_workers++;
    }
    pthread_mutex_unlock(&wq->mutex);
-   Dmsg0(200, "Return workq_remove\n");
+   Dmsg0(400, "Return workq_remove\n");
    return stat;
 }
 
@@ -290,7 +290,7 @@ void *workq_server(void *arg)
    workq_ele_t *we;
    int stat, timedout;
 
-   Dmsg0(200, "Start workq_server\n");
+   Dmsg0(400, "Start workq_server\n");
    if ((stat = pthread_mutex_lock(&wq->mutex)) != 0) {
       return NULL;
    }
@@ -299,9 +299,9 @@ void *workq_server(void *arg)
       struct timeval tv;
       struct timezone tz;
 
-      Dmsg0(200, "Top of for loop\n");
+      Dmsg0(400, "Top of for loop\n");
       timedout = 0;
-      Dmsg0(200, "gettimeofday()\n");
+      Dmsg0(400, "gettimeofday()\n");
       gettimeofday(&tv, &tz);
       timeout.tv_nsec = 0;
       timeout.tv_sec = tv.tv_sec + 2;
@@ -310,7 +310,7 @@ void *workq_server(void *arg)
 	 /*
 	  * Wait 2 seconds, then if no more work, exit
 	  */
-         Dmsg0(200, "pthread_cond_timedwait()\n");
+         Dmsg0(400, "pthread_cond_timedwait()\n");
 #ifdef xxxxxxxxxxxxxxxx_was_HAVE_CYGWIN
 	 /* CYGWIN dies with a page fault the second
 	  * time that pthread_cond_timedwait() is called
@@ -321,13 +321,13 @@ void *workq_server(void *arg)
 #else
 	 stat = pthread_cond_timedwait(&wq->work, &wq->mutex, &timeout);
 #endif
-         Dmsg1(200, "timedwait=%d\n", stat);
+         Dmsg1(400, "timedwait=%d\n", stat);
 	 if (stat == ETIMEDOUT) {
 	    timedout = 1;
 	    break;
 	 } else if (stat != 0) {
             /* This shouldn't happen */
-            Dmsg0(200, "This shouldn't happen\n");
+            Dmsg0(400, "This shouldn't happen\n");
 	    wq->num_workers--;
 	    pthread_mutex_unlock(&wq->mutex);
 	    return NULL;
@@ -343,15 +343,15 @@ void *workq_server(void *arg)
 	    return NULL;
 	 }
          /* Call user's routine here */
-         Dmsg0(200, "Calling user engine.\n");
+         Dmsg0(400, "Calling user engine.\n");
 	 wq->engine(we->data);
-         Dmsg0(200, "Back from user engine.\n");
+         Dmsg0(400, "Back from user engine.\n");
 	 free(we);		      /* release work entry */
-         Dmsg0(200, "relock mutex\n"); 
+         Dmsg0(400, "relock mutex\n"); 
 	 if ((stat = pthread_mutex_lock(&wq->mutex)) != 0) {
 	    return NULL;
 	 }
-         Dmsg0(200, "Done lock mutex\n");
+         Dmsg0(400, "Done lock mutex\n");
       }
       /*
        * If no more work request, and we are asked to quit, then do it
@@ -359,31 +359,31 @@ void *workq_server(void *arg)
       if (wq->first == NULL && wq->quit) {
 	 wq->num_workers--;
 	 if (wq->num_workers == 0) {
-            Dmsg0(200, "Wake up destroy routine\n");
+            Dmsg0(400, "Wake up destroy routine\n");
 	    /* Wake up destroy routine if he is waiting */
 	    pthread_cond_broadcast(&wq->work);
 	 }
-         Dmsg0(200, "Unlock mutex\n");
+         Dmsg0(400, "Unlock mutex\n");
 	 pthread_mutex_unlock(&wq->mutex);
-         Dmsg0(200, "Return from workq_server\n");
+         Dmsg0(400, "Return from workq_server\n");
 	 return NULL;
       }
-      Dmsg0(200, "Check for work request\n");
+      Dmsg0(400, "Check for work request\n");
       /* 
        * If no more work requests, and we waited long enough, quit
        */
-      Dmsg1(200, "wq->first==NULL = %d\n", wq->first==NULL);
-      Dmsg1(200, "timedout=%d\n", timedout);
+      Dmsg1(400, "wq->first==NULL = %d\n", wq->first==NULL);
+      Dmsg1(400, "timedout=%d\n", timedout);
       if (wq->first == NULL && timedout) {
-         Dmsg0(200, "break big loop\n");
+         Dmsg0(400, "break big loop\n");
 	 wq->num_workers--;
 	 break;
       }
-      Dmsg0(200, "Loop again\n");
+      Dmsg0(400, "Loop again\n");
    } /* end of big for loop */
 
-   Dmsg0(200, "unlock mutex\n");
+   Dmsg0(400, "unlock mutex\n");
    pthread_mutex_unlock(&wq->mutex);
-   Dmsg0(200, "End workq_server\n");
+   Dmsg0(400, "End workq_server\n");
    return NULL;
 }
diff --git a/bacula/src/stored/acquire.c b/bacula/src/stored/acquire.c
index bce27ef00c..70e69964a9 100644
--- a/bacula/src/stored/acquire.c
+++ b/bacula/src/stored/acquire.c
@@ -159,6 +159,7 @@ DCR *acquire_device_for_read(JCR *jcr)
       switch (read_dev_volume_label(dcr)) {
       case VOL_OK:
 	 vol_ok = true;
+	 memcpy(&dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dev->VolCatInfo));
 	 break; 		   /* got it */
       case VOL_IO_ERROR:
 	 /*
@@ -258,8 +259,8 @@ DCR *acquire_device_for_append(JCR *jcr)
    P(mutex);			     /* lock all devices */
    Dmsg1(190, "acquire_append device is %s\n", dev_is_tape(dev)?"tape":"disk");
 	     
-
    if (dev_state(dev, ST_APPEND)) {
+      Dmsg0(190, "device already in append.\n");
       /* 
        * Device already in append mode	 
        *
@@ -273,6 +274,7 @@ DCR *acquire_device_for_append(JCR *jcr)
       if (!dir_get_volume_info(dcr, GET_VOL_INFO_FOR_WRITE) &&
 	  !(dir_find_next_appendable_volume(dcr) &&
 	    strcmp(dev->VolHdr.VolName, dcr->VolumeName) == 0)) { /* wrong tape mounted */
+         Dmsg0(190, "Wrong tape mounted.\n");
 	 if (dev->num_writers != 0) {
 	    DEVICE *d = ((DEVRES *)dev->device)->dev;
 	    uint32_t open_vols = 0;
@@ -301,6 +303,7 @@ DCR *acquire_device_for_append(JCR *jcr)
 	    }
 	 }
 	 /* Wrong tape mounted, release it, then fall through to get correct one */
+         Dmsg0(190, "Wrong tape mounted, release and try mount.\n");
 	 release = true;
 	 do_mount = true;
       } else {
@@ -310,14 +313,19 @@ DCR *acquire_device_for_append(JCR *jcr)
 	  *   we need to recycle the tape.
 	  */
           recycle = strcmp(dcr->VolCatInfo.VolCatStatus, "Recycle") == 0;
+          Dmsg1(190, "Correct tape mounted. recycle=%d\n", recycle);
 	  if (recycle && dev->num_writers != 0) {
              Jmsg(jcr, M_FATAL, 0, _("Cannot recycle volume \"%s\""
                   " because it is in use by another job.\n"));
 	     goto get_out;
 	  }
+	  if (dev->num_writers == 0) {
+	     memcpy(&dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dev->VolCatInfo));
+	  }
        }
    } else { 
       /* Not already in append mode, so mount the device */
+      Dmsg0(190, "Not in append mode, try mount.\n");
       if (dev_state(dev, ST_READ)) {
          Jmsg(jcr, M_FATAL, 0, _("Device %s is busy reading.\n"), dev_name(dev));
 	 goto get_out;
@@ -327,6 +335,7 @@ DCR *acquire_device_for_append(JCR *jcr)
    }
 
    if (do_mount || recycle) {
+      Dmsg0(190, "Do mount_next_write_vol\n");
       if (!mount_next_write_volume(dcr, release)) {
 	 if (!job_canceled(jcr)) {
             /* Reduce "noise" -- don't print if job canceled */
@@ -410,7 +419,7 @@ bool release_device(JCR *jcr)
    }
 
    /* Fire off Alert command and include any output */
-   if (jcr->device->alert_command) {
+   if (!job_canceled(jcr) && jcr->device->alert_command) {
       POOLMEM *alert;
       int status = 1;
       BPIPE *bpipe;
diff --git a/bacula/src/stored/append.c b/bacula/src/stored/append.c
index 1cd0780cf4..262c3aa3e3 100644
--- a/bacula/src/stored/append.c
+++ b/bacula/src/stored/append.c
@@ -71,12 +71,18 @@ bool do_append_data(JCR *jcr)
    dev = dcr->dev;
    memset(&rec, 0, sizeof(rec));
 
+   if (dev->VolCatInfo.VolCatName[0] == 0) {
+      Dmsg0(000, "NULL Volume name. This shouldn't happen!!!\n");
+   }
    Dmsg1(20, "Begin append device=%s\n", dev_name(dev));
 
    begin_data_spool(jcr);
    begin_attribute_spool(jcr);
 
    Dmsg0(100, "Just after acquire_device_for_append\n");
+   if (dev->VolCatInfo.VolCatName[0] == 0) {
+      Dmsg0(000, "NULL Volume name. This shouldn't happen!!!\n");
+   }
    /*
     * Write Begin Session Record
     */
@@ -86,6 +92,9 @@ bool do_append_data(JCR *jcr)
       set_jcr_job_status(jcr, JS_ErrorTerminated);
       ok = false;
    }
+   if (dev->VolCatInfo.VolCatName[0] == 0) {
+      Dmsg0(000, "NULL Volume name. This shouldn't happen!!!\n");
+   }
 
    /* Tell File daemon to send data */
    bnet_fsend(fd_sock, OK_data);
@@ -150,7 +159,7 @@ bool do_append_data(JCR *jcr)
       }
       stream = (int32_t)str_to_int64(p);
 
-      Dmsg2(190, "<filed: Header FilInx=%d stream=%d\n", file_index, stream);
+      Dmsg2(490, "<filed: Header FilInx=%d stream=%d\n", file_index, stream);
 
       if (!(file_index > 0 && (file_index == last_file_index ||
 	  file_index == last_file_index + 1))) {
@@ -174,12 +183,12 @@ bool do_append_data(JCR *jcr)
 	 rec.data_len = ds->msglen;
 	 rec.data = ds->msg;		/* use message buffer */
 
-         Dmsg4(250, "before writ_rec FI=%d SessId=%d Strm=%s len=%d\n",
+         Dmsg4(450, "before writ_rec FI=%d SessId=%d Strm=%s len=%d\n",
 	    rec.FileIndex, rec.VolSessionId, stream_to_ascii(rec.Stream,rec.FileIndex), 
 	    rec.data_len);
 	  
 	 while (!write_record_to_block(dcr->block, &rec)) {
-            Dmsg2(150, "!write_record_to_block data_len=%d rem=%d\n", rec.data_len,
+            Dmsg2(650, "!write_record_to_block data_len=%d rem=%d\n", rec.data_len,
 		       rec.remainder);
 	    if (!write_block_to_device(dcr)) {
                Dmsg2(90, "Got write_block_to_dev error on device %s. %s\n",
@@ -195,7 +204,7 @@ bool do_append_data(JCR *jcr)
 	    break;
 	 }
 	 jcr->JobBytes += rec.data_len;   /* increment bytes this job */
-         Dmsg4(200, "write_record FI=%s SessId=%d Strm=%s len=%d\n",
+         Dmsg4(350, "write_record FI=%s SessId=%d Strm=%s len=%d\n",
 	    FI_to_ascii(rec.FileIndex), rec.VolSessionId, 
 	    stream_to_ascii(rec.Stream, rec.FileIndex), rec.data_len);
 
@@ -206,7 +215,7 @@ bool do_append_data(JCR *jcr)
 	       if (are_attributes_spooled(jcr)) {
 		  jcr->dir_bsock->spool = true;
 	       }
-               Dmsg0(200, "Send attributes.\n");
+               Dmsg0(350, "Send attributes.\n");
 	       if (!dir_update_file_attributes(dcr, &rec)) {
 		  jcr->dir_bsock->spool = false;
                   Jmsg(jcr, M_FATAL, 0, _("Error updating file attributes. ERR=%s\n"),
@@ -230,6 +239,9 @@ bool do_append_data(JCR *jcr)
    set_jcr_job_status(jcr, ok?JS_Terminated:JS_ErrorTerminated);
 
    Dmsg1(200, "Write session label JobStatus=%d\n", jcr->JobStatus);
+   if (dev->VolCatInfo.VolCatName[0] == 0) {
+      Dmsg0(000, "NULL Volume name. This shouldn't happen!!!\n");
+   }
 
    /*
     * If !OK, check if we can still write. This may not be the case
@@ -242,6 +254,9 @@ bool do_append_data(JCR *jcr)
 	 set_jcr_job_status(jcr, JS_ErrorTerminated);
 	 ok = false;
       }
+      if (dev->VolCatInfo.VolCatName[0] == 0) {
+         Dmsg0(000, "NULL Volume name. This shouldn't happen!!!\n");
+      }
       Dmsg0(90, "back from write_end_session_label()\n");
       /* Flush out final partial block of this session */
       if (!write_block_to_device(dcr)) {
@@ -250,6 +265,9 @@ bool do_append_data(JCR *jcr)
 	 ok = false;
       }
    }
+   if (dev->VolCatInfo.VolCatName[0] == 0) {
+      Dmsg0(000, "NULL Volume name. This shouldn't happen!!!\n");
+   }
 
    if (!ok) {
       discard_data_spool(jcr);
diff --git a/bacula/src/stored/askdir.c b/bacula/src/stored/askdir.c
index a0ec63e294..ca19abed61 100644
--- a/bacula/src/stored/askdir.c
+++ b/bacula/src/stored/askdir.c
@@ -88,7 +88,7 @@ static bool do_get_volume_info(DCR *dcr)
        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,
@@ -108,7 +108,7 @@ static bool do_get_volume_info(DCR *dcr)
     bstrncpy(dcr->VolumeName, vol.VolCatName, sizeof(dcr->VolumeName));
     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;
 }
@@ -130,7 +130,7 @@ bool dir_get_volume_info(DCR *dcr, enum get_vol_info_rw writing)
     BSOCK *dir = jcr->dir_bsock;
 
     bstrncpy(dcr->VolCatInfo.VolCatName, dcr->VolumeName, sizeof(dcr->VolCatInfo.VolCatName));
-    Dmsg1(200, "dir_get_volume_info=%s\n", 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);
@@ -144,7 +144,7 @@ bool dir_get_volume_info(DCR *dcr, 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(DCR *dcr)
@@ -154,10 +154,15 @@ bool dir_find_next_appendable_volume(DCR *dcr)
     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(dcr)) {
-          Dmsg2(200, "JobId=%d got possible Vol=%s\n", jcr->JobId, dcr->VolumeName);
+          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(DCR *dcr)
 		free_locked_jcr(njcr);
 		continue;	      /* us */
 	     }
-             Dmsg2(200, "Compare to JobId=%d using Vol=%s\n", njcr->JobId, njcr->dcr->VolumeName);
+             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(DCR *dcr)
 	  }
 	  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(DCR *dcr)
 	  return false;
        }
     }
-    Dmsg0(200, "dir_find_next_appendable_volume return true\n");
+    Dmsg0(400, "dir_find_next_appendable_volume return true\n");
     return true; 
 }
 
@@ -212,14 +217,16 @@ bool dir_update_volume_info(DCR *dcr, bool label)
 
    if (vol->VolCatName[0] == 0) {
       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_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));
@@ -237,14 +244,15 @@ bool dir_update_volume_info(DCR *dcr, 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(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, &dcr->VolCatInfo, sizeof(dev->VolCatInfo));
    return true;
@@ -267,14 +275,14 @@ bool dir_create_jobmedia_record(DCR *dcr)
       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_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_FATAL, 0, _("Error creating JobMedia record: %s\n"), dir->msg);
@@ -334,7 +342,7 @@ bool dir_ask_sysop_to_create_appendable_volume(DCR *dcr)
    DEVICE *dev = dcr->dev;
    JCR *jcr = dcr->jcr;
 
-   Dmsg0(200, "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)) {
@@ -357,7 +365,7 @@ bool dir_ask_sysop_to_create_appendable_volume(DCR *dcr)
 	 if (!unmounted && ((dcr->VolumeName[0] && !dev_cap(dev, CAP_REM) && 
 		dev_cap(dev, CAP_LABEL)) ||
 		 (dcr->VolumeName[0] && dcr->VolCatInfo.Slot))) {
-            Dmsg0(200, "Return 1 from mount without wait.\n");
+            Dmsg0(400, "Return 1 from mount without wait.\n");
 	    return true;
 	 }
 	 jstat = JS_WaitMount;
@@ -366,7 +374,7 @@ bool dir_ask_sysop_to_create_appendable_volume(DCR *dcr)
 "Please mount Volume \"%s\" on Storage Device \"%s\" for Job %s\n"
 "Use \"mount\" command to release Job.\n"),
 	      dcr->VolumeName, dcr->dev_name, jcr->Job);
-            Dmsg3(200, "Mount %s on %s for Job %s\n",
+            Dmsg3(400, "Mount %s on %s for Job %s\n",
 		  dcr->VolumeName, dcr->dev_name, jcr->Job);
 	 }
       } else {
@@ -391,7 +399,7 @@ Please use the \"label\"  command to create a new Volume for:\n\
 
       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;
       }
 
@@ -400,7 +408,7 @@ Please use the \"label\"  command to create a new Volume for:\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(200, "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;
@@ -417,7 +425,7 @@ Please use the \"label\"  command to create a new Volume for:\n\
          Jmsg(jcr, M_WARNING, 0, _("pthread error in mount_next_volume stat=%d ERR=%s\n"), stat,
 	    be.strerror(stat));
       }
-      Dmsg1(200, "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 (dcr->VolumeName[0] == 0 && !job_canceled(jcr) &&
@@ -442,7 +450,7 @@ volumes for Job=%s.\n"), jcr->Job);
    }
    set_jcr_job_status(jcr, JS_Running);
    dir_send_job_status(jcr);
-   Dmsg0(200, "leave dir_ask_sysop_to_mount_create_appendable_volume\n");
+   Dmsg0(400, "leave dir_ask_sysop_to_mount_create_appendable_volume\n");
    return true;
 }
 
@@ -465,7 +473,7 @@ bool dir_ask_sysop_to_mount_volume(DCR *dcr)
    DEVICE *dev = dcr->dev;
    JCR *jcr = dcr->jcr;
 
-   Dmsg0(200, "enter dir_ask_sysop_to_mount_volume\n");
+   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;
@@ -482,7 +490,7 @@ bool dir_ask_sysop_to_mount_volume(DCR *dcr)
          msg = _("Please mount");
          Jmsg(jcr, M_MOUNT, 0, _("%s Volume \"%s\" on Storage Device \"%s\" for Job %s\n"),
 	      msg, dcr->VolumeName, dcr->dev_name, jcr->Job);
-         Dmsg3(200, "Mount \"%s\" on device \"%s\" for Job %s\n",
+         Dmsg3(400, "Mount \"%s\" on device \"%s\" for Job %s\n",
 	       dcr->VolumeName, dcr->dev_name, jcr->Job);
       }
 
@@ -491,8 +499,8 @@ bool dir_ask_sysop_to_mount_volume(DCR *dcr)
 
       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=%s\n", edit_blocked_reason(dev));
+         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;
       }
 
@@ -501,7 +509,7 @@ bool dir_ask_sysop_to_mount_volume(DCR *dcr)
             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(200, "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;
@@ -518,12 +526,12 @@ bool dir_ask_sysop_to_mount_volume(DCR *dcr)
          Jmsg(jcr, M_FATAL, 0, _("pthread error in mount_next_volume stat=%d ERR=%s\n"), stat,
 	    be.strerror(stat));
       }
-      Dmsg1(200, "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(200, "leave dir_ask_sysop_to_mount_volume\n");
+   Dmsg0(400, "leave dir_ask_sysop_to_mount_volume\n");
    return true;
 }
 
@@ -576,12 +584,12 @@ static int wait_for_sysop(DCR *dcr)
    for ( ; !job_canceled(jcr); ) {
       time_t now, start;
 
-      Dmsg3(200, "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(200, "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);
@@ -592,7 +600,7 @@ static int wait_for_sysop(DCR *dcr)
 	    /* send heartbeats */
 	    if (jcr->file_bsock) {
 	       bnet_sig(jcr->file_bsock, BNET_HEARTBEAT);
-               Dmsg0(200, "Send heartbeat to FD.\n");
+               Dmsg0(400, "Send heartbeat to FD.\n");
 	    }
 	    if (jcr->dir_bsock) {
 	       bnet_sig(jcr->dir_bsock, BNET_HEARTBEAT);
@@ -611,13 +619,13 @@ static int wait_for_sysop(DCR *dcr)
 	 break; 		   /* on error return */
       }
       if (dev->rem_wait_sec <= 0) {  /* on exceeding wait time return */
-         Dmsg0(200, "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=%s\n", edit_blocked_reason(dev));
+         Dmsg1(400, "In wait blocked=%s\n", edit_blocked_reason(dev));
 	 dev->poll = true;	      /* returning a poll event */
 	 break;
       }
@@ -639,7 +647,7 @@ static int wait_for_sysop(DCR *dcr)
       gettimeofday(&tv, &tz);
       timeout.tv_nsec = tv.tv_usec * 1000;
       timeout.tv_sec = tv.tv_sec + add_wait; /* additional wait */
-      Dmsg1(200, "Additional wait %d sec.\n", add_wait);
+      Dmsg1(400, "Additional wait %d sec.\n", add_wait);
    }
 
    if (!unmounted) {
diff --git a/bacula/src/stored/block.c b/bacula/src/stored/block.c
index 375145a94f..37d4b7e813 100644
--- a/bacula/src/stored/block.c
+++ b/bacula/src/stored/block.c
@@ -33,6 +33,7 @@
 #include "stored.h"
 
 extern int debug_level;
+static bool terminate_writing_volume(DCR *dcr);
 
 /*
  * Dump the block header, then walk through
@@ -183,7 +184,7 @@ void ser_block_header(DEV_BLOCK *block)
    uint32_t CheckSum = 0;
    uint32_t block_len = block->binbuf;
    
-   Dmsg1(190, "ser_block_header: block_len=%d\n", block_len);
+   Dmsg1(390, "ser_block_header: block_len=%d\n", block_len);
    ser_begin(block->buf, BLKHDR2_LENGTH);
    ser_uint32(CheckSum);
    ser_uint32(block_len);
@@ -197,7 +198,7 @@ void ser_block_header(DEV_BLOCK *block)
    /* Checksum whole block except for the checksum */
    CheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH, 
 		 block_len-BLKHDR_CS_LENGTH);
-   Dmsg1(190, "ser_bloc_header: checksum=%x\n", CheckSum);
+   Dmsg1(390, "ser_bloc_header: checksum=%x\n", CheckSum);
    ser_begin(block->buf, BLKHDR2_LENGTH);
    ser_uint32(CheckSum);	      /* now add checksum to block header */
 }
@@ -282,7 +283,7 @@ static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block)
       return false;
    }
 
-   Dmsg1(190, "unser_block_header block_len=%d\n", block_len);
+   Dmsg1(390, "unser_block_header block_len=%d\n", block_len);
    /* Find end of block or end of buffer whichever is smaller */
    if (block_len > block->read_len) {
       block_end = block->read_len;
@@ -292,7 +293,7 @@ static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block)
    block->binbuf = block_end - bhl;
    block->block_len = block_len;
    block->BlockNumber = BlockNumber;
-   Dmsg3(190, "Read binbuf = %d %d block_len=%d\n", block->binbuf,
+   Dmsg3(390, "Read binbuf = %d %d block_len=%d\n", block->binbuf,
       bhl, block_len);
    if (block_len <= block->read_len) {
       BlockCheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
@@ -342,6 +343,10 @@ bool write_block_to_device(DCR *dcr)
     * The same applies for if we are in a new file.
     */
    if (dcr->NewVol || dcr->NewFile) {
+      if (job_canceled(jcr)) {
+	 stat = false;
+	 goto bail_out;
+      }
       /* Create a jobmedia record for this job */
       if (!dir_create_jobmedia_record(dcr)) {
 	 dev->dev_errno = EIO;
@@ -362,7 +367,7 @@ bool write_block_to_device(DCR *dcr)
 
    if (!write_block_to_dev(dcr)) {
        if (job_canceled(jcr)) {
-	  stat = 0;
+	  stat = false;
        } else {
 	  stat = fixup_device_block_write_error(dcr);
        }
@@ -404,6 +409,11 @@ bool write_block_to_dev(DCR *dcr)
       Jmsg(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM.\n"));
       return false;
    }
+   if (!(dev->state & ST_APPEND)) {
+      dev->dev_errno = EIO;
+      Jmsg(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume.\n"));
+      return false;
+   }
    wlen = block->binbuf;
    if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
       Dmsg0(100, "return write_block_to_dev no data to write\n");
@@ -455,21 +465,7 @@ bool write_block_to_dev(DCR *dcr)
       }
       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
 	    edit_uint64_with_commas(max_cap, ed1),  dev->dev_name);
-      block->write_failed = true;
-      if (weof_dev(dev, 1) != 0) {	      /* end tape */
-         Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
-	 dev->VolCatInfo.VolCatErrors++;
-      }
-      /* Don't do update after second EOF or file count will be wrong */
-      Dmsg0(100, "dir_update_volume_info\n");
-      dev->VolCatInfo.VolCatFiles = dev->file;
-      dir_update_volume_info(dcr, false);
-      if (dev_cap(dev, CAP_TWOEOF) && weof_dev(dev, 1) != 0) {	/* write eof */
-	 /* This may not be fatal since we already wrote an EOF */
-         Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
-	 dev->VolCatInfo.VolCatErrors++;
-      }
-      dev->state |= (ST_EOF | ST_EOT | ST_WEOT);
+      terminate_writing_volume(dcr);
       dev->dev_errno = ENOSPC;
       return false;
    }
@@ -477,45 +473,35 @@ bool write_block_to_dev(DCR *dcr)
    /* Limit maximum File size on volume to user specified value */
    if ((dev->max_file_size > 0) && 
        (dev->file_size+block->binbuf) >= dev->max_file_size) {
+      dev->file_size = 0;	      /* reset file size */
 
       if (dev_state(dev, ST_TAPE) && weof_dev(dev, 1) != 0) {		 /* write eof */
-	 /* Write EOF */
-         Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
-	 block->write_failed = true;
-	 dev->VolCatInfo.VolCatErrors++;
-	 dev->state |= (ST_EOF | ST_EOT | ST_WEOT);
-         Dmsg0(100, "dir_update_volume_info\n");
-	 dev->VolCatInfo.VolCatFiles = dev->file;
-	 dir_update_volume_info(dcr, false);
+         Dmsg0(190, "WEOF error in max file size.\n");
+	 terminate_writing_volume(dcr);
 	 dev->dev_errno = ENOSPC;
 	 return false;
       }
 
       /* Create a JobMedia record so restore can seek */
-      Dmsg0(100, "dir_update_volume_info\n");
-      dev->VolCatInfo.VolCatFiles = dev->file;
-      dir_update_volume_info(dcr, false);
       if (!dir_create_jobmedia_record(dcr)) {
+         Dmsg0(190, "Error from create_job_media.\n");
 	 dev->dev_errno = EIO;
-          Jmsg(jcr, M_ERROR, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
+          Jmsg(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
 	       dcr->VolCatInfo.VolCatName, jcr->Job);
-	  if (!forge_on) {
-	     return false;
-	  }
+	  terminate_writing_volume(dcr);
+	  dev->dev_errno = EIO;
+	  return false;
       }
-      dev->file_size = 0;	      /* reset file size */
-      /* 
-       * Walk through all attached jcrs indicating the file has changed   
-       */
-      Dmsg1(100, "Walk attached jcrs. Volume=%s\n", dev->VolCatInfo.VolCatName);
-#ifdef xxx
-      for (JCR *mjcr=NULL; (mjcr=next_attached_jcr(dev, mjcr)); ) {
-	 if (mjcr->JobId == 0) {
-	    continue;		      /* ignore console */
-	 }
-	 mjcr->dcr->NewFile = true;   /* set reminder to do set_new_file_params */
+      dev->VolCatInfo.VolCatFiles = dev->file;
+      if (!dir_update_volume_info(dcr, false)) {
+         Dmsg0(190, "Error from update_vol_info.\n");
+	 terminate_writing_volume(dcr);
+	 dev->dev_errno = EIO;
+	 return false;
       }
-#endif
+      Dmsg0(100, "dir_update_volume_info max file size -- OK\n");
+
+
       /*
        * Walk through all attached dcrs setting flag to call
        * set_new_file_parameters() when that dcr is next used.
@@ -532,7 +518,7 @@ bool write_block_to_dev(DCR *dcr)
    }
 
    dev->VolCatInfo.VolCatWrites++;
-   Dmsg1(200, "Write block of %u bytes\n", wlen);      
+   Dmsg1(300, "Write block of %u bytes\n", wlen);      
 #ifdef DEBUG_BLOCK_ZEROING
    uint32_t *bp = (uint32_t *)block->buf;
    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
@@ -557,13 +543,6 @@ bool write_block_to_dev(DCR *dcr)
        */
       if (stat == -1) {
 	 berrno be;
-	 /* I have added the ifdefing here because it appears on
-	  * FreeBSD where MTIOCERRSTAT is defined, this not only
-	  * clears the error but clears the residual unwritten
-	  * buffers -> data loss. As a consequence, on those
-	  * systems (FreeBSD like), do the clrerror() only after
-	  * the weof_dev() call.
-	  */
 	 clrerror_dev(dev, -1);
 	 if (dev->dev_errno == 0) {
 	    dev->dev_errno = ENOSPC;	    /* out of space */
@@ -583,22 +562,11 @@ bool write_block_to_dev(DCR *dcr)
       Dmsg6(100, "=== Write error. size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n", 
 	 wlen, stat, dev->block_num, block->BlockNumber, dev->dev_errno, strerror(dev->dev_errno));
 
-      block->write_failed = true;
-      if (weof_dev(dev, 1) != 0) {	   /* end the tape */
-	 dev->VolCatInfo.VolCatErrors++;
-         Jmsg(jcr, M_FATAL, 0, "%s", dev->errmsg);
-	 ok = false;
-      }
-      Dmsg0(100, "dir_update_volume_info\n");
-      dev->VolCatInfo.VolCatFiles = dev->file;
-      dir_update_volume_info(dcr, false);
-      if (ok && dev_cap(dev, CAP_TWOEOF) && weof_dev(dev, 1) != 0) {  /* end the tape */
-	 dev->VolCatInfo.VolCatErrors++;
-	 /* This may not be fatal since we already wrote an EOF */
-         Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
+      ok = terminate_writing_volume(dcr);
+      if (!ok && !forge_on) {
+	 return false;
       }
-      dev->state |= (ST_EOF | ST_EOT | ST_WEOT);
-	
+
 #define CHECK_LAST_BLOCK
 #ifdef	CHECK_LAST_BLOCK
       /* 
@@ -683,12 +651,68 @@ bool write_block_to_dev(DCR *dcr)
    dev->file_addr += wlen;	      /* update file address */
    dev->file_size += wlen;
 
-   Dmsg2(190, "write_block: wrote block %d bytes=%d\n", dev->block_num,
-      wlen);
+   Dmsg2(300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
    empty_block(block);
    return true;
 }
 
+static bool terminate_writing_volume(DCR *dcr)
+{
+   DEVICE *dev = dcr->dev;
+   bool ok = true;
+
+   /* Create a JobMedia record to indicated end of tape */
+   dev->VolCatInfo.VolCatFiles = dev->file;
+   if (!dir_create_jobmedia_record(dcr)) {
+      Dmsg0(190, "Error from create JobMedia\n");
+      dev->dev_errno = EIO;
+       Jmsg(dcr->jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
+	    dcr->VolCatInfo.VolCatName, dcr->jcr->Job);
+       ok = false;
+       goto bail_out;
+   }
+   dcr->block->write_failed = true;
+   if (weof_dev(dev, 1) != 0) { 	/* end the tape */
+      dev->VolCatInfo.VolCatErrors++;
+      Jmsg(dcr->jcr, M_ERROR, 0, "Error writing final EOF to tape. This tape may not be readable.\n"
+           "%s", dev->errmsg);
+      ok = false;
+      Dmsg0(100, "WEOF error.\n");
+   }
+   dev->VolCatInfo.VolCatFiles = dev->file;
+   if (!dir_update_volume_info(dcr, false)) {
+      ok = false;
+   }
+   Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
+
+
+   /*
+    * Walk through all attached dcrs setting flag to call
+    * set_new_file_parameters() when that dcr is next used.
+    */
+   DCR *mdcr;
+   foreach_dlist(mdcr, dev->attached_dcrs) {
+      if (mdcr->jcr->JobId == 0) {
+	 continue;
+      }
+      mdcr->NewFile = true;	   /* set reminder to do set_new_file_params */
+   }
+   /* Set new file/block parameters for current dcr */
+   set_new_file_parameters(dcr);
+
+   if (ok && dev_cap(dev, CAP_TWOEOF) && weof_dev(dev, 1) != 0) {  /* end the tape */
+      dev->VolCatInfo.VolCatErrors++;
+      /* This may not be fatal since we already wrote an EOF */
+      Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
+   }
+bail_out:
+   dev->state |= (ST_EOF|ST_EOT|ST_WEOT);
+   dev->state &= ~ST_APPEND;	      /* make tape read-only */
+   Dmsg1(100, "Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
+   return ok;
+}
+
+
 /*  
  * Read block with locking
  *
diff --git a/bacula/src/stored/dev.c b/bacula/src/stored/dev.c
index 4d770d3726..79b3fc3ad4 100644
--- a/bacula/src/stored/dev.c
+++ b/bacula/src/stored/dev.c
@@ -360,10 +360,10 @@ int _rewind_dev(char *file, int line, DEVICE *dev)
 
 /*
  * Rewind the device.
- *  Returns: 1 on success
- *	     0 on failure
+ *  Returns: true  on success
+ *	     false on failure
  */
-int rewind_dev(DEVICE *dev)
+bool rewind_dev(DEVICE *dev)
 {
    struct mtop mt_com;
    unsigned int i;
@@ -374,9 +374,9 @@ int rewind_dev(DEVICE *dev)
       Mmsg1(&dev->errmsg, _("Bad call to rewind_dev. Device %s not open\n"),
 	    dev->dev_name);
       Emsg0(M_FATAL, 0, dev->errmsg);
-      return 0;
+      return false;
    }
-   dev->state &= ~(ST_APPEND|ST_READ|ST_EOT|ST_EOF|ST_WEOT);  /* remove EOF/EOT flags */
+   dev->state &= ~(ST_EOT|ST_EOF|ST_WEOT);  /* remove EOF/EOT flags */
    dev->block_num = dev->file = 0;
    dev->file_addr = 0;
    if (dev->state & ST_TAPE) {
@@ -388,6 +388,7 @@ int rewind_dev(DEVICE *dev)
        */
       for (i=dev->max_rewind_wait; ; i -= 5) {
 	 if (ioctl(dev->fd, MTIOCTOP, (char *)&mt_com) < 0) {
+	    berrno be;
 	    if (i == dev->max_rewind_wait) {
                Dmsg1(200, "Rewind error, %s. retrying ...\n", strerror(errno));
 	    }
@@ -398,20 +399,21 @@ int rewind_dev(DEVICE *dev)
 	       continue;
 	    }
             Mmsg2(&dev->errmsg, _("Rewind error on %s. ERR=%s.\n"),
-	       dev->dev_name, strerror(dev->dev_errno));
-	    return 0;
+	       dev->dev_name, be.strerror(dev->dev_errno));
+	    return false;
 	 }
 	 break;
       }
    } else if (dev->state & ST_FILE) {
       if (lseek(dev->fd, (off_t)0, SEEK_SET) < 0) {
+	 berrno be;
 	 dev->dev_errno = errno;
          Mmsg2(&dev->errmsg, _("lseek error on %s. ERR=%s.\n"),
-	    dev->dev_name, strerror(dev->dev_errno));
-	 return 0;
+	    dev->dev_name, be.strerror(dev->dev_errno));
+	 return false;
       }
    }
-   return 1;
+   return true;
 }
 
 /* 
@@ -446,8 +448,9 @@ eod_dev(DEVICE *dev)
 	 return 1;
       }
       dev->dev_errno = errno;
+      berrno be;
       Mmsg2(&dev->errmsg, _("lseek error on %s. ERR=%s.\n"),
-	     dev->dev_name, strerror(dev->dev_errno));
+	     dev->dev_name, be.strerror(dev->dev_errno));
       return 0;
    }
 #ifdef MTEOM
@@ -478,18 +481,20 @@ eod_dev(DEVICE *dev)
    }
    if (dev_cap(dev, CAP_FASTFSF) || dev_cap(dev, CAP_EOM)) {
       if ((stat=ioctl(dev->fd, MTIOCTOP, (char *)&mt_com)) < 0) {
-         Dmsg1(50, "ioctl error: %s\n", strerror(dev->dev_errno));
+	 berrno be;
 	 clrerror_dev(dev, mt_com.mt_op);
+         Dmsg1(50, "ioctl error: %s\n", be.strerror(dev->dev_errno));
 	 update_pos_dev(dev);
          Mmsg2(&dev->errmsg, _("ioctl MTEOM error on %s. ERR=%s.\n"),
-	    dev->dev_name, strerror(dev->dev_errno));
+	    dev->dev_name, be.strerror(dev->dev_errno));
 	 return 0;
       }
 
       if (ioctl(dev->fd, MTIOCGET, (char *)&mt_stat) < 0) {
-	 dev->dev_errno = errno;
+	 berrno be;
+	 clrerror_dev(dev, -1);
          Mmsg2(&dev->errmsg, _("ioctl MTIOCGET error on %s. ERR=%s.\n"),
-	    dev->dev_name, strerror(dev->dev_errno));
+	    dev->dev_name, be.strerror(dev->dev_errno));
 	 return 0;
       }
       Dmsg2(100, "EOD file=%d block=%d\n", mt_stat.mt_fileno, mt_stat.mt_blkno);
@@ -620,9 +625,10 @@ uint32_t status_dev(DEVICE *dev)
       Dmsg0(-20," Bacula status:");
       Dmsg2(-20," file=%d block=%d\n", dev->file, dev->block_num);
       if (ioctl(dev->fd, MTIOCGET, (char *)&mt_stat) < 0) {
+	 berrno be;
 	 dev->dev_errno = errno;
          Mmsg2(&dev->errmsg, _("ioctl MTIOCGET error on %s. ERR=%s.\n"),
-	    dev->dev_name, strerror(dev->dev_errno));
+	    dev->dev_name, be.strerror(dev->dev_errno));
 	 return 0;
       }
       Dmsg0(-20, " Device status:");
@@ -695,9 +701,10 @@ bool load_dev(DEVICE *dev)
    }
 #ifndef MTLOAD
    Dmsg0(200, "stored: MTLOAD command not available\n");
+   berrno be;
    dev->dev_errno = ENOTTY;	      /* function not available */
    Mmsg2(&dev->errmsg, _("ioctl MTLOAD error on %s. ERR=%s.\n"),
-	 dev->dev_name, strerror(dev->dev_errno));	return 0;
+	 dev->dev_name, be.strerror(dev->dev_errno));	   return 0;
    return false;
 #else
 
@@ -706,9 +713,10 @@ bool load_dev(DEVICE *dev)
    mt_com.mt_op = MTLOAD;
    mt_com.mt_count = 1;
    if (ioctl(dev->fd, MTIOCTOP, (char *)&mt_com) < 0) {
+      berrno be;
       dev->dev_errno = errno;
       Mmsg2(&dev->errmsg, _("ioctl MTLOAD error on %s. ERR=%s.\n"),
-	 dev->dev_name, strerror(dev->dev_errno));	return 0;
+	 dev->dev_name, be.strerror(dev->dev_errno));	   return 0;
       return false;
    }
    return true;
@@ -745,9 +753,10 @@ bool offline_dev(DEVICE *dev)
    mt_com.mt_op = MTOFFL;
    mt_com.mt_count = 1;
    if (ioctl(dev->fd, MTIOCTOP, (char *)&mt_com) < 0) {
+      berrno be;
       dev->dev_errno = errno;
       Mmsg2(&dev->errmsg, _("ioctl MTOFFL error on %s. ERR=%s.\n"),
-	 dev->dev_name, strerror(dev->dev_errno));
+	 dev->dev_name, be.strerror(dev->dev_errno));
       return false;
    }
    Dmsg1(100, "Offlined device %s\n", dev->dev_name);
@@ -766,6 +775,7 @@ int offline_or_rewind_dev(DEVICE *dev)
     *  such as backspacing after writing and EOF. If it is not
     *  done, all future references to the drive get and I/O error.
     */
+      clrerror_dev(dev, MTREW);
       return rewind_dev(dev);
    }
 }
@@ -887,11 +897,12 @@ fsf_dev(DEVICE *dev, int num)
          Dmsg0(200, "Doing MTFSF\n");
 	 stat = ioctl(dev->fd, MTIOCTOP, (char *)&mt_com);
 	 if (stat < 0) {		 /* error => EOT */
+	    berrno be;
 	    dev->state |= ST_EOT;
             Dmsg0(200, "Set ST_EOT\n");
 	    clrerror_dev(dev, MTFSF);
             Mmsg2(&dev->errmsg, _("ioctl MTFSF error on %s. ERR=%s.\n"),
-	       dev->dev_name, strerror(dev->dev_errno));
+	       dev->dev_name, be.strerror(dev->dev_errno));
             Dmsg0(200, "Got < 0 for MTFSF\n");
             Dmsg1(200, "%s", dev->errmsg);
 	 } else {
@@ -959,9 +970,10 @@ bsf_dev(DEVICE *dev, int num)
    mt_com.mt_count = num;
    stat = ioctl(dev->fd, MTIOCTOP, (char *)&mt_com);
    if (stat < 0) {
+      berrno be;
       clrerror_dev(dev, MTBSF);
       Mmsg2(dev->errmsg, _("ioctl MTBSF error on %s. ERR=%s.\n"),
-	 dev->dev_name, strerror(dev->dev_errno));
+	 dev->dev_name, be.strerror(dev->dev_errno));
    }
    update_pos_dev(dev);
    return stat == 0;
@@ -1002,6 +1014,7 @@ fsr_dev(DEVICE *dev, int num)
       dev->state &= ~ST_EOF;
       dev->block_num += num;
    } else {
+      berrno be;
       struct mtget mt_stat;
       if (ioctl(dev->fd, MTIOCGET, (char *)&mt_stat) == 0 && mt_stat.mt_fileno >= 0) {
          Dmsg4(100, "Adjust from %d:%d to %d:%d\n", dev->file, 
@@ -1020,7 +1033,7 @@ fsr_dev(DEVICE *dev, int num)
       }
       clrerror_dev(dev, MTFSR);
       Mmsg2(dev->errmsg, _("ioctl MTFSR error on %s. ERR=%s.\n"),
-	 dev->dev_name, strerror(dev->dev_errno));
+	 dev->dev_name, be.strerror(dev->dev_errno));
    }
    update_pos_dev(dev);
    return stat == 0;
@@ -1060,9 +1073,10 @@ bsr_dev(DEVICE *dev, int num)
    mt_com.mt_count = num;
    stat = ioctl(dev->fd, MTIOCTOP, (char *)&mt_com);
    if (stat < 0) {
+      berrno be;
       clrerror_dev(dev, MTBSR);
       Mmsg2(dev->errmsg, _("ioctl MTBSR error on %s. ERR=%s.\n"),
-	 dev->dev_name, strerror(dev->dev_errno));
+	 dev->dev_name, be.strerror(dev->dev_errno));
    }
    update_pos_dev(dev);
    return stat == 0;
@@ -1147,12 +1161,12 @@ weof_dev(DEVICE *dev, int num)
       return 0;
    }
    dev->state &= ~(ST_EOT | ST_EOF);  /* remove EOF/EOT flags */
-   dev->block_num = 0;
    Dmsg0(29, "weof_dev\n");
    mt_com.mt_op = MTWEOF;
    mt_com.mt_count = num;
    stat = ioctl(dev->fd, MTIOCTOP, (char *)&mt_com);
    if (stat == 0) {
+      dev->block_num = 0;
       dev->file += num;
       dev->file_addr = 0;
    } else {
diff --git a/bacula/src/stored/device.c b/bacula/src/stored/device.c
index 7d5a9af81b..73dd46ba0b 100644
--- a/bacula/src/stored/device.c
+++ b/bacula/src/stored/device.c
@@ -100,15 +100,6 @@ bool fixup_device_block_write_error(DCR *dcr)
    /* Unlock, but leave BLOCKED */
    unlock_device(dev);
 
-   /* Create a jobmedia record for this job */
-   if (!dir_create_jobmedia_record(dcr)) {
-       Jmsg(jcr, M_ERROR, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
-	    dcr->VolCatInfo.VolCatName, jcr->Job);
-       P(dev->mutex);
-       unblock_device(dev);
-       return false;
-   }
-
    bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus));
    Dmsg2(100, "Call update_vol_info Stat=%s Vol=%s\n", 
       dev->VolCatInfo.VolCatStatus, dev->VolCatInfo.VolCatName);
@@ -153,8 +144,9 @@ bool fixup_device_block_write_error(DCR *dcr)
     */
    Dmsg0(190, "write label block to dev\n");
    if (!write_block_to_dev(dcr)) {
+      berrno be;
       Pmsg1(0, "write_block_to_device Volume label failed. ERR=%s",
-	strerror_dev(dev));
+	be.strerror(dev->dev_errno));
       free_block(label_blk);
       dcr->block = block;
       unblock_device(dev);
@@ -189,8 +181,9 @@ bool fixup_device_block_write_error(DCR *dcr)
    /* Write overflow block to device */
    Dmsg0(190, "Write overflow block to dev\n");
    if (!write_block_to_dev(dcr)) {
+      berrno be;
       Pmsg1(0, "write_block_to_device overflow block failed. ERR=%s",
-	strerror_dev(dev));
+	be.strerror(dev->dev_errno));
       unblock_device(dev);
       return false;		   /* device locked */
    }
diff --git a/bacula/src/stored/fd_cmds.c b/bacula/src/stored/fd_cmds.c
index b6d801cd7e..482cc68b47 100644
--- a/bacula/src/stored/fd_cmds.c
+++ b/bacula/src/stored/fd_cmds.c
@@ -233,14 +233,14 @@ static bool append_close_session(JCR *jcr)
 {
    BSOCK *fd = jcr->file_bsock;
 
-   Dmsg1(120, "<filed: %s\n", fd->msg);
+   Dmsg1(120, "<filed: %s", fd->msg);
    if (!jcr->session_opened) {
       bnet_fsend(fd, NOT_opened);
       return false;
    }
    /* Send final statistics to File daemon */
    bnet_fsend(fd, OK_close, jcr->JobStatus);
-   Dmsg1(120, ">filed: %s\n", fd->msg);
+   Dmsg1(120, ">filed: %s", fd->msg);
 
    bnet_sig(fd, BNET_EOD);	      /* send EOD to File daemon */
        
@@ -260,7 +260,7 @@ static bool read_data_cmd(JCR *jcr)
 {
    BSOCK *fd = jcr->file_bsock;
 
-   Dmsg1(120, "Read data: %s\n", fd->msg);
+   Dmsg1(120, "Read data: %s", fd->msg);
    if (jcr->session_opened) {
       Dmsg1(120, "<bfiled: %s", fd->msg);
       return do_read_data(jcr);
diff --git a/bacula/src/stored/job.c b/bacula/src/stored/job.c
index d3654939f8..fd13c59596 100644
--- a/bacula/src/stored/job.c
+++ b/bacula/src/stored/job.c
@@ -272,7 +272,7 @@ static bool use_device_cmd(JCR *jcr)
 	    bstrncpy(dcr->media_type, media_type, name_len);
 	    bstrncpy(dcr->dev_name, dev_name, name_len);
 	    jcr->device = device;
-	    Dmsg4(120, use_device, dev_name.c_str(), media_type.c_str(), pool_name.c_str(), pool_type.c_str());
+            Dmsg1(220, "Got: %s", dir->msg);
 	    return bnet_fsend(dir, OK_device);
 	 }
       }
diff --git a/bacula/src/stored/label.c b/bacula/src/stored/label.c
index aca6f901e6..1b9caa213b 100644
--- a/bacula/src/stored/label.c
+++ b/bacula/src/stored/label.c
@@ -397,6 +397,7 @@ bool write_new_volume_label_to_dev(DCR *dcr, const char *VolName, const char *Po
 
    Dmsg0(99, "write_volume_label()\n");
    empty_block(dcr->block);
+   /* Create PRE_LABEL */	
    create_volume_label(dev, VolName, PoolName);
 
    if (!rewind_dev(dev)) {
@@ -410,6 +411,8 @@ bool write_new_volume_label_to_dev(DCR *dcr, const char *VolName, const char *Po
    create_volume_label_record(dcr, dcr->rec);
    dcr->rec->Stream = 0;
 
+   /* Temporarily mark in append state to enable writing */
+   dev->state |= ST_APPEND;
    if (!write_record_to_block(dcr->block, dcr->rec)) {
       Dmsg2(30, "Bad Label write on %s. ERR=%s\n", dev_name(dev), strerror_dev(dev));
       memset(&dev->VolHdr, 0, sizeof(dev->VolHdr));
@@ -426,15 +429,17 @@ bool write_new_volume_label_to_dev(DCR *dcr, const char *VolName, const char *Po
    }
    Dmsg0(99, " Wrote block to device\n");
      
-   weof_dev(dev, 1);
-   dev->state |= ST_LABEL;
-   ok = true;
+   if (weof_dev(dev, 1) == 0) {
+      dev->state |= ST_LABEL;
+      ok = true;
+   }
 
    if (debug_level >= 20)  {
       dump_volume_label(dev);
    }
 
 bail_out:
+   dev->state &= ~ST_APPEND;	      /* remove append since this is PRE_LABEL */
    return ok;
 }     
 
@@ -556,8 +561,8 @@ bool write_session_label(DCR *dcr, int label)
       return false;
    }
 
-   Dmsg6(20, "Write sesson_label record JobId=%d FI=%s SessId=%d Strm=%s len=%d\n\
-remainder=%d\n", jcr->JobId,
+   Dmsg6(20, "Write sesson_label record JobId=%d FI=%s SessId=%d Strm=%s len=%d " 
+             "remainder=%d\n", jcr->JobId,
       FI_to_ascii(rec->FileIndex), rec->VolSessionId, 
       stream_to_ascii(rec->Stream, rec->FileIndex), rec->data_len,
       rec->remainder);
diff --git a/bacula/src/stored/mount.c b/bacula/src/stored/mount.c
index efb0ce602f..66a0403292 100644
--- a/bacula/src/stored/mount.c
+++ b/bacula/src/stored/mount.c
@@ -116,8 +116,6 @@ mount_next_vol:
     * It assumes that the device is not already in use!
     *
     */
-   dev->state &= ~(ST_APPEND|ST_READ|ST_EOT|ST_WEOT|ST_EOF);
-
    if (autoload_device(dcr, 1, NULL) > 0) {
       autochanger = true;
       ask = false;
@@ -268,7 +266,9 @@ read_volume:
          Dmsg0(100, "dir_update_vol_info. Set Append\n");
          /* Copy Director's info into the device info */
 	 memcpy(&dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dev->VolCatInfo));
-	 dir_update_volume_info(dcr, true);  /* indicate tape labeled */
+	 if (!dir_update_volume_info(dcr, true)) {  /* indicate tape labeled */
+	    return false;
+	 }
          Jmsg(jcr, M_INFO, 0, _("Labeled new Volume \"%s\" on device %s.\n"),
 	    dcr->VolumeName, dev_name(dev));
 	 goto read_volume;	/* read label we just wrote */
@@ -344,12 +344,14 @@ The number of files mismatch! Volume=%u Catalog=%u\n"),
       }
       dev->VolCatInfo.VolCatMounts++;	   /* Update mounts */
       Dmsg1(100, "update volinfo mounts=%d\n", dev->VolCatInfo.VolCatMounts);
-      dir_update_volume_info(dcr, false);
+      if (!dir_update_volume_info(dcr, false)) {
+	 return false;
+      }
       /* Return an empty block */
       empty_block(block);	      /* we used it for reading so set for write */
    }
    dev->state |= ST_APPEND;
-   Dmsg0(100, "Normal return from read_dev_for_append\n");
+   Dmsg0(100, "set APPEND, normal return from read_dev_for_append\n");
    return true;
 }
 
@@ -363,9 +365,11 @@ static bool rewrite_volume_label(DCR *dcr, bool recycle)
    DEVICE *dev = dcr->dev;
    JCR *jcr = dcr->jcr;
 
-   Dmsg1(190, "ready_for_append found freshly labeled volume. dev=%x\n", dev);
+   Dmsg1(190, "set append found freshly labeled volume. dev=%x\n", dev);
    dev->VolHdr.LabelType = VOL_LABEL; /* set Volume label */
+   dev->state |= ST_APPEND;
    if (!write_volume_label_to_block(dcr)) {
+      Dmsg0(200, "Error from write volume label.\n");
       return false;
    }
    /*
@@ -385,9 +389,11 @@ static bool rewrite_volume_label(DCR *dcr, bool recycle)
 	 }
       }
       /* Attempt write to check write permission */
+      Dmsg0(200, "Attempt to write to device.\n");
       if (!write_block_to_dev(dcr)) {
          Jmsg2(jcr, M_ERROR, 0, _("Unable to write device \"%s\". ERR=%s\n"),
 	    dev_name(dev), strerror_dev(dev));
+         Dmsg0(200, "===ERROR write block to dev\n");
 	 return false;
       }
    }
@@ -409,7 +415,9 @@ static bool rewrite_volume_label(DCR *dcr, bool recycle)
    }
    Dmsg0(100, "dir_update_vol_info. Set Append\n");
    bstrncpy(dev->VolCatInfo.VolCatStatus, "Append", sizeof(dev->VolCatInfo.VolCatStatus));
-   dir_update_volume_info(dcr, true);  /* indicate doing relabel */
+   if (!dir_update_volume_info(dcr, true)) {  /* indicate doing relabel */
+      return false;
+   }
    if (recycle) {
       Jmsg(jcr, M_INFO, 0, _("Recycled volume \"%s\" on device \"%s\", all previous data lost.\n"),
 	 dcr->VolumeName, dev_name(dev));
@@ -421,7 +429,8 @@ static bool rewrite_volume_label(DCR *dcr, bool recycle)
     * End writing real Volume label (from pre-labeled tape), or recycling
     *  the volume.
     */
-    return true;
+   Dmsg0(200, "OK from rewite vol label.\n");
+   return true;
 }
 
 
@@ -474,6 +483,7 @@ void release_volume(DCR *dcr)
    DEVICE *dev = dcr->dev;
    if (dcr->WroteVol) {
       Jmsg0(jcr, M_ERROR, 0, "Hey!!!!! WroteVol non-zero !!!!!\n");
+      Dmsg0(190, "Hey!!!!! WroteVol non-zero !!!!!\n");
    }
    /* 
     * First erase all memory of the current volume   
@@ -497,4 +507,5 @@ void release_volume(DCR *dcr)
    if (dev->state & ST_OPENED) {
       offline_or_rewind_dev(dev);
    }
+   Dmsg0(190, "===== release_volume ---");
 }
diff --git a/bacula/src/stored/protos.h b/bacula/src/stored/protos.h
index 4956dfa7ec..4c8560a49f 100644
--- a/bacula/src/stored/protos.h
+++ b/bacula/src/stored/protos.h
@@ -92,14 +92,12 @@ void     term_dev(DEVICE *dev);
 char *   strerror_dev(DEVICE *dev);
 void     clrerror_dev(DEVICE *dev, int func);
 bool     update_pos_dev(DEVICE *dev);
-int      rewind_dev(DEVICE *dev);
+bool     rewind_dev(DEVICE *dev);
 bool     load_dev(DEVICE *dev);
 bool     offline_dev(DEVICE *dev);
 int      flush_dev(DEVICE *dev);
 int      weof_dev(DEVICE *dev, int num);
 int      write_block(DEVICE *dev);
-int      write_dev(DEVICE *dev, char *buf, size_t len);
-int      read_dev(DEVICE *dev, char *buf, size_t len);
 uint32_t status_dev(DEVICE *dev);
 int      eod_dev(DEVICE *dev);
 bool     fsf_dev(DEVICE *dev, int num);
diff --git a/bacula/src/stored/record.c b/bacula/src/stored/record.c
index d3bb44eab6..ce68807165 100644
--- a/bacula/src/stored/record.c
+++ b/bacula/src/stored/record.c
@@ -170,13 +170,13 @@ void empty_record(DEV_RECORD *rec)
  */
 void free_record(DEV_RECORD *rec) 
 {
-   Dmsg0(150, "Enter free_record.\n");
+   Dmsg0(350, "Enter free_record.\n");
    if (rec->data) {
       free_pool_memory(rec->data);
    }
-   Dmsg0(150, "Data buf is freed.\n");
+   Dmsg0(350, "Data buf is freed.\n");
    free_pool_memory((POOLMEM *)rec);
-   Dmsg0(150, "Leave free_record.\n");
+   Dmsg0(350, "Leave free_record.\n");
 } 
 
 
@@ -204,7 +204,7 @@ bool write_record_to_block(DEV_BLOCK *block, DEV_RECORD *rec)
    ASSERT(block->binbuf == (uint32_t) (block->bufp - block->buf));
    ASSERT(block->buf_len >= block->binbuf);
 
-   Dmsg6(190, "write_record_to_block() FI=%s SessId=%d Strm=%s len=%d\n\
+   Dmsg6(490, "write_record_to_block() FI=%s SessId=%d Strm=%s len=%d\n\
 rem=%d remainder=%d\n",
       FI_to_ascii(rec->FileIndex), rec->VolSessionId, 
       stream_to_ascii(rec->Stream, rec->FileIndex), rec->data_len,
@@ -403,7 +403,7 @@ bool read_record_from_block(DEV_BLOCK *block, DEV_RECORD *rec)
     * Get the header. There is always a full header,
     * otherwise we find it in the next block.
     */
-   Dmsg3(100, "Block=%d Ver=%d size=%u\n", block->BlockNumber, block->BlockVer,
+   Dmsg3(450, "Block=%d Ver=%d size=%u\n", block->BlockNumber, block->BlockVer,
 	 block->block_len);
    if (block->BlockVer == 1) {
       rhl = RECHDR1_LENGTH;
@@ -411,7 +411,7 @@ bool read_record_from_block(DEV_BLOCK *block, DEV_RECORD *rec)
       rhl = RECHDR2_LENGTH;
    }
    if (remlen >= rhl) {
-      Dmsg4(90, "Enter read_record_block: remlen=%d data_len=%d rem=%d blkver=%d\n", 
+      Dmsg4(450, "Enter read_record_block: remlen=%d data_len=%d rem=%d blkver=%d\n", 
 	    remlen, rec->data_len, rec->remainder, block->BlockVer);
 
       unser_begin(block->bufp, WRITE_RECHDR_LENGTH);
@@ -436,7 +436,7 @@ bool read_record_from_block(DEV_BLOCK *block, DEV_RECORD *rec)
       if (rec->remainder && (rec->VolSessionId != VolSessionId || 
 			     rec->VolSessionTime != VolSessionTime)) {
 	 rec->state |= REC_NO_MATCH;
-         Dmsg0(500, "remainder and VolSession doesn't match\n");
+         Dmsg0(450, "remainder and VolSession doesn't match\n");
 	 return false;		   /* This is from some other Session */
       }
 
@@ -468,7 +468,7 @@ bool read_record_from_block(DEV_BLOCK *block, DEV_RECORD *rec)
 	 block->LastIndex = FileIndex;
       }
 
-      Dmsg6(100, "rd_rec_blk() got FI=%s SessId=%d Strm=%s len=%u\n"
+      Dmsg6(450, "rd_rec_blk() got FI=%s SessId=%d Strm=%s len=%u\n"
                  "remlen=%d data_len=%d\n",
 	 FI_to_ascii(rec->FileIndex), rec->VolSessionId, 
 	 stream_to_ascii(rec->Stream, rec->FileIndex), data_bytes, remlen, 
@@ -482,7 +482,7 @@ bool read_record_from_block(DEV_BLOCK *block, DEV_RECORD *rec)
        * higher level routine to fetch the next block and
        * then reread.
        */
-      Dmsg0(90, "read_record_block: nothing\n");
+      Dmsg0(450, "read_record_block: nothing\n");
 #ifdef xxx
       if (!rec->remainder) {
 	 rec->remainder = 1;	      /* set to expect continuation */
@@ -519,12 +519,12 @@ bool read_record_from_block(DEV_BLOCK *block, DEV_RECORD *rec)
       block->binbuf -= remlen;
       rec->data_len += remlen;
       rec->remainder = 1;	      /* partial record transferred */
-      Dmsg1(90, "read_record_block: partial xfered=%d\n", rec->data_len);
+      Dmsg1(450, "read_record_block: partial xfered=%d\n", rec->data_len);
       rec->state |= (REC_PARTIAL_RECORD | REC_BLOCK_EMPTY);
       return 1;
    }
    rec->remainder = 0;
-   Dmsg4(90, "Rtn full rd_rec_blk FI=%s SessId=%d Strm=%s len=%d\n",
+   Dmsg4(450, "Rtn full rd_rec_blk FI=%s SessId=%d Strm=%s len=%d\n",
       FI_to_ascii(rec->FileIndex), rec->VolSessionId, 
       stream_to_ascii(rec->Stream, rec->FileIndex), rec->data_len);
    return true; 		      /* transferred full record */
diff --git a/bacula/src/stored/spool.c b/bacula/src/stored/spool.c
index a69fbc1948..1034be67dc 100644
--- a/bacula/src/stored/spool.c
+++ b/bacula/src/stored/spool.c
@@ -242,14 +242,14 @@ static bool despool_data(DCR *dcr, bool commit)
 	 break;
       }
       ok = write_block_to_device(dcr);
-      Dmsg3(100, "Write block ok=%d FI=%d LI=%d\n", ok, block->FirstIndex, block->LastIndex);
+      Dmsg3(800, "Write block ok=%d FI=%d LI=%d\n", ok, block->FirstIndex, block->LastIndex);
    }
    dcr->block = block;		      /* reset block */
 
    lseek(rdcr->spool_fd, 0, SEEK_SET); /* rewind */
    if (ftruncate(rdcr->spool_fd, 0) != 0) {
       berrno be;
-      Jmsg(dcr->jcr, M_FATAL, 0, _("Ftruncate spool file failed: ERR=%s\n"), 
+      Jmsg(dcr->jcr, M_ERROR, 0, _("Ftruncate spool file failed: ERR=%s\n"), 
 	 be.strerror());
       Pmsg1(000, "Bad return from ftruncate. ERR=%s\n", be.strerror());
       ok = false;
@@ -327,7 +327,7 @@ static int read_block_from_spool_file(DCR *dcr)
    block->LastIndex = hdr.LastIndex;
    block->VolSessionId = dcr->jcr->VolSessionId;
    block->VolSessionTime = dcr->jcr->VolSessionTime;
-   Dmsg2(100, "Read block FI=%d LI=%d\n", block->FirstIndex, block->LastIndex);
+   Dmsg2(800, "Read block FI=%d LI=%d\n", block->FirstIndex, block->LastIndex);
    return RB_OK;
 }
 
@@ -395,7 +395,7 @@ bool write_block_to_spool_file(DCR *dcr)
      return false;
    }
 
-   Dmsg2(100, "Wrote block FI=%d LI=%d\n", block->FirstIndex, block->LastIndex);
+   Dmsg2(800, "Wrote block FI=%d LI=%d\n", block->FirstIndex, block->LastIndex);
    empty_block(block);
    return true;
 }
diff --git a/bacula/src/stored/stored.c b/bacula/src/stored/stored.c
index 6f55cc4209..4a45fb86c7 100644
--- a/bacula/src/stored/stored.c
+++ b/bacula/src/stored/stored.c
@@ -337,6 +337,7 @@ void *device_allocation(void *arg)
 	 dcr = new_dcr(jcr, device->dev);
 	 switch (read_dev_volume_label(dcr)) {
 	    case VOL_OK:
+	       memcpy(&dcr->dev->VolCatInfo, &dcr->VolCatInfo, sizeof(dcr->dev->VolCatInfo));
 	       break;
 	    default:
                Emsg1(M_WARNING, 0, _("Could not mount device %s\n"), device->device_name);
diff --git a/bacula/src/version.h b/bacula/src/version.h
index c277453820..0753d865a5 100644
--- a/bacula/src/version.h
+++ b/bacula/src/version.h
@@ -1,8 +1,8 @@
 /* */
 #undef  VERSION
 #define VERSION "1.35.5"
-#define BDATE   "25 September 2004"
-#define LSMDATE "25Sep04"
+#define BDATE   "26 September 2004"
+#define LSMDATE "26Sep04"
 
 /* Debug flags */
 #undef  DEBUG