fed6a33a114669e298fc29f75b2d5664e385c3a6
[debian/amanda] / server-src / taper.c
1 /*
2  * Amanda, The Advanced Maryland Automatic Network Disk Archiver
3  * Copyright (c) 1991-1998, 2000 University of Maryland at College Park
4  * All Rights Reserved.
5  *
6  * Permission to use, copy, modify, distribute, and sell this software and its
7  * documentation for any purpose is hereby granted without fee, provided that
8  * the above copyright notice appear in all copies and that both that
9  * copyright notice and this permission notice appear in supporting
10  * documentation, and that the name of U.M. not be used in advertising or
11  * publicity pertaining to distribution of the software without specific,
12  * written prior permission.  U.M. makes no representations about the
13  * suitability of this software for any purpose.  It is provided "as is"
14  * without express or implied warranty.
15  *
16  * U.M. DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE, INCLUDING ALL
17  * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS, IN NO EVENT SHALL U.M.
18  * BE LIABLE FOR ANY SPECIAL, INDIRECT OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
19  * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION
20  * OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN
21  * CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
22  *
23  * Authors: the Amanda Development Team.  Its members are listed in a
24  * file named AUTHORS, in the root directory of this distribution.
25  */
26 /* $Id: taper.c 6512 2007-05-24 17:00:24Z ian $
27  *
28  * moves files from holding disk to tape, or from a socket to tape
29  */
30
31 /* FIXME: This file needs to use gettext. */
32
33 #include <glib.h>
34 #include "physmem.h"
35
36 #include "changer.h"
37 #include "clock.h"
38 #include "conffile.h"
39 #include "device.h"
40 #include "logfile.h"
41 #include "server_util.h"
42 #include "stream.h"
43 #include "tapefile.h"
44 #include "taperscan.h"
45 #include "taper-source.h"
46 #include "timestamp.h"
47 #include "util.h"
48 #include "version.h"
49 #include "queueing.h"
50 #include "device-queueing.h"
51
52 /* FIXME: This should not be here. */
53 #define CONNECT_TIMEOUT (2*60)
54
55 /* Use this instead of global variables, so that we are reentrant. */
56 typedef struct {
57     Device * device;
58     char * driver_start_time;
59     int    cur_tape;
60     char * next_tape_label;
61     char * next_tape_device;
62     taper_scan_tracker_t * taper_scan_tracker;
63     char * last_errmsg;
64     off_t  total_bytes;
65     int have_changer;
66 } taper_state_t;
67
68 typedef struct {
69     char * handle;
70     char * hostname;
71     char * diskname;
72     int level;
73     char * timestamp;
74     char * id_string;
75     TaperSource * source;
76     int current_part;
77     GTimeVal total_time;
78     guint64 total_bytes;
79 } dump_info_t;
80
81 static gboolean label_new_tape(taper_state_t * state, dump_info_t * dump_info);
82
83 static void init_taper_state(taper_state_t* state) {
84     state->device = NULL;
85     state->driver_start_time = NULL;
86     state->taper_scan_tracker = taper_scan_tracker_new();
87     state->last_errmsg = NULL;
88     state->total_bytes = 0;
89 }
90
91 static void cleanup(taper_state_t * state) {
92     amfree(state->driver_start_time);
93     amfree(state->next_tape_label);
94     amfree(state->next_tape_device);
95     amfree(state->last_errmsg);
96     taper_scan_tracker_free(state->taper_scan_tracker);
97     if (state->device != NULL) {
98         g_object_unref(state->device);
99         state->device = NULL;
100     }
101 }
102
103 static void free_dump_info(dump_info_t * info) {
104     amfree(info->handle);
105     amfree(info->hostname);
106     amfree(info->diskname);
107     amfree(info->timestamp);
108     amfree(info->id_string);
109     if (info->source != NULL) {
110         g_object_unref(info->source);
111         info->source = NULL;
112     }
113 }
114
115 /* Validate that a command has the proper number of arguments, and
116    print a meaningful error message if not. It returns only if the
117    check is successful. */
118 static void validate_args(struct cmdargs * cmdargs,
119                           char ** argnames) {
120     int len = g_strv_length(argnames);
121
122     if (len > cmdargs->argc) {
123         error("error [taper %s: not enough args; first missing arg is %s]",
124               cmdstr[cmdargs->cmd], argnames[cmdargs->argc]);
125     }
126
127     if (len < cmdargs->argc) {
128         error("error [taper %s: Too many args: Got %d, expected %d.]",
129               cmdstr[cmdargs->cmd], cmdargs->argc, len);
130     }
131 }
132
133 /* Open a socket to the dumper. Returns TRUE if everything is happy, FALSE
134    otherwise. */
135 static gboolean open_read_socket(dump_info_t * info, char * split_diskbuffer,
136                              guint64 splitsize, guint64 fallback_splitsize) {
137     in_port_t port = 0;
138     int socket;
139     int fd;
140     int result;
141     struct addrinfo *res;
142
143     if ((result = resolve_hostname("localhost", 0, &res, NULL) != 0)) {
144         char *m;
145         char *q;
146         int save_errno = errno;
147         char *qdiskname = quote_string(info->diskname);
148
149         m = vstralloc("[localhost resolve failure: ",
150                       strerror(save_errno),
151                       "]",
152                       NULL);
153         q = quote_string(m);
154         putresult(TAPE_ERROR, "%s %s\n", info->handle, q);
155         log_add(L_FAIL, "%s %s %s %d %s",
156                 info->hostname, qdiskname, info->timestamp,
157                 info->level, q);
158         amfree(qdiskname);
159         amfree(m);
160         amfree(q);
161         return FALSE;
162     }
163
164     socket = stream_server(res->ai_family, &port, 0, STREAM_BUFSIZE, 0);
165     freeaddrinfo(res);
166
167     if (socket < 0) {
168         char *m;
169         char *q;
170         int save_errno = errno;
171         char *qdiskname = quote_string(info->diskname);
172
173         m = vstralloc("[port create failure: ",
174                       strerror(save_errno),
175                       "]",
176                       NULL);
177         q = quote_string(m);
178         putresult(TAPE_ERROR, "%s %s\n", info->handle, q);
179         log_add(L_FAIL, "%s %s %s %d %s",
180                 info->hostname, qdiskname, info->timestamp,
181                 info->level, q);
182         amfree(qdiskname);
183         amfree(m);
184         amfree(q);
185         return FALSE;
186     }
187
188     putresult(PORT, "%d\n", port);
189
190     fd = stream_accept(socket, CONNECT_TIMEOUT, 0, STREAM_BUFSIZE);
191
192     if (fd < 0) {
193         char *m, *q;
194         int save_errno = errno;
195         char *qdiskname = quote_string(info->diskname);
196         m = vstralloc("[port connect failure: ",
197                       strerror(save_errno),
198                       "]",
199                       NULL);
200         q = quote_string(m);
201         putresult(TAPE_ERROR, "%s %s\n", info->handle, q);
202         log_add(L_FAIL, "%s %s %s %d %s",
203                 info->hostname, qdiskname, info->timestamp,
204                 info->level, q);
205         amfree(qdiskname);
206         aclose(socket);
207         amfree(m);
208         amfree(q);
209         return FALSE;
210     } else {
211         aclose(socket);
212     }
213
214     info->source = taper_source_new(info->handle, PORT_WRITE, NULL, fd,
215                                     split_diskbuffer, splitsize,
216                                     fallback_splitsize);
217     /* FIXME: This should be handled properly. */
218     g_assert(info->source != NULL);
219     return TRUE;
220 }
221
222 typedef struct {
223     ConsumerFunctor next_consumer;
224     gpointer next_consumer_data;
225     guint64 bytes_written;
226 } CountingConsumerData;
227
228 /* A ConsumerFunctor. This consumer just passes its arguments on to a
229    second consumer, but counts the number of bytes successfully
230    written. */
231 static ssize_t counting_consumer(gpointer user_data, queue_buffer_t * buffer) {
232     ssize_t result;
233     CountingConsumerData * data = user_data;
234
235     result = data->next_consumer(data->next_consumer_data, buffer);
236     
237     if (result > 0) {
238         data->bytes_written += result;
239     }
240
241     return result;
242 }
243
244 static gboolean boolean_prolong(void * data) {
245     if (data == NULL) {
246         return TRUE; /* Do not interrupt. */
247     } else {
248         return *(gboolean*)data;
249     }
250 }
251
252 /* A (simpler) wrapper around taper_scan(). */
253 static gboolean simple_taper_scan(taper_state_t * state,
254                                   gboolean* prolong, char ** error_message) {
255     char ** label = &(state->next_tape_label);
256     char ** device = &(state->next_tape_device);
257     char *timestamp = NULL;
258     int result;
259     result = taper_scan(NULL, label, &timestamp, device,
260                         state->taper_scan_tracker,
261                         CHAR_taperscan_output_callback,
262                         error_message, boolean_prolong, prolong);
263     if (prolong != NULL && !*prolong) {
264         g_fprintf(stderr, _("Cancelled taper scan.\n"));
265         return FALSE;
266     } else if (result < 0) {
267         g_fprintf(stderr, _("Failed taper scan: %s\n"), (*error_message)?(*error_message):_("(no error message)"));
268         amfree(timestamp);
269         return FALSE;
270     } else {
271         g_fprintf(stderr, _("taper: using label `%s' date `%s'\n"), *label,
272                 state->driver_start_time);
273         if (result == 3) {
274             log_add(L_INFO,
275             _("Will write new label `%s' to new tape"),
276                     *label);
277         }
278
279     }
280     amfree(timestamp);
281     return TRUE;
282 }
283
284 typedef struct {
285     taper_state_t * state;
286     gboolean prolong; /* scan stops when this is FALSE. */
287     char *errmsg;
288 } tape_search_request_t;
289
290 /* A GThread that runs taper_scan. */
291 static gpointer tape_search_thread(gpointer data) {
292     tape_search_request_t * request = data;
293
294     if (request->state->next_tape_label != NULL &&
295         request->state->next_tape_device != NULL) {
296         return GINT_TO_POINTER(TRUE);
297     } else {
298         amfree(request->state->next_tape_label);
299         amfree(request->state->next_tape_device);
300     }
301
302     return GINT_TO_POINTER
303         (simple_taper_scan(request->state,
304                            &(request->prolong),
305                            &(request->errmsg)));
306 }
307
308 static void log_taper_scan_errmsg(char * errmsg) {
309     char *c, *c1;
310     if (errmsg == NULL)
311         return;
312
313     c = c1 = errmsg;
314     while (*c != '\0') {
315         if (*c == '\n') {
316             *c = '\0';
317             log_add(L_WARNING,"%s", c1);
318             c1 = c+1;
319         }
320         c++;
321     }
322     if (strlen(c1) > 1 )
323         log_add(L_WARNING,"%s", c1);
324     amfree(errmsg);
325 }
326
327 /* If handle is NULL, then this function assumes that we are in startup mode.
328  * In that case it will wait for a command from driver. If handle is not NULL,
329  * this this function will ask for permission with REQUEST-NEW-TAPE. */
330 static gboolean find_new_tape(taper_state_t * state, dump_info_t * dump) {
331     GThread * tape_search = NULL;
332     tape_search_request_t search_request;
333     gboolean use_threads;
334     struct cmdargs *cmdargs;
335     cmd_t cmd;
336
337     if (state->device != NULL) {
338         return TRUE;
339     }
340
341     /* We save the value here in case it changes while we're running. */
342     use_threads = g_thread_supported();
343
344     search_request.state = state;
345     search_request.prolong = TRUE;
346     search_request.errmsg = NULL;
347     if (use_threads) {
348         tape_search = g_thread_create(tape_search_thread,
349                                       &search_request, TRUE, NULL);
350     }
351     
352     putresult(REQUEST_NEW_TAPE, "%s\n", dump->handle);
353     cmdargs = getcmd();
354     cmd = cmdargs->cmd;
355
356     switch (cmd) {
357     default:
358         g_fprintf(stderr, "taper: Got odd message from driver, expected NEW-TAPE or NO-NEW-TAPE.\n");
359         /* FALLTHROUGH. */
360     case NEW_TAPE: {
361         gboolean search_result;
362         if (use_threads) {
363             search_result = GPOINTER_TO_INT(g_thread_join(tape_search));
364         } else {
365             search_result =
366                 GPOINTER_TO_INT(tape_search_thread(&search_request));
367         }
368         if (search_result) {
369             /* We don't say NEW_TAPE until we actually write the label. */
370             amfree(search_request.errmsg);
371             free_cmdargs(cmdargs);
372             return TRUE;
373         } else {
374             putresult(NO_NEW_TAPE, "%s\n", dump->handle);
375             log_taper_scan_errmsg(search_request.errmsg);
376             log_add(L_ERROR, "no-tape [%s]", "No more writable valid tape found");
377             free_cmdargs(cmdargs);
378             return FALSE;
379         }
380     }
381     case NO_NEW_TAPE:
382         search_request.prolong = FALSE;
383         if (use_threads) {
384             g_thread_join(tape_search);
385         }
386         log_add(L_ERROR, "no-tape [%s]", cmdargs->argv[1]);
387         state->last_errmsg = stralloc(cmdargs->argv[1]);
388         free_cmdargs(cmdargs);
389         return FALSE;
390     }
391     /* NOTREACHED */
392 }
393
394 /* Returns TRUE if the old volume details are not the same as the new ones. */
395 static gboolean check_volume_changed(Device * device,
396                                      char * old_label, char * old_timestamp) {
397     /* If one is NULL and the other is not, something changed. */
398     if ((old_label == NULL) != (device->volume_label == NULL))
399         return TRUE;
400     if ((old_timestamp == NULL) != (device->volume_time == NULL))
401         return TRUE;
402     /* If details were not NULL and is now different, we have a difference. */
403     if (old_label != NULL && strcmp(old_label, device->volume_label) != 0)
404         return TRUE;
405     if (old_timestamp != NULL &&
406         strcmp(old_timestamp, device->volume_time) != 0)
407         return TRUE;
408
409     /* If we got here, everything is cool. */
410     return FALSE;
411 }
412
413 static void
414 update_tapelist(
415     taper_state_t *state)
416 {
417     char *tapelist_name = NULL;
418     char *tapelist_name_old = NULL;
419     tape_t *tp;
420     char *comment = NULL;
421
422     tapelist_name = config_dir_relative(getconf_str(CNF_TAPELIST));
423     if (state->cur_tape == 0) {
424         tapelist_name_old = stralloc2(tapelist_name, ".yesterday");
425     } else {
426         char cur_str[NUM_STR_SIZE];
427         g_snprintf(cur_str, SIZEOF(cur_str), "%d", state->cur_tape - 1);
428         tapelist_name_old = vstralloc(tapelist_name,
429                                       ".today.", cur_str, NULL);
430     }
431
432    if (read_tapelist(tapelist_name) != 0) {
433         log_add(L_INFO, "pid-done %ld", (long)getpid());
434         error("could not load tapelist \"%s\"", tapelist_name);
435         /*NOTREACHED*/
436     }
437
438     /* make a copy of the tapelist file */
439     if (write_tapelist(tapelist_name_old)) {
440         log_add(L_INFO, "pid-done %ld", (long)getpid());
441         error("could not write tapelist: %s", strerror(errno));
442         /*NOTREACHED*/
443     }
444     amfree(tapelist_name_old);
445
446     /* get a copy of the comment, before freeing the old record */
447     tp = lookup_tapelabel(state->device->volume_label);
448     if (tp && tp->comment)
449         comment = stralloc(tp->comment);
450
451     /* edit the tapelist and rewrite it */
452     remove_tapelabel(state->device->volume_label);
453     add_tapelabel(state->driver_start_time,
454                   state->device->volume_label,
455                   comment);
456     if (write_tapelist(tapelist_name)) {
457         error("could not write tapelist: %s", strerror(errno));
458         /*NOTREACHED*/
459     }
460     amfree(tapelist_name);
461     amfree(comment);
462 }
463
464 /* Find and label a new tape, if one is not already open. Returns TRUE
465  * if a tape could be written. */
466 static gboolean find_and_label_new_tape(taper_state_t * state,
467                                         dump_info_t * dump_info) {
468     if (state->device != NULL) {
469         return TRUE;
470     }
471     state->total_bytes = 0;
472  
473     if (!find_new_tape(state, dump_info)) {
474         return FALSE;
475     }
476
477     return label_new_tape(state, dump_info);
478 }
479
480 static gboolean label_new_tape(taper_state_t * state, dump_info_t * dump_info) {
481     char *old_volume_name = NULL;
482     char *old_volume_time = NULL;
483     tape_search_request_t request;
484     gboolean search_result;
485     DeviceStatusFlags status;
486
487     /* If we got here, it means that we have found a tape to label and
488      * have gotten permission from the driver to write it. But we
489      * still can say NO-NEW-TAPE if a problem shows up, and must still
490      * say NEW-TAPE if one doesn't. */
491
492     amfree(state->last_errmsg);
493     state->device = device_open(state->next_tape_device);
494     g_assert(state->device != NULL);
495     amfree(state->next_tape_device);
496
497     if (state->device->status != DEVICE_STATUS_SUCCESS)
498         goto skip_volume;
499
500     if (!device_configure(state->device, TRUE))
501         goto skip_volume;
502
503     /* if we have an error, and are sure it isn't just an unlabeled volume,
504      * then skip this volume */
505     status = device_read_label(state->device);
506     if ((status & ~DEVICE_STATUS_VOLUME_UNLABELED) &&
507         !(status & DEVICE_STATUS_VOLUME_UNLABELED))
508         goto skip_volume;
509
510     old_volume_name = g_strdup(state->device->volume_label);
511     old_volume_time = g_strdup(state->device->volume_time);
512
513     if (!device_start(state->device, ACCESS_WRITE, state->next_tape_label,
514                       state->driver_start_time)) {
515         gboolean tape_used;
516
517         /* Something broke, see if we can tell if the volume was erased or
518          * not. */
519         g_fprintf(stderr, "taper: Error writing label %s to device %s: %s.\n",
520                 state->next_tape_label, state->device->device_name,
521                 device_error_or_status(state->device));
522
523         if (!device_finish(state->device))
524             goto request_new_volume;
525
526         /* This time, if we can't read the label, assume we've overwritten
527          * the volume or otherwise corrupted it */
528         status = device_read_label(state->device);
529         if ((status & ~DEVICE_STATUS_VOLUME_UNLABELED) &&
530             !(status & DEVICE_STATUS_VOLUME_UNLABELED))
531             goto request_new_volume;
532
533         tape_used = check_volume_changed(state->device, old_volume_name, 
534                                          old_volume_time);
535
536         if (tape_used)
537             goto request_new_volume;
538         else
539             goto skip_volume;
540     }
541
542     amfree(old_volume_name);
543     amfree(old_volume_time);
544     amfree(state->next_tape_label);
545
546     update_tapelist(state);
547     state->cur_tape++;
548
549     if (state->have_changer &&
550         changer_label("UNKNOWN", state->device->volume_label) != 0) {
551         error(_("couldn't update barcode database"));
552         /*NOTREACHED*/
553     }
554
555     log_add(L_START, "datestamp %s label %s tape %d",
556             state->driver_start_time, state->device->volume_label,
557             state->cur_tape);
558     putresult(NEW_TAPE, "%s %s\n", dump_info->handle,
559               state->device->volume_label);
560
561     return TRUE;
562
563 request_new_volume:
564     /* Tell the driver we overwrote this volume, even if it was empty, and request
565      * a new volume. */
566     if (state->device)
567         state->last_errmsg = newstralloc(state->last_errmsg, device_error_or_status(state->device));
568     else
569         state->last_errmsg = newstralloc(state->last_errmsg, "(unknown)");
570
571     putresult(NEW_TAPE, "%s %s\n", dump_info->handle,
572               state->next_tape_label);
573     if (old_volume_name) {
574         log_add(L_WARNING, "Problem writing label '%s' to volume %s "
575                 "(volume may be erased): %s\n",
576                 state->next_tape_label, old_volume_name,
577                 state->last_errmsg);
578     } else {
579         log_add(L_WARNING, "Problem writing label '%s' to new volume "
580                 "(volume may be erased): %s\n", state->next_tape_label,
581                 state->last_errmsg);
582     }
583
584     if (state->device) {
585         g_object_unref(state->device);
586         state->device = NULL;
587     }
588
589     amfree(state->next_tape_label);
590     amfree(old_volume_name);
591     amfree(old_volume_time);
592
593     return find_and_label_new_tape(state, dump_info);
594
595 skip_volume:
596     /* grab a new volume without talking to the driver again -- we do this if we're
597      * confident we didn't overwrite the last tape we got. */
598     if (state->device)
599         state->last_errmsg = newstralloc(state->last_errmsg, device_error_or_status(state->device));
600     else
601         state->last_errmsg = newstralloc(state->last_errmsg, "(unknown)");
602
603     if (old_volume_name) {
604         log_add(L_WARNING, "Problem writing label '%s' to volume '%s' "
605                 "(old volume data intact): %s\n",
606                 state->next_tape_label, old_volume_name, state->last_errmsg);
607     } else {
608         log_add(L_WARNING, "Problem writing label '%s' to new volume "
609                 "(old volume data intact): %s\n", state->next_tape_label,
610                 state->last_errmsg);
611     }
612
613     if (state->device) {
614         g_object_unref(state->device);
615         state->device = NULL;
616     }
617
618     amfree(state->next_tape_label);
619     amfree(old_volume_name);
620     amfree(old_volume_time);
621
622     request.state = state;
623     request.prolong = TRUE;
624     request.errmsg = NULL;
625     search_result = GPOINTER_TO_INT(tape_search_thread(&request));
626     if (search_result) {
627         amfree(request.errmsg);
628         return label_new_tape(state, dump_info);
629     } else {
630         /* Problem finding a new tape! */
631         log_taper_scan_errmsg(request.errmsg);
632         putresult(NO_NEW_TAPE, "%s\n", dump_info->handle);
633         return FALSE;
634     }
635 }
636
637 /* Find out if the dump is PARTIAL or not, and set the proper driver
638    and logfile tags for the dump. */
639 static void find_completion_tags(dump_info_t * dump_info, /* IN */
640                                  cmd_t * result_cmd,      /* OUT */
641                                  logtype_t * result_log   /* OUT */) {
642     if (taper_source_is_partial(dump_info->source)) {
643         *result_cmd = PARTIAL;
644         *result_log = L_PARTIAL;
645     } else {
646         *result_cmd = DONE;
647         *result_log = L_DONE;
648     }
649 }
650
651 /* Put an L_PARTIAL message to the logfile. */
652 static void put_partial_log(dump_info_t * dump_info, double dump_time,
653                             guint64 dump_kbytes, char *errstr) {
654     char * qdiskname = quote_string(dump_info->diskname);
655
656     log_add(L_PARTIAL, "%s %s %s %d %d [sec %f kb %ju kps %f] %s",
657             dump_info->hostname, qdiskname, dump_info->timestamp,
658             dump_info->current_part, dump_info->level, dump_time,
659             (uintmax_t)dump_kbytes, dump_kbytes / dump_time,
660             errstr);
661     amfree(qdiskname);
662 }
663
664 /* Figure out what to do after a part attempt. Returns TRUE if another
665    attempt should proceed for this dump; FALSE if we are done. */
666 static gboolean finish_part_attempt(taper_state_t * taper_state,
667                                     dump_info_t * dump_info,
668                                     queue_result_flags queue_result,
669                                     GTimeVal run_time, guint64 run_bytes) {
670     double part_time = g_timeval_to_double(run_time);
671     guint64 part_kbytes = run_bytes / 1024;
672     double part_kbps = run_bytes / (1024 * part_time);
673         
674     char * qdiskname = quote_string(dump_info->diskname);
675
676     if (queue_result == QUEUE_SUCCESS) {
677         dump_info->total_time = timesadd(run_time, dump_info->total_time);
678         dump_info->total_bytes += run_bytes;
679
680         log_add(L_PART, "%s %d %s %s %s %d/%d %d [sec %f kb %ju kps %f]",
681                 taper_state->device->volume_label,
682                 taper_state->device->file, dump_info->hostname, qdiskname,
683                 dump_info->timestamp, dump_info->current_part,
684                 taper_source_predict_parts(dump_info->source),
685                 dump_info->level, part_time, (uintmax_t)part_kbytes, part_kbps);
686         putresult(PARTDONE, "%s %s %d %ju \"[sec %f kb %ju kps %f]\"\n",
687                   dump_info->handle, taper_state->device->volume_label,
688                   taper_state->device->file, (uintmax_t)part_kbytes, part_time,
689                   (uintmax_t)part_kbytes, part_kbps);
690         taper_state->total_bytes += run_bytes;
691         
692         if (taper_source_get_end_of_data(dump_info->source)) {
693             cmd_t result_cmd;
694             logtype_t result_log;
695             double dump_time = g_timeval_to_double(dump_info->total_time);
696             guint64 dump_kbytes = dump_info->total_bytes / 1024;
697             double dump_kbps = dump_info->total_bytes / (1024 * dump_time);
698
699             find_completion_tags(dump_info, &result_cmd, &result_log);
700
701             g_object_unref(dump_info->source);
702             dump_info->source = NULL;
703         
704             log_add(result_log, "%s %s %s %d %d [sec %f kb %ju kps %f]",
705                     dump_info->hostname, qdiskname, dump_info->timestamp,
706                     dump_info->current_part, dump_info->level, dump_time,
707                     (uintmax_t)dump_kbytes, dump_kbps);
708             putresult(result_cmd, "%s INPUT-GOOD TAPE-GOOD "
709                       "\"[sec %f kb %ju kps %f]\" \"\" \"\"\n",
710                       dump_info->handle, dump_time, (uintmax_t)dump_kbytes,
711                       dump_kbps);
712             
713             amfree(qdiskname);
714             return FALSE;
715         } else if (taper_source_get_end_of_part(dump_info->source)) {
716             taper_source_start_new_part(dump_info->source);
717             dump_info->current_part ++;
718             amfree(qdiskname);
719             return TRUE;
720         }
721         /* If we didn't read EOF or EOP, then an error
722            occured. But we read QUEUE_SUCCESS, so something is
723            b0rked. */
724         g_assert_not_reached();
725     } else {
726         char * volume_label = strdup(taper_state->device->volume_label);
727         int file_number = taper_state->device->file;
728         double dump_time, dump_kbps;
729         guint64 dump_kbytes;
730         char *producer_errstr = quote_string(
731                                    taper_source_get_errmsg(dump_info->source));
732         char *consumer_errstr = quote_string(
733                                    device_error(taper_state->device));
734
735         log_add(L_PARTPARTIAL,
736                 "%s %d %s %s %s %d/%d %d [sec %f kb %ju kps %f] %s",
737                 volume_label, file_number, dump_info->hostname, qdiskname,
738                 dump_info->timestamp, dump_info->current_part,
739                 taper_source_predict_parts(dump_info->source),
740                 dump_info->level, part_time, (uintmax_t)part_kbytes, part_kbps,
741                 consumer_errstr);
742         log_add(L_INFO, "tape %s kb %lld fm %d [OK]\n",
743                 volume_label,
744                 (long long)((taper_state->total_bytes+(off_t)1023) / (off_t)1024),
745                 taper_state->device->file);
746
747         /* A problem occured. */
748         if (queue_result & QUEUE_CONSUMER_ERROR) {
749             /* Make a note if this was EOM (we treat EOM the same as any other error,
750              * so it's just for debugging purposes */
751             if (taper_state->device->is_eof)
752                 g_debug("device %s ran out of space", taper_state->device->device_name);
753
754             /* Close the device. */
755             device_finish(taper_state->device);
756             g_object_unref(taper_state->device);
757             taper_state->device = NULL;
758         }
759         
760         amfree(volume_label);
761         
762         if ((queue_result & QUEUE_CONSUMER_ERROR) &&
763             (!(queue_result & QUEUE_PRODUCER_ERROR)) &&
764             taper_source_seek_to_part_start(dump_info->source)) {
765             /* It is recoverable. */
766             log_add(L_INFO, "Will request retry of failed split part.");
767             if (find_and_label_new_tape(taper_state, dump_info)) {
768                 /* dump_info->current_part is unchanged. */
769                 amfree(qdiskname);
770                 return TRUE;
771             }
772         }
773
774         dump_info->total_time = timesadd(run_time, dump_info->total_time);
775         dump_info->total_bytes += run_bytes;
776         dump_time = g_timeval_to_double(dump_info->total_time);
777         dump_kbytes = dump_info->total_bytes / 1024;
778         dump_kbps = dump_info->total_bytes / (1024 * dump_time);
779         
780         putresult(PARTIAL,
781                   "%s INPUT-%s TAPE-%s "
782                   "\"[sec %f kb %ju kps %f]\" %s %s\n",
783                   dump_info->handle,
784                   (queue_result & QUEUE_PRODUCER_ERROR) ? "ERROR" : "GOOD",
785                   (queue_result & QUEUE_CONSUMER_ERROR) ? "ERROR" : "GOOD",
786                   dump_time, (uintmax_t)dump_kbytes, dump_kbps,
787                   producer_errstr, consumer_errstr);
788         if (queue_result & QUEUE_CONSUMER_ERROR) {
789             put_partial_log(dump_info, dump_time, dump_kbytes,
790                             consumer_errstr);
791         } else {
792             put_partial_log(dump_info, dump_time, dump_kbytes,
793                             producer_errstr);
794         }
795         amfree(producer_errstr);
796         amfree(consumer_errstr);
797     }
798
799     amfree(qdiskname);
800     return FALSE;
801 }
802
803 /* Generate the actual header structure to write to tape. This means dropping
804  * bits related to the holding disk, and adding bits for split dumps. */
805 static dumpfile_t * munge_headers(dump_info_t * dump_info) {
806     dumpfile_t * rval;
807     int expected_splits;
808     
809     rval = taper_source_get_first_header(dump_info->source);
810
811     if (rval == NULL) {
812         return NULL;
813     }
814
815     rval->cont_filename[0] = '\0';
816
817     expected_splits = taper_source_predict_parts(dump_info->source);
818
819     if (expected_splits != 1) {
820         rval->type = F_SPLIT_DUMPFILE;
821         rval->partnum = dump_info->current_part;
822         rval->totalparts = expected_splits;
823     }
824
825     return rval;
826 }
827
828 /* We call this when we can't find a tape to write data to. This could
829    happen with the first (or only) part of a file, but it could also
830    happen with an intermediate part of a split dump. dump_bytes
831    is 0 if this is the first part of a dump. */
832 static void bail_no_volume(
833     dump_info_t *dump_info,
834     char *errmsg)
835 {
836     char *errstr;
837     if (errmsg)
838         errstr = quote_string(errmsg);
839     else
840         errstr = quote_string("no new tape");
841     if (dump_info->total_bytes > 0) {
842         /* Second or later part of a split dump, so PARTIAL message. */
843         double dump_time = g_timeval_to_double(dump_info->total_time);
844         guint64 dump_kbytes = dump_info->total_bytes / 1024;
845         double dump_kbps = dump_kbytes / dump_time;
846         putresult(PARTIAL,
847                   "%s INPUT-GOOD TAPE-ERROR "
848                   "\"[sec %f kb %ju kps %f]\" \"\" %s\n",
849                   dump_info->handle, 
850                   dump_time, (uintmax_t)dump_kbytes, dump_kbps, errstr);
851         put_partial_log(dump_info, dump_time, dump_kbytes, errstr);
852     } else {
853         char * qdiskname = quote_string(dump_info->diskname);
854         putresult(FAILED,
855                   "%s INPUT-GOOD TAPE-ERROR \"\" %s\n",
856                   dump_info->handle, errstr);
857         log_add(L_FAIL, "%s %s %s %d %s",
858                 dump_info->hostname, qdiskname, dump_info->timestamp,
859                 dump_info->level, errstr);
860         amfree(qdiskname);
861     }
862     amfree(errstr);
863 }
864
865 /* Link up the TaperSource with the Device, including retries etc. */
866 static void run_device_output(taper_state_t * taper_state,
867                               dump_info_t * dump_info) {
868     GValue val;
869     guint file_number;
870     dump_info->current_part = 1;
871     dump_info->total_time.tv_sec = 0;
872     dump_info->total_time.tv_usec = 0;
873     dump_info->total_bytes = 0;
874
875     for (;;) {
876         GTimeVal start_time, end_time, run_time;
877         StreamingRequirement streaming_mode;
878         queue_result_flags queue_result;
879         CountingConsumerData consumer_data;
880         dumpfile_t *this_header;
881         size_t max_memory;
882         
883         this_header = munge_headers(dump_info);
884         if (this_header == NULL) {
885             char * qdiskname = quote_string(dump_info->diskname);
886             char * errstr = taper_source_get_errmsg(dump_info->source);
887             if (!errstr)
888                 errstr = "Failed reading dump header.";
889             errstr = quote_string(errstr);
890             putresult(FAILED,
891              "%s INPUT-ERROR TAPE-GOOD %s \"\"\n",
892                       dump_info->handle, errstr);
893             log_add(L_FAIL, "%s %s %s %d %s",
894                     dump_info->hostname, qdiskname, dump_info->timestamp,
895                     dump_info->level, errstr);
896             amfree(qdiskname);
897             amfree(errstr);
898             return;
899         }            
900
901         if (!find_and_label_new_tape(taper_state, dump_info)) {
902             bail_no_volume(dump_info, taper_state->last_errmsg);
903             dumpfile_free(this_header);
904             return;
905         }
906
907         while (!device_start_file(taper_state->device, this_header)) {
908             /* Close the device. */
909             device_finish(taper_state->device);
910             g_object_unref(taper_state->device);
911             taper_state->device = NULL;
912
913             if (!find_and_label_new_tape(taper_state, dump_info)) {
914                 bail_no_volume(dump_info, taper_state->last_errmsg);
915                 dumpfile_free(this_header);
916                 return;
917             }
918         }
919         dumpfile_free(this_header);
920
921         bzero(&val, sizeof(val));
922         if (!device_property_get(taper_state->device, PROPERTY_STREAMING, &val)
923             || !G_VALUE_HOLDS(&val, STREAMING_REQUIREMENT_TYPE)) {
924             g_fprintf(stderr, "taper: Couldn't get streaming type!\n");
925             streaming_mode = STREAMING_REQUIREMENT_REQUIRED;
926         } else {
927             streaming_mode = g_value_get_enum(&val);
928         }
929     
930         file_number = taper_state->device->file;
931
932         consumer_data.next_consumer = device_write_consumer;
933         consumer_data.next_consumer_data = taper_state->device;
934         consumer_data.bytes_written = 0;
935
936         g_get_current_time(&start_time);
937
938         if (getconf_seen(CNF_DEVICE_OUTPUT_BUFFER_SIZE)) {
939             max_memory = getconf_size(CNF_DEVICE_OUTPUT_BUFFER_SIZE);
940             if (getconf_seen(CNF_TAPEBUFS)) {
941                 g_fprintf(stderr,
942                         "Configuration directives 'device_output_buffer_size' "
943                         "and \n"
944                         "'tapebufs' are incompatible; using former.\n");
945             }
946         } else if (getconf_seen(CNF_TAPEBUFS)) {
947             max_memory = getconf_int(CNF_TAPEBUFS) *
948                 taper_state->device->block_size;
949         } else {
950             /* Use default. */
951             max_memory = getconf_size(CNF_DEVICE_OUTPUT_BUFFER_SIZE);
952         }
953
954         queue_result = do_consumer_producer_queue_full
955             (taper_source_producer,
956              dump_info->source,
957              counting_consumer,
958              &consumer_data,
959              taper_state->device->block_size, max_memory,
960              streaming_mode);
961
962         g_get_current_time(&end_time);
963         run_time = timesub(end_time, start_time);
964
965         /* The device_write_consumer leaves the file open, so close it now. */
966         if (!device_finish_file(taper_state->device)) {
967             queue_result = queue_result | QUEUE_CONSUMER_ERROR;
968         }
969
970         if (!finish_part_attempt(taper_state, dump_info, queue_result,
971                                  run_time, consumer_data.bytes_written)) {
972             break;
973         }
974     }
975 }
976
977 /* Handle a PORT_WRITE command. */
978 static void process_port_write(taper_state_t * state,
979                                struct cmdargs * cmdargs) {
980     dump_info_t dump_state;
981     guint64 splitsize;
982     guint64 fallback_splitsize;
983     char * split_diskbuffer;
984     char * argnames[] = {"command",               /* 0 */
985                          "handle",                /* 1 */
986                          "hostname",              /* 2 */
987                          "diskname",              /* 3 */
988                          "level",                 /* 4 */
989                          "datestamp",             /* 5 */
990                          "splitsize",             /* 6 */
991                          "split_diskbuffer",      /* 7 */
992                          "fallback_splitsize",    /* 8 */
993                           NULL };
994
995     validate_args(cmdargs, argnames);
996
997     dump_state.handle = g_strdup(cmdargs->argv[1]);
998     dump_state.hostname = g_strdup(cmdargs->argv[2]);
999     dump_state.diskname = g_strdup(cmdargs->argv[3]);
1000     
1001     errno = 0;
1002     dump_state.level = strtol(cmdargs->argv[4], NULL, 10);
1003     if (errno != 0) {
1004         error("error [taper PORT-WRITE: Invalid dump level %s]",
1005               cmdargs->argv[4]);
1006         g_assert_not_reached();
1007     }
1008     
1009     dump_state.timestamp = strdup(cmdargs->argv[5]);
1010
1011     errno = 0;
1012     splitsize = g_ascii_strtoull(cmdargs->argv[6], NULL, 10);
1013     if (errno != 0) {
1014         error("error [taper PORT-WRITE: Invalid splitsize %s]",
1015               cmdargs->argv[6]);
1016         g_assert_not_reached();
1017     }
1018     
1019     if (strcmp(cmdargs->argv[7], "NULL") == 0) {
1020         split_diskbuffer = NULL;
1021     } else {
1022         split_diskbuffer = g_strdup(cmdargs->argv[7]);
1023     }
1024     
1025     errno = 0;
1026     fallback_splitsize = g_ascii_strtoull(cmdargs->argv[8], NULL, 10);
1027     if (errno != 0) {
1028         error("error [taper PORT-WRITE: Invalid fallback_splitsize %s]",
1029               cmdargs->argv[8]);
1030         g_assert_not_reached();
1031     }
1032
1033     dump_state.id_string = g_strdup_printf("%s:%s.%d", dump_state.hostname,
1034                                            dump_state.diskname,
1035                                            dump_state.level);
1036     
1037     if (!open_read_socket(&dump_state, split_diskbuffer, splitsize,
1038                           fallback_splitsize)) {
1039         free(split_diskbuffer);
1040         return;
1041     }
1042     free(split_diskbuffer);
1043
1044     run_device_output(state, &dump_state);
1045
1046     free_dump_info(&dump_state);
1047 }
1048
1049 /* Handle a FILE_WRITE command. */
1050 static void process_file_write(taper_state_t * state,
1051                                struct cmdargs * cmdargs) {
1052     dump_info_t dump_state;
1053     char * holding_disk_file;
1054     guint64 splitsize;
1055     char * argnames[] = {"command",               /* 0 */
1056                          "handle",                /* 1 */
1057                          "filename",              /* 2 */
1058                          "hostname",              /* 3 */
1059                          "diskname",              /* 4 */
1060                          "level",                 /* 5 */
1061                          "datestamp",             /* 6 */
1062                          "splitsize",             /* 7 */
1063                           NULL };
1064
1065     validate_args(cmdargs, argnames);
1066
1067     dump_state.handle = g_strdup(cmdargs->argv[1]);
1068     holding_disk_file = g_strdup(cmdargs->argv[2]);
1069     dump_state.hostname = g_strdup(cmdargs->argv[3]);
1070     dump_state.diskname = g_strdup(cmdargs->argv[4]);
1071     
1072     errno = 0;
1073     dump_state.level = strtol(cmdargs->argv[5], NULL, 10);
1074     if (errno != 0) {
1075         error("error [taper FILE-WRITE: Invalid dump level %s]",
1076               cmdargs->argv[5]);
1077         g_assert_not_reached();
1078     }
1079     
1080     dump_state.timestamp = strdup(cmdargs->argv[6]);
1081
1082     errno = 0;
1083     splitsize = g_ascii_strtoull(cmdargs->argv[7], NULL, 10);
1084     if (errno != 0) {
1085         error("error [taper FILE-WRITE: Invalid splitsize %s]",
1086               cmdargs->argv[7]);
1087         g_assert_not_reached();
1088     }
1089
1090     dump_state.id_string = g_strdup_printf("%s:%s.%d", dump_state.hostname,
1091                                            dump_state.diskname,
1092                                            dump_state.level);
1093     
1094     dump_state.source = taper_source_new(dump_state.handle, FILE_WRITE,
1095                                          holding_disk_file, -1,
1096                                          NULL, splitsize, -1);
1097     /* FIXME: This should be handled properly. */
1098     g_assert(dump_state.source != NULL);
1099
1100     run_device_output(state, &dump_state);
1101
1102     free_dump_info(&dump_state);
1103     amfree(holding_disk_file);
1104 }
1105
1106 /* Send QUITTING message to driver and associated logging. Always
1107    returns false. */
1108 static gboolean send_quitting(taper_state_t * state) {
1109     putresult(QUITTING, "\n");
1110     g_fprintf(stderr,"taper: DONE\n");
1111     cleanup(state);
1112     return FALSE;
1113 }
1114
1115 /* This function recieves the START_TAPER command from driver, and
1116    returns the attached timestamp. */
1117 static gboolean find_first_tape(taper_state_t * state) {
1118     struct cmdargs *cmdargs;
1119     tape_search_request_t search_request;
1120     GThread * tape_search = NULL;
1121     gboolean use_threads;
1122
1123     /* We save the value here in case it changes while we're running. */
1124     use_threads = g_thread_supported();
1125
1126     search_request.state = state;
1127     search_request.prolong = TRUE;
1128     search_request.errmsg = NULL;
1129     
1130     if (use_threads) {
1131         tape_search = g_thread_create(tape_search_thread,
1132                                       &search_request, TRUE, NULL);
1133     }
1134
1135     cmdargs = getcmd();
1136
1137     switch (cmdargs->cmd) {
1138     case START_TAPER: {
1139         gboolean search_result;
1140         state->driver_start_time = strdup(cmdargs->argv[1]);
1141         if (use_threads) {
1142             search_result = GPOINTER_TO_INT(g_thread_join(tape_search));
1143         } else {
1144             search_result =
1145                 GPOINTER_TO_INT(tape_search_thread(&search_request));
1146         }
1147         if (search_result) {
1148             putresult(TAPER_OK, "\n");
1149         } else {
1150             putresult(TAPE_ERROR, "Could not find a tape to use.\n");
1151             log_add(L_ERROR, "no-tape [%s]", "Could not find a tape to use");
1152             if (search_request.errmsg != NULL) {
1153                 char *c, *c1;
1154                 c = c1 = search_request.errmsg;
1155                 while (*c != '\0') {
1156                     if (*c == '\n') {
1157                         *c = '\0';
1158                         log_add(L_WARNING,"%s", c1);
1159                         c1 = c+1;
1160                     }
1161                     c++;
1162                 }
1163                 if (strlen(c1) > 1 )
1164                     log_add(L_WARNING,"%s", c1);
1165             }
1166         }
1167         amfree(search_request.errmsg);
1168         free_cmdargs(cmdargs);
1169         return TRUE;
1170     }
1171     case QUIT:
1172         search_request.prolong = FALSE;
1173         if (use_threads) {
1174             g_thread_join(tape_search);
1175         }
1176         free_cmdargs(cmdargs);
1177         return send_quitting(state);
1178     default:
1179         error("error [file_reader_side cmd %d argc %d]", cmdargs->cmd, cmdargs->argc);
1180     }
1181
1182     g_assert_not_reached();
1183 }
1184
1185 /* In running mode (not startup mode), get a command from driver and
1186    deal with it. */
1187 static gboolean process_driver_command(taper_state_t * state) {
1188     struct cmdargs *cmdargs;
1189     char * q;
1190
1191     /* This will return QUIT if driver has died. */
1192     cmdargs = getcmd();
1193     switch (cmdargs->cmd) {
1194     case PORT_WRITE:
1195         /*
1196          * PORT-WRITE
1197          *   handle
1198          *   hostname
1199          *   features
1200          *   diskname
1201          *   level
1202          *   datestamp
1203          *   splitsize
1204          *   split_diskbuffer
1205          */
1206         process_port_write(state, cmdargs);
1207         break;
1208         
1209     case FILE_WRITE:
1210         /*
1211          * FILE-WRITE
1212          *   handle
1213          *   filename
1214          *   hostname
1215          *   features
1216          *   diskname
1217          *   level
1218          *   datestamp
1219          *   splitsize
1220          */
1221         process_file_write(state, cmdargs);
1222         break;
1223         
1224     case QUIT:
1225         free_cmdargs(cmdargs);
1226         if (state->device && state->device->volume_label) {
1227             log_add(L_INFO, "tape %s kb %lld fm %d [OK]\n",
1228                     state->device->volume_label,
1229                     (long long)((state->total_bytes+(off_t)1023) / (off_t)1024),
1230                     state->device->file);
1231         }
1232         return send_quitting(state);
1233     default:
1234         if (cmdargs->argc >= 1) {
1235             q = quote_string(cmdargs->argv[0]);
1236         } else {
1237             q = stralloc("(no input?)");
1238         }
1239         putresult(BAD_COMMAND, "%s\n", q);
1240         amfree(q);
1241         break;
1242     }
1243     free_cmdargs(cmdargs);
1244
1245     return TRUE;
1246 }
1247
1248 int main(int argc, char ** argv) {
1249     char * tapelist_name;
1250     taper_state_t state;
1251     config_overwrites_t *cfg_ovr = NULL;
1252     char *cfg_opt = NULL;
1253
1254     /*
1255      * Configure program for internationalization:
1256      *   1) Only set the message locale for now.
1257      *   2) Set textdomain for all amanda related programs to "amanda"
1258      *      We don't want to be forced to support dozens of message catalogs.
1259      */
1260     setlocale(LC_MESSAGES, "C");
1261     textdomain("amanda");
1262     
1263     safe_fd(-1, 0);
1264     set_pname("taper");
1265
1266     dbopen("server");
1267
1268     device_api_init();
1269     init_taper_state(&state);
1270
1271     /* Don't die when child closes pipe */
1272     signal(SIGPIPE, SIG_IGN);
1273
1274     g_fprintf(stderr, _("%s: pid %ld executable %s version %s\n"),
1275             get_pname(), (long) getpid(), argv[0], version());
1276     dbprintf(_("%s: pid %ld executable %s version %s\n"),
1277               get_pname(), (long) getpid(), argv[0], version());
1278
1279     /* Process options */
1280
1281     cfg_ovr = extract_commandline_config_overwrites(&argc, &argv);
1282
1283     if(argc > 2) {
1284         error("Too many arguments!\n");
1285         g_assert_not_reached();
1286     }
1287     if (argc > 1)
1288         cfg_opt = argv[1];
1289     config_init(CONFIG_INIT_EXPLICIT_NAME | CONFIG_INIT_USE_CWD, cfg_opt);
1290     apply_config_overwrites(cfg_ovr);
1291
1292     if (config_errors(NULL) >= CFGERR_ERRORS) {
1293         g_critical(_("errors processing config file"));
1294     }
1295
1296     safe_cd();
1297
1298     set_logerror(logerror);
1299
1300     check_running_as(RUNNING_AS_DUMPUSER);
1301
1302     dbrename(get_config_name(), DBG_SUBDIR_SERVER);
1303
1304     log_add(L_INFO, "%s pid %ld", get_pname(), (long)getpid());
1305
1306     tapelist_name = config_dir_relative(getconf_str(CNF_TAPELIST));
1307
1308     if (read_tapelist(tapelist_name) != 0) {
1309         log_add(L_INFO, "pid-done %ld", (long)getpid());
1310         error("could not load tapelist \"%s\"", tapelist_name);
1311         g_assert_not_reached();
1312     }
1313     amfree(tapelist_name);
1314
1315     state.have_changer = changer_init();
1316     if (state.have_changer < 0) {
1317         log_add(L_INFO, "pid-done %ld", (long)getpid());
1318         error("changer initialization failed: %s", strerror(errno));
1319         g_assert_not_reached();
1320     }
1321
1322     state.next_tape_label = NULL;
1323     state.next_tape_device = NULL;
1324     state.cur_tape = 0;
1325     
1326     if (!find_first_tape(&state)) {
1327         log_add(L_INFO, "pid-done %ld", (long)getpid());
1328         return EXIT_SUCCESS;
1329     }
1330
1331     while (process_driver_command(&state));
1332     log_add(L_INFO, "pid-done %ld", (long)getpid());
1333     return EXIT_SUCCESS;
1334 }