89088018d475f4d90d574249f0a1a8150437f7bb
[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 static double get_kbps(double kb, double secs) {
253     /* avoid division by zero */
254     if (secs < 0.0001)
255         return 0.0;
256     return kb / secs;
257 }
258
259 /* A (simpler) wrapper around taper_scan(). */
260 static gboolean simple_taper_scan(taper_state_t * state,
261                                   gboolean* prolong, char ** error_message) {
262     char ** label = &(state->next_tape_label);
263     char ** device = &(state->next_tape_device);
264     char *timestamp = NULL;
265     int result;
266     result = taper_scan(NULL, label, &timestamp, device,
267                         state->taper_scan_tracker,
268                         CHAR_taperscan_output_callback,
269                         error_message, boolean_prolong, prolong);
270     if (prolong != NULL && !*prolong) {
271         g_fprintf(stderr, _("Cancelled taper scan.\n"));
272         return FALSE;
273     } else if (result < 0) {
274         g_fprintf(stderr, _("Failed taper scan: %s\n"), (*error_message)?(*error_message):_("(no error message)"));
275         amfree(timestamp);
276         return FALSE;
277     } else {
278         g_fprintf(stderr, _("taper: using label `%s' date `%s'\n"), *label,
279                 state->driver_start_time);
280         if (result == 3) {
281             log_add(L_INFO,
282             _("Will write new label `%s' to new tape"),
283                     *label);
284         }
285
286     }
287     amfree(timestamp);
288     return TRUE;
289 }
290
291 typedef struct {
292     taper_state_t * state;
293     gboolean prolong; /* scan stops when this is FALSE. */
294     char *errmsg;
295 } tape_search_request_t;
296
297 /* A GThread that runs taper_scan. */
298 static gpointer tape_search_thread(gpointer data) {
299     tape_search_request_t * request = data;
300
301     if (request->state->next_tape_label != NULL &&
302         request->state->next_tape_device != NULL) {
303         return GINT_TO_POINTER(TRUE);
304     } else {
305         amfree(request->state->next_tape_label);
306         amfree(request->state->next_tape_device);
307     }
308
309     return GINT_TO_POINTER
310         (simple_taper_scan(request->state,
311                            &(request->prolong),
312                            &(request->errmsg)));
313 }
314
315 static void log_taper_scan_errmsg(char * errmsg) {
316     char *c, *c1;
317     if (errmsg == NULL)
318         return;
319
320     c = c1 = errmsg;
321     while (*c != '\0') {
322         if (*c == '\n') {
323             *c = '\0';
324             log_add(L_WARNING,"%s", c1);
325             c1 = c+1;
326         }
327         c++;
328     }
329     if (strlen(c1) > 1 )
330         log_add(L_WARNING,"%s", c1);
331     amfree(errmsg);
332 }
333
334 /* If handle is NULL, then this function assumes that we are in startup mode.
335  * In that case it will wait for a command from driver. If handle is not NULL,
336  * this this function will ask for permission with REQUEST-NEW-TAPE. */
337 static gboolean find_new_tape(taper_state_t * state, dump_info_t * dump) {
338     GThread * tape_search = NULL;
339     tape_search_request_t search_request;
340     gboolean use_threads;
341     struct cmdargs *cmdargs;
342     cmd_t cmd;
343
344     if (state->device != NULL) {
345         return TRUE;
346     }
347
348     /* We save the value here in case it changes while we're running. */
349     use_threads = g_thread_supported();
350
351     search_request.state = state;
352     search_request.prolong = TRUE;
353     search_request.errmsg = NULL;
354     if (use_threads) {
355         tape_search = g_thread_create(tape_search_thread,
356                                       &search_request, TRUE, NULL);
357     }
358     
359     putresult(REQUEST_NEW_TAPE, "%s\n", dump->handle);
360     cmdargs = getcmd();
361     cmd = cmdargs->cmd;
362
363     switch (cmd) {
364     default:
365         g_fprintf(stderr, "taper: Got odd message from driver, expected NEW-TAPE or NO-NEW-TAPE.\n");
366         /* FALLTHROUGH. */
367     case NEW_TAPE: {
368         gboolean search_result;
369         if (use_threads) {
370             search_result = GPOINTER_TO_INT(g_thread_join(tape_search));
371         } else {
372             search_result =
373                 GPOINTER_TO_INT(tape_search_thread(&search_request));
374         }
375         if (search_result) {
376             /* We don't say NEW_TAPE until we actually write the label. */
377             amfree(search_request.errmsg);
378             free_cmdargs(cmdargs);
379             return TRUE;
380         } else {
381             putresult(NO_NEW_TAPE, "%s\n", dump->handle);
382             log_taper_scan_errmsg(search_request.errmsg);
383             log_add(L_ERROR, "no-tape [%s]", "No more writable valid tape found");
384             free_cmdargs(cmdargs);
385             return FALSE;
386         }
387     }
388     case NO_NEW_TAPE:
389         search_request.prolong = FALSE;
390         if (use_threads) {
391             g_thread_join(tape_search);
392         }
393         log_add(L_ERROR, "no-tape [%s]", cmdargs->argv[1]);
394         state->last_errmsg = stralloc(cmdargs->argv[1]);
395         free_cmdargs(cmdargs);
396         return FALSE;
397     }
398     /* NOTREACHED */
399 }
400
401 /* Returns TRUE if the old volume details are not the same as the new ones. */
402 static gboolean check_volume_changed(Device * device,
403                                      char * old_label, char * old_timestamp) {
404     /* If one is NULL and the other is not, something changed. */
405     if ((old_label == NULL) != (device->volume_label == NULL))
406         return TRUE;
407     if ((old_timestamp == NULL) != (device->volume_time == NULL))
408         return TRUE;
409     /* If details were not NULL and is now different, we have a difference. */
410     if (old_label != NULL && strcmp(old_label, device->volume_label) != 0)
411         return TRUE;
412     if (old_timestamp != NULL &&
413         strcmp(old_timestamp, device->volume_time) != 0)
414         return TRUE;
415
416     /* If we got here, everything is cool. */
417     return FALSE;
418 }
419
420 static void
421 update_tapelist(
422     taper_state_t *state)
423 {
424     char *tapelist_name = NULL;
425     char *tapelist_name_old = NULL;
426     tape_t *tp;
427     char *comment = NULL;
428
429     tapelist_name = config_dir_relative(getconf_str(CNF_TAPELIST));
430     if (state->cur_tape == 0) {
431         tapelist_name_old = stralloc2(tapelist_name, ".yesterday");
432     } else {
433         char cur_str[NUM_STR_SIZE];
434         g_snprintf(cur_str, SIZEOF(cur_str), "%d", state->cur_tape - 1);
435         tapelist_name_old = vstralloc(tapelist_name,
436                                       ".today.", cur_str, NULL);
437     }
438
439    if (read_tapelist(tapelist_name) != 0) {
440         log_add(L_INFO, "pid-done %ld", (long)getpid());
441         error("could not load tapelist \"%s\"", tapelist_name);
442         /*NOTREACHED*/
443     }
444
445     /* make a copy of the tapelist file */
446     if (write_tapelist(tapelist_name_old)) {
447         log_add(L_INFO, "pid-done %ld", (long)getpid());
448         error("could not write tapelist: %s", strerror(errno));
449         /*NOTREACHED*/
450     }
451     amfree(tapelist_name_old);
452
453     /* get a copy of the comment, before freeing the old record */
454     tp = lookup_tapelabel(state->device->volume_label);
455     if (tp && tp->comment)
456         comment = stralloc(tp->comment);
457
458     /* edit the tapelist and rewrite it */
459     remove_tapelabel(state->device->volume_label);
460     add_tapelabel(state->driver_start_time,
461                   state->device->volume_label,
462                   comment);
463     if (write_tapelist(tapelist_name)) {
464         error("could not write tapelist: %s", strerror(errno));
465         /*NOTREACHED*/
466     }
467     amfree(tapelist_name);
468     amfree(comment);
469 }
470
471 /* Find and label a new tape, if one is not already open. Returns TRUE
472  * if a tape could be written. */
473 static gboolean find_and_label_new_tape(taper_state_t * state,
474                                         dump_info_t * dump_info) {
475     if (state->device != NULL) {
476         return TRUE;
477     }
478     state->total_bytes = 0;
479  
480     if (!find_new_tape(state, dump_info)) {
481         return FALSE;
482     }
483
484     return label_new_tape(state, dump_info);
485 }
486
487 static gboolean label_new_tape(taper_state_t * state, dump_info_t * dump_info) {
488     char *old_volume_name = NULL;
489     char *old_volume_time = NULL;
490     tape_search_request_t request;
491     gboolean search_result;
492     DeviceStatusFlags status;
493
494     /* If we got here, it means that we have found a tape to label and
495      * have gotten permission from the driver to write it. But we
496      * still can say NO-NEW-TAPE if a problem shows up, and must still
497      * say NEW-TAPE if one doesn't. */
498
499     amfree(state->last_errmsg);
500     state->device = device_open(state->next_tape_device);
501     g_assert(state->device != NULL);
502     amfree(state->next_tape_device);
503
504     if (state->device->status != DEVICE_STATUS_SUCCESS)
505         goto skip_volume;
506
507     if (!device_configure(state->device, TRUE))
508         goto skip_volume;
509
510     /* if we have an error, and are sure it isn't just an unlabeled volume,
511      * then skip this volume */
512     status = device_read_label(state->device);
513     if ((status & ~DEVICE_STATUS_VOLUME_UNLABELED) &&
514         !(status & DEVICE_STATUS_VOLUME_UNLABELED))
515         goto skip_volume;
516
517     old_volume_name = g_strdup(state->device->volume_label);
518     old_volume_time = g_strdup(state->device->volume_time);
519
520     if (!device_start(state->device, ACCESS_WRITE, state->next_tape_label,
521                       state->driver_start_time)) {
522         gboolean tape_used;
523
524         /* Something broke, see if we can tell if the volume was erased or
525          * not. */
526         g_fprintf(stderr, "taper: Error writing label %s to device %s: %s.\n",
527                 state->next_tape_label, state->device->device_name,
528                 device_error_or_status(state->device));
529
530         if (!device_finish(state->device))
531             goto request_new_volume;
532
533         /* This time, if we can't read the label, assume we've overwritten
534          * the volume or otherwise corrupted it */
535         status = device_read_label(state->device);
536         if ((status & ~DEVICE_STATUS_VOLUME_UNLABELED) &&
537             !(status & DEVICE_STATUS_VOLUME_UNLABELED))
538             goto request_new_volume;
539
540         tape_used = check_volume_changed(state->device, old_volume_name, 
541                                          old_volume_time);
542
543         if (tape_used)
544             goto request_new_volume;
545         else
546             goto skip_volume;
547     }
548
549     amfree(old_volume_name);
550     amfree(old_volume_time);
551     amfree(state->next_tape_label);
552
553     update_tapelist(state);
554     state->cur_tape++;
555
556     if (state->have_changer &&
557         changer_label("UNKNOWN", state->device->volume_label) != 0) {
558         error(_("couldn't update barcode database"));
559         /*NOTREACHED*/
560     }
561
562     log_add(L_START, "datestamp %s label %s tape %d",
563             state->driver_start_time, state->device->volume_label,
564             state->cur_tape);
565     putresult(NEW_TAPE, "%s %s\n", dump_info->handle,
566               state->device->volume_label);
567
568     return TRUE;
569
570 request_new_volume:
571     /* Tell the driver we overwrote this volume, even if it was empty, and request
572      * a new volume. */
573     if (state->device)
574         state->last_errmsg = newstralloc(state->last_errmsg, device_error_or_status(state->device));
575     else
576         state->last_errmsg = newstralloc(state->last_errmsg, "(unknown)");
577
578     putresult(NEW_TAPE, "%s %s\n", dump_info->handle,
579               state->next_tape_label);
580     if (old_volume_name) {
581         log_add(L_WARNING, "Problem writing label '%s' to volume %s "
582                 "(volume may be erased): %s\n",
583                 state->next_tape_label, old_volume_name,
584                 state->last_errmsg);
585     } else {
586         log_add(L_WARNING, "Problem writing label '%s' to new volume "
587                 "(volume may be erased): %s\n", state->next_tape_label,
588                 state->last_errmsg);
589     }
590
591     if (state->device) {
592         g_object_unref(state->device);
593         state->device = NULL;
594     }
595
596     amfree(state->next_tape_label);
597     amfree(old_volume_name);
598     amfree(old_volume_time);
599
600     return find_and_label_new_tape(state, dump_info);
601
602 skip_volume:
603     /* grab a new volume without talking to the driver again -- we do this if we're
604      * confident we didn't overwrite the last tape we got. */
605     if (state->device)
606         state->last_errmsg = newstralloc(state->last_errmsg, device_error_or_status(state->device));
607     else
608         state->last_errmsg = newstralloc(state->last_errmsg, "(unknown)");
609
610     if (old_volume_name) {
611         log_add(L_WARNING, "Problem writing label '%s' to volume '%s' "
612                 "(old volume data intact): %s\n",
613                 state->next_tape_label, old_volume_name, state->last_errmsg);
614     } else {
615         log_add(L_WARNING, "Problem writing label '%s' to new volume "
616                 "(old volume data intact): %s\n", state->next_tape_label,
617                 state->last_errmsg);
618     }
619
620     if (state->device) {
621         g_object_unref(state->device);
622         state->device = NULL;
623     }
624
625     amfree(state->next_tape_label);
626     amfree(old_volume_name);
627     amfree(old_volume_time);
628
629     request.state = state;
630     request.prolong = TRUE;
631     request.errmsg = NULL;
632     search_result = GPOINTER_TO_INT(tape_search_thread(&request));
633     if (search_result) {
634         amfree(request.errmsg);
635         return label_new_tape(state, dump_info);
636     } else {
637         /* Problem finding a new tape! */
638         log_taper_scan_errmsg(request.errmsg);
639         putresult(NO_NEW_TAPE, "%s\n", dump_info->handle);
640         return FALSE;
641     }
642 }
643
644 /* Find out if the dump is PARTIAL or not, and set the proper driver
645    and logfile tags for the dump. */
646 static void find_completion_tags(dump_info_t * dump_info, /* IN */
647                                  cmd_t * result_cmd,      /* OUT */
648                                  logtype_t * result_log   /* OUT */) {
649     /* result_cmd is always DONE because the taper wrote all the input to
650      * the output. driver need to know if the taper completed its job.
651      * result_log is set to L_PARTIAL if the image is partial, the log
652      * must tell if the image is partial or complete.
653      */
654        
655     if (taper_source_is_partial(dump_info->source)) {
656         *result_cmd = DONE;
657         *result_log = L_PARTIAL;
658     } else {
659         *result_cmd = DONE;
660         *result_log = L_DONE;
661     }
662 }
663
664 /* Put an L_PARTIAL message to the logfile. */
665 static void put_partial_log(dump_info_t * dump_info, double dump_time,
666                             guint64 dump_kbytes, char *errstr) {
667     char * qdiskname = quote_string(dump_info->diskname);
668
669     log_add(L_PARTIAL, "%s %s %s %d %d [sec %f kb %ju kps %f] %s",
670             dump_info->hostname, qdiskname, dump_info->timestamp,
671             dump_info->current_part, dump_info->level, dump_time,
672             (uintmax_t)dump_kbytes, get_kbps(dump_kbytes, dump_time),
673             errstr);
674     amfree(qdiskname);
675 }
676
677 /* Figure out what to do after a part attempt. Returns TRUE if another
678    attempt should proceed for this dump; FALSE if we are done. */
679 static gboolean finish_part_attempt(taper_state_t * taper_state,
680                                     dump_info_t * dump_info,
681                                     queue_result_flags queue_result,
682                                     GTimeVal run_time, guint64 run_bytes) {
683     double part_time = g_timeval_to_double(run_time);
684     guint64 part_kbytes = run_bytes / 1024;
685     double part_kbps = get_kbps((double)run_bytes / 1024.0, part_time);
686         
687     char * qdiskname = quote_string(dump_info->diskname);
688
689     if (queue_result == QUEUE_SUCCESS) {
690         dump_info->total_time = timesadd(run_time, dump_info->total_time);
691         dump_info->total_bytes += run_bytes;
692
693         log_add(L_PART, "%s %d %s %s %s %d/%d %d [sec %f kb %ju kps %f]",
694                 taper_state->device->volume_label,
695                 taper_state->device->file, dump_info->hostname, qdiskname,
696                 dump_info->timestamp, dump_info->current_part,
697                 taper_source_predict_parts(dump_info->source),
698                 dump_info->level, part_time, (uintmax_t)part_kbytes, part_kbps);
699         putresult(PARTDONE, "%s %s %d %ju \"[sec %f kb %ju kps %f]\"\n",
700                   dump_info->handle, taper_state->device->volume_label,
701                   taper_state->device->file, (uintmax_t)part_kbytes, part_time,
702                   (uintmax_t)part_kbytes, part_kbps);
703         taper_state->total_bytes += run_bytes;
704         
705         if (taper_source_get_end_of_data(dump_info->source)) {
706             cmd_t result_cmd;
707             logtype_t result_log;
708             double dump_time = g_timeval_to_double(dump_info->total_time);
709             guint64 dump_kbytes = dump_info->total_bytes / 1024;
710             double dump_kbps = get_kbps((double)dump_info->total_bytes / 1024.0, dump_time);
711
712             find_completion_tags(dump_info, &result_cmd, &result_log);
713
714             g_object_unref(dump_info->source);
715             dump_info->source = NULL;
716         
717             log_add(result_log, "%s %s %s %d %d [sec %f kb %ju kps %f]",
718                     dump_info->hostname, qdiskname, dump_info->timestamp,
719                     dump_info->current_part, dump_info->level, dump_time,
720                     (uintmax_t)dump_kbytes, dump_kbps);
721             putresult(result_cmd, "%s INPUT-GOOD TAPE-GOOD "
722                       "\"[sec %f kb %ju kps %f]\" \"\" \"\"\n",
723                       dump_info->handle, dump_time, (uintmax_t)dump_kbytes,
724                       dump_kbps);
725             
726             amfree(qdiskname);
727             return FALSE;
728         } else if (taper_source_get_end_of_part(dump_info->source)) {
729             taper_source_start_new_part(dump_info->source);
730             dump_info->current_part ++;
731             amfree(qdiskname);
732             return TRUE;
733         }
734         /* If we didn't read EOF or EOP, then an error
735            occured. But we read QUEUE_SUCCESS, so something is
736            b0rked. */
737         g_assert_not_reached();
738     } else {
739         char * volume_label = strdup(taper_state->device->volume_label);
740         int file_number = taper_state->device->file;
741         double dump_time, dump_kbps;
742         guint64 dump_kbytes;
743         char *producer_errstr = quote_string(
744                                    taper_source_get_errmsg(dump_info->source));
745         char *consumer_errstr = quote_string(
746                                    device_error(taper_state->device));
747
748         log_add(L_PARTPARTIAL,
749                 "%s %d %s %s %s %d/%d %d [sec %f kb %ju kps %f] %s",
750                 volume_label, file_number, dump_info->hostname, qdiskname,
751                 dump_info->timestamp, dump_info->current_part,
752                 taper_source_predict_parts(dump_info->source),
753                 dump_info->level, part_time, (uintmax_t)part_kbytes, part_kbps,
754                 consumer_errstr);
755         log_add(L_INFO, "tape %s kb %lld fm %d [OK]\n",
756                 volume_label,
757                 (long long)((taper_state->total_bytes+(off_t)1023) / (off_t)1024),
758                 taper_state->device->file);
759
760         /* A problem occured. */
761         if (queue_result & QUEUE_CONSUMER_ERROR) {
762             /* Make a note if this was EOM (we treat EOM the same as any other error,
763              * so it's just for debugging purposes */
764             if (taper_state->device->is_eof)
765                 g_debug("device %s ran out of space", taper_state->device->device_name);
766
767             /* Close the device. */
768             device_finish(taper_state->device);
769             g_object_unref(taper_state->device);
770             taper_state->device = NULL;
771         }
772         
773         amfree(volume_label);
774         
775         if ((queue_result & QUEUE_CONSUMER_ERROR) &&
776             (!(queue_result & QUEUE_PRODUCER_ERROR)) &&
777             taper_source_seek_to_part_start(dump_info->source)) {
778             /* It is recoverable. */
779             log_add(L_INFO, "Will request retry of failed split part.");
780             if (find_and_label_new_tape(taper_state, dump_info)) {
781                 /* dump_info->current_part is unchanged. */
782                 amfree(qdiskname);
783                 return TRUE;
784             }
785         }
786
787         dump_info->total_time = timesadd(run_time, dump_info->total_time);
788         dump_info->total_bytes += run_bytes;
789         dump_time = g_timeval_to_double(dump_info->total_time);
790         dump_kbytes = dump_info->total_bytes / 1024;
791         dump_kbps = get_kbps((double)dump_info->total_bytes / 1024.0, dump_time);
792         
793         putresult(PARTIAL,
794                   "%s INPUT-%s TAPE-%s "
795                   "\"[sec %f kb %ju kps %f]\" %s %s\n",
796                   dump_info->handle,
797                   (queue_result & QUEUE_PRODUCER_ERROR) ? "ERROR" : "GOOD",
798                   (queue_result & QUEUE_CONSUMER_ERROR) ? "ERROR" : "GOOD",
799                   dump_time, (uintmax_t)dump_kbytes, dump_kbps,
800                   producer_errstr, consumer_errstr);
801         if (queue_result & QUEUE_CONSUMER_ERROR) {
802             put_partial_log(dump_info, dump_time, dump_kbytes,
803                             consumer_errstr);
804         } else {
805             put_partial_log(dump_info, dump_time, dump_kbytes,
806                             producer_errstr);
807         }
808         amfree(producer_errstr);
809         amfree(consumer_errstr);
810     }
811
812     amfree(qdiskname);
813     return FALSE;
814 }
815
816 /* Generate the actual header structure to write to tape. This means dropping
817  * bits related to the holding disk, and adding bits for split dumps. */
818 static dumpfile_t * munge_headers(dump_info_t * dump_info) {
819     dumpfile_t * rval;
820     int expected_splits;
821     
822     rval = taper_source_get_first_header(dump_info->source);
823
824     if (rval == NULL) {
825         return NULL;
826     }
827
828     rval->cont_filename[0] = '\0';
829
830     expected_splits = taper_source_predict_parts(dump_info->source);
831
832     if (expected_splits != 1) {
833         rval->type = F_SPLIT_DUMPFILE;
834         rval->partnum = dump_info->current_part;
835         rval->totalparts = expected_splits;
836     }
837
838     return rval;
839 }
840
841 /* We call this when we can't find a tape to write data to. This could
842    happen with the first (or only) part of a file, but it could also
843    happen with an intermediate part of a split dump. dump_bytes
844    is 0 if this is the first part of a dump. */
845 static void bail_no_volume(
846     dump_info_t *dump_info,
847     char *errmsg)
848 {
849     char *errstr;
850     if (errmsg)
851         errstr = quote_string(errmsg);
852     else
853         errstr = quote_string("no new tape");
854     if (dump_info->total_bytes > 0) {
855         /* Second or later part of a split dump, so PARTIAL message. */
856         double dump_time = g_timeval_to_double(dump_info->total_time);
857         guint64 dump_kbytes = dump_info->total_bytes / 1024;
858         double dump_kbps = get_kbps(dump_kbytes, dump_time);
859         putresult(PARTIAL,
860                   "%s INPUT-GOOD TAPE-ERROR "
861                   "\"[sec %f kb %ju kps %f]\" \"\" %s\n",
862                   dump_info->handle, 
863                   dump_time, (uintmax_t)dump_kbytes, dump_kbps, errstr);
864         put_partial_log(dump_info, dump_time, dump_kbytes, errstr);
865     } else {
866         char * qdiskname = quote_string(dump_info->diskname);
867         putresult(FAILED,
868                   "%s INPUT-GOOD TAPE-ERROR \"\" %s\n",
869                   dump_info->handle, errstr);
870         log_add(L_FAIL, "%s %s %s %d %s",
871                 dump_info->hostname, qdiskname, dump_info->timestamp,
872                 dump_info->level, errstr);
873         amfree(qdiskname);
874     }
875     amfree(errstr);
876 }
877
878 /* Link up the TaperSource with the Device, including retries etc. */
879 static void run_device_output(taper_state_t * taper_state,
880                               dump_info_t * dump_info) {
881     GValue val;
882     guint file_number;
883     dump_info->current_part = 1;
884     dump_info->total_time.tv_sec = 0;
885     dump_info->total_time.tv_usec = 0;
886     dump_info->total_bytes = 0;
887
888     for (;;) {
889         GTimeVal start_time, end_time, run_time;
890         StreamingRequirement streaming_mode;
891         queue_result_flags queue_result;
892         CountingConsumerData consumer_data;
893         dumpfile_t *this_header;
894         size_t max_memory;
895         
896         this_header = munge_headers(dump_info);
897         if (this_header == NULL) {
898             char * qdiskname = quote_string(dump_info->diskname);
899             char * errstr = taper_source_get_errmsg(dump_info->source);
900             if (!errstr)
901                 errstr = "Failed reading dump header.";
902             errstr = quote_string(errstr);
903             putresult(FAILED,
904              "%s INPUT-ERROR TAPE-GOOD %s \"\"\n",
905                       dump_info->handle, errstr);
906             log_add(L_FAIL, "%s %s %s %d %s",
907                     dump_info->hostname, qdiskname, dump_info->timestamp,
908                     dump_info->level, errstr);
909             amfree(qdiskname);
910             amfree(errstr);
911             return;
912         }            
913
914         if (!find_and_label_new_tape(taper_state, dump_info)) {
915             bail_no_volume(dump_info, taper_state->last_errmsg);
916             dumpfile_free(this_header);
917             return;
918         }
919
920         while (!device_start_file(taper_state->device, this_header)) {
921             /* Close the device. */
922             device_finish(taper_state->device);
923             g_object_unref(taper_state->device);
924             taper_state->device = NULL;
925
926             if (!find_and_label_new_tape(taper_state, dump_info)) {
927                 bail_no_volume(dump_info, taper_state->last_errmsg);
928                 dumpfile_free(this_header);
929                 return;
930             }
931         }
932         dumpfile_free(this_header);
933
934         bzero(&val, sizeof(val));
935         if (!device_property_get(taper_state->device, PROPERTY_STREAMING, &val)
936             || !G_VALUE_HOLDS(&val, STREAMING_REQUIREMENT_TYPE)) {
937             g_fprintf(stderr, "taper: Couldn't get streaming type!\n");
938             streaming_mode = STREAMING_REQUIREMENT_REQUIRED;
939         } else {
940             streaming_mode = g_value_get_enum(&val);
941         }
942     
943         file_number = taper_state->device->file;
944
945         consumer_data.next_consumer = device_write_consumer;
946         consumer_data.next_consumer_data = taper_state->device;
947         consumer_data.bytes_written = 0;
948
949         g_get_current_time(&start_time);
950
951         if (getconf_seen(CNF_DEVICE_OUTPUT_BUFFER_SIZE)) {
952             max_memory = getconf_size(CNF_DEVICE_OUTPUT_BUFFER_SIZE);
953             if (getconf_seen(CNF_TAPEBUFS)) {
954                 g_fprintf(stderr,
955                         "Configuration directives 'device_output_buffer_size' "
956                         "and \n"
957                         "'tapebufs' are incompatible; using former.\n");
958             }
959         } else if (getconf_seen(CNF_TAPEBUFS)) {
960             max_memory = getconf_int(CNF_TAPEBUFS) *
961                 taper_state->device->block_size;
962         } else {
963             /* Use default. */
964             max_memory = getconf_size(CNF_DEVICE_OUTPUT_BUFFER_SIZE);
965         }
966
967         queue_result = do_consumer_producer_queue_full
968             (taper_source_producer,
969              dump_info->source,
970              counting_consumer,
971              &consumer_data,
972              taper_state->device->block_size, max_memory,
973              streaming_mode);
974
975         g_get_current_time(&end_time);
976         run_time = timesub(end_time, start_time);
977
978         /* The device_write_consumer leaves the file open, so close it now. */
979         if (!device_finish_file(taper_state->device)) {
980             queue_result = queue_result | QUEUE_CONSUMER_ERROR;
981         }
982
983         if (!finish_part_attempt(taper_state, dump_info, queue_result,
984                                  run_time, consumer_data.bytes_written)) {
985             break;
986         }
987     }
988 }
989
990 /* Handle a PORT_WRITE command. */
991 static void process_port_write(taper_state_t * state,
992                                struct cmdargs * cmdargs) {
993     dump_info_t dump_state;
994     guint64 splitsize;
995     guint64 fallback_splitsize;
996     char * split_diskbuffer;
997     char * argnames[] = {"command",               /* 0 */
998                          "handle",                /* 1 */
999                          "hostname",              /* 2 */
1000                          "diskname",              /* 3 */
1001                          "level",                 /* 4 */
1002                          "datestamp",             /* 5 */
1003                          "splitsize",             /* 6 */
1004                          "split_diskbuffer",      /* 7 */
1005                          "fallback_splitsize",    /* 8 */
1006                           NULL };
1007
1008     validate_args(cmdargs, argnames);
1009
1010     dump_state.handle = g_strdup(cmdargs->argv[1]);
1011     dump_state.hostname = g_strdup(cmdargs->argv[2]);
1012     dump_state.diskname = g_strdup(cmdargs->argv[3]);
1013     
1014     errno = 0;
1015     dump_state.level = strtol(cmdargs->argv[4], NULL, 10);
1016     if (errno != 0) {
1017         error("error [taper PORT-WRITE: Invalid dump level %s]",
1018               cmdargs->argv[4]);
1019         g_assert_not_reached();
1020     }
1021     
1022     dump_state.timestamp = strdup(cmdargs->argv[5]);
1023
1024     errno = 0;
1025     splitsize = g_ascii_strtoull(cmdargs->argv[6], NULL, 10);
1026     if (errno != 0) {
1027         error("error [taper PORT-WRITE: Invalid splitsize %s]",
1028               cmdargs->argv[6]);
1029         g_assert_not_reached();
1030     }
1031     
1032     if (strcmp(cmdargs->argv[7], "NULL") == 0) {
1033         split_diskbuffer = NULL;
1034     } else {
1035         split_diskbuffer = g_strdup(cmdargs->argv[7]);
1036     }
1037     
1038     errno = 0;
1039     fallback_splitsize = g_ascii_strtoull(cmdargs->argv[8], NULL, 10);
1040     if (errno != 0) {
1041         error("error [taper PORT-WRITE: Invalid fallback_splitsize %s]",
1042               cmdargs->argv[8]);
1043         g_assert_not_reached();
1044     }
1045
1046     dump_state.id_string = g_strdup_printf("%s:%s.%d", dump_state.hostname,
1047                                            dump_state.diskname,
1048                                            dump_state.level);
1049     
1050     if (!open_read_socket(&dump_state, split_diskbuffer, splitsize,
1051                           fallback_splitsize)) {
1052         free(split_diskbuffer);
1053         return;
1054     }
1055     free(split_diskbuffer);
1056
1057     run_device_output(state, &dump_state);
1058
1059     free_dump_info(&dump_state);
1060 }
1061
1062 /* Handle a FILE_WRITE command. */
1063 static void process_file_write(taper_state_t * state,
1064                                struct cmdargs * cmdargs) {
1065     dump_info_t dump_state;
1066     char * holding_disk_file;
1067     guint64 splitsize;
1068     char * argnames[] = {"command",               /* 0 */
1069                          "handle",                /* 1 */
1070                          "filename",              /* 2 */
1071                          "hostname",              /* 3 */
1072                          "diskname",              /* 4 */
1073                          "level",                 /* 5 */
1074                          "datestamp",             /* 6 */
1075                          "splitsize",             /* 7 */
1076                           NULL };
1077
1078     validate_args(cmdargs, argnames);
1079
1080     dump_state.handle = g_strdup(cmdargs->argv[1]);
1081     holding_disk_file = g_strdup(cmdargs->argv[2]);
1082     dump_state.hostname = g_strdup(cmdargs->argv[3]);
1083     dump_state.diskname = g_strdup(cmdargs->argv[4]);
1084     
1085     errno = 0;
1086     dump_state.level = strtol(cmdargs->argv[5], NULL, 10);
1087     if (errno != 0) {
1088         error("error [taper FILE-WRITE: Invalid dump level %s]",
1089               cmdargs->argv[5]);
1090         g_assert_not_reached();
1091     }
1092     
1093     dump_state.timestamp = strdup(cmdargs->argv[6]);
1094
1095     errno = 0;
1096     splitsize = g_ascii_strtoull(cmdargs->argv[7], NULL, 10);
1097     if (errno != 0) {
1098         error("error [taper FILE-WRITE: Invalid splitsize %s]",
1099               cmdargs->argv[7]);
1100         g_assert_not_reached();
1101     }
1102
1103     dump_state.id_string = g_strdup_printf("%s:%s.%d", dump_state.hostname,
1104                                            dump_state.diskname,
1105                                            dump_state.level);
1106     
1107     dump_state.source = taper_source_new(dump_state.handle, FILE_WRITE,
1108                                          holding_disk_file, -1,
1109                                          NULL, splitsize, -1);
1110     /* FIXME: This should be handled properly. */
1111     g_assert(dump_state.source != NULL);
1112
1113     run_device_output(state, &dump_state);
1114
1115     free_dump_info(&dump_state);
1116     amfree(holding_disk_file);
1117 }
1118
1119 /* Send QUITTING message to driver and associated logging. Always
1120    returns false. */
1121 static gboolean send_quitting(taper_state_t * state) {
1122     putresult(QUITTING, "\n");
1123     g_fprintf(stderr,"taper: DONE\n");
1124     cleanup(state);
1125     return FALSE;
1126 }
1127
1128 /* This function recieves the START_TAPER command from driver, and
1129    returns the attached timestamp. */
1130 static gboolean find_first_tape(taper_state_t * state) {
1131     struct cmdargs *cmdargs;
1132     tape_search_request_t search_request;
1133     GThread * tape_search = NULL;
1134     gboolean use_threads;
1135
1136     /* We save the value here in case it changes while we're running. */
1137     use_threads = g_thread_supported();
1138
1139     search_request.state = state;
1140     search_request.prolong = TRUE;
1141     search_request.errmsg = NULL;
1142     
1143     if (use_threads) {
1144         tape_search = g_thread_create(tape_search_thread,
1145                                       &search_request, TRUE, NULL);
1146     }
1147
1148     cmdargs = getcmd();
1149
1150     switch (cmdargs->cmd) {
1151     case START_TAPER: {
1152         gboolean search_result;
1153         state->driver_start_time = strdup(cmdargs->argv[1]);
1154         if (use_threads) {
1155             search_result = GPOINTER_TO_INT(g_thread_join(tape_search));
1156         } else {
1157             search_result =
1158                 GPOINTER_TO_INT(tape_search_thread(&search_request));
1159         }
1160         if (search_result) {
1161             putresult(TAPER_OK, "\n");
1162         } else {
1163             putresult(TAPE_ERROR, "Could not find a tape to use.\n");
1164             log_add(L_ERROR, "no-tape [%s]", "Could not find a tape to use");
1165             if (search_request.errmsg != NULL) {
1166                 char *c, *c1;
1167                 c = c1 = search_request.errmsg;
1168                 while (*c != '\0') {
1169                     if (*c == '\n') {
1170                         *c = '\0';
1171                         log_add(L_WARNING,"%s", c1);
1172                         c1 = c+1;
1173                     }
1174                     c++;
1175                 }
1176                 if (strlen(c1) > 1 )
1177                     log_add(L_WARNING,"%s", c1);
1178             }
1179         }
1180         amfree(search_request.errmsg);
1181         free_cmdargs(cmdargs);
1182         return TRUE;
1183     }
1184     case QUIT:
1185         search_request.prolong = FALSE;
1186         if (use_threads) {
1187             g_thread_join(tape_search);
1188         }
1189         free_cmdargs(cmdargs);
1190         return send_quitting(state);
1191     default:
1192         error("error [file_reader_side cmd %d argc %d]", cmdargs->cmd, cmdargs->argc);
1193     }
1194
1195     g_assert_not_reached();
1196 }
1197
1198 /* In running mode (not startup mode), get a command from driver and
1199    deal with it. */
1200 static gboolean process_driver_command(taper_state_t * state) {
1201     struct cmdargs *cmdargs;
1202     char * q;
1203
1204     /* This will return QUIT if driver has died. */
1205     cmdargs = getcmd();
1206     switch (cmdargs->cmd) {
1207     case PORT_WRITE:
1208         /*
1209          * PORT-WRITE
1210          *   handle
1211          *   hostname
1212          *   features
1213          *   diskname
1214          *   level
1215          *   datestamp
1216          *   splitsize
1217          *   split_diskbuffer
1218          */
1219         process_port_write(state, cmdargs);
1220         break;
1221         
1222     case FILE_WRITE:
1223         /*
1224          * FILE-WRITE
1225          *   handle
1226          *   filename
1227          *   hostname
1228          *   features
1229          *   diskname
1230          *   level
1231          *   datestamp
1232          *   splitsize
1233          */
1234         process_file_write(state, cmdargs);
1235         break;
1236         
1237     case QUIT:
1238         free_cmdargs(cmdargs);
1239         if (state->device && state->device->volume_label) {
1240             log_add(L_INFO, "tape %s kb %lld fm %d [OK]\n",
1241                     state->device->volume_label,
1242                     (long long)((state->total_bytes+(off_t)1023) / (off_t)1024),
1243                     state->device->file);
1244         }
1245         return send_quitting(state);
1246     default:
1247         if (cmdargs->argc >= 1) {
1248             q = quote_string(cmdargs->argv[0]);
1249         } else {
1250             q = stralloc("(no input?)");
1251         }
1252         putresult(BAD_COMMAND, "%s\n", q);
1253         amfree(q);
1254         break;
1255     }
1256     free_cmdargs(cmdargs);
1257
1258     return TRUE;
1259 }
1260
1261 int main(int argc, char ** argv) {
1262     char * tapelist_name;
1263     taper_state_t state;
1264     config_overwrites_t *cfg_ovr = NULL;
1265     char *cfg_opt = NULL;
1266
1267     /*
1268      * Configure program for internationalization:
1269      *   1) Only set the message locale for now.
1270      *   2) Set textdomain for all amanda related programs to "amanda"
1271      *      We don't want to be forced to support dozens of message catalogs.
1272      */
1273     setlocale(LC_MESSAGES, "C");
1274     textdomain("amanda");
1275     
1276     safe_fd(-1, 0);
1277     set_pname("taper");
1278
1279     dbopen("server");
1280
1281     device_api_init();
1282     init_taper_state(&state);
1283
1284     /* Don't die when child closes pipe */
1285     signal(SIGPIPE, SIG_IGN);
1286
1287     g_fprintf(stderr, _("%s: pid %ld executable %s version %s\n"),
1288             get_pname(), (long) getpid(), argv[0], version());
1289     dbprintf(_("%s: pid %ld executable %s version %s\n"),
1290               get_pname(), (long) getpid(), argv[0], version());
1291
1292     /* Process options */
1293
1294     cfg_ovr = extract_commandline_config_overwrites(&argc, &argv);
1295
1296     if(argc > 2) {
1297         error("Too many arguments!\n");
1298         g_assert_not_reached();
1299     }
1300     if (argc > 1)
1301         cfg_opt = argv[1];
1302     config_init(CONFIG_INIT_EXPLICIT_NAME | CONFIG_INIT_USE_CWD, cfg_opt);
1303     apply_config_overwrites(cfg_ovr);
1304
1305     if (config_errors(NULL) >= CFGERR_ERRORS) {
1306         g_critical(_("errors processing config file"));
1307     }
1308
1309     safe_cd();
1310
1311     set_logerror(logerror);
1312
1313     check_running_as(RUNNING_AS_DUMPUSER);
1314
1315     dbrename(get_config_name(), DBG_SUBDIR_SERVER);
1316
1317     log_add(L_INFO, "%s pid %ld", get_pname(), (long)getpid());
1318
1319     tapelist_name = config_dir_relative(getconf_str(CNF_TAPELIST));
1320
1321     if (read_tapelist(tapelist_name) != 0) {
1322         log_add(L_INFO, "pid-done %ld", (long)getpid());
1323         error("could not load tapelist \"%s\"", tapelist_name);
1324         g_assert_not_reached();
1325     }
1326     amfree(tapelist_name);
1327
1328     state.have_changer = changer_init();
1329     if (state.have_changer < 0) {
1330         log_add(L_INFO, "pid-done %ld", (long)getpid());
1331         error("changer initialization failed: %s", strerror(errno));
1332         g_assert_not_reached();
1333     }
1334
1335     state.next_tape_label = NULL;
1336     state.next_tape_device = NULL;
1337     state.cur_tape = 0;
1338     
1339     if (!find_first_tape(&state)) {
1340         log_add(L_INFO, "pid-done %ld", (long)getpid());
1341         return EXIT_SUCCESS;
1342     }
1343
1344     while (process_driver_command(&state));
1345     log_add(L_INFO, "pid-done %ld", (long)getpid());
1346     return EXIT_SUCCESS;
1347 }