2 Bacula(R) - The Network Backup Solution
4 Copyright (C) 2000-2017 Kern Sibbald
6 The original author of Bacula is Kern Sibbald, with contributions
7 from many others, a complete list can be found in the file AUTHORS.
9 You may use this file and others of this release according to the
10 license defined in the LICENSE file, which includes the Affero General
11 Public License, v3.0 ("AGPLv3") and some additional permissions and
12 terms pursuant to its AGPLv3 Section 7.
14 This notice must be preserved when any source code is
15 conveyed and/or propagated.
17 Bacula(R) is a registered trademark of Kern Sibbald.
20 * Bacula message handling routines
22 * NOTE: don't use any Jmsg or Qmsg calls within this file,
23 * except in q_msg or j_msg (setup routines),
24 * otherwise you may get into recursive calls if there are
25 * errors, and that can lead to looping or deadlocks.
27 * Kern Sibbald, April 2000
34 sql_query_call p_sql_query = NULL;
35 sql_escape_call p_sql_escape = NULL;
37 #define FULL_LOCATION 1 /* set for file:line in Debug messages */
40 * This is where we define "Globals" because all the
41 * daemons include this file.
43 dlist *daemon_msg_queue = NULL;
44 pthread_mutex_t daemon_msg_queue_mutex = PTHREAD_MUTEX_INITIALIZER;
45 static bool dequeuing_daemon_msgs = false;
46 const char *working_directory = NULL; /* working directory path stored here */
47 const char *assert_msg = NULL; /* ASSERT2 error message */
48 const char *version = VERSION " (" BDATE ")";
49 const char *dist_name = DISTNAME " " DISTVER;
50 char *exepath = (char *)NULL;
51 char *exename = (char *)NULL;
52 char db_engine_name[50] = {0}; /* Database engine name or type */
53 char con_fname[500]; /* Console filename */
54 char my_name[MAX_NAME_LENGTH] = {0}; /* daemon name is stored here */
55 char host_name[50] = {0}; /* host machine name */
56 char fail_time[30] = {0}; /* Time of failure */
57 int verbose = 0; /* increase User messages */
58 int64_t debug_level = 0; /* debug level */
59 int64_t debug_level_tags = 0; /* debug tags */
60 int32_t debug_flags = 0; /* debug flags */
61 int console_msg_pending = false;
62 utime_t daemon_start_time = 0; /* Daemon start time */
63 FILE *con_fd = NULL; /* Console file descriptor */
64 brwlock_t con_lock; /* Console lock structure */
65 bool dbg_timestamp = false; /* print timestamp in debug output */
66 bool dbg_thread = false; /* add thread_id to details */
67 bool prt_kaboom = false; /* Print kaboom output */
68 job_code_callback_t message_job_code_callback = NULL; /* Job code callback. Only used by director. */
70 /* Forward referenced functions */
72 /* Imported functions */
73 void create_jcr_key();
77 /* Exclude spaces but require .mail at end */
78 #define MAIL_REGEX "^[^ ]+\\.mail$"
80 /* Allow only one thread to tweak d->fd at a time */
81 static pthread_mutex_t fides_mutex = PTHREAD_MUTEX_INITIALIZER;
82 static MSGS *daemon_msgs; /* global messages */
83 static void (*message_callback)(int type, char *msg) = NULL;
84 static FILE *trace_fd = NULL;
85 #if defined(HAVE_WIN32)
86 static bool trace = true;
88 static bool trace = false;
90 static int hangup = 0;
91 static int blowup = 0;
94 const char *host_os = HOST_OS;
95 const char *distname = DISTNAME;
96 const char *distver = DISTVER;
99 * Walk back in a string from end looking for a
101 * This routine is passed the start of the string and
102 * the end of the string, it returns either the beginning
103 * of the string or where it found a path separator.
105 static const char *bstrrpath(const char *start, const char *end)
107 while ( end > start ) {
109 if (IsPathSeparator(*end)) {
116 /* Some message class methods */
128 * Wait for not in use variable to be clear
130 void MSGS::wait_not_in_use() /* leaves fides_mutex set */
133 while (m_in_use || m_closing) {
135 bmicrosleep(0, 200); /* wait */
141 * Handle message delivery errors
143 static void delivery_error(const char *fmt,...)
148 char dt[MAX_TIME_LENGTH];
151 pool_buf = get_pool_memory(PM_EMSG);
153 bstrftime_ny(dt, sizeof(dt), time(NULL));
158 i = Mmsg(pool_buf, "%s Message delivery ERROR: ", dt);
161 maxlen = sizeof_pool_memory(pool_buf) - i - 1;
162 va_start(arg_ptr, fmt);
163 len = bvsnprintf(pool_buf+i, maxlen, fmt, arg_ptr);
165 if (len < 0 || len >= (maxlen-5)) {
166 pool_buf = realloc_pool_memory(pool_buf, maxlen + i + maxlen/2);
172 fputs(pool_buf, stdout); /* print this here to INSURE that it is printed */
174 syslog(LOG_DAEMON|LOG_ERR, "%s", pool_buf);
175 free_memory(pool_buf);
178 void set_debug_flags(char *options)
180 for (char *p = options; *p ; p++) {
182 case '0': /* clear flags */
186 case 'i': /* used by FD */
187 case 'd': /* used by FD */
191 dbg_timestamp = true;
195 dbg_timestamp = false;
207 /* truncate the trace file */
208 if (trace && trace_fd) {
209 ftruncate(fileno(trace_fd), 0);
214 /* Turn on/off add_events for P()/V() */
215 debug_flags |= DEBUG_MUTEX_EVENT;
219 /* Display event stack during lockdump */
220 debug_flags |= DEBUG_PRINT_EVENT;
224 Dmsg1(000, "Unknown debug flag %c\n", *p);
229 void register_message_callback(void msg_callback(int type, char *msg))
231 message_callback = msg_callback;
236 * Set daemon name. Also, find canonical execution
237 * path. Note, exepath has spare room for tacking on
238 * the exename so that we can reconstruct the full name.
240 * Note, this routine can get called multiple times
241 * The second time is to put the name as found in the
242 * Resource record. On the second call, generally,
243 * argv is NULL to avoid doing the path code twice.
245 void my_name_is(int argc, char *argv[], const char *name)
251 if (gethostname(host_name, sizeof(host_name)) != 0) {
252 bstrncpy(host_name, "Hostname unknown", sizeof(host_name));
254 bstrncpy(my_name, name, sizeof(my_name));
255 if (argc>0 && argv && argv[0]) {
256 /* strip trailing filename and save exepath */
257 for (l=p=argv[0]; *p; p++) {
258 if (IsPathSeparator(*p)) {
259 l = p; /* set pos of last slash */
262 if (IsPathSeparator(*l)) {
266 #if defined(HAVE_WIN32)
267 /* On Windows allow c: drive specification */
277 exename = (char *)malloc(len);
283 exepath = (char *)malloc(strlen(argv[0]) + 1 + len);
284 for (p=argv[0],q=exepath; p < l; ) {
288 if (strchr(exepath, '.') || !IsPathSeparator(exepath[0])) {
289 if (getcwd(cpath, sizeof(cpath))) {
291 exepath = (char *)malloc(strlen(cpath) + 1 + len);
292 strcpy(exepath, cpath);
295 Dmsg2(500, "exepath=%s\nexename=%s\n", exepath, exename);
299 /* Set special ASSERT2 message where debugger can find it */
301 set_assert_msg(const char *file, int line, const char *msg)
304 bsnprintf(buf, sizeof(buf), "ASSERT at %s:%d-%u ERR=%s",
305 get_basename(file), line, get_jobid_from_tsd(), msg);
306 assert_msg = bstrdup(buf);
309 void set_db_engine_name(const char *name)
311 bstrncpy(db_engine_name, name, sizeof(db_engine_name)-1);
315 * Initialize message handler for a daemon or a Job
316 * We make a copy of the MSGS resource passed, so it belows
317 * to the job or daemon and thus can be modified.
319 * NULL for jcr -> initialize global messages for daemon
320 * non-NULL -> initialize jcr using Message resource
323 init_msg(JCR *jcr, MSGS *msg, job_code_callback_t job_code_callback)
325 DEST *d, *dnew, *temp_chain = NULL;
328 if (jcr == NULL && msg == NULL) {
329 init_last_jobs_list();
330 /* Create a daemon key then set invalid jcr */
331 /* Maybe we should give the daemon a jcr??? */
333 set_jcr_in_tsd(INVALID_JCR);
336 message_job_code_callback = job_code_callback;
338 #if !defined(HAVE_WIN32)
340 * Make sure we have fd's 0, 1, 2 open
341 * If we don't do this one of our sockets may open
342 * there and if we then use stdout, it could
343 * send total garbage to our socket.
347 fd = open("/dev/null", O_RDONLY, 0644);
351 for(i=1; fd + i <= 2; i++) {
358 * If msg is NULL, initialize global chain for STDOUT and syslog
361 daemon_msgs = (MSGS *)malloc(sizeof(MSGS));
362 memset(daemon_msgs, 0, sizeof(MSGS));
363 for (i=1; i<=M_MAX; i++) {
364 add_msg_dest(daemon_msgs, MD_STDOUT, i, NULL, NULL);
366 Dmsg1(050, "Create daemon global message resource %p\n", daemon_msgs);
371 * Walk down the message resource chain duplicating it
372 * for the current Job.
374 for (d=msg->dest_chain; d; d=d->next) {
375 dnew = (DEST *)malloc(sizeof(DEST));
376 memcpy(dnew, d, sizeof(DEST));
377 dnew->next = temp_chain;
379 dnew->mail_filename = NULL;
381 dnew->mail_cmd = bstrdup(d->mail_cmd);
384 dnew->where = bstrdup(d->where);
390 jcr->jcr_msgs = (MSGS *)malloc(sizeof(MSGS));
391 memset(jcr->jcr_msgs, 0, sizeof(MSGS));
392 jcr->jcr_msgs->dest_chain = temp_chain;
393 memcpy(jcr->jcr_msgs->send_msg, msg->send_msg, sizeof(msg->send_msg));
395 /* If we have default values, release them now */
397 free_msgs_res(daemon_msgs);
399 daemon_msgs = (MSGS *)malloc(sizeof(MSGS));
400 memset(daemon_msgs, 0, sizeof(MSGS));
401 daemon_msgs->dest_chain = temp_chain;
402 memcpy(daemon_msgs->send_msg, msg->send_msg, sizeof(msg->send_msg));
405 Dmsg2(250, "Copy message resource %p to %p\n", msg, temp_chain);
408 /* Initialize so that the console (User Agent) can
409 * receive messages -- stored in a file.
411 void init_console_msg(const char *wd)
415 bsnprintf(con_fname, sizeof(con_fname), "%s%c%s.conmsg", wd, PathSeparator, my_name);
416 fd = open(con_fname, O_CREAT|O_RDWR|O_BINARY, 0600);
419 Emsg2(M_ERROR_TERM, 0, _("Could not open console message file %s: ERR=%s\n"),
420 con_fname, be.bstrerror());
422 if (lseek(fd, 0, SEEK_END) > 0) {
423 console_msg_pending = 1;
426 con_fd = bfopen(con_fname, "a+b");
429 Emsg2(M_ERROR, 0, _("Could not open console message file %s: ERR=%s\n"),
430 con_fname, be.bstrerror());
432 if (rwl_init(&con_lock) != 0) {
434 Emsg1(M_ERROR_TERM, 0, _("Could not get con mutex: ERR=%s\n"),
440 * Called only during parsing of the config file.
442 * Add a message destination. I.e. associate a message type with
443 * a destination (code).
444 * Note, where in the case of dest_code FILE is a filename,
445 * but in the case of MAIL is a space separated list of
446 * email addresses, ...
448 void add_msg_dest(MSGS *msg, int dest_code, int msg_type, char *where, char *mail_cmd)
452 * First search the existing chain and see if we
453 * can simply add this msg_type to an existing entry.
455 for (d=msg->dest_chain; d; d=d->next) {
456 if (dest_code == d->dest_code && ((where == NULL && d->where == NULL) ||
457 (strcmp(where, d->where) == 0))) {
458 Dmsg4(850, "Add to existing d=%p msgtype=%d destcode=%d where=%s\n",
459 d, msg_type, dest_code, NPRT(where));
460 set_bit(msg_type, d->msg_types);
461 set_bit(msg_type, msg->send_msg); /* set msg_type bit in our local */
465 /* Not found, create a new entry */
466 d = (DEST *)malloc(sizeof(DEST));
467 memset(d, 0, sizeof(DEST));
468 d->next = msg->dest_chain;
469 d->dest_code = dest_code;
470 set_bit(msg_type, d->msg_types); /* set type bit in structure */
471 set_bit(msg_type, msg->send_msg); /* set type bit in our local */
473 d->where = bstrdup(where);
476 d->mail_cmd = bstrdup(mail_cmd);
478 Dmsg5(850, "add new d=%p msgtype=%d destcode=%d where=%s mailcmd=%s\n",
479 d, msg_type, dest_code, NPRT(where), NPRT(d->mail_cmd));
484 * Called only during parsing of the config file.
486 * Remove a message destination
488 void rem_msg_dest(MSGS *msg, int dest_code, int msg_type, char *where)
492 for (d=msg->dest_chain; d; d=d->next) {
493 Dmsg2(850, "Remove_msg_dest d=%p where=%s\n", d, NPRT(d->where));
494 if (bit_is_set(msg_type, d->msg_types) && (dest_code == d->dest_code) &&
495 ((where == NULL && d->where == NULL) ||
496 (strcmp(where, d->where) == 0))) {
497 Dmsg3(850, "Found for remove d=%p msgtype=%d destcode=%d\n",
498 d, msg_type, dest_code);
499 clear_bit(msg_type, d->msg_types);
500 Dmsg0(850, "Return rem_msg_dest\n");
508 * Create a unique filename for the mail command
510 static void make_unique_mail_filename(JCR *jcr, POOLMEM *&name, DEST *d)
513 Mmsg(name, "%s/%s.%s.%d.mail", working_directory, my_name,
514 jcr->Job, (int)(intptr_t)d);
516 Mmsg(name, "%s/%s.%s.%d.mail", working_directory, my_name,
517 my_name, (int)(intptr_t)d);
519 Dmsg1(850, "mailname=%s\n", name);
525 static BPIPE *open_mail_pipe(JCR *jcr, POOLMEM *&cmd, DEST *d)
530 cmd = edit_job_codes(jcr, cmd, d->mail_cmd, d->where, message_job_code_callback);
532 Mmsg(cmd, "/usr/lib/sendmail -F Bacula %s", d->where);
536 if ((bpipe = open_bpipe(cmd, 120, "rw"))) {
537 /* If we had to use sendmail, add subject */
539 fprintf(bpipe->wfd, "Subject: %s\r\n\r\n", _("Bacula Message"));
543 delivery_error(_("open mail pipe %s failed: ERR=%s\n"),
544 cmd, be.bstrerror());
550 * Close the messages for this Messages resource, which means to close
551 * any open files, and dispatch any pending email messages.
553 void close_msg(JCR *jcr)
561 Dmsg1(580, "Close_msg jcr=%p\n", jcr);
563 if (jcr == NULL) { /* NULL -> global chain */
566 msgs = jcr->jcr_msgs;
567 jcr->jcr_msgs = NULL;
573 /* Wait for item to be not in use, then mark closing */
574 if (msgs->is_closing()) {
577 msgs->wait_not_in_use(); /* leaves fides_mutex set */
578 /* Note get_closing() does not lock because we are already locked */
579 if (msgs->get_closing()) {
586 Dmsg1(850, "===Begin close msg resource at %p\n", msgs);
587 cmd = get_pool_memory(PM_MESSAGE);
588 for (d=msgs->dest_chain; d; ) {
591 switch (d->dest_code) {
595 fclose(d->fd); /* close open file descriptor */
600 case MD_MAIL_ON_ERROR:
601 case MD_MAIL_ON_SUCCESS:
602 Dmsg0(850, "Got MD_MAIL, MD_MAIL_ON_ERROR or MD_MAIL_ON_SUCCESS\n");
606 success = jcr && (jcr->JobStatus == JS_Terminated || jcr->JobStatus == JS_Warnings);
608 if (d->dest_code == MD_MAIL_ON_ERROR && success) {
609 goto rem_temp_file; /* no mail */
610 } else if (d->dest_code == MD_MAIL_ON_SUCCESS && !success) {
611 goto rem_temp_file; /* no mail */
614 if (!(bpipe=open_mail_pipe(jcr, cmd, d))) {
615 Pmsg0(000, _("open mail pipe failed.\n"));
616 goto rem_temp_file; /* error get out */
618 Dmsg0(850, "Opened mail pipe\n");
620 line = get_memory(len);
622 while (fgets(line, len, d->fd)) {
623 fputs(line, bpipe->wfd);
625 if (!close_wpipe(bpipe)) { /* close write pipe sending mail */
627 Pmsg1(000, _("close error: ERR=%s\n"), be.bstrerror());
631 * Since we are closing all messages, before "recursing"
632 * make sure we are not closing the daemon messages, otherwise
635 if (msgs != daemon_msgs) {
636 /* read what mail prog returned -- should be nothing */
637 while (fgets(line, len, bpipe->rfd)) {
638 delivery_error(_("Mail prog: %s"), line);
642 stat = close_bpipe(bpipe);
643 if (stat != 0 && msgs != daemon_msgs) {
646 Dmsg1(850, "Calling emsg. CMD=%s\n", cmd);
647 delivery_error(_("Mail program terminated in error.\n"
649 "ERR=%s\n"), cmd, be.bstrerror());
654 /* Remove temp mail file */
659 /* Exclude spaces in mail_filename */
660 if (d->mail_filename) {
661 safer_unlink(d->mail_filename, MAIL_REGEX);
662 free_pool_memory(d->mail_filename);
663 d->mail_filename = NULL;
665 Dmsg0(850, "end mail or mail on error\n");
672 d = d->next; /* point to next buffer */
674 free_pool_memory(cmd);
675 Dmsg0(850, "Done walking message chain.\n");
680 msgs->clear_closing();
682 Dmsg0(850, "===End close msg resource\n");
686 * Free memory associated with Messages resource
688 void free_msgs_res(MSGS *msgs)
692 /* Walk down the message chain releasing allocated buffers */
693 for (d=msgs->dest_chain; d; ) {
702 old = d; /* save pointer to release */
703 d = d->next; /* point to next buffer */
704 free(old); /* free the destination item */
706 msgs->dest_chain = NULL;
707 free(msgs); /* free the head */
712 * Terminate the message handler for good.
713 * Release the global destination chain.
715 * Also, clean up a few other items (cons, exepath). Note,
716 * these really should be done elsewhere.
720 Dmsg0(850, "Enter term_msg\n");
721 close_msg(NULL); /* close global chain */
722 free_msgs_res(daemon_msgs); /* free the resources */
742 working_directory = NULL;
743 term_last_jobs_list();
746 static bool open_dest_file(JCR *jcr, DEST *d, const char *mode)
748 d->fd = bfopen(d->where, mode);
751 delivery_error(_("fopen %s failed: ERR=%s\n"), d->where, be.bstrerror());
757 /* Split the output for syslog (it converts \n to ' ' and is
758 * limited to 1024 characters per syslog message
760 static void send_to_syslog(int mode, const char *msg)
767 while (*p && ((p2 = strchr(p, '\n')) != NULL)) {
768 len = MIN((int)sizeof(buf) - 1, p2 - p + 1); /* Add 1 to keep \n */
769 strncpy(buf, p, len);
771 syslog(mode, "%s", buf);
772 p = p2+1; /* skip \n */
774 if (*p != 0) { /* no \n at the end ? */
775 syslog(mode, "%s", p);
780 * Handle sending the message to the appropriate place
782 void dispatch_message(JCR *jcr, int type, utime_t mtime, char *msg)
785 char dt[MAX_TIME_LENGTH];
791 bool created_jcr = false;
793 Dmsg2(850, "Enter dispatch_msg type=%d msg=%s", type, msg);
796 * Most messages are prefixed by a date and time. If mtime is
797 * zero, then we use the current time. If mtime is 1 (special
798 * kludge), we do not prefix the date and time. Otherwise,
799 * we assume mtime is a utime_t and use it.
807 mtime = time(NULL); /* get time for SQL log */
809 bstrftime_ny(dt, sizeof(dt), mtime);
815 /* If the program registered a callback, send it there */
816 if (message_callback) {
817 message_callback(type, msg);
821 /* For serious errors make sure message is printed or logged */
822 if (type == M_ABORT || type == M_ERROR_TERM) {
826 if (type == M_ABORT) {
827 syslog(LOG_DAEMON|LOG_ERR, "%s", msg);
832 /* Now figure out where to send the message */
835 jcr = get_jcr_from_tsd();
838 jcr = new_jcr(sizeof(JCR), NULL);
842 msgs = jcr->jcr_msgs;
848 * If closing this message resource, print and send to syslog,
851 if (msgs->is_closing()) {
855 syslog(LOG_DAEMON|LOG_ERR, "%s", msg);
860 for (d=msgs->dest_chain; d; d=d->next) {
861 if (bit_is_set(type, d->msg_types)) {
863 switch (d->dest_code) {
866 if (!jcr || !jcr->db) {
869 if (p_sql_query && p_sql_escape) {
870 POOLMEM *cmd = get_pool_memory(PM_MESSAGE);
871 POOLMEM *esc_msg = get_pool_memory(PM_MESSAGE);
873 int len = strlen(msg) + 1;
874 esc_msg = check_pool_memory_size(esc_msg, len*2+1);
875 ok = p_sql_escape(jcr, jcr->db, esc_msg, msg, len);
877 bstrutime(dt, sizeof(dt), mtime);
878 Mmsg(cmd, "INSERT INTO Log (JobId, Time, LogText) VALUES (%s,'%s','%s')",
879 edit_int64(jcr->JobId, ed1), dt, esc_msg);
880 ok = p_sql_query(jcr, cmd);
883 delivery_error(_("Message delivery error: Unable to store data in database.\n"));
885 free_pool_memory(cmd);
886 free_pool_memory(esc_msg);
890 Dmsg1(850, "CONSOLE for following msg: %s", msg);
892 con_fd = bfopen(con_fname, "a+b");
893 Dmsg0(850, "Console file not open.\n");
896 Pw(con_lock); /* get write lock on console message file */
899 (void)fwrite(dt, dtlen, 1, con_fd);
903 (void)fwrite(msg, len, 1, con_fd);
904 if (msg[len-1] != '\n') {
905 (void)fwrite("\n", 2, 1, con_fd);
908 (void)fwrite("\n", 2, 1, con_fd);
911 console_msg_pending = true;
916 Dmsg1(850, "SYSLOG for following msg: %s\n", msg);
918 * We really should do an openlog() here.
920 send_to_syslog(LOG_DAEMON|LOG_ERR, msg);
923 Dmsg1(850, "OPERATOR for following msg: %s\n", msg);
924 mcmd = get_pool_memory(PM_MESSAGE);
925 if ((bpipe=open_mail_pipe(jcr, mcmd, d))) {
927 fputs(dt, bpipe->wfd);
928 fputs(msg, bpipe->wfd);
929 /* Messages to the operator go one at a time */
930 stat = close_bpipe(bpipe);
934 delivery_error(_("Msg delivery error: Operator mail program terminated in error.\n"
936 "ERR=%s\n"), mcmd, be.bstrerror());
939 free_pool_memory(mcmd);
942 case MD_MAIL_ON_ERROR:
943 case MD_MAIL_ON_SUCCESS:
944 Dmsg1(850, "MAIL for following msg: %s", msg);
945 if (msgs->is_closing()) {
950 POOLMEM *name = get_pool_memory(PM_MESSAGE);
951 make_unique_mail_filename(jcr, name, d);
952 d->fd = bfopen(name, "w+b");
955 delivery_error(_("Msg delivery error: fopen %s failed: ERR=%s\n"), name,
957 free_pool_memory(name);
958 msgs->clear_in_use();
961 d->mail_filename = name;
964 len = strlen(msg) + dtlen;;
965 if (len > d->max_len) {
966 d->max_len = len; /* keep max line length */
969 msgs->clear_in_use();
972 Dmsg1(850, "APPEND for following msg: %s", msg);
976 Dmsg1(850, "FILE for following msg: %s", msg);
979 if (msgs->is_closing()) {
983 if (!d->fd && !open_dest_file(jcr, d, mode)) {
984 msgs->clear_in_use();
989 /* On error, we close and reopen to handle log rotation */
993 if (open_dest_file(jcr, d, mode)) {
998 msgs->clear_in_use();
1001 Dmsg1(850, "DIRECTOR for following msg: %s", msg);
1002 if (jcr && jcr->dir_bsock && !jcr->dir_bsock->errors) {
1003 jcr->dir_bsock->fsend("Jmsg JobId=%ld type=%d level=%lld %s",
1004 jcr->JobId, type, mtime, msg);
1006 Dmsg1(800, "no jcr for following msg: %s", msg);
1010 Dmsg1(850, "STDOUT for following msg: %s", msg);
1011 if (type != M_ABORT && type != M_ERROR_TERM) { /* already printed */
1018 Dmsg1(850, "STDERR for following msg: %s", msg);
1033 /*********************************************************************
1035 * This subroutine returns the filename portion of a path.
1036 * It is used because some compilers set __FILE__
1037 * to the full path. Try to return base + next higher path.
1040 const char *get_basename(const char *pathname)
1042 const char *basename;
1044 if ((basename = bstrrpath(pathname, pathname+strlen(pathname))) == pathname) {
1046 } else if ((basename = bstrrpath(pathname, basename-1)) == pathname) {
1055 * print or write output to trace file
1057 static void pt_out(char *buf)
1060 * Used the "trace on" command in the console to turn on
1061 * output to the trace file. "trace off" will close the file.
1066 bsnprintf(fn, sizeof(fn), "%s/%s.trace", working_directory ? working_directory : "./", my_name);
1067 trace_fd = bfopen(fn, "a+b");
1070 fputs(buf, trace_fd);
1074 /* Some problem, turn off tracing */
1083 /*********************************************************************
1085 * This subroutine prints a debug message if the level number
1086 * is less than or equal the debug_level. File and line numbers
1087 * are included for more detail if desired, but not currently
1090 * If the level is negative, the details of file and line number
1095 vd_msg(const char *file, int line, int64_t level, const char *fmt, va_list arg_ptr)
1098 int len = 0; /* space used in buf */
1099 bool details = true;
1107 if (chk_dbglvl(level)) {
1108 if (dbg_timestamp) {
1110 bstrftimes(buf+len, sizeof(buf)-len, mtime);
1115 #ifdef FULL_LOCATION
1118 len += bsnprintf(buf+len, sizeof(buf)-len, "%s[%lld]: %s:%d-%u ",
1119 my_name, bthread_get_thread_id(),
1120 get_basename(file), line, get_jobid_from_tsd());
1122 len += bsnprintf(buf+len, sizeof(buf)-len, "%s: %s:%d-%u ",
1123 my_name, get_basename(file), line, get_jobid_from_tsd());
1127 bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
1134 d_msg(const char *file, int line, int64_t level, const char *fmt,...)
1137 va_start(arg_ptr, fmt);
1138 vd_msg(file, line, level, fmt, arg_ptr); /* without tags */
1144 * Set trace flag on/off. If argument is negative, there is no change
1146 void set_trace(int trace_flag)
1148 if (trace_flag < 0) {
1150 } else if (trace_flag > 0) {
1155 if (!trace && trace_fd) {
1156 FILE *ltrace_fd = trace_fd;
1158 bmicrosleep(0, 100000); /* yield to prevent seg faults */
1163 void set_hangup(int hangup_value)
1165 if (hangup_value != -1) {
1166 hangup = hangup_value;
1170 int get_hangup(void)
1175 void set_blowup(int blowup_value)
1177 if (blowup_value != -1) {
1178 blowup = blowup_value;
1182 int get_blowup(void)
1187 bool handle_hangup_blowup(JCR *jcr, uint32_t file_count, uint64_t byte_count)
1189 if (hangup == 0 && blowup == 0) {
1193 /* Debug code: check if we must hangup or blowup */
1194 if ((hangup > 0 && (file_count > (uint32_t)hangup)) ||
1195 (hangup < 0 && (byte_count/1024 > (uint32_t)-hangup))) {
1196 jcr->setJobStatus(JS_Incomplete);
1198 Jmsg1(jcr, M_FATAL, 0, "Debug hangup requested after %d files.\n", hangup);
1200 Jmsg1(jcr, M_FATAL, 0, "Debug hangup requested after %d Kbytes.\n", -hangup);
1205 if ((blowup > 0 && (file_count > (uint32_t)blowup)) ||
1206 (blowup < 0 && (byte_count/1024 > (uint32_t)-blowup))) {
1208 Jmsg1(jcr, M_ABORT, 0, "Debug blowup requested after %d files.\n", blowup);
1210 Jmsg1(jcr, M_ABORT, 0, "Debug blowup requested after %d Kbytes.\n", -blowup);
1212 /* will never reach this line */
1218 bool get_trace(void)
1223 /*********************************************************************
1225 * This subroutine prints a message regardless of the debug level
1227 * If the level is negative, the details of file and line number
1231 p_msg(const char *file, int line, int level, const char *fmt,...)
1234 int len = 0; /* space used in buf */
1237 if (dbg_timestamp) {
1238 utime_t mtime = time(NULL);
1239 bstrftimes(buf+len, sizeof(buf)-len, mtime);
1244 #ifdef FULL_LOCATION
1246 len += bsnprintf(buf+len, sizeof(buf)-len, "%s: %s:%d-%u ",
1247 my_name, get_basename(file), line, get_jobid_from_tsd());
1251 va_start(arg_ptr, fmt);
1252 bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
1259 /*********************************************************************
1261 * subroutine writes a debug message to the trace file if the level number
1262 * is less than or equal the debug_level. File and line numbers
1263 * are included for more detail if desired, but not currently
1266 * If the level is negative, the details of file and line number
1270 t_msg(const char *file, int line, int64_t level, const char *fmt,...)
1277 level = level & ~DT_ALL; /* level should be tag free */
1284 if (level <= debug_level) {
1286 bsnprintf(buf, sizeof(buf), "%s/%s.trace", working_directory ? working_directory : ".", my_name);
1287 trace_fd = bfopen(buf, "a+b");
1290 #ifdef FULL_LOCATION
1292 len = bsnprintf(buf, sizeof(buf), "%s: %s:%d ", my_name, get_basename(file), line);
1299 va_start(arg_ptr, fmt);
1300 bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
1302 if (trace_fd != NULL) {
1303 fputs(buf, trace_fd);
1309 /* *********************************************************
1311 * print an error message
1315 e_msg(const char *file, int line, int type, int level, const char *fmt,...)
1322 * Check if we have a message destination defined.
1323 * We always report M_ABORT and M_ERROR_TERM
1325 if (!daemon_msgs || ((type != M_ABORT && type != M_ERROR_TERM) &&
1326 !bit_is_set(type, daemon_msgs->send_msg))) {
1327 return; /* no destination */
1331 len = bsnprintf(buf, sizeof(buf), _("%s: ABORTING due to ERROR in %s:%d\n"),
1332 my_name, get_basename(file), line);
1335 len = bsnprintf(buf, sizeof(buf), _("%s: ERROR TERMINATION at %s:%d\n"),
1336 my_name, get_basename(file), line);
1339 if (level == -1) /* skip details */
1340 len = bsnprintf(buf, sizeof(buf), _("%s: Fatal Error because: "), my_name);
1342 len = bsnprintf(buf, sizeof(buf), _("%s: Fatal Error at %s:%d because:\n"), my_name, get_basename(file), line);
1345 if (level == -1) /* skip details */
1346 len = bsnprintf(buf, sizeof(buf), _("%s: ERROR: "), my_name);
1348 len = bsnprintf(buf, sizeof(buf), _("%s: ERROR in %s:%d "), my_name, get_basename(file), line);
1351 len = bsnprintf(buf, sizeof(buf), _("%s: Warning: "), my_name);
1354 len = bsnprintf(buf, sizeof(buf), _("%s: Security violation: "), my_name);
1357 len = bsnprintf(buf, sizeof(buf), "%s: ", my_name);
1361 va_start(arg_ptr, fmt);
1362 bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
1366 dispatch_message(NULL, type, 0, buf);
1368 if (type == M_ABORT) {
1370 p[0] = 0; /* generate segmentation violation */
1372 if (type == M_ERROR_TERM) {
1377 /* Check in the msgs resource if a given type is defined */
1378 bool is_message_type_set(JCR *jcr, int type)
1382 msgs = jcr->jcr_msgs;
1385 msgs = daemon_msgs; /* if no jcr, we use daemon handler */
1387 if (msgs && (type != M_ABORT && type != M_ERROR_TERM) &&
1388 !bit_is_set(type, msgs->send_msg)) {
1389 return false; /* no destination */
1394 /* *********************************************************
1396 * Generate a Job message
1400 Jmsg(JCR *jcr, int type, utime_t mtime, const char *fmt,...)
1409 Dmsg1(850, "Enter Jmsg type=%d\n", type);
1411 /* Special case for the console, which has a dir_bsock and JobId==0,
1412 * in that case, we send the message directly back to the
1415 if (jcr && jcr->JobId == 0 && jcr->dir_bsock) {
1416 BSOCK *dir = jcr->dir_bsock;
1417 va_start(arg_ptr, fmt);
1418 dir->msglen = bvsnprintf(dir->msg, sizeof_pool_memory(dir->msg),
1421 jcr->dir_bsock->send();
1425 /* The watchdog thread can't use Jmsg directly, we always queued it */
1426 if (is_watchdog()) {
1427 va_start(arg_ptr, fmt);
1428 bvsnprintf(rbuf, sizeof(rbuf), fmt, arg_ptr);
1430 Qmsg(jcr, type, mtime, "%s", rbuf);
1436 jcr = get_jcr_from_tsd();
1439 if (!jcr->dequeuing_msgs) { /* Avoid recursion */
1440 /* Dequeue messages to keep the original order */
1441 dequeue_messages(jcr);
1443 msgs = jcr->jcr_msgs;
1447 msgs = daemon_msgs; /* if no jcr, we use daemon handler */
1451 * Check if we have a message destination defined.
1452 * We always report M_ABORT and M_ERROR_TERM
1454 if (msgs && (type != M_ABORT && type != M_ERROR_TERM) &&
1455 !bit_is_set(type, msgs->send_msg)) {
1456 return; /* no destination */
1460 len = bsnprintf(rbuf, sizeof(rbuf), _("%s ABORTING due to ERROR\n"), my_name);
1463 len = bsnprintf(rbuf, sizeof(rbuf), _("%s ERROR TERMINATION\n"), my_name);
1466 len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Fatal error: "), my_name, JobId);
1468 jcr->setJobStatus(JS_FatalError);
1470 if (jcr && jcr->JobErrors == 0) {
1475 len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Error: "), my_name, JobId);
1481 len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Warning: "), my_name, JobId);
1487 len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Security violation: "),
1491 len = bsnprintf(rbuf, sizeof(rbuf), "%s JobId %u: ", my_name, JobId);
1495 va_start(arg_ptr, fmt);
1496 bvsnprintf(rbuf+len, sizeof(rbuf)-len, fmt, arg_ptr);
1499 dispatch_message(jcr, type, mtime, rbuf);
1501 if (type == M_ABORT){
1503 printf("Bacula forced SEG FAULT to obtain traceback.\n");
1504 syslog(LOG_DAEMON|LOG_ERR, "Bacula forced SEG FAULT to obtain traceback.\n");
1505 p[0] = 0; /* generate segmentation violation */
1507 if (type == M_ERROR_TERM) {
1513 * If we come here, prefix the message with the file:line-number,
1514 * then pass it on to the normal Jmsg routine.
1516 void j_msg(const char *file, int line, JCR *jcr, int type, utime_t mtime, const char *fmt,...)
1522 va_start(arg_ptr, fmt);
1523 vd_msg(file, line, 0, fmt, arg_ptr);
1526 pool_buf = get_pool_memory(PM_EMSG);
1527 i = Mmsg(pool_buf, "%s:%d ", get_basename(file), line);
1530 maxlen = sizeof_pool_memory(pool_buf) - i - 1;
1531 va_start(arg_ptr, fmt);
1532 len = bvsnprintf(pool_buf+i, maxlen, fmt, arg_ptr);
1534 if (len < 0 || len >= (maxlen-5)) {
1535 pool_buf = realloc_pool_memory(pool_buf, maxlen + i + maxlen/2);
1541 Jmsg(jcr, type, mtime, "%s", pool_buf);
1542 free_memory(pool_buf);
1547 * Edit a message into a Pool memory buffer, with file:lineno
1549 int m_msg(const char *file, int line, POOLMEM **pool_buf, const char *fmt, ...)
1554 i = sprintf(*pool_buf, "%s:%d ", get_basename(file), line);
1557 maxlen = sizeof_pool_memory(*pool_buf) - i - 1;
1558 va_start(arg_ptr, fmt);
1559 len = bvsnprintf(*pool_buf+i, maxlen, fmt, arg_ptr);
1561 if (len < 0 || len >= (maxlen-5)) {
1562 *pool_buf = realloc_pool_memory(*pool_buf, maxlen + i + maxlen/2);
1570 int m_msg(const char *file, int line, POOLMEM *&pool_buf, const char *fmt, ...)
1575 i = sprintf(pool_buf, "%s:%d ", get_basename(file), line);
1578 maxlen = sizeof_pool_memory(pool_buf) - i - 1;
1579 va_start(arg_ptr, fmt);
1580 len = bvsnprintf(pool_buf+i, maxlen, fmt, arg_ptr);
1582 if (len < 0 || len >= (maxlen-5)) {
1583 pool_buf = realloc_pool_memory(pool_buf, maxlen + i + maxlen/2);
1593 * Edit a message into a Pool Memory buffer NO file:lineno
1594 * Returns: string length of what was edited.
1596 int Mmsg(POOLMEM **pool_buf, const char *fmt, ...)
1602 maxlen = sizeof_pool_memory(*pool_buf) - 1;
1603 va_start(arg_ptr, fmt);
1604 len = bvsnprintf(*pool_buf, maxlen, fmt, arg_ptr);
1606 if (len < 0 || len >= (maxlen-5)) {
1607 *pool_buf = realloc_pool_memory(*pool_buf, maxlen + maxlen/2);
1615 int Mmsg(POOLMEM *&pool_buf, const char *fmt, ...)
1621 maxlen = sizeof_pool_memory(pool_buf) - 1;
1622 va_start(arg_ptr, fmt);
1623 len = bvsnprintf(pool_buf, maxlen, fmt, arg_ptr);
1625 if (len < 0 || len >= (maxlen-5)) {
1626 pool_buf = realloc_pool_memory(pool_buf, maxlen + maxlen/2);
1634 int Mmsg(POOL_MEM &pool_buf, const char *fmt, ...)
1640 maxlen = pool_buf.max_size() - 1;
1641 va_start(arg_ptr, fmt);
1642 len = bvsnprintf(pool_buf.c_str(), maxlen, fmt, arg_ptr);
1644 if (len < 0 || len >= (maxlen-5)) {
1645 pool_buf.realloc_pm(maxlen + maxlen/2);
1655 * We queue messages rather than print them directly. This
1656 * is generally used in low level routines (msg handler, bnet)
1657 * to prevent recursion (i.e. if you are in the middle of
1658 * sending a message, it is a bit messy to recursively call
1659 * yourself when the bnet packet is not reentrant).
1661 void Qmsg(JCR *jcr, int type, utime_t mtime, const char *fmt,...)
1668 pool_buf = get_pool_memory(PM_EMSG);
1671 maxlen = sizeof_pool_memory(pool_buf) - 1;
1672 va_start(arg_ptr, fmt);
1673 len = bvsnprintf(pool_buf, maxlen, fmt, arg_ptr);
1675 if (len < 0 || len >= (maxlen-5)) {
1676 pool_buf = realloc_pool_memory(pool_buf, maxlen + maxlen/2);
1681 item = (MQUEUE_ITEM *)malloc(sizeof(MQUEUE_ITEM) + strlen(pool_buf) + 1);
1683 item->mtime = time(NULL);
1684 strcpy(item->msg, pool_buf);
1686 jcr = get_jcr_from_tsd();
1689 if (jcr && type==M_FATAL) {
1690 jcr->setJobStatus(JS_FatalError);
1693 /* If no jcr or no queue or dequeuing send to syslog */
1694 if (!jcr || !jcr->msg_queue || jcr->dequeuing_msgs) {
1695 syslog(LOG_DAEMON|LOG_ERR, "%s", item->msg);
1696 P(daemon_msg_queue_mutex);
1697 if (daemon_msg_queue) {
1698 daemon_msg_queue->append(item);
1700 V(daemon_msg_queue_mutex);
1702 /* Queue message for later sending */
1703 P(jcr->msg_queue_mutex);
1704 jcr->msg_queue->append(item);
1705 V(jcr->msg_queue_mutex);
1707 free_memory(pool_buf);
1713 void dequeue_messages(JCR *jcr)
1718 /* Avoid bad calls and recursion */
1719 if (!jcr || jcr->dequeuing_msgs) {
1723 /* Dequeue daemon messages */
1724 if (daemon_msg_queue && !dequeuing_daemon_msgs) {
1725 P(daemon_msg_queue_mutex);
1726 dequeuing_daemon_msgs = true;
1727 jcr->dequeuing_msgs = true;
1729 jcr->JobId = 0; /* set daemon JobId == 0 */
1730 if (jcr->dir_bsock) jcr->dir_bsock->suppress_error_messages(true);
1731 foreach_dlist(item, daemon_msg_queue) {
1732 Jmsg(jcr, item->type, item->mtime, "%s", item->msg);
1734 if (jcr->dir_bsock) jcr->dir_bsock->suppress_error_messages(false);
1735 /* Remove messages just sent */
1736 daemon_msg_queue->destroy();
1737 jcr->JobId = JobId; /* restore JobId */
1738 jcr->dequeuing_msgs = false;
1739 dequeuing_daemon_msgs = false;
1740 V(daemon_msg_queue_mutex);
1743 /* Dequeue Job specific messages */
1744 if (!jcr->msg_queue || jcr->dequeuing_msgs) {
1747 P(jcr->msg_queue_mutex);
1748 jcr->dequeuing_msgs = true;
1749 if (jcr->dir_bsock) jcr->dir_bsock->suppress_error_messages(true);
1750 foreach_dlist(item, jcr->msg_queue) {
1751 Jmsg(jcr, item->type, item->mtime, "%s", item->msg);
1753 if (jcr->dir_bsock) jcr->dir_bsock->suppress_error_messages(false);
1754 /* Remove messages just sent */
1755 jcr->msg_queue->destroy();
1756 jcr->dequeuing_msgs = false;
1757 V(jcr->msg_queue_mutex);
1762 * If we come here, prefix the message with the file:line-number,
1763 * then pass it on to the normal Qmsg routine.
1765 void q_msg(const char *file, int line, JCR *jcr, int type, utime_t mtime, const char *fmt,...)
1771 pool_buf = get_pool_memory(PM_EMSG);
1772 i = Mmsg(pool_buf, "%s:%d ", get_basename(file), line);
1775 maxlen = sizeof_pool_memory(pool_buf) - i - 1;
1776 va_start(arg_ptr, fmt);
1777 len = bvsnprintf(pool_buf+i, maxlen, fmt, arg_ptr);
1779 if (len < 0 || len >= (maxlen-5)) {
1780 pool_buf = realloc_pool_memory(pool_buf, maxlen + i + maxlen/2);
1786 Qmsg(jcr, type, mtime, "%s", pool_buf);
1787 free_memory(pool_buf);
1791 /* not all in alphabetical order. New commands are added after existing commands with similar letters
1792 to prevent breakage of existing user scripts. */
1794 const char *tag; /* command */
1795 int64_t bit; /* bit to set */
1796 const char *help; /* main purpose */
1799 /* setdebug tag=all,-plugin */
1800 static struct debugtags debug_tags[] = {
1801 { NT_("lock"), DT_LOCK, _("Debug lock information")},
1802 { NT_("network"), DT_NETWORK, _("Debug network information")},
1803 { NT_("plugin"), DT_PLUGIN, _("Debug plugin information")},
1804 { NT_("volume"), DT_VOLUME, _("Debug volume information")},
1805 { NT_("sql"), DT_SQL, _("Debug SQL queries")},
1806 { NT_("bvfs"), DT_BVFS, _("Debug BVFS queries")},
1807 { NT_("memory"), DT_MEMORY, _("Debug memory allocation")},
1808 { NT_("scheduler"), DT_SCHEDULER,_("Debug scheduler information")},
1809 { NT_("protocol"), DT_PROTOCOL, _("Debug protocol information")},
1810 { NT_("snapshot"), DT_SNAPSHOT, _("Debug snapshots")},
1811 { NT_("asx"), DT_ASX, _("ASX personal's debugging")},
1812 { NT_("all"), DT_ALL, _("Debug all information")},
1816 #define MAX_TAG (sizeof(debug_tags) / sizeof(struct debugtags))
1818 const char *debug_get_tag(uint32_t pos, const char **desc)
1820 if (pos < MAX_TAG) {
1822 *desc = debug_tags[pos].help;
1824 return debug_tags[pos].tag;
1830 bool debug_find_tag(const char *tagname, bool add, int64_t *current_level)
1832 Dmsg3(010, "add=%d tag=%s level=%lld\n", add, tagname, *current_level);
1834 /* Nothing in the buffer */
1837 for (int i=0; debug_tags[i].tag ; i++) {
1838 if (strcasecmp(debug_tags[i].tag, tagname) == 0) {
1840 *current_level |= debug_tags[i].bit;
1842 *current_level &= ~(debug_tags[i].bit);
1850 bool debug_parse_tags(const char *options, int64_t *current_level)
1852 bool operation; /* + => true, - false */
1853 char *p, *t, tag[256];
1854 int max = sizeof(tag) - 1;
1856 int64_t level= *current_level;
1860 operation = true; /* add by default */
1863 Dmsg0(100, "No options for tags\n");
1867 for (p = (char *)options; *p ; p++) {
1868 if (*p == ',' || *p == '+' || *p == '-' || *p == '!') {
1869 /* finish tag keyword */
1872 ret &= debug_find_tag(tag, operation, &level);
1884 operation = (*p == '+');
1887 } else if (isalpha(*p) && (t - tag) < max) {
1890 } else { /* not isalpha or too long */
1891 Dmsg1(010, "invalid %c\n", *p);
1896 /* At the end, finish the string and look it */
1898 if (t > tag) { /* something found */
1900 ret &= debug_find_tag(tag, operation, &level);
1903 *current_level = level;
1907 int generate_daemon_event(JCR *jcr, const char *event) { return 0; }