Imported Upstream version 2.6.1
[debian/amanda] / server-src / taper.c
index d5b72af25578559da2f06619a78911551d6060ce..fed6a33a114669e298fc29f75b2d5664e385c3a6 100644 (file)
 #include "taperscan.h"
 #include "taper-source.h"
 #include "timestamp.h"
-#include "token.h"
+#include "util.h"
 #include "version.h"
+#include "queueing.h"
+#include "device-queueing.h"
 
 /* FIXME: This should not be here. */
 #define CONNECT_TIMEOUT (2*60)
@@ -58,6 +60,9 @@ typedef struct {
     char * next_tape_label;
     char * next_tape_device;
     taper_scan_tracker_t * taper_scan_tracker;
+    char * last_errmsg;
+    off_t  total_bytes;
+    int have_changer;
 } taper_state_t;
 
 typedef struct {
@@ -79,12 +84,15 @@ static void init_taper_state(taper_state_t* state) {
     state->device = NULL;
     state->driver_start_time = NULL;
     state->taper_scan_tracker = taper_scan_tracker_new();
+    state->last_errmsg = NULL;
+    state->total_bytes = 0;
 }
 
 static void cleanup(taper_state_t * state) {
     amfree(state->driver_start_time);
     amfree(state->next_tape_label);
     amfree(state->next_tape_device);
+    amfree(state->last_errmsg);
     taper_scan_tracker_free(state->taper_scan_tracker);
     if (state->device != NULL) {
         g_object_unref(state->device);
@@ -107,19 +115,18 @@ static void free_dump_info(dump_info_t * info) {
 /* Validate that a command has the proper number of arguments, and
    print a meaningful error message if not. It returns only if the
    check is successful. */
-static void validate_args(cmd_t cmd, struct cmdargs * args,
+static void validate_args(struct cmdargs * cmdargs,
                           char ** argnames) {
-    int i;
-    
-    for (i = 0; argnames[i] != NULL; i ++) {
-        if (i > args->argc) {
-            error("error [taper %s: not enough args: %s]",
-                  cmdstr[cmd], argnames[i]);
-        }
+    int len = g_strv_length(argnames);
+
+    if (len > cmdargs->argc) {
+       error("error [taper %s: not enough args; first missing arg is %s]",
+             cmdstr[cmdargs->cmd], argnames[cmdargs->argc]);
     }
-    if (i < args->argc) {
+
+    if (len < cmdargs->argc) {
         error("error [taper %s: Too many args: Got %d, expected %d.]",
-              cmdstr[cmd], args->argc, i);
+              cmdstr[cmdargs->cmd], cmdargs->argc, len);
     }
 }
 
@@ -143,7 +150,7 @@ static gboolean open_read_socket(dump_info_t * info, char * split_diskbuffer,
                       strerror(save_errno),
                       "]",
                       NULL);
-        q = squote(m);
+        q = quote_string(m);
         putresult(TAPE_ERROR, "%s %s\n", info->handle, q);
         log_add(L_FAIL, "%s %s %s %d %s",
                 info->hostname, qdiskname, info->timestamp,
@@ -167,7 +174,7 @@ static gboolean open_read_socket(dump_info_t * info, char * split_diskbuffer,
                       strerror(save_errno),
                       "]",
                       NULL);
-        q = squote(m);
+        q = quote_string(m);
         putresult(TAPE_ERROR, "%s %s\n", info->handle, q);
         log_add(L_FAIL, "%s %s %s %d %s",
                 info->hostname, qdiskname, info->timestamp,
@@ -190,7 +197,7 @@ static gboolean open_read_socket(dump_info_t * info, char * split_diskbuffer,
                       strerror(save_errno),
                       "]",
                       NULL);
-        q = squote(m);
+        q = quote_string(m);
         putresult(TAPE_ERROR, "%s %s\n", info->handle, q);
         log_add(L_FAIL, "%s %s %s %d %s",
                 info->hostname, qdiskname, info->timestamp,
@@ -221,8 +228,8 @@ typedef struct {
 /* A ConsumerFunctor. This consumer just passes its arguments on to a
    second consumer, but counts the number of bytes successfully
    written. */
-static int counting_consumer(gpointer user_data, queue_buffer_t * buffer) {
-    int result;
+static ssize_t counting_consumer(gpointer user_data, queue_buffer_t * buffer) {
+    ssize_t result;
     CountingConsumerData * data = user_data;
 
     result = data->next_consumer(data->next_consumer_data, buffer);
@@ -265,7 +272,7 @@ static gboolean simple_taper_scan(taper_state_t * state,
                 state->driver_start_time);
         if (result == 3) {
             log_add(L_INFO,
-            _("Will write new label `%s' to new (previously non-amanda) tape"),
+            _("Will write new label `%s' to new tape"),
                     *label);
         }
 
@@ -324,8 +331,8 @@ static gboolean find_new_tape(taper_state_t * state, dump_info_t * dump) {
     GThread * tape_search = NULL;
     tape_search_request_t search_request;
     gboolean use_threads;
+    struct cmdargs *cmdargs;
     cmd_t cmd;
-    struct cmdargs args;
 
     if (state->device != NULL) {
         return TRUE;
@@ -343,7 +350,9 @@ static gboolean find_new_tape(taper_state_t * state, dump_info_t * dump) {
     }
     
     putresult(REQUEST_NEW_TAPE, "%s\n", dump->handle);
-    cmd = getcmd(&args);
+    cmdargs = getcmd();
+    cmd = cmdargs->cmd;
+
     switch (cmd) {
     default:
         g_fprintf(stderr, "taper: Got odd message from driver, expected NEW-TAPE or NO-NEW-TAPE.\n");
@@ -359,10 +368,13 @@ static gboolean find_new_tape(taper_state_t * state, dump_info_t * dump) {
         if (search_result) {
             /* We don't say NEW_TAPE until we actually write the label. */
            amfree(search_request.errmsg);
+           free_cmdargs(cmdargs);
             return TRUE;
         } else {
             putresult(NO_NEW_TAPE, "%s\n", dump->handle);
             log_taper_scan_errmsg(search_request.errmsg);
+           log_add(L_ERROR, "no-tape [%s]", "No more writable valid tape found");
+           free_cmdargs(cmdargs);
             return FALSE;
         }
     }
@@ -371,8 +383,12 @@ static gboolean find_new_tape(taper_state_t * state, dump_info_t * dump) {
         if (use_threads) {
             g_thread_join(tape_search);
         }
+       log_add(L_ERROR, "no-tape [%s]", cmdargs->argv[1]);
+       state->last_errmsg = stralloc(cmdargs->argv[1]);
+       free_cmdargs(cmdargs);
         return FALSE;
     }
+    /* NOTREACHED */
 }
 
 /* Returns TRUE if the old volume details are not the same as the new ones. */
@@ -400,6 +416,8 @@ update_tapelist(
 {
     char *tapelist_name = NULL;
     char *tapelist_name_old = NULL;
+    tape_t *tp;
+    char *comment = NULL;
 
     tapelist_name = config_dir_relative(getconf_str(CNF_TAPELIST));
     if (state->cur_tape == 0) {
@@ -411,20 +429,36 @@ update_tapelist(
                                      ".today.", cur_str, NULL);
     }
 
+   if (read_tapelist(tapelist_name) != 0) {
+        log_add(L_INFO, "pid-done %ld", (long)getpid());
+        error("could not load tapelist \"%s\"", tapelist_name);
+        /*NOTREACHED*/
+    }
+
+    /* make a copy of the tapelist file */
     if (write_tapelist(tapelist_name_old)) {
+        log_add(L_INFO, "pid-done %ld", (long)getpid());
        error("could not write tapelist: %s", strerror(errno));
        /*NOTREACHED*/
     }
     amfree(tapelist_name_old);
 
+    /* get a copy of the comment, before freeing the old record */
+    tp = lookup_tapelabel(state->device->volume_label);
+    if (tp && tp->comment)
+       comment = stralloc(tp->comment);
+
+    /* edit the tapelist and rewrite it */
     remove_tapelabel(state->device->volume_label);
     add_tapelabel(state->driver_start_time,
-                  state->device->volume_label);
+                  state->device->volume_label,
+                 comment);
     if (write_tapelist(tapelist_name)) {
        error("could not write tapelist: %s", strerror(errno));
        /*NOTREACHED*/
     }
     amfree(tapelist_name);
+    amfree(comment);
 }
 
 /* Find and label a new tape, if one is not already open. Returns TRUE
@@ -434,7 +468,8 @@ static gboolean find_and_label_new_tape(taper_state_t * state,
     if (state->device != NULL) {
         return TRUE;
     }
-    
+    state->total_bytes = 0;
     if (!find_new_tape(state, dump_info)) {
         return FALSE;
     }
@@ -447,25 +482,29 @@ static gboolean label_new_tape(taper_state_t * state, dump_info_t * dump_info) {
     char *old_volume_time = NULL;
     tape_search_request_t request;
     gboolean search_result;
-    ReadLabelStatusFlags status;
+    DeviceStatusFlags status;
 
     /* If we got here, it means that we have found a tape to label and
      * have gotten permission from the driver to write it. But we
      * still can say NO-NEW-TAPE if a problem shows up, and must still
      * say NEW-TAPE if one doesn't. */
 
+    amfree(state->last_errmsg);
     state->device = device_open(state->next_tape_device);
+    g_assert(state->device != NULL);
     amfree(state->next_tape_device);
-    if (state->device == NULL)
+
+    if (state->device->status != DEVICE_STATUS_SUCCESS)
        goto skip_volume;
 
-    device_set_startup_properties_from_config(state->device);
+    if (!device_configure(state->device, TRUE))
+       goto skip_volume;
 
     /* if we have an error, and are sure it isn't just an unlabeled volume,
      * then skip this volume */
     status = device_read_label(state->device);
-    if ((status & ~READ_LABEL_STATUS_VOLUME_UNLABELED) &&
-       !(status & READ_LABEL_STATUS_VOLUME_UNLABELED))
+    if ((status & ~DEVICE_STATUS_VOLUME_UNLABELED) &&
+       !(status & DEVICE_STATUS_VOLUME_UNLABELED))
        goto skip_volume;
 
     old_volume_name = g_strdup(state->device->volume_label);
@@ -477,8 +516,9 @@ static gboolean label_new_tape(taper_state_t * state, dump_info_t * dump_info) {
 
         /* Something broke, see if we can tell if the volume was erased or
          * not. */
-        g_fprintf(stderr, "taper: Error writing label %s to device %s.\n",
-                state->next_tape_label, state->device->device_name);
+        g_fprintf(stderr, "taper: Error writing label %s to device %s: %s.\n",
+                state->next_tape_label, state->device->device_name,
+               device_error_or_status(state->device));
 
         if (!device_finish(state->device))
            goto request_new_volume;
@@ -486,17 +526,17 @@ static gboolean label_new_tape(taper_state_t * state, dump_info_t * dump_info) {
        /* This time, if we can't read the label, assume we've overwritten
         * the volume or otherwise corrupted it */
        status = device_read_label(state->device);
-       if ((status & ~READ_LABEL_STATUS_VOLUME_UNLABELED) &&
-           !(status & READ_LABEL_STATUS_VOLUME_UNLABELED))
+       if ((status & ~DEVICE_STATUS_VOLUME_UNLABELED) &&
+           !(status & DEVICE_STATUS_VOLUME_UNLABELED))
            goto request_new_volume;
 
         tape_used = check_volume_changed(state->device, old_volume_name, 
                                          old_volume_time);
-        if (tape_used) {
+
+        if (tape_used)
            goto request_new_volume;
-        } else {
+        else
            goto skip_volume;
-        }
     }
 
     amfree(old_volume_name);
@@ -506,6 +546,12 @@ static gboolean label_new_tape(taper_state_t * state, dump_info_t * dump_info) {
     update_tapelist(state);
     state->cur_tape++;
 
+    if (state->have_changer &&
+       changer_label("UNKNOWN", state->device->volume_label) != 0) {
+       error(_("couldn't update barcode database"));
+       /*NOTREACHED*/
+    }
+
     log_add(L_START, "datestamp %s label %s tape %d",
             state->driver_start_time, state->device->volume_label,
             state->cur_tape);
@@ -517,20 +563,27 @@ static gboolean label_new_tape(taper_state_t * state, dump_info_t * dump_info) {
 request_new_volume:
     /* Tell the driver we overwrote this volume, even if it was empty, and request
      * a new volume. */
-    if (state->device) {
-        g_object_unref(state->device);
-        state->device = NULL;
-    }
+    if (state->device)
+       state->last_errmsg = newstralloc(state->last_errmsg, device_error_or_status(state->device));
+    else
+       state->last_errmsg = newstralloc(state->last_errmsg, "(unknown)");
 
     putresult(NEW_TAPE, "%s %s\n", dump_info->handle,
              state->next_tape_label);
     if (old_volume_name) {
-       log_add(L_WARNING, "Problem writing label '%s' to volume %s, "
-               "volume may be erased.\n",
-               state->next_tape_label, old_volume_name);
+       log_add(L_WARNING, "Problem writing label '%s' to volume %s "
+               "(volume may be erased): %s\n",
+               state->next_tape_label, old_volume_name,
+               state->last_errmsg);
     } else {
-       log_add(L_WARNING, "Problem writing label '%s' to new volume, "
-               "volume may be erased.\n", state->next_tape_label);
+       log_add(L_WARNING, "Problem writing label '%s' to new volume "
+               "(volume may be erased): %s\n", state->next_tape_label,
+               state->last_errmsg);
+    }
+
+    if (state->device) {
+        g_object_unref(state->device);
+        state->device = NULL;
     }
 
     amfree(state->next_tape_label);
@@ -542,18 +595,24 @@ request_new_volume:
 skip_volume:
     /* grab a new volume without talking to the driver again -- we do this if we're
      * confident we didn't overwrite the last tape we got. */
-    if (state->device) {
-        g_object_unref(state->device);
-        state->device = NULL;
-    }
+    if (state->device)
+       state->last_errmsg = newstralloc(state->last_errmsg, device_error_or_status(state->device));
+    else
+       state->last_errmsg = newstralloc(state->last_errmsg, "(unknown)");
 
     if (old_volume_name) {
-       log_add(L_WARNING, "Problem writing label '%s' to volume '%s', "
-               "old volume data intact\n",
-               state->next_tape_label, old_volume_name);
+       log_add(L_WARNING, "Problem writing label '%s' to volume '%s' "
+               "(old volume data intact): %s\n",
+               state->next_tape_label, old_volume_name, state->last_errmsg);
     } else {
-       log_add(L_WARNING, "Problem writing label '%s' to new volume, "
-               "old volume data intact\n", state->next_tape_label);
+       log_add(L_WARNING, "Problem writing label '%s' to new volume "
+               "(old volume data intact): %s\n", state->next_tape_label,
+               state->last_errmsg);
+    }
+
+    if (state->device) {
+        g_object_unref(state->device);
+        state->device = NULL;
     }
 
     amfree(state->next_tape_label);
@@ -591,13 +650,14 @@ static void find_completion_tags(dump_info_t * dump_info, /* IN */
 
 /* Put an L_PARTIAL message to the logfile. */
 static void put_partial_log(dump_info_t * dump_info, double dump_time,
-                            guint64 dump_kbytes) {
+                            guint64 dump_kbytes, char *errstr) {
     char * qdiskname = quote_string(dump_info->diskname);
 
-    log_add(L_PARTIAL, "%s %s %s %d %d [sec %f kb %ju kps %f] \"\"",
+    log_add(L_PARTIAL, "%s %s %s %d %d [sec %f kb %ju kps %f] %s",
             dump_info->hostname, qdiskname, dump_info->timestamp,
             dump_info->current_part, dump_info->level, dump_time,
-            (uintmax_t)dump_kbytes, dump_kbytes / dump_time);
+            (uintmax_t)dump_kbytes, dump_kbytes / dump_time,
+           errstr);
     amfree(qdiskname);
 }
 
@@ -627,6 +687,7 @@ static gboolean finish_part_attempt(taper_state_t * taper_state,
                   dump_info->handle, taper_state->device->volume_label,
                   taper_state->device->file, (uintmax_t)part_kbytes, part_time,
                  (uintmax_t)part_kbytes, part_kbps);
+       taper_state->total_bytes += run_bytes;
         
         if (taper_source_get_end_of_data(dump_info->source)) {
             cmd_t result_cmd;
@@ -666,21 +727,36 @@ static gboolean finish_part_attempt(taper_state_t * taper_state,
         int file_number = taper_state->device->file;
         double dump_time, dump_kbps;
         guint64 dump_kbytes;
+       char *producer_errstr = quote_string(
+                                  taper_source_get_errmsg(dump_info->source));
+       char *consumer_errstr = quote_string(
+                                  device_error(taper_state->device));
+
+        log_add(L_PARTPARTIAL,
+                "%s %d %s %s %s %d/%d %d [sec %f kb %ju kps %f] %s",
+                volume_label, file_number, dump_info->hostname, qdiskname,
+                dump_info->timestamp, dump_info->current_part,
+                taper_source_predict_parts(dump_info->source),
+                dump_info->level, part_time, (uintmax_t)part_kbytes, part_kbps,
+               consumer_errstr);
+       log_add(L_INFO, "tape %s kb %lld fm %d [OK]\n",
+               volume_label,
+               (long long)((taper_state->total_bytes+(off_t)1023) / (off_t)1024),
+               taper_state->device->file);
 
         /* A problem occured. */
         if (queue_result & QUEUE_CONSUMER_ERROR) {
+           /* Make a note if this was EOM (we treat EOM the same as any other error,
+            * so it's just for debugging purposes */
+           if (taper_state->device->is_eof)
+               g_debug("device %s ran out of space", taper_state->device->device_name);
+
             /* Close the device. */
             device_finish(taper_state->device);
             g_object_unref(taper_state->device);
             taper_state->device = NULL;
         }
         
-        log_add(L_PARTPARTIAL,
-                "%s %d %s %s %s %d/%d %d [sec %f kb %ju kps %f] \"\"",
-                volume_label, file_number, dump_info->hostname, qdiskname,
-                dump_info->timestamp, dump_info->current_part,
-                taper_source_predict_parts(dump_info->source),
-                dump_info->level, part_time, (uintmax_t)part_kbytes, part_kbps);
         amfree(volume_label);
         
         if ((queue_result & QUEUE_CONSUMER_ERROR) &&
@@ -703,12 +779,21 @@ static gboolean finish_part_attempt(taper_state_t * taper_state,
         
         putresult(PARTIAL,
                   "%s INPUT-%s TAPE-%s "
-                  "\"[sec %f kb %ju kps %f]\" \"\" \"\"\n",
+                  "\"[sec %f kb %ju kps %f]\" %s %s\n",
                   dump_info->handle,
                   (queue_result & QUEUE_PRODUCER_ERROR) ? "ERROR" : "GOOD",
                   (queue_result & QUEUE_CONSUMER_ERROR) ? "ERROR" : "GOOD",
-                  dump_time, (uintmax_t)dump_kbytes, dump_kbps);
-        put_partial_log(dump_info, dump_time, dump_kbytes);
+                  dump_time, (uintmax_t)dump_kbytes, dump_kbps,
+                 producer_errstr, consumer_errstr);
+       if (queue_result & QUEUE_CONSUMER_ERROR) {
+            put_partial_log(dump_info, dump_time, dump_kbytes,
+                           consumer_errstr);
+       } else {
+            put_partial_log(dump_info, dump_time, dump_kbytes,
+                           producer_errstr);
+       }
+       amfree(producer_errstr);
+       amfree(consumer_errstr);
     }
 
     amfree(qdiskname);
@@ -744,7 +829,15 @@ static dumpfile_t * munge_headers(dump_info_t * dump_info) {
    happen with the first (or only) part of a file, but it could also
    happen with an intermediate part of a split dump. dump_bytes
    is 0 if this is the first part of a dump. */
-static void bail_no_volume(dump_info_t * dump_info) {
+static void bail_no_volume(
+    dump_info_t *dump_info,
+    char *errmsg)
+{
+    char *errstr;
+    if (errmsg)
+       errstr = quote_string(errmsg);
+    else
+       errstr = quote_string("no new tape");
     if (dump_info->total_bytes > 0) {
         /* Second or later part of a split dump, so PARTIAL message. */
         double dump_time = g_timeval_to_double(dump_info->total_time);
@@ -752,20 +845,21 @@ static void bail_no_volume(dump_info_t * dump_info) {
         double dump_kbps = dump_kbytes / dump_time;
         putresult(PARTIAL,
                   "%s INPUT-GOOD TAPE-ERROR "
-                  "\"[sec %f kb %ju kps %f]\" \"\" \"no new tape\"\n",
+                  "\"[sec %f kb %ju kps %f]\" \"\" %s\n",
                   dump_info->handle, 
-                  dump_time, (uintmax_t)dump_kbytes, dump_kbps);
-        put_partial_log(dump_info, dump_time, dump_kbytes);
+                  dump_time, (uintmax_t)dump_kbytes, dump_kbps, errstr);
+        put_partial_log(dump_info, dump_time, dump_kbytes, errstr);
     } else {
         char * qdiskname = quote_string(dump_info->diskname);
         putresult(FAILED,
-                  "%s INPUT-GOOD TAPE-ERROR \"\" \"No new tape.\"\n",
-                  dump_info->handle);
-        log_add(L_FAIL, "%s %s %s %d \"No new tape.\"",
+                  "%s INPUT-GOOD TAPE-ERROR \"\" %s\n",
+                  dump_info->handle, errstr);
+        log_add(L_FAIL, "%s %s %s %d %s",
                 dump_info->hostname, qdiskname, dump_info->timestamp,
-                dump_info->level);
+                dump_info->level, errstr);
        amfree(qdiskname);
     }
+    amfree(errstr);
 }
 
 /* Link up the TaperSource with the Device, including retries etc. */
@@ -789,28 +883,40 @@ static void run_device_output(taper_state_t * taper_state,
         this_header = munge_headers(dump_info);
         if (this_header == NULL) {
             char * qdiskname = quote_string(dump_info->diskname);
+           char * errstr = taper_source_get_errmsg(dump_info->source);
+           if (!errstr)
+               errstr = "Failed reading dump header.";
+           errstr = quote_string(errstr);
             putresult(FAILED,
-             "%s INPUT-ERROR TAPE-GOOD \"Failed reading dump header.\" \"\"\n",
-                      dump_info->handle);
-            log_add(L_FAIL, "%s %s %s %d \"Failed reading dump header.\"",
+             "%s INPUT-ERROR TAPE-GOOD %s \"\"\n",
+                      dump_info->handle, errstr);
+            log_add(L_FAIL, "%s %s %s %d %s",
                     dump_info->hostname, qdiskname, dump_info->timestamp,
-                    dump_info->level);
+                    dump_info->level, errstr);
             amfree(qdiskname);
+           amfree(errstr);
             return;
         }            
 
         if (!find_and_label_new_tape(taper_state, dump_info)) {
-            bail_no_volume(dump_info);
-           amfree(this_header);
+            bail_no_volume(dump_info, taper_state->last_errmsg);
+           dumpfile_free(this_header);
             return;
         }
 
-        if (!device_start_file(taper_state->device, this_header)) {
-            bail_no_volume(dump_info);
-           amfree(this_header);
-            return;
+       while (!device_start_file(taper_state->device, this_header)) {
+            /* Close the device. */
+            device_finish(taper_state->device);
+            g_object_unref(taper_state->device);
+            taper_state->device = NULL;
+
+            if (!find_and_label_new_tape(taper_state, dump_info)) {
+               bail_no_volume(dump_info, taper_state->last_errmsg);
+               dumpfile_free(this_header);
+               return;
+            }
         }
-       amfree(this_header);
+       dumpfile_free(this_header);
 
         bzero(&val, sizeof(val));
         if (!device_property_get(taper_state->device, PROPERTY_STREAMING, &val)
@@ -839,7 +945,7 @@ static void run_device_output(taper_state_t * taper_state,
             }
         } else if (getconf_seen(CNF_TAPEBUFS)) {
             max_memory = getconf_int(CNF_TAPEBUFS) *
-                device_write_max_size(taper_state->device);
+                taper_state->device->block_size;
         } else {
             /* Use default. */
             max_memory = getconf_size(CNF_DEVICE_OUTPUT_BUFFER_SIZE);
@@ -850,16 +956,14 @@ static void run_device_output(taper_state_t * taper_state,
              dump_info->source,
              counting_consumer,
              &consumer_data,
-             device_write_max_size(taper_state->device), max_memory,
+             taper_state->device->block_size, max_memory,
              streaming_mode);
 
         g_get_current_time(&end_time);
         run_time = timesub(end_time, start_time);
 
-        /* The device_write_consumer may have closed the file with a short
-         * write, so we only finish here if it needs it. */
-        if (taper_state->device->in_file &&
-            !device_finish_file(taper_state->device)) {
+        /* The device_write_consumer leaves the file open, so close it now. */
+        if (!device_finish_file(taper_state->device)) {
             queue_result = queue_result | QUEUE_CONSUMER_ERROR;
         }
 
@@ -877,52 +981,52 @@ static void process_port_write(taper_state_t * state,
     guint64 splitsize;
     guint64 fallback_splitsize;
     char * split_diskbuffer;
-    char * argnames[] = {"command",               /* 1 */
-                        "handle",                /* 2 */
-                         "hostname",              /* 3 */
-                         "diskname",              /* 4 */
-                         "level",                 /* 5 */
-                         "datestamp",             /* 6 */
-                         "splitsize",             /* 7 */
-                         "split_diskbuffer",      /* 8 */
-                         "fallback_splitsize",    /* 9 */
+    char * argnames[] = {"command",               /* 0 */
+                        "handle",                /* 1 */
+                         "hostname",              /* 2 */
+                         "diskname",              /* 3 */
+                         "level",                 /* 4 */
+                         "datestamp",             /* 5 */
+                         "splitsize",             /* 6 */
+                         "split_diskbuffer",      /* 7 */
+                         "fallback_splitsize",    /* 8 */
                           NULL };
 
-    validate_args(PORT_WRITE, cmdargs, argnames);
+    validate_args(cmdargs, argnames);
 
-    dump_state.handle = g_strdup(cmdargs->argv[2]);
-    dump_state.hostname = g_strdup(cmdargs->argv[3]);
-    dump_state.diskname = unquote_string(cmdargs->argv[4]);
+    dump_state.handle = g_strdup(cmdargs->argv[1]);
+    dump_state.hostname = g_strdup(cmdargs->argv[2]);
+    dump_state.diskname = g_strdup(cmdargs->argv[3]);
     
     errno = 0;
-    dump_state.level = strtol(cmdargs->argv[5], NULL, 10);
+    dump_state.level = strtol(cmdargs->argv[4], NULL, 10);
     if (errno != 0) {
         error("error [taper PORT-WRITE: Invalid dump level %s]",
-              cmdargs->argv[5]);
+              cmdargs->argv[4]);
         g_assert_not_reached();
     }
     
-    dump_state.timestamp = strdup(cmdargs->argv[6]);
+    dump_state.timestamp = strdup(cmdargs->argv[5]);
 
     errno = 0;
-    splitsize = g_ascii_strtoull(cmdargs->argv[7], NULL, 10);
+    splitsize = g_ascii_strtoull(cmdargs->argv[6], NULL, 10);
     if (errno != 0) {
         error("error [taper PORT-WRITE: Invalid splitsize %s]",
-              cmdargs->argv[7]);
+              cmdargs->argv[6]);
         g_assert_not_reached();
     }
     
-    if (strcmp(cmdargs->argv[8], "NULL") == 0) {
+    if (strcmp(cmdargs->argv[7], "NULL") == 0) {
         split_diskbuffer = NULL;
     } else {
-        split_diskbuffer = g_strdup(cmdargs->argv[8]);
+        split_diskbuffer = g_strdup(cmdargs->argv[7]);
     }
     
     errno = 0;
-    fallback_splitsize = g_ascii_strtoull(cmdargs->argv[9], NULL, 10);
+    fallback_splitsize = g_ascii_strtoull(cmdargs->argv[8], NULL, 10);
     if (errno != 0) {
         error("error [taper PORT-WRITE: Invalid fallback_splitsize %s]",
-              cmdargs->argv[9]);
+              cmdargs->argv[8]);
         g_assert_not_reached();
     }
 
@@ -948,38 +1052,38 @@ static void process_file_write(taper_state_t * state,
     dump_info_t dump_state;
     char * holding_disk_file;
     guint64 splitsize;
-    char * argnames[] = {"command",               /* 1 */
-                        "handle",                /* 2 */
-                         "filename",              /* 3 */
-                         "hostname",              /* 4 */
-                         "diskname",              /* 5 */
-                         "level",                 /* 6 */
-                         "datestamp",             /* 7 */
-                         "splitsize",             /* 8 */
+    char * argnames[] = {"command",               /* 0 */
+                        "handle",                /* 1 */
+                         "filename",              /* 2 */
+                         "hostname",              /* 3 */
+                         "diskname",              /* 4 */
+                         "level",                 /* 5 */
+                         "datestamp",             /* 6 */
+                         "splitsize",             /* 7 */
                           NULL };
 
-    validate_args(FILE_WRITE, cmdargs, argnames);
+    validate_args(cmdargs, argnames);
 
-    dump_state.handle = g_strdup(cmdargs->argv[2]);
-    holding_disk_file = unquote_string(cmdargs->argv[3]);
-    dump_state.hostname = g_strdup(cmdargs->argv[4]);
-    dump_state.diskname = unquote_string(cmdargs->argv[5]);
+    dump_state.handle = g_strdup(cmdargs->argv[1]);
+    holding_disk_file = g_strdup(cmdargs->argv[2]);
+    dump_state.hostname = g_strdup(cmdargs->argv[3]);
+    dump_state.diskname = g_strdup(cmdargs->argv[4]);
     
     errno = 0;
-    dump_state.level = strtol(cmdargs->argv[6], NULL, 10);
+    dump_state.level = strtol(cmdargs->argv[5], NULL, 10);
     if (errno != 0) {
         error("error [taper FILE-WRITE: Invalid dump level %s]",
               cmdargs->argv[5]);
         g_assert_not_reached();
     }
     
-    dump_state.timestamp = strdup(cmdargs->argv[7]);
+    dump_state.timestamp = strdup(cmdargs->argv[6]);
 
     errno = 0;
-    splitsize = g_ascii_strtoull(cmdargs->argv[8], NULL, 10);
+    splitsize = g_ascii_strtoull(cmdargs->argv[7], NULL, 10);
     if (errno != 0) {
         error("error [taper FILE-WRITE: Invalid splitsize %s]",
-              cmdargs->argv[8]);
+              cmdargs->argv[7]);
         g_assert_not_reached();
     }
 
@@ -1011,9 +1115,7 @@ static gboolean send_quitting(taper_state_t * state) {
 /* This function recieves the START_TAPER command from driver, and
    returns the attached timestamp. */
 static gboolean find_first_tape(taper_state_t * state) {
-    cmd_t cmd;
-    /* Note: cmdargs.argv is never freed. In the entire Amanda codebase. */
-    struct cmdargs cmdargs;
+    struct cmdargs *cmdargs;
     tape_search_request_t search_request;
     GThread * tape_search = NULL;
     gboolean use_threads;
@@ -1030,12 +1132,12 @@ static gboolean find_first_tape(taper_state_t * state) {
                                       &search_request, TRUE, NULL);
     }
 
-    cmd = getcmd(&cmdargs);
+    cmdargs = getcmd();
 
-    switch (cmd) {
+    switch (cmdargs->cmd) {
     case START_TAPER: {
         gboolean search_result;
-        state->driver_start_time = strdup(cmdargs.argv[2]);
+        state->driver_start_time = strdup(cmdargs->argv[1]);
         if (use_threads) {
             search_result = GPOINTER_TO_INT(g_thread_join(tape_search));
         } else {
@@ -1063,6 +1165,7 @@ static gboolean find_first_tape(taper_state_t * state) {
            }
         }
        amfree(search_request.errmsg);
+       free_cmdargs(cmdargs);
         return TRUE;
     }
     case QUIT:
@@ -1070,9 +1173,10 @@ static gboolean find_first_tape(taper_state_t * state) {
         if (use_threads) {
             g_thread_join(tape_search);
         }
+       free_cmdargs(cmdargs);
         return send_quitting(state);
     default:
-        error("error [file_reader_side cmd %d argc %d]", cmd, cmdargs.argc);
+        error("error [file_reader_side cmd %d argc %d]", cmdargs->cmd, cmdargs->argc);
     }
 
     g_assert_not_reached();
@@ -1081,13 +1185,12 @@ static gboolean find_first_tape(taper_state_t * state) {
 /* In running mode (not startup mode), get a command from driver and
    deal with it. */
 static gboolean process_driver_command(taper_state_t * state) {
-    cmd_t cmd;
-    struct cmdargs cmdargs;
+    struct cmdargs *cmdargs;
     char * q;
 
     /* This will return QUIT if driver has died. */
-    cmd = getcmd(&cmdargs);
-    switch (cmd) {
+    cmdargs = getcmd();
+    switch (cmdargs->cmd) {
     case PORT_WRITE:
         /*
          * PORT-WRITE
@@ -1100,7 +1203,7 @@ static gboolean process_driver_command(taper_state_t * state) {
          *   splitsize
          *   split_diskbuffer
          */
-        process_port_write(state, &cmdargs);
+        process_port_write(state, cmdargs);
         break;
         
     case FILE_WRITE:
@@ -1115,16 +1218,21 @@ static gboolean process_driver_command(taper_state_t * state) {
          *   datestamp
          *   splitsize
          */
-        process_file_write(state, &cmdargs);
+        process_file_write(state, cmdargs);
         break;
         
     case QUIT:
+       free_cmdargs(cmdargs);
+       if (state->device && state->device->volume_label) {
+           log_add(L_INFO, "tape %s kb %lld fm %d [OK]\n",
+                   state->device->volume_label,
+                   (long long)((state->total_bytes+(off_t)1023) / (off_t)1024),
+                   state->device->file);
+       }
         return send_quitting(state);
     default:
-        if (cmdargs.argc >= 1) {
-            q = squote(cmdargs.argv[1]);
-        } else if (cmdargs.argc >= 0) {
-            q = squote(cmdargs.argv[0]);
+        if (cmdargs->argc >= 1) {
+            q = quote_string(cmdargs->argv[0]);
         } else {
             q = stralloc("(no input?)");
         }
@@ -1132,13 +1240,13 @@ static gboolean process_driver_command(taper_state_t * state) {
         amfree(q);
         break;
     }
+    free_cmdargs(cmdargs);
 
     return TRUE;
 }
 
 int main(int argc, char ** argv) {
     char * tapelist_name;
-    int have_changer;
     taper_state_t state;
     config_overwrites_t *cfg_ovr = NULL;
     char *cfg_opt = NULL;
@@ -1178,28 +1286,35 @@ int main(int argc, char ** argv) {
     }
     if (argc > 1)
        cfg_opt = argv[1];
-    config_init(CONFIG_INIT_EXPLICIT_NAME | CONFIG_INIT_USE_CWD | CONFIG_INIT_FATAL,
-               cfg_opt);
+    config_init(CONFIG_INIT_EXPLICIT_NAME | CONFIG_INIT_USE_CWD, cfg_opt);
     apply_config_overwrites(cfg_ovr);
 
+    if (config_errors(NULL) >= CFGERR_ERRORS) {
+       g_critical(_("errors processing config file"));
+    }
+
     safe_cd();
 
     set_logerror(logerror);
 
     check_running_as(RUNNING_AS_DUMPUSER);
 
-    dbrename(config_name, DBG_SUBDIR_SERVER);
+    dbrename(get_config_name(), DBG_SUBDIR_SERVER);
+
+    log_add(L_INFO, "%s pid %ld", get_pname(), (long)getpid());
 
     tapelist_name = config_dir_relative(getconf_str(CNF_TAPELIST));
 
     if (read_tapelist(tapelist_name) != 0) {
+       log_add(L_INFO, "pid-done %ld", (long)getpid());
         error("could not load tapelist \"%s\"", tapelist_name);
         g_assert_not_reached();
     }
     amfree(tapelist_name);
 
-    have_changer = changer_init();
-    if (have_changer < 0) {
+    state.have_changer = changer_init();
+    if (state.have_changer < 0) {
+       log_add(L_INFO, "pid-done %ld", (long)getpid());
         error("changer initialization failed: %s", strerror(errno));
         g_assert_not_reached();
     }
@@ -1209,9 +1324,11 @@ int main(int argc, char ** argv) {
     state.cur_tape = 0;
     
     if (!find_first_tape(&state)) {
+       log_add(L_INFO, "pid-done %ld", (long)getpid());
         return EXIT_SUCCESS;
     }
 
     while (process_driver_command(&state));
+    log_add(L_INFO, "pid-done %ld", (long)getpid());
     return EXIT_SUCCESS;
 }