]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/lib/message.c
Merge branch 'master' into basejobv3
[bacula/bacula] / bacula / src / lib / message.c
1 /*
2    Bacula® - The Network Backup Solution
3
4    Copyright (C) 2000-2008 Free Software Foundation Europe e.V.
5
6    The main author of Bacula is Kern Sibbald, with contributions from
7    many others, a complete list can be found in the file AUTHORS.
8    This program is Free Software; you can redistribute it and/or
9    modify it under the terms of version two of the GNU General Public
10    License as published by the Free Software Foundation and included
11    in the file LICENSE.
12
13    This program is distributed in the hope that it will be useful, but
14    WITHOUT ANY WARRANTY; without even the implied warranty of
15    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
16    General Public License for more details.
17
18    You should have received a copy of the GNU General Public License
19    along with this program; if not, write to the Free Software
20    Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
21    02110-1301, USA.
22
23    Bacula® is a registered trademark of Kern Sibbald.
24    The licensor of Bacula is the Free Software Foundation Europe
25    (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
26    Switzerland, email:ftf@fsfeurope.org.
27 */
28 /*
29  * Bacula message handling routines
30  *
31  *   Kern Sibbald, April 2000
32  *
33  *   Version $Id$
34  *
35  */
36
37
38 #include "bacula.h"
39 #include "jcr.h"
40
41 sql_query p_sql_query = NULL;
42 sql_escape p_sql_escape = NULL;
43
44 #define FULL_LOCATION 1               /* set for file:line in Debug messages */
45
46 /*
47  *  This is where we define "Globals" because all the
48  *    daemons include this file.
49  */
50 const char *working_directory = NULL;       /* working directory path stored here */
51 int verbose = 0;                      /* increase User messages */
52 int debug_level = 0;                  /* debug level */
53 bool dbg_timestamp = false;           /* print timestamp in debug output */
54 utime_t daemon_start_time = 0;        /* Daemon start time */
55 const char *version = VERSION " (" BDATE ")";
56 char my_name[30];                     /* daemon name is stored here */
57 char host_name[50];                   /* host machine name */
58 char *exepath = (char *)NULL;
59 char *exename = (char *)NULL;
60 int console_msg_pending = false;
61 char con_fname[500];                  /* Console filename */
62 FILE *con_fd = NULL;                  /* Console file descriptor */
63 brwlock_t con_lock;                   /* Console lock structure */
64
65 /* Forward referenced functions */
66
67 /* Imported functions */
68 void create_jcr_key();
69
70 /* Static storage */
71
72 /* Used to allow only one thread close the daemon messages at a time */
73 static pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER;
74 static MSGS *daemon_msgs;              /* global messages */
75 static char *catalog_db = NULL;       /* database type */
76 static void (*message_callback)(int type, char *msg) = NULL;
77 static FILE *trace_fd = NULL;
78 #if defined(HAVE_WIN32)
79 static bool trace = true;
80 #else
81 static bool trace = false;
82 #endif
83
84 /* Constants */
85 const char *host_os = HOST_OS;
86 const char *distname = DISTNAME;
87 const char *distver = DISTVER;
88
89
90 void register_message_callback(void msg_callback(int type, char *msg))
91 {
92    message_callback = msg_callback;
93 }
94
95
96 /*
97  * Set daemon name. Also, find canonical execution
98  *  path.  Note, exepath has spare room for tacking on
99  *  the exename so that we can reconstruct the full name.
100  *
101  * Note, this routine can get called multiple times
102  *  The second time is to put the name as found in the
103  *  Resource record. On the second call, generally,
104  *  argv is NULL to avoid doing the path code twice.
105  */
106 void my_name_is(int argc, char *argv[], const char *name)
107 {
108    char *l, *p, *q;
109    char cpath[1024];
110    int len;
111
112    if (gethostname(host_name, sizeof(host_name)) != 0) {
113       bstrncpy(host_name, "Hostname unknown", sizeof(host_name));
114    }
115    bstrncpy(my_name, name, sizeof(my_name));
116    if (argc>0 && argv && argv[0]) {
117       /* strip trailing filename and save exepath */
118       for (l=p=argv[0]; *p; p++) {
119          if (IsPathSeparator(*p)) {
120             l = p;                       /* set pos of last slash */
121          }
122       }
123       if (IsPathSeparator(*l)) {
124          l++;
125       } else {
126          l = argv[0];
127 #if defined(HAVE_WIN32)
128          /* On Windows allow c: junk */
129          if (l[1] == ':') {
130             l += 2;
131          }
132 #endif
133       }
134       len = strlen(l) + 1;
135       if (exename) {
136          free(exename);
137       }
138       exename = (char *)malloc(len);
139       strcpy(exename, l);
140
141       if (exepath) {
142          free(exepath);
143       }
144       exepath = (char *)malloc(strlen(argv[0]) + 1 + len);
145       for (p=argv[0],q=exepath; p < l; ) {
146          *q++ = *p++;
147       }
148       *q = 0;
149       if (strchr(exepath, '.') || !IsPathSeparator(exepath[0])) {
150          if (getcwd(cpath, sizeof(cpath))) {
151             free(exepath);
152             exepath = (char *)malloc(strlen(cpath) + 1 + len);
153             strcpy(exepath, cpath);
154          }
155       }
156       Dmsg2(500, "exepath=%s\nexename=%s\n", exepath, exename);
157    }
158 }
159
160 const char *
161 get_db_type(void)
162 {
163    return catalog_db != NULL ? catalog_db : "unknown";
164 }
165
166 void
167 set_db_type(const char *name)
168 {
169    if (catalog_db != NULL) {
170       free(catalog_db);
171    }
172    catalog_db = bstrdup(name);
173 }
174
175 /*
176  * Initialize message handler for a daemon or a Job
177  *   We make a copy of the MSGS resource passed, so it belows
178  *   to the job or daemon and thus can be modified.
179  *
180  *   NULL for jcr -> initialize global messages for daemon
181  *   non-NULL     -> initialize jcr using Message resource
182  */
183 void
184 init_msg(JCR *jcr, MSGS *msg)
185 {
186    DEST *d, *dnew, *temp_chain = NULL;
187    int i;
188
189    if (jcr == NULL && msg == NULL) {
190       init_last_jobs_list();
191       /* Create a daemon key then set invalid jcr */
192       /* Maybe we should give the daemon a jcr??? */
193       create_jcr_key();
194       set_jcr_in_tsd(INVALID_JCR);
195    }
196
197 #if !defined(HAVE_WIN32)
198    /*
199     * Make sure we have fd's 0, 1, 2 open
200     *  If we don't do this one of our sockets may open
201     *  there and if we then use stdout, it could
202     *  send total garbage to our socket.
203     *
204     */
205    int fd;
206    fd = open("/dev/null", O_RDONLY, 0644);
207    if (fd > 2) {
208       close(fd);
209    } else {
210       for(i=1; fd + i <= 2; i++) {
211          dup2(fd, fd+i);
212       }
213    }
214
215 #endif
216    /*
217     * If msg is NULL, initialize global chain for STDOUT and syslog
218     */
219    if (msg == NULL) {
220       daemon_msgs = (MSGS *)malloc(sizeof(MSGS));
221       memset(daemon_msgs, 0, sizeof(MSGS));
222       for (i=1; i<=M_MAX; i++) {
223          add_msg_dest(daemon_msgs, MD_STDOUT, i, NULL, NULL);
224       }
225       Dmsg1(050, "Create daemon global message resource %p\n", daemon_msgs);
226       return;
227    }
228
229    /*
230     * Walk down the message resource chain duplicating it
231     * for the current Job.
232     */
233    for (d=msg->dest_chain; d; d=d->next) {
234       dnew = (DEST *)malloc(sizeof(DEST));
235       memcpy(dnew, d, sizeof(DEST));
236       dnew->next = temp_chain;
237       dnew->fd = NULL;
238       dnew->mail_filename = NULL;
239       if (d->mail_cmd) {
240          dnew->mail_cmd = bstrdup(d->mail_cmd);
241       }
242       if (d->where) {
243          dnew->where = bstrdup(d->where);
244       }
245       temp_chain = dnew;
246    }
247
248    if (jcr) {
249       jcr->jcr_msgs = (MSGS *)malloc(sizeof(MSGS));
250       memset(jcr->jcr_msgs, 0, sizeof(MSGS));
251       jcr->jcr_msgs->dest_chain = temp_chain;
252       memcpy(jcr->jcr_msgs->send_msg, msg->send_msg, sizeof(msg->send_msg));
253    } else {
254       /* If we have default values, release them now */
255       if (daemon_msgs) {
256          free_msgs_res(daemon_msgs);
257       }
258       daemon_msgs = (MSGS *)malloc(sizeof(MSGS));
259       memset(daemon_msgs, 0, sizeof(MSGS));
260       daemon_msgs->dest_chain = temp_chain;
261       memcpy(daemon_msgs->send_msg, msg->send_msg, sizeof(msg->send_msg));
262    }
263    Dmsg2(250, "Copy message resource %p to %p\n", msg, temp_chain);
264
265 }
266
267 /* Initialize so that the console (User Agent) can
268  * receive messages -- stored in a file.
269  */
270 void init_console_msg(const char *wd)
271 {
272    int fd;
273
274    bsnprintf(con_fname, sizeof(con_fname), "%s%c%s.conmsg", wd, PathSeparator, my_name);
275    fd = open(con_fname, O_CREAT|O_RDWR|O_BINARY, 0600);
276    if (fd == -1) {
277       berrno be;
278       Emsg2(M_ERROR_TERM, 0, _("Could not open console message file %s: ERR=%s\n"),
279           con_fname, be.bstrerror());
280    }
281    if (lseek(fd, 0, SEEK_END) > 0) {
282       console_msg_pending = 1;
283    }
284    close(fd);
285    con_fd = fopen(con_fname, "a+b");
286    if (!con_fd) {
287       berrno be;
288       Emsg2(M_ERROR, 0, _("Could not open console message file %s: ERR=%s\n"),
289           con_fname, be.bstrerror());
290    }
291    if (rwl_init(&con_lock) != 0) {
292       berrno be;
293       Emsg1(M_ERROR_TERM, 0, _("Could not get con mutex: ERR=%s\n"),
294          be.bstrerror());
295    }
296 }
297
298 /*
299  * Called only during parsing of the config file.
300  *
301  * Add a message destination. I.e. associate a message type with
302  *  a destination (code).
303  * Note, where in the case of dest_code FILE is a filename,
304  *  but in the case of MAIL is a space separated list of
305  *  email addresses, ...
306  */
307 void add_msg_dest(MSGS *msg, int dest_code, int msg_type, char *where, char *mail_cmd)
308 {
309    DEST *d;
310    /*
311     * First search the existing chain and see if we
312     * can simply add this msg_type to an existing entry.
313     */
314    for (d=msg->dest_chain; d; d=d->next) {
315       if (dest_code == d->dest_code && ((where == NULL && d->where == NULL) ||
316                      (strcmp(where, d->where) == 0))) {
317          Dmsg4(850, "Add to existing d=%p msgtype=%d destcode=%d where=%s\n",
318              d, msg_type, dest_code, NPRT(where));
319          set_bit(msg_type, d->msg_types);
320          set_bit(msg_type, msg->send_msg);  /* set msg_type bit in our local */
321          return;
322       }
323    }
324    /* Not found, create a new entry */
325    d = (DEST *)malloc(sizeof(DEST));
326    memset(d, 0, sizeof(DEST));
327    d->next = msg->dest_chain;
328    d->dest_code = dest_code;
329    set_bit(msg_type, d->msg_types);      /* set type bit in structure */
330    set_bit(msg_type, msg->send_msg);     /* set type bit in our local */
331    if (where) {
332       d->where = bstrdup(where);
333    }
334    if (mail_cmd) {
335       d->mail_cmd = bstrdup(mail_cmd);
336    }
337    Dmsg5(850, "add new d=%p msgtype=%d destcode=%d where=%s mailcmd=%s\n",
338           d, msg_type, dest_code, NPRT(where), NPRT(d->mail_cmd));
339    msg->dest_chain = d;
340 }
341
342 /*
343  * Called only during parsing of the config file.
344  *
345  * Remove a message destination
346  */
347 void rem_msg_dest(MSGS *msg, int dest_code, int msg_type, char *where)
348 {
349    DEST *d;
350
351    for (d=msg->dest_chain; d; d=d->next) {
352       Dmsg2(850, "Remove_msg_dest d=%p where=%s\n", d, NPRT(d->where));
353       if (bit_is_set(msg_type, d->msg_types) && (dest_code == d->dest_code) &&
354           ((where == NULL && d->where == NULL) ||
355                      (strcmp(where, d->where) == 0))) {
356          Dmsg3(850, "Found for remove d=%p msgtype=%d destcode=%d\n",
357                d, msg_type, dest_code);
358          clear_bit(msg_type, d->msg_types);
359          Dmsg0(850, "Return rem_msg_dest\n");
360          return;
361       }
362    }
363 }
364
365
366 /*
367  * Create a unique filename for the mail command
368  */
369 static void make_unique_mail_filename(JCR *jcr, POOLMEM *&name, DEST *d)
370 {
371    if (jcr) {
372       Mmsg(name, "%s/%s.%s.%d.mail", working_directory, my_name,
373                  jcr->Job, (int)(intptr_t)d);
374    } else {
375       Mmsg(name, "%s/%s.%s.%d.mail", working_directory, my_name,
376                  my_name, (int)(intptr_t)d);
377    }
378    Dmsg1(850, "mailname=%s\n", name);
379 }
380
381 /*
382  * Open a mail pipe
383  */
384 static BPIPE *open_mail_pipe(JCR *jcr, POOLMEM *&cmd, DEST *d)
385 {
386    BPIPE *bpipe;
387
388    if (d->mail_cmd) {
389       cmd = edit_job_codes(jcr, cmd, d->mail_cmd, d->where);
390    } else {
391       Mmsg(cmd, "/usr/lib/sendmail -F Bacula %s", d->where);
392    }
393    fflush(stdout);
394
395    if ((bpipe = open_bpipe(cmd, 120, "rw"))) {
396       /* If we had to use sendmail, add subject */
397       if (!d->mail_cmd) {
398          fprintf(bpipe->wfd, "Subject: %s\r\n\r\n", _("Bacula Message"));
399       }
400    } else {
401       berrno be;
402       Jmsg(jcr, M_ERROR, 0, _("open mail pipe %s failed: ERR=%s\n"),
403          cmd, be.bstrerror());
404    }
405    return bpipe;
406 }
407
408 /*
409  * Close the messages for this Messages resource, which means to close
410  *  any open files, and dispatch any pending email messages.
411  */
412 void close_msg(JCR *jcr)
413 {
414    MSGS *msgs;
415    DEST *d;
416    BPIPE *bpipe;
417    POOLMEM *cmd, *line;
418    int len, stat;
419
420    Dmsg1(580, "Close_msg jcr=%p\n", jcr);
421
422    if (jcr == NULL) {                /* NULL -> global chain */
423       msgs = daemon_msgs;
424       P(mutex);                       /* only one thread walking the chain */
425    } else {
426       msgs = jcr->jcr_msgs;
427       jcr->jcr_msgs = NULL;
428    }
429    if (msgs == NULL) {
430       return;
431    }
432    Dmsg1(850, "===Begin close msg resource at %p\n", msgs);
433    cmd = get_pool_memory(PM_MESSAGE);
434    for (d=msgs->dest_chain; d; ) {
435       if (d->fd) {
436          switch (d->dest_code) {
437          case MD_FILE:
438          case MD_APPEND:
439             if (d->fd) {
440                fclose(d->fd);            /* close open file descriptor */
441                d->fd = NULL;
442             }
443             break;
444          case MD_MAIL:
445          case MD_MAIL_ON_ERROR:
446          case MD_MAIL_ON_SUCCESS:
447             Dmsg0(850, "Got MD_MAIL, MD_MAIL_ON_ERROR or MD_MAIL_ON_SUCCESS\n");
448             if (!d->fd) {
449                break;
450             }
451             if (
452                 (d->dest_code == MD_MAIL_ON_ERROR && jcr &&
453                   (jcr->JobStatus == JS_Terminated || jcr->JobStatus == JS_Warnings)) 
454                 ||
455                 (d->dest_code == MD_MAIL_ON_SUCCESS && jcr &&
456                  jcr->JobStatus == JS_ErrorTerminated)
457                 ) {
458                goto rem_temp_file;
459             }
460
461             if (!(bpipe=open_mail_pipe(jcr, cmd, d))) {
462                Pmsg0(000, _("open mail pipe failed.\n"));
463                goto rem_temp_file;
464             }
465             Dmsg0(850, "Opened mail pipe\n");
466             len = d->max_len+10;
467             line = get_memory(len);
468             rewind(d->fd);
469             while (fgets(line, len, d->fd)) {
470                fputs(line, bpipe->wfd);
471             }
472             if (!close_wpipe(bpipe)) {       /* close write pipe sending mail */
473                berrno be;
474                Pmsg1(000, _("close error: ERR=%s\n"), be.bstrerror());
475             }
476
477             /*
478              * Since we are closing all messages, before "recursing"
479              * make sure we are not closing the daemon messages, otherwise
480              * kaboom.
481              */
482             if (msgs != daemon_msgs) {
483                /* read what mail prog returned -- should be nothing */
484                while (fgets(line, len, bpipe->rfd)) {
485                   Jmsg1(jcr, M_INFO, 0, _("Mail prog: %s"), line);
486                }
487             }
488
489             stat = close_bpipe(bpipe);
490             if (stat != 0 && msgs != daemon_msgs) {
491                berrno be;
492                be.set_errno(stat);
493                Dmsg1(850, "Calling emsg. CMD=%s\n", cmd);
494                Jmsg2(jcr, M_ERROR, 0, _("Mail program terminated in error.\n"
495                                         "CMD=%s\n"
496                                         "ERR=%s\n"), cmd, be.bstrerror());
497             }
498             free_memory(line);
499 rem_temp_file:
500             /* Remove temp file */
501             fclose(d->fd);
502             d->fd = NULL;
503             unlink(d->mail_filename);
504             free_pool_memory(d->mail_filename);
505             d->mail_filename = NULL;
506             Dmsg0(850, "end mail or mail on error\n");
507             break;
508          default:
509             break;
510          }
511          d->fd = NULL;
512       }
513       d = d->next;                    /* point to next buffer */
514    }
515    free_pool_memory(cmd);
516    Dmsg0(850, "Done walking message chain.\n");
517    if (jcr) {
518       free_msgs_res(msgs);
519       msgs = NULL;
520    } else {
521       V(mutex);
522    }
523    Dmsg0(850, "===End close msg resource\n");
524 }
525
526 /*
527  * Free memory associated with Messages resource
528  */
529 void free_msgs_res(MSGS *msgs)
530 {
531    DEST *d, *old;
532
533    /* Walk down the message chain releasing allocated buffers */
534    for (d=msgs->dest_chain; d; ) {
535       if (d->where) {
536          free(d->where);
537       }
538       if (d->mail_cmd) {
539          free(d->mail_cmd);
540       }
541       old = d;                        /* save pointer to release */
542       d = d->next;                    /* point to next buffer */
543       free(old);                      /* free the destination item */
544    }
545    msgs->dest_chain = NULL;
546    free(msgs);                        /* free the head */
547 }
548
549
550 /*
551  * Terminate the message handler for good.
552  * Release the global destination chain.
553  *
554  * Also, clean up a few other items (cons, exepath). Note,
555  *   these really should be done elsewhere.
556  */
557 void term_msg()
558 {
559    Dmsg0(850, "Enter term_msg\n");
560    close_msg(NULL);                   /* close global chain */
561    free_msgs_res(daemon_msgs);        /* free the resources */
562    daemon_msgs = NULL;
563    if (con_fd) {
564       fflush(con_fd);
565       fclose(con_fd);
566       con_fd = NULL;
567    }
568    if (exepath) {
569       free(exepath);
570       exepath = NULL;
571    }
572    if (exename) {
573       free(exename);
574       exename = NULL;
575    }
576    if (trace_fd) {
577       fclose(trace_fd);
578       trace_fd = NULL;
579    }
580    if (catalog_db) {
581       free(catalog_db);
582       catalog_db = NULL;
583    }
584    term_last_jobs_list();
585 }
586
587 static bool open_dest_file(JCR *jcr, DEST *d, const char *mode) 
588 {
589    d->fd = fopen(d->where, mode);
590    if (!d->fd) {
591       berrno be;
592       d->fd = stdout;
593       Qmsg2(jcr, M_ERROR, 0, _("fopen %s failed: ERR=%s\n"), d->where, be.bstrerror());
594       d->fd = NULL;
595       return false;
596    }
597    return true;
598 }
599
600 /*
601  * Handle sending the message to the appropriate place
602  */
603 void dispatch_message(JCR *jcr, int type, utime_t mtime, char *msg)
604 {
605     DEST *d;
606     char dt[MAX_TIME_LENGTH];
607     POOLMEM *mcmd;
608     int len, dtlen;
609     MSGS *msgs;
610     BPIPE *bpipe;
611     const char *mode;
612
613     Dmsg2(850, "Enter dispatch_msg type=%d msg=%s", type, msg);
614
615     /*
616      * Most messages are prefixed by a date and time. If mtime is
617      *  zero, then we use the current time.  If mtime is 1 (special
618      *  kludge), we do not prefix the date and time. Otherwise,
619      *  we assume mtime is a utime_t and use it.
620      */
621     if (mtime == 0) {
622        mtime = time(NULL);
623     }
624     if (mtime == 1) {
625        *dt = 0;
626        dtlen = 0;
627        mtime = time(NULL);      /* get time for SQL log */
628     } else {
629        bstrftime_ny(dt, sizeof(dt), mtime);
630        dtlen = strlen(dt);
631        dt[dtlen++] = ' ';
632        dt[dtlen] = 0;
633     }
634
635     /* If the program registered a callback, send it there */
636     if (message_callback) {
637        message_callback(type, msg);
638        return;
639     }
640
641     if (type == M_ABORT || type == M_ERROR_TERM) {
642        fputs(dt, stdout);
643        fputs(msg, stdout);         /* print this here to INSURE that it is printed */
644        fflush(stdout);
645     }
646
647
648     /* Now figure out where to send the message */
649     msgs = NULL;
650     if (!jcr) {
651        jcr = get_jcr_from_tsd();
652     }
653     if (jcr) {
654        msgs = jcr->jcr_msgs;
655     }
656     if (msgs == NULL) {
657        msgs = daemon_msgs;
658     }
659     for (d=msgs->dest_chain; d; d=d->next) {
660        if (bit_is_set(type, d->msg_types)) {
661           switch (d->dest_code) {
662              case MD_CATALOG:
663                 char ed1[50];
664                 if (!jcr || !jcr->db) {
665                    break;
666                 }
667                 if (p_sql_query && p_sql_escape) {
668                    POOLMEM *cmd = get_pool_memory(PM_MESSAGE);
669                    POOLMEM *esc_msg = get_pool_memory(PM_MESSAGE);
670                    
671                    int len = strlen(msg) + 1;
672                    esc_msg = check_pool_memory_size(esc_msg, len*2+1);
673                    p_sql_escape(jcr, jcr->db, esc_msg, msg, len);
674
675                    bstrutime(dt, sizeof(dt), mtime);
676                    Mmsg(cmd, "INSERT INTO Log (JobId, Time, LogText) VALUES (%s,'%s','%s')",
677                          edit_int64(jcr->JobId, ed1), dt, esc_msg);
678                    p_sql_query(jcr, cmd);
679                    
680                    free_pool_memory(cmd);
681                    free_pool_memory(esc_msg);
682                 }
683                 break;
684              case MD_CONSOLE:
685                 Dmsg1(850, "CONSOLE for following msg: %s", msg);
686                 if (!con_fd) {
687                    con_fd = fopen(con_fname, "a+b");
688                    Dmsg0(850, "Console file not open.\n");
689                 }
690                 if (con_fd) {
691                    Pw(con_lock);      /* get write lock on console message file */
692                    errno = 0;
693                    if (dtlen) {
694                       (void)fwrite(dt, dtlen, 1, con_fd);
695                    }
696                    len = strlen(msg);
697                    if (len > 0) {
698                       (void)fwrite(msg, len, 1, con_fd);
699                       if (msg[len-1] != '\n') {
700                          (void)fwrite("\n", 2, 1, con_fd);
701                       }
702                    } else {
703                       (void)fwrite("\n", 2, 1, con_fd);
704                    }
705                    fflush(con_fd);
706                    console_msg_pending = true;
707                    Vw(con_lock);
708                 }
709                 break;
710              case MD_SYSLOG:
711                 Dmsg1(850, "SYSLOG for following msg: %s\n", msg);
712                 /*
713                  * We really should do an openlog() here.
714                  */
715                 syslog(LOG_DAEMON|LOG_ERR, "%s", msg);
716                 break;
717              case MD_OPERATOR:
718                 Dmsg1(850, "OPERATOR for following msg: %s\n", msg);
719                 mcmd = get_pool_memory(PM_MESSAGE);
720                 if ((bpipe=open_mail_pipe(jcr, mcmd, d))) {
721                    int stat;
722                    fputs(dt, bpipe->wfd);
723                    fputs(msg, bpipe->wfd);
724                    /* Messages to the operator go one at a time */
725                    stat = close_bpipe(bpipe);
726                    if (stat != 0) {
727                       berrno be;
728                       be.set_errno(stat);
729                       Qmsg2(jcr, M_ERROR, 0, _("Operator mail program terminated in error.\n"
730                             "CMD=%s\n"
731                             "ERR=%s\n"), mcmd, be.bstrerror());
732                    }
733                 }
734                 free_pool_memory(mcmd);
735                 break;
736              case MD_MAIL:
737              case MD_MAIL_ON_ERROR:
738              case MD_MAIL_ON_SUCCESS:
739                 Dmsg1(850, "MAIL for following msg: %s", msg);
740                 if (!d->fd) {
741                    POOLMEM *name = get_pool_memory(PM_MESSAGE);
742                    make_unique_mail_filename(jcr, name, d);
743                    d->fd = fopen(name, "w+b");
744                    if (!d->fd) {
745                       berrno be;
746                       d->fd = stdout;
747                       Qmsg2(jcr, M_ERROR, 0, _("fopen %s failed: ERR=%s\n"), name,
748                             be.bstrerror());
749                       d->fd = NULL;
750                       free_pool_memory(name);
751                       break;
752                    }
753                    d->mail_filename = name;
754                 }
755                 fputs(dt, d->fd);
756                 len = strlen(msg) + dtlen;;
757                 if (len > d->max_len) {
758                    d->max_len = len;      /* keep max line length */
759                 }
760                 fputs(msg, d->fd);
761                 break;
762              case MD_APPEND:
763                 Dmsg1(850, "APPEND for following msg: %s", msg);
764                 mode = "ab";
765                 goto send_to_file;
766              case MD_FILE:
767                 Dmsg1(850, "FILE for following msg: %s", msg);
768                 mode = "w+b";
769 send_to_file:
770                 if (!d->fd && !open_dest_file(jcr, d, mode)) {
771                    break;
772                 }
773                 fputs(dt, d->fd);
774                 fputs(msg, d->fd);
775                 /* On error, we close and reopen to handle log rotation */
776                 if (ferror(d->fd)) {
777                    fclose(d->fd);
778                    d->fd = NULL;
779                    if (open_dest_file(jcr, d, mode)) {
780                       fputs(dt, d->fd);
781                       fputs(msg, d->fd);
782                    }
783                 }
784                 break;
785              case MD_DIRECTOR:
786                 Dmsg1(850, "DIRECTOR for following msg: %s", msg);
787                 if (jcr && jcr->dir_bsock && !jcr->dir_bsock->errors) {
788                    jcr->dir_bsock->fsend("Jmsg Job=%s type=%d level=%lld %s",
789                       jcr->Job, type, mtime, msg);
790                 } else {
791                    Dmsg1(800, "no jcr for following msg: %s", msg);
792                 }
793                 break;
794              case MD_STDOUT:
795                 Dmsg1(850, "STDOUT for following msg: %s", msg);
796                 if (type != M_ABORT && type != M_ERROR_TERM) { /* already printed */
797                    fputs(dt, stdout);
798                    fputs(msg, stdout);
799                    fflush(stdout);
800                 }
801                 break;
802              case MD_STDERR:
803                 Dmsg1(850, "STDERR for following msg: %s", msg);
804                 fputs(dt, stderr);
805                 fputs(msg, stderr);
806                 fflush(stdout);
807                 break;
808              default:
809                 break;
810           }
811        }
812     }
813 }
814
815 /*********************************************************************
816  *
817  *  This subroutine returns the filename portion of a Windows 
818  *  path.  It is used because Microsoft Visual Studio sets __FILE__ 
819  *  to the full path.
820  */
821
822 inline const char *
823 get_basename(const char *pathname)
824 {
825 #if defined(_MSC_VER)
826    const char *basename;
827    
828    if ((basename = strrchr(pathname, '\\')) == NULL) {
829       basename = pathname;
830    } else {
831       basename++;
832    }
833
834    return basename;
835 #else
836    return pathname;
837 #endif
838 }
839
840 /*********************************************************************
841  *
842  *  This subroutine prints a debug message if the level number
843  *  is less than or equal the debug_level. File and line numbers
844  *  are included for more detail if desired, but not currently
845  *  printed.
846  *
847  *  If the level is negative, the details of file and line number
848  *  are not printed.
849  */
850 void
851 d_msg(const char *file, int line, int level, const char *fmt,...)
852 {
853     char      buf[5000];
854     int       len;
855     va_list   arg_ptr;
856     bool      details = true;
857     utime_t   mtime;
858
859     if (level < 0) {
860        details = false;
861        level = -level;
862     }
863
864     if (level <= debug_level) {
865        if (dbg_timestamp) {
866           mtime = time(NULL);
867           bstrftimes(buf, sizeof(buf), mtime);
868           len = strlen(buf);
869           buf[len++] = ' ';
870           buf[len] = 0;
871           fputs(buf, stdout);
872        }
873     
874 #ifdef FULL_LOCATION
875        if (details) {
876           len = bsnprintf(buf, sizeof(buf), "%s: %s:%d-%u ", 
877                 my_name, get_basename(file), line, get_jobid_from_tsd());
878        } else {
879           len = 0;
880        }
881 #else
882        len = 0;
883 #endif
884        va_start(arg_ptr, fmt);
885        bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
886        va_end(arg_ptr);
887
888        /*
889         * Used the "trace on" command in the console to turn on
890         *  output to the trace file.  "trace off" will close the file.
891         */
892        if (trace) {
893           if (!trace_fd) {
894              char fn[200];
895              bsnprintf(fn, sizeof(fn), "%s/%s.trace", working_directory ? working_directory : "./", my_name);
896              trace_fd = fopen(fn, "a+b");
897           }
898           if (trace_fd) {
899              fputs(buf, trace_fd);
900              fflush(trace_fd);
901           } else {
902              /* Some problem, turn off tracing */
903              trace = false;
904           }
905        } else {   /* not tracing */
906           fputs(buf, stdout);
907           fflush(stdout);
908        }
909     }
910 }
911
912 /*
913  * Set trace flag on/off. If argument is negative, there is no change
914  */
915 void set_trace(int trace_flag)
916 {
917    if (trace_flag < 0) {
918       return;
919    } else if (trace_flag > 0) {
920       trace = true;
921    } else {
922       trace = false;
923    }
924    if (!trace && trace_fd) {
925       FILE *ltrace_fd = trace_fd;
926       trace_fd = NULL;
927       bmicrosleep(0, 100000);         /* yield to prevent seg faults */
928       fclose(ltrace_fd);
929    }
930 }
931
932 bool get_trace(void)
933 {
934    return trace;
935 }
936
937 /*********************************************************************
938  *
939  *  This subroutine prints a message regardless of the debug level
940  *
941  *  If the level is negative, the details of file and line number
942  *  are not printed.
943  */
944 void
945 p_msg(const char *file, int line, int level, const char *fmt,...)
946 {
947     char      buf[5000];
948     int       len;
949     va_list   arg_ptr;
950
951 #ifdef FULL_LOCATION
952     if (level >= 0) {
953        len = bsnprintf(buf, sizeof(buf), "%s: %s:%d ", my_name, get_basename(file), line);
954     } else {
955        len = 0;
956     }
957 #else
958     len = 0;
959 #endif
960     va_start(arg_ptr, fmt);
961     bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
962     va_end(arg_ptr);
963     fputs(buf, stdout);
964     fflush(stdout);
965 }
966
967
968 /*********************************************************************
969  *
970  *  subroutine writes a debug message to the trace file if the level number
971  *  is less than or equal the debug_level. File and line numbers
972  *  are included for more detail if desired, but not currently
973  *  printed.
974  *
975  *  If the level is negative, the details of file and line number
976  *  are not printed.
977  */
978 void
979 t_msg(const char *file, int line, int level, const char *fmt,...)
980 {
981     char      buf[5000];
982     int       len;
983     va_list   arg_ptr;
984     int       details = TRUE;
985
986     if (level < 0) {
987        details = FALSE;
988        level = -level;
989     }
990
991     if (level <= debug_level) {
992        if (!trace_fd) {
993           bsnprintf(buf, sizeof(buf), "%s/%s.trace", working_directory ? working_directory : ".", my_name);
994           trace_fd = fopen(buf, "a+b");
995        }
996
997 #ifdef FULL_LOCATION
998        if (details) {
999           len = bsnprintf(buf, sizeof(buf), "%s: %s:%d ", my_name, get_basename(file), line);
1000        } else {
1001           len = 0;
1002        }
1003 #else
1004        len = 0;
1005 #endif
1006        va_start(arg_ptr, fmt);
1007        bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
1008        va_end(arg_ptr);
1009        if (trace_fd != NULL) {
1010            fputs(buf, trace_fd);
1011            fflush(trace_fd);
1012        }
1013    }
1014 }
1015
1016 /* *********************************************************
1017  *
1018  * print an error message
1019  *
1020  */
1021 void
1022 e_msg(const char *file, int line, int type, int level, const char *fmt,...)
1023 {
1024     char     buf[5000];
1025     va_list   arg_ptr;
1026     int len;
1027
1028     /*
1029      * Check if we have a message destination defined.
1030      * We always report M_ABORT and M_ERROR_TERM
1031      */
1032     if (!daemon_msgs || ((type != M_ABORT && type != M_ERROR_TERM) &&
1033                          !bit_is_set(type, daemon_msgs->send_msg))) {
1034        return;                        /* no destination */
1035     }
1036     switch (type) {
1037     case M_ABORT:
1038        len = bsnprintf(buf, sizeof(buf), _("%s: ABORTING due to ERROR in %s:%d\n"),
1039                my_name, get_basename(file), line);
1040        break;
1041     case M_ERROR_TERM:
1042        len = bsnprintf(buf, sizeof(buf), _("%s: ERROR TERMINATION at %s:%d\n"),
1043                my_name, get_basename(file), line);
1044        break;
1045     case M_FATAL:
1046        if (level == -1)            /* skip details */
1047           len = bsnprintf(buf, sizeof(buf), _("%s: Fatal Error because: "), my_name);
1048        else
1049           len = bsnprintf(buf, sizeof(buf), _("%s: Fatal Error at %s:%d because:\n"), my_name, get_basename(file), line);
1050        break;
1051     case M_ERROR:
1052        if (level == -1)            /* skip details */
1053           len = bsnprintf(buf, sizeof(buf), _("%s: ERROR: "), my_name);
1054        else
1055           len = bsnprintf(buf, sizeof(buf), _("%s: ERROR in %s:%d "), my_name, get_basename(file), line);
1056        break;
1057     case M_WARNING:
1058        len = bsnprintf(buf, sizeof(buf), _("%s: Warning: "), my_name);
1059        break;
1060     case M_SECURITY:
1061        len = bsnprintf(buf, sizeof(buf), _("%s: Security violation: "), my_name);
1062        break;
1063     default:
1064        len = bsnprintf(buf, sizeof(buf), "%s: ", my_name);
1065        break;
1066     }
1067
1068     va_start(arg_ptr, fmt);
1069     bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
1070     va_end(arg_ptr);
1071
1072     dispatch_message(NULL, type, 0, buf);
1073
1074     if (type == M_ABORT) {
1075        char *p = 0;
1076        p[0] = 0;                      /* generate segmentation violation */
1077     }
1078     if (type == M_ERROR_TERM) {
1079        exit(1);
1080     }
1081 }
1082
1083 /* *********************************************************
1084  *
1085  * Generate a Job message
1086  *
1087  */
1088 void
1089 Jmsg(JCR *jcr, int type, utime_t mtime, const char *fmt,...)
1090 {
1091     char     rbuf[5000];
1092     va_list   arg_ptr;
1093     int len;
1094     MSGS *msgs;
1095     uint32_t JobId = 0;
1096
1097
1098     Dmsg1(850, "Enter Jmsg type=%d\n", type);
1099
1100     /* Special case for the console, which has a dir_bsock and JobId==0,
1101      *  in that case, we send the message directly back to the
1102      *  dir_bsock.
1103      */
1104     if (jcr && jcr->JobId == 0 && jcr->dir_bsock) {
1105        BSOCK *dir = jcr->dir_bsock;
1106        va_start(arg_ptr, fmt);
1107        dir->msglen = bvsnprintf(dir->msg, sizeof_pool_memory(dir->msg),
1108                                 fmt, arg_ptr);
1109        va_end(arg_ptr);
1110        jcr->dir_bsock->send();
1111        return;
1112     }
1113
1114     msgs = NULL;
1115     if (!jcr) {
1116        jcr = get_jcr_from_tsd();
1117     }
1118     if (jcr) {
1119        msgs = jcr->jcr_msgs;
1120        JobId = jcr->JobId;
1121     }
1122     if (!msgs) {
1123        msgs = daemon_msgs;            /* if no jcr, we use daemon handler */
1124     }
1125
1126     /*
1127      * Check if we have a message destination defined.
1128      * We always report M_ABORT and M_ERROR_TERM
1129      */
1130     if (msgs && (type != M_ABORT && type != M_ERROR_TERM) &&
1131          !bit_is_set(type, msgs->send_msg)) {
1132        return;                        /* no destination */
1133     }
1134     switch (type) {
1135     case M_ABORT:
1136        len = bsnprintf(rbuf, sizeof(rbuf), _("%s ABORTING due to ERROR\n"), my_name);
1137        break;
1138     case M_ERROR_TERM:
1139        len = bsnprintf(rbuf, sizeof(rbuf), _("%s ERROR TERMINATION\n"), my_name);
1140        break;
1141     case M_FATAL:
1142        len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Fatal error: "), my_name, JobId);
1143        if (jcr) {
1144           set_jcr_job_status(jcr, JS_FatalError);
1145        }
1146        break;
1147     case M_ERROR:
1148        len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Error: "), my_name, JobId);
1149        if (jcr) {
1150           jcr->JobErrors++;
1151        }
1152        break;
1153     case M_WARNING:
1154        len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Warning: "), my_name, JobId);
1155        if (jcr) {
1156           jcr->JobWarnings++;
1157        }
1158        break;
1159     case M_SECURITY:
1160        len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Security violation: "), 
1161                my_name, JobId);
1162        break;
1163     default:
1164        len = bsnprintf(rbuf, sizeof(rbuf), "%s JobId %u: ", my_name, JobId);
1165        break;
1166     }
1167
1168     va_start(arg_ptr, fmt);
1169     bvsnprintf(rbuf+len,  sizeof(rbuf)-len, fmt, arg_ptr);
1170     va_end(arg_ptr);
1171
1172     dispatch_message(jcr, type, mtime, rbuf);
1173
1174     if (type == M_ABORT){
1175        char *p = 0;
1176        printf("Bacula forced SEG FAULT to obtain traceback.\n");
1177        syslog(LOG_DAEMON|LOG_ERR, "Bacula forced SEG FAULT to obtain traceback.\n");
1178        p[0] = 0;                      /* generate segmentation violation */
1179     }
1180     if (type == M_ERROR_TERM) {
1181        exit(1);
1182     }
1183 }
1184
1185 /*
1186  * If we come here, prefix the message with the file:line-number,
1187  *  then pass it on to the normal Jmsg routine.
1188  */
1189 void j_msg(const char *file, int line, JCR *jcr, int type, utime_t mtime, const char *fmt,...)
1190 {
1191    va_list   arg_ptr;
1192    int i, len, maxlen;
1193    POOLMEM *pool_buf;
1194
1195    pool_buf = get_pool_memory(PM_EMSG);
1196    i = Mmsg(pool_buf, "%s:%d ", get_basename(file), line);
1197
1198    for (;;) {
1199       maxlen = sizeof_pool_memory(pool_buf) - i - 1;
1200       va_start(arg_ptr, fmt);
1201       len = bvsnprintf(pool_buf+i, maxlen, fmt, arg_ptr);
1202       va_end(arg_ptr);
1203       if (len < 0 || len >= (maxlen-5)) {
1204          pool_buf = realloc_pool_memory(pool_buf, maxlen + i + maxlen/2);
1205          continue;
1206       }
1207       break;
1208    }
1209
1210    Jmsg(jcr, type, mtime, "%s", pool_buf);
1211    free_memory(pool_buf);
1212 }
1213
1214
1215 /*
1216  * Edit a message into a Pool memory buffer, with file:lineno
1217  */
1218 int m_msg(const char *file, int line, POOLMEM **pool_buf, const char *fmt, ...)
1219 {
1220    va_list   arg_ptr;
1221    int i, len, maxlen;
1222
1223    i = sprintf(*pool_buf, "%s:%d ", get_basename(file), line);
1224
1225    for (;;) {
1226       maxlen = sizeof_pool_memory(*pool_buf) - i - 1;
1227       va_start(arg_ptr, fmt);
1228       len = bvsnprintf(*pool_buf+i, maxlen, fmt, arg_ptr);
1229       va_end(arg_ptr);
1230       if (len < 0 || len >= (maxlen-5)) {
1231          *pool_buf = realloc_pool_memory(*pool_buf, maxlen + i + maxlen/2);
1232          continue;
1233       }
1234       break;
1235    }
1236    return len;
1237 }
1238
1239 int m_msg(const char *file, int line, POOLMEM *&pool_buf, const char *fmt, ...)
1240 {
1241    va_list   arg_ptr;
1242    int i, len, maxlen;
1243
1244    i = sprintf(pool_buf, "%s:%d ", get_basename(file), line);
1245
1246    for (;;) {
1247       maxlen = sizeof_pool_memory(pool_buf) - i - 1;
1248       va_start(arg_ptr, fmt);
1249       len = bvsnprintf(pool_buf+i, maxlen, fmt, arg_ptr);
1250       va_end(arg_ptr);
1251       if (len < 0 || len >= (maxlen-5)) {
1252          pool_buf = realloc_pool_memory(pool_buf, maxlen + i + maxlen/2);
1253          continue;
1254       }
1255       break;
1256    }
1257    return len;
1258 }
1259
1260
1261 /*
1262  * Edit a message into a Pool Memory buffer NO file:lineno
1263  *  Returns: string length of what was edited.
1264  */
1265 int Mmsg(POOLMEM **pool_buf, const char *fmt, ...)
1266 {
1267    va_list   arg_ptr;
1268    int len, maxlen;
1269
1270    for (;;) {
1271       maxlen = sizeof_pool_memory(*pool_buf) - 1;
1272       va_start(arg_ptr, fmt);
1273       len = bvsnprintf(*pool_buf, maxlen, fmt, arg_ptr);
1274       va_end(arg_ptr);
1275       if (len < 0 || len >= (maxlen-5)) {
1276          *pool_buf = realloc_pool_memory(*pool_buf, maxlen + maxlen/2);
1277          continue;
1278       }
1279       break;
1280    }
1281    return len;
1282 }
1283
1284 int Mmsg(POOLMEM *&pool_buf, const char *fmt, ...)
1285 {
1286    va_list   arg_ptr;
1287    int len, maxlen;
1288
1289    for (;;) {
1290       maxlen = sizeof_pool_memory(pool_buf) - 1;
1291       va_start(arg_ptr, fmt);
1292       len = bvsnprintf(pool_buf, maxlen, fmt, arg_ptr);
1293       va_end(arg_ptr);
1294       if (len < 0 || len >= (maxlen-5)) {
1295          pool_buf = realloc_pool_memory(pool_buf, maxlen + maxlen/2);
1296          continue;
1297       }
1298       break;
1299    }
1300    return len;
1301 }
1302
1303 int Mmsg(POOL_MEM &pool_buf, const char *fmt, ...)
1304 {
1305    va_list   arg_ptr;
1306    int len, maxlen;
1307
1308    for (;;) {
1309       maxlen = pool_buf.max_size() - 1;
1310       va_start(arg_ptr, fmt);
1311       len = bvsnprintf(pool_buf.c_str(), maxlen, fmt, arg_ptr);
1312       va_end(arg_ptr);
1313       if (len < 0 || len >= (maxlen-5)) {
1314          pool_buf.realloc_pm(maxlen + maxlen/2);
1315          continue;
1316       }
1317       break;
1318    }
1319    return len;
1320 }
1321
1322
1323 static pthread_mutex_t msg_queue_mutex = PTHREAD_MUTEX_INITIALIZER;
1324
1325 /*
1326  * We queue messages rather than print them directly. This
1327  *  is generally used in low level routines (msg handler, bnet)
1328  *  to prevent recursion (i.e. if you are in the middle of
1329  *  sending a message, it is a bit messy to recursively call
1330  *  yourself when the bnet packet is not reentrant).
1331  */
1332 void Qmsg(JCR *jcr, int type, utime_t mtime, const char *fmt,...)
1333 {
1334    va_list   arg_ptr;
1335    int len, maxlen;
1336    POOLMEM *pool_buf;
1337    MQUEUE_ITEM *item;
1338
1339    pool_buf = get_pool_memory(PM_EMSG);
1340
1341    for (;;) {
1342       maxlen = sizeof_pool_memory(pool_buf) - 1;
1343       va_start(arg_ptr, fmt);
1344       len = bvsnprintf(pool_buf, maxlen, fmt, arg_ptr);
1345       va_end(arg_ptr);
1346       if (len < 0 || len >= (maxlen-5)) {
1347          pool_buf = realloc_pool_memory(pool_buf, maxlen + maxlen/2);
1348          continue;
1349       }
1350       break;
1351    }
1352    item = (MQUEUE_ITEM *)malloc(sizeof(MQUEUE_ITEM) + strlen(pool_buf) + 1);
1353    item->type = type;
1354    item->mtime = time(NULL);
1355    strcpy(item->msg, pool_buf);
1356    if (!jcr) {
1357       jcr = get_jcr_from_tsd();
1358    }
1359    /* If no jcr or dequeuing send to daemon to avoid recursion */
1360    if ((jcr && !jcr->msg_queue) || !jcr || jcr->dequeuing) {
1361       /* jcr==NULL => daemon message, safe to send now */
1362       Jmsg(jcr, item->type, item->mtime, "%s", item->msg);
1363       free(item);
1364    } else {
1365       /* Queue message for later sending */
1366       P(msg_queue_mutex);
1367       jcr->msg_queue->append(item);
1368       V(msg_queue_mutex);
1369    }
1370    free_memory(pool_buf);
1371 }
1372
1373 /*
1374  * Dequeue messages
1375  */
1376 void dequeue_messages(JCR *jcr)
1377 {
1378    MQUEUE_ITEM *item;
1379    P(msg_queue_mutex);
1380    if (!jcr->msg_queue) {
1381       goto bail_out;
1382    }
1383    jcr->dequeuing = true;
1384    foreach_dlist(item, jcr->msg_queue) {
1385       Jmsg(jcr, item->type, item->mtime, "%s", item->msg);
1386    }
1387    jcr->msg_queue->destroy();
1388    jcr->dequeuing = false;
1389
1390 bail_out:
1391    V(msg_queue_mutex);
1392 }
1393
1394
1395 /*
1396  * If we come here, prefix the message with the file:line-number,
1397  *  then pass it on to the normal Qmsg routine.
1398  */
1399 void q_msg(const char *file, int line, JCR *jcr, int type, utime_t mtime, const char *fmt,...)
1400 {
1401    va_list   arg_ptr;
1402    int i, len, maxlen;
1403    POOLMEM *pool_buf;
1404
1405    pool_buf = get_pool_memory(PM_EMSG);
1406    i = Mmsg(pool_buf, "%s:%d ", file, line);
1407
1408    for (;;) {
1409       maxlen = sizeof_pool_memory(pool_buf) - i - 1;
1410       va_start(arg_ptr, fmt);
1411       len = bvsnprintf(pool_buf+i, maxlen, fmt, arg_ptr);
1412       va_end(arg_ptr);
1413       if (len < 0 || len >= (maxlen-5)) {
1414          pool_buf = realloc_pool_memory(pool_buf, maxlen + i + maxlen/2);
1415          continue;
1416       }
1417       break;
1418    }
1419
1420    Qmsg(jcr, type, mtime, "%s", pool_buf);
1421    free_memory(pool_buf);
1422 }