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