/*
- * Bacula message handling routines
- *
- * Kern Sibbald, April 2000
- *
- * Version $Id$
- *
- */
-/*
- Copyright (C) 2000-2006 Kern Sibbald
+ Bacula(R) - The Network Backup Solution
- This program is free software; you can redistribute it and/or
- modify it under the terms of the GNU General Public License
- version 2 as amended with additional clauses defined in the
- file LICENSE in the main source directory.
+ Copyright (C) 2000-2016 Kern Sibbald
- This program is distributed in the hope that it will be useful,
- but WITHOUT ANY WARRANTY; without even the implied warranty of
- MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
- the file LICENSE for additional details.
+ The original author of Bacula is Kern Sibbald, with contributions
+ from many others, a complete list can be found in the file AUTHORS.
- */
+ You may use this file and others of this release according to the
+ license defined in the LICENSE file, which includes the Affero General
+ Public License, v3.0 ("AGPLv3") and some additional permissions and
+ terms pursuant to its AGPLv3 Section 7.
+ This notice must be preserved when any source code is
+ conveyed and/or propagated.
+ Bacula(R) is a registered trademark of Kern Sibbald.
+*/
+/*
+ * Bacula message handling routines
+ *
+ * NOTE: don't use any Jmsg or Qmsg calls within this file,
+ * except in q_msg or j_msg (setup routines),
+ * otherwise you may get into recursive calls if there are
+ * errors, and that can lead to looping or deadlocks.
+ *
+ * Kern Sibbald, April 2000
+ *
+ */
#include "bacula.h"
#include "jcr.h"
-sql_query p_sql_query = NULL;
+sql_query_call p_sql_query = NULL;
+sql_escape_call p_sql_escape = NULL;
#define FULL_LOCATION 1 /* set for file:line in Debug messages */
* This is where we define "Globals" because all the
* daemons include this file.
*/
-const char *working_directory = NULL; /* working directory path stored here */
-int verbose = 0; /* increase User messages */
-int debug_level = 0; /* debug level */
-time_t daemon_start_time = 0; /* Daemon start time */
+const char *working_directory = NULL; /* working directory path stored here */
+const char *assert_msg = NULL; /* ASSERT2 error message */
const char *version = VERSION " (" BDATE ")";
-char my_name[30]; /* daemon name is stored here */
+const char *dist_name = DISTNAME " " DISTVER;
char *exepath = (char *)NULL;
char *exename = (char *)NULL;
-int console_msg_pending = 0;
+char db_engine_name[50] = {0}; /* Database engine name or type */
char con_fname[500]; /* Console filename */
+char my_name[MAX_NAME_LENGTH] = {0}; /* daemon name is stored here */
+char host_name[50] = {0}; /* host machine name */
+char fail_time[30] = {0}; /* Time of failure */
+int verbose = 0; /* increase User messages */
+int64_t debug_level = 0; /* debug level */
+int64_t debug_level_tags = 0; /* debug tags */
+int32_t debug_flags = 0; /* debug flags */
+int console_msg_pending = false;
+utime_t daemon_start_time = 0; /* Daemon start time */
FILE *con_fd = NULL; /* Console file descriptor */
brwlock_t con_lock; /* Console lock structure */
+bool dbg_timestamp = false; /* print timestamp in debug output */
+bool dbg_thread = false; /* add thread_id to details */
+bool prt_kaboom = false; /* Print kaboom output */
+job_code_callback_t message_job_code_callback = NULL; /* Job code callback. Only used by director. */
+
+/* Forward referenced functions */
+/* Imported functions */
+void create_jcr_key();
-#if defined(HAVE_POSTGRESQL)
-char catalog_db[] = "PostgreSQL";
-#elif defined(HAVE_MYSQL)
-char catalog_db[] = "MySQL";
-#elif defined(HAVE_SQLITE)
-char catalog_db[] = "SQLite";
-#else
-char catalog_db[] = "Internal";
-#endif
+/* Static storage */
-const char *host_os = HOST_OS;
-const char *distname = DISTNAME;
-const char *distver = DISTVER;
+/* Exclude spaces but require .mail at end */
+#define MAIL_REGEX "^[^ ]+\\.mail$"
+
+/* Allow only one thread to tweak d->fd at a time */
+static pthread_mutex_t fides_mutex = PTHREAD_MUTEX_INITIALIZER;
+static MSGS *daemon_msgs; /* global messages */
+static void (*message_callback)(int type, char *msg) = NULL;
static FILE *trace_fd = NULL;
#if defined(HAVE_WIN32)
static bool trace = true;
#else
static bool trace = false;
#endif
+static int hangup = 0;
+static int blowup = 0;
-/* Forward referenced functions */
+/* Constants */
+const char *host_os = HOST_OS;
+const char *distname = DISTNAME;
+const char *distver = DISTVER;
-/* Imported functions */
+/*
+ * Walk back in a string from end looking for a
+ * path separator.
+ * This routine is passed the start of the string and
+ * the end of the string, it returns either the beginning
+ * of the string or where it found a path separator.
+ */
+static const char *bstrrpath(const char *start, const char *end)
+{
+ while ( end > start ) {
+ end--;
+ if (IsPathSeparator(*end)) {
+ break;
+ }
+ }
+ return end;
+}
+/* Some message class methods */
+void MSGS::lock()
+{
+ P(fides_mutex);
+}
-/* Static storage */
+void MSGS::unlock()
+{
+ V(fides_mutex);
+}
-/* Used to allow only one thread close the daemon messages at a time */
-static pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER;
-static MSGS *daemon_msgs; /* global messages */
+/*
+ * Wait for not in use variable to be clear
+ */
+void MSGS::wait_not_in_use() /* leaves fides_mutex set */
+{
+ lock();
+ while (m_in_use || m_closing) {
+ unlock();
+ bmicrosleep(0, 200); /* wait */
+ lock();
+ }
+}
+
+/*
+ * Handle message delivery errors
+ */
+static void delivery_error(const char *fmt,...)
+{
+ va_list arg_ptr;
+ int i, len, maxlen;
+ POOLMEM *pool_buf;
+ char dt[MAX_TIME_LENGTH];
+ int dtlen;
+
+ pool_buf = get_pool_memory(PM_EMSG);
+
+ bstrftime_ny(dt, sizeof(dt), time(NULL));
+ dtlen = strlen(dt);
+ dt[dtlen++] = ' ';
+ dt[dtlen] = 0;
+
+ i = Mmsg(pool_buf, "%s Message delivery ERROR: ", dt);
+
+ for (;;) {
+ maxlen = sizeof_pool_memory(pool_buf) - i - 1;
+ va_start(arg_ptr, fmt);
+ len = bvsnprintf(pool_buf+i, maxlen, fmt, arg_ptr);
+ va_end(arg_ptr);
+ if (len < 0 || len >= (maxlen-5)) {
+ pool_buf = realloc_pool_memory(pool_buf, maxlen + i + maxlen/2);
+ continue;
+ }
+ break;
+ }
+
+ fputs(pool_buf, stdout); /* print this here to INSURE that it is printed */
+ fflush(stdout);
+ syslog(LOG_DAEMON|LOG_ERR, "%s", pool_buf);
+ free_memory(pool_buf);
+}
+
+void set_debug_flags(char *options)
+{
+ for (char *p = options; *p ; p++) {
+ switch(*p) {
+ case '0': /* clear flags */
+ debug_flags = 0;
+ break;
+
+ case 'i': /* used by FD */
+ case 'd': /* used by FD */
+ break;
+
+ case 't':
+ dbg_timestamp = true;
+ break;
+
+ case 'T':
+ dbg_timestamp = false;
+ break;
+
+ case 'h':
+ dbg_thread = true;
+ break;
+
+ case 'H':
+ dbg_thread = false;
+ break;
+
+ case 'c':
+ /* truncate the trace file */
+ if (trace && trace_fd) {
+ ftruncate(fileno(trace_fd), 0);
+ }
+ break;
+
+ case 'l':
+ /* Turn on/off add_events for P()/V() */
+ debug_flags |= DEBUG_MUTEX_EVENT;
+ break;
+
+ case 'p':
+ /* Display event stack during lockdump */
+ debug_flags |= DEBUG_PRINT_EVENT;
+ break;
+
+ default:
+ Dmsg1(000, "Unknown debug flag %c\n", *p);
+ }
+ }
+}
+
+void register_message_callback(void msg_callback(int type, char *msg))
+{
+ message_callback = msg_callback;
+}
/*
* Resource record. On the second call, generally,
* argv is NULL to avoid doing the path code twice.
*/
-#define BTRACE_EXTRA 20
void my_name_is(int argc, char *argv[], const char *name)
{
char *l, *p, *q;
char cpath[1024];
int len;
+ if (gethostname(host_name, sizeof(host_name)) != 0) {
+ bstrncpy(host_name, "Hostname unknown", sizeof(host_name));
+ }
bstrncpy(my_name, name, sizeof(my_name));
if (argc>0 && argv && argv[0]) {
/* strip trailing filename and save exepath */
for (l=p=argv[0]; *p; p++) {
- if (*p == '/') {
+ if (IsPathSeparator(*p)) {
l = p; /* set pos of last slash */
}
}
- if (*l == '/') {
+ if (IsPathSeparator(*l)) {
l++;
} else {
l = argv[0];
#if defined(HAVE_WIN32)
- /* On Windows allow c: junk */
+ /* On Windows allow c: drive specification */
if (l[1] == ':') {
l += 2;
}
*q++ = *p++;
}
*q = 0;
- if (strchr(exepath, '.') || exepath[0] != '/') {
+ if (strchr(exepath, '.') || !IsPathSeparator(exepath[0])) {
if (getcwd(cpath, sizeof(cpath))) {
free(exepath);
exepath = (char *)malloc(strlen(cpath) + 1 + len);
}
}
+/* Set special ASSERT2 message where debugger can find it */
+void
+set_assert_msg(const char *file, int line, const char *msg)
+{
+ char buf[2000];
+ bsnprintf(buf, sizeof(buf), "ASSERT at %s:%d-%u ERR=%s",
+ get_basename(file), line, get_jobid_from_tsd(), msg);
+ assert_msg = bstrdup(buf);
+}
+
+void set_db_engine_name(const char *name)
+{
+ bstrncpy(db_engine_name, name, sizeof(db_engine_name)-1);
+}
+
/*
* Initialize message handler for a daemon or a Job
* We make a copy of the MSGS resource passed, so it belows
* non-NULL -> initialize jcr using Message resource
*/
void
-init_msg(JCR *jcr, MSGS *msg)
+init_msg(JCR *jcr, MSGS *msg, job_code_callback_t job_code_callback)
{
DEST *d, *dnew, *temp_chain = NULL;
+ int i;
if (jcr == NULL && msg == NULL) {
init_last_jobs_list();
+ /* Create a daemon key then set invalid jcr */
+ /* Maybe we should give the daemon a jcr??? */
+ create_jcr_key();
+ set_jcr_in_tsd(INVALID_JCR);
}
+ message_job_code_callback = job_code_callback;
+
#if !defined(HAVE_WIN32)
/*
* Make sure we have fd's 0, 1, 2 open
*
*/
int fd;
- int i;
fd = open("/dev/null", O_RDONLY, 0644);
if (fd > 2) {
close(fd);
if (msg == NULL) {
daemon_msgs = (MSGS *)malloc(sizeof(MSGS));
memset(daemon_msgs, 0, sizeof(MSGS));
-#if !defined(HAVE_WIN32)
for (i=1; i<=M_MAX; i++) {
add_msg_dest(daemon_msgs, MD_STDOUT, i, NULL, NULL);
}
-#endif
Dmsg1(050, "Create daemon global message resource %p\n", daemon_msgs);
return;
}
daemon_msgs->dest_chain = temp_chain;
memcpy(daemon_msgs->send_msg, msg->send_msg, sizeof(msg->send_msg));
}
- Dmsg2(250, "Copy message resource %p to %p\n", msg, temp_chain);
+ Dmsg2(250, "Copy message resource %p to %p\n", msg, temp_chain);
}
/* Initialize so that the console (User Agent) can
{
int fd;
- bsnprintf(con_fname, sizeof(con_fname), "%s/%s.conmsg", wd, my_name);
+ bsnprintf(con_fname, sizeof(con_fname), "%s%c%s.conmsg", wd, PathSeparator, my_name);
fd = open(con_fname, O_CREAT|O_RDWR|O_BINARY, 0600);
if (fd == -1) {
berrno be;
Emsg2(M_ERROR_TERM, 0, _("Could not open console message file %s: ERR=%s\n"),
- con_fname, be.strerror());
+ con_fname, be.bstrerror());
}
if (lseek(fd, 0, SEEK_END) > 0) {
console_msg_pending = 1;
if (!con_fd) {
berrno be;
Emsg2(M_ERROR, 0, _("Could not open console message file %s: ERR=%s\n"),
- con_fname, be.strerror());
+ con_fname, be.bstrerror());
}
if (rwl_init(&con_lock) != 0) {
berrno be;
Emsg1(M_ERROR_TERM, 0, _("Could not get con mutex: ERR=%s\n"),
- be.strerror());
+ be.bstrerror());
}
}
{
if (jcr) {
Mmsg(name, "%s/%s.%s.%d.mail", working_directory, my_name,
- jcr->Job, (int)(long)d);
+ jcr->Job, (int)(intptr_t)d);
} else {
Mmsg(name, "%s/%s.%s.%d.mail", working_directory, my_name,
- my_name, (int)(long)d);
+ my_name, (int)(intptr_t)d);
}
Dmsg1(850, "mailname=%s\n", name);
}
BPIPE *bpipe;
if (d->mail_cmd) {
- cmd = edit_job_codes(jcr, cmd, d->mail_cmd, d->where);
+ cmd = edit_job_codes(jcr, cmd, d->mail_cmd, d->where, message_job_code_callback);
} else {
Mmsg(cmd, "/usr/lib/sendmail -F Bacula %s", d->where);
}
fflush(stdout);
- if (!(bpipe = open_bpipe(cmd, 120, "rw"))) {
+ if ((bpipe = open_bpipe(cmd, 120, "rw"))) {
+ /* If we had to use sendmail, add subject */
+ if (!d->mail_cmd) {
+ fprintf(bpipe->wfd, "Subject: %s\r\n\r\n", _("Bacula Message"));
+ }
+ } else {
berrno be;
- Jmsg(jcr, M_ERROR, 0, _("open mail pipe %s failed: ERR=%s\n"),
- cmd, be.strerror());
- }
-
- /* If we had to use sendmail, add subject */
- if (!d->mail_cmd) {
- fprintf(bpipe->wfd, "Subject: %s\r\n\r\n", _("Bacula Message"));
+ delivery_error(_("open mail pipe %s failed: ERR=%s\n"),
+ cmd, be.bstrerror());
}
-
return bpipe;
}
if (jcr == NULL) { /* NULL -> global chain */
msgs = daemon_msgs;
- P(mutex); /* only one thread walking the chain */
} else {
msgs = jcr->jcr_msgs;
jcr->jcr_msgs = NULL;
if (msgs == NULL) {
return;
}
+
+ /* Wait for item to be not in use, then mark closing */
+ if (msgs->is_closing()) {
+ return;
+ }
+ msgs->wait_not_in_use(); /* leaves fides_mutex set */
+ /* Note get_closing() does not lock because we are already locked */
+ if (msgs->get_closing()) {
+ msgs->unlock();
+ return;
+ }
+ msgs->set_closing();
+ msgs->unlock();
+
Dmsg1(850, "===Begin close msg resource at %p\n", msgs);
cmd = get_pool_memory(PM_MESSAGE);
for (d=msgs->dest_chain; d; ) {
+ bool success;
if (d->fd) {
switch (d->dest_code) {
case MD_FILE:
case MD_APPEND:
if (d->fd) {
fclose(d->fd); /* close open file descriptor */
+ d->fd = NULL;
}
break;
case MD_MAIL:
case MD_MAIL_ON_ERROR:
- Dmsg0(850, "Got MD_MAIL or MD_MAIL_ON_ERROR\n");
+ case MD_MAIL_ON_SUCCESS:
+ Dmsg0(850, "Got MD_MAIL, MD_MAIL_ON_ERROR or MD_MAIL_ON_SUCCESS\n");
if (!d->fd) {
break;
}
- if (d->dest_code == MD_MAIL_ON_ERROR && jcr &&
- jcr->JobStatus == JS_Terminated) {
- goto rem_temp_file;
+ success = jcr && (jcr->JobStatus == JS_Terminated || jcr->JobStatus == JS_Warnings);
+ if (d->dest_code == MD_MAIL_ON_ERROR && success) {
+ goto rem_temp_file; /* no mail */
+ } else if (d->dest_code == MD_MAIL_ON_SUCCESS && !success) {
+ goto rem_temp_file; /* no mail */
}
if (!(bpipe=open_mail_pipe(jcr, cmd, d))) {
Pmsg0(000, _("open mail pipe failed.\n"));
- goto rem_temp_file;
+ goto rem_temp_file; /* error get out */
}
Dmsg0(850, "Opened mail pipe\n");
len = d->max_len+10;
}
if (!close_wpipe(bpipe)) { /* close write pipe sending mail */
berrno be;
- Pmsg1(000, _("close error: ERR=%s\n"), be.strerror());
+ Pmsg1(000, _("close error: ERR=%s\n"), be.bstrerror());
}
/*
if (msgs != daemon_msgs) {
/* read what mail prog returned -- should be nothing */
while (fgets(line, len, bpipe->rfd)) {
- Jmsg1(jcr, M_INFO, 0, _("Mail prog: %s"), line);
+ delivery_error(_("Mail prog: %s"), line);
}
}
berrno be;
be.set_errno(stat);
Dmsg1(850, "Calling emsg. CMD=%s\n", cmd);
- Jmsg2(jcr, M_ERROR, 0, _("Mail program terminated in error.\n"
- "CMD=%s\n"
- "ERR=%s\n"), cmd, be.strerror());
+ delivery_error(_("Mail program terminated in error.\n"
+ "CMD=%s\n"
+ "ERR=%s\n"), cmd, be.bstrerror());
}
free_memory(line);
+
rem_temp_file:
- /* Remove temp file */
- fclose(d->fd);
- unlink(d->mail_filename);
- free_pool_memory(d->mail_filename);
- d->mail_filename = NULL;
+ /* Remove temp mail file */
+ if (d->fd) {
+ fclose(d->fd);
+ d->fd = NULL;
+ }
+ /* Exclude spaces in mail_filename */
+ if (d->mail_filename) {
+ safer_unlink(d->mail_filename, MAIL_REGEX);
+ free_pool_memory(d->mail_filename);
+ d->mail_filename = NULL;
+ }
Dmsg0(850, "end mail or mail on error\n");
break;
default:
free_msgs_res(msgs);
msgs = NULL;
} else {
- V(mutex);
+ msgs->clear_closing();
}
Dmsg0(850, "===End close msg resource\n");
}
for (d=msgs->dest_chain; d; ) {
if (d->where) {
free(d->where);
+ d->where = NULL;
}
if (d->mail_cmd) {
free(d->mail_cmd);
+ d->mail_cmd = NULL;
}
old = d; /* save pointer to release */
d = d->next; /* point to next buffer */
if (trace_fd) {
fclose(trace_fd);
trace_fd = NULL;
+ trace = false;
}
+ working_directory = NULL;
term_last_jobs_list();
}
+static bool open_dest_file(JCR *jcr, DEST *d, const char *mode)
+{
+ d->fd = fopen(d->where, mode);
+ if (!d->fd) {
+ berrno be;
+ delivery_error(_("fopen %s failed: ERR=%s\n"), d->where, be.bstrerror());
+ return false;
+ }
+ return true;
+}
+/* Split the output for syslog (it converts \n to ' ' and is
+ * limited to 1024 characters per syslog message
+ */
+static void send_to_syslog(int mode, const char *msg)
+{
+ int len;
+ char buf[1024];
+ const char *p2;
+ const char *p = msg;
+
+ while (*p && ((p2 = strchr(p, '\n')) != NULL)) {
+ len = MIN((int)sizeof(buf) - 1, p2 - p + 1); /* Add 1 to keep \n */
+ strncpy(buf, p, len);
+ buf[len] = 0;
+ syslog(mode, "%s", buf);
+ p = p2+1; /* skip \n */
+ }
+ if (*p != 0) { /* no \n at the end ? */
+ syslog(mode, "%s", p);
+ }
+}
/*
* Handle sending the message to the appropriate place
*/
-void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg)
+void dispatch_message(JCR *jcr, int type, utime_t mtime, char *msg)
{
DEST *d;
char dt[MAX_TIME_LENGTH];
int len, dtlen;
MSGS *msgs;
BPIPE *bpipe;
+ const char *mode;
Dmsg2(850, "Enter dispatch_msg type=%d msg=%s", type, msg);
* Most messages are prefixed by a date and time. If mtime is
* zero, then we use the current time. If mtime is 1 (special
* kludge), we do not prefix the date and time. Otherwise,
- * we assume mtime is a time_t and use it.
+ * we assume mtime is a utime_t and use it.
*/
if (mtime == 0) {
mtime = time(NULL);
if (mtime == 1) {
*dt = 0;
dtlen = 0;
+ mtime = time(NULL); /* get time for SQL log */
} else {
bstrftime_ny(dt, sizeof(dt), mtime);
dtlen = strlen(dt);
dt[dtlen] = 0;
}
+ /* If the program registered a callback, send it there */
+ if (message_callback) {
+ message_callback(type, msg);
+ return;
+ }
+
+ /* For serious errors make sure message is printed or logged */
if (type == M_ABORT || type == M_ERROR_TERM) {
-#if !defined(HAVE_WIN32)
fputs(dt, stdout);
- fputs(msg, stdout); /* print this here to INSURE that it is printed */
+ fputs(msg, stdout);
fflush(stdout);
-#endif
+ if (type == M_ABORT) {
+ syslog(LOG_DAEMON|LOG_ERR, "%s", msg);
+ }
}
+
/* Now figure out where to send the message */
msgs = NULL;
+ if (!jcr) {
+ jcr = get_jcr_from_tsd();
+ }
if (jcr) {
msgs = jcr->jcr_msgs;
}
if (msgs == NULL) {
msgs = daemon_msgs;
}
+ /*
+ * If closing this message resource, print and send to syslog,
+ * then get out.
+ */
+ if (msgs->is_closing()) {
+ fputs(dt, stdout);
+ fputs(msg, stdout);
+ fflush(stdout);
+ syslog(LOG_DAEMON|LOG_ERR, "%s", msg);
+ return;
+ }
+
for (d=msgs->dest_chain; d; d=d->next) {
if (bit_is_set(type, d->msg_types)) {
+ bool ok;
switch (d->dest_code) {
case MD_CATALOG:
char ed1[50];
- if (!jcr || !jcr->db) {
+ if (!jcr || !jcr->db) {
break;
}
- if (p_sql_query) {
- POOL_MEM cmd(PM_MESSAGE);
- bstrftimes(dt, sizeof(dt), mtime);
- Mmsg(cmd, "INSERT INTO Log (JobId, Time, LogText) VALUES (%s,'%s','%s')",
- edit_int64(jcr->JobId, ed1), dt, msg);
- p_sql_query(jcr, cmd.c_str());
+ if (p_sql_query && p_sql_escape) {
+ POOLMEM *cmd = get_pool_memory(PM_MESSAGE);
+ POOLMEM *esc_msg = get_pool_memory(PM_MESSAGE);
+
+ int len = strlen(msg) + 1;
+ esc_msg = check_pool_memory_size(esc_msg, len*2+1);
+ ok = p_sql_escape(jcr, jcr->db, esc_msg, msg, len);
+ if (ok) {
+ bstrutime(dt, sizeof(dt), mtime);
+ Mmsg(cmd, "INSERT INTO Log (JobId, Time, LogText) VALUES (%s,'%s','%s')",
+ edit_int64(jcr->JobId, ed1), dt, esc_msg);
+ ok = p_sql_query(jcr, cmd);
+ }
+ if (!ok) {
+ delivery_error(_("Message delivery error: Unable to store data in database.\n"));
+ }
+ free_pool_memory(cmd);
+ free_pool_memory(esc_msg);
}
break;
case MD_CONSOLE:
(void)fwrite("\n", 2, 1, con_fd);
}
fflush(con_fd);
- console_msg_pending = TRUE;
+ console_msg_pending = true;
Vw(con_lock);
}
break;
/*
* We really should do an openlog() here.
*/
- syslog(LOG_DAEMON|LOG_ERR, "%s", msg);
+ send_to_syslog(LOG_DAEMON|LOG_ERR, msg);
break;
case MD_OPERATOR:
Dmsg1(850, "OPERATOR for following msg: %s\n", msg);
if (stat != 0) {
berrno be;
be.set_errno(stat);
- Qmsg2(jcr, M_ERROR, 0, _("Operator mail program terminated in error.\n"
+ delivery_error(_("Msg delivery error: Operator mail program terminated in error.\n"
"CMD=%s\n"
- "ERR=%s\n"), mcmd, be.strerror());
+ "ERR=%s\n"), mcmd, be.bstrerror());
}
}
free_pool_memory(mcmd);
break;
case MD_MAIL:
case MD_MAIL_ON_ERROR:
+ case MD_MAIL_ON_SUCCESS:
Dmsg1(850, "MAIL for following msg: %s", msg);
+ if (msgs->is_closing()) {
+ break;
+ }
+ msgs->set_in_use();
if (!d->fd) {
POOLMEM *name = get_pool_memory(PM_MESSAGE);
make_unique_mail_filename(jcr, name, d);
d->fd = fopen(name, "w+b");
if (!d->fd) {
berrno be;
- d->fd = stdout;
- Qmsg2(jcr, M_ERROR, 0, _("fopen %s failed: ERR=%s\n"), name,
- be.strerror());
- d->fd = NULL;
+ delivery_error(_("Msg delivery error: fopen %s failed: ERR=%s\n"), name,
+ be.bstrerror());
free_pool_memory(name);
+ msgs->clear_in_use();
break;
}
d->mail_filename = name;
d->max_len = len; /* keep max line length */
}
fputs(msg, d->fd);
+ msgs->clear_in_use();
break;
+ case MD_APPEND:
+ Dmsg1(850, "APPEND for following msg: %s", msg);
+ mode = "ab";
+ goto send_to_file;
case MD_FILE:
Dmsg1(850, "FILE for following msg: %s", msg);
- if (!d->fd) {
- d->fd = fopen(d->where, "w+b");
- if (!d->fd) {
- berrno be;
- d->fd = stdout;
- Qmsg2(jcr, M_ERROR, 0, _("fopen %s failed: ERR=%s\n"), d->where,
- be.strerror());
- d->fd = NULL;
- break;
- }
+ mode = "w+b";
+send_to_file:
+ if (msgs->is_closing()) {
+ break;
+ }
+ msgs->set_in_use();
+ if (!d->fd && !open_dest_file(jcr, d, mode)) {
+ msgs->clear_in_use();
+ break;
}
fputs(dt, d->fd);
fputs(msg, d->fd);
- break;
- case MD_APPEND:
- Dmsg1(850, "APPEND for following msg: %s", msg);
- if (!d->fd) {
- d->fd = fopen(d->where, "ab");
- if (!d->fd) {
- berrno be;
- d->fd = stdout;
- Qmsg2(jcr, M_ERROR, 0, _("fopen %s failed: ERR=%s\n"), d->where,
- be.strerror());
- d->fd = NULL;
- break;
+ /* On error, we close and reopen to handle log rotation */
+ if (ferror(d->fd)) {
+ fclose(d->fd);
+ d->fd = NULL;
+ if (open_dest_file(jcr, d, mode)) {
+ fputs(dt, d->fd);
+ fputs(msg, d->fd);
}
}
- fputs(dt, d->fd);
- fputs(msg, d->fd);
+ msgs->clear_in_use();
break;
case MD_DIRECTOR:
Dmsg1(850, "DIRECTOR for following msg: %s", msg);
if (jcr && jcr->dir_bsock && !jcr->dir_bsock->errors) {
- bnet_fsend(jcr->dir_bsock, "Jmsg Job=%s type=%d level=%d %s",
+ jcr->dir_bsock->fsend("Jmsg Job=%s type=%d level=%lld %s",
jcr->Job, type, mtime, msg);
+ } else {
+ Dmsg1(800, "no jcr for following msg: %s", msg);
}
break;
case MD_STDOUT:
if (type != M_ABORT && type != M_ERROR_TERM) { /* already printed */
fputs(dt, stdout);
fputs(msg, stdout);
+ fflush(stdout);
}
break;
case MD_STDERR:
Dmsg1(850, "STDERR for following msg: %s", msg);
fputs(dt, stderr);
fputs(msg, stderr);
+ fflush(stdout);
break;
default:
break;
/*********************************************************************
*
- * This subroutine returns the filename portion of a Windows
- * path. It is used because Microsoft Visual Studio sets __FILE__
- * to the full path.
+ * This subroutine returns the filename portion of a path.
+ * It is used because some compilers set __FILE__
+ * to the full path. Try to return base + next higher path.
*/
-inline const char *
-get_basename(const char *pathname)
+const char *get_basename(const char *pathname)
{
-#if defined(_MSC_VER)
const char *basename;
-
- if ((basename = strrchr(pathname, '\\')) == NULL) {
- basename = pathname;
+
+ if ((basename = bstrrpath(pathname, pathname+strlen(pathname))) == pathname) {
+ /* empty */
+ } else if ((basename = bstrrpath(pathname, basename-1)) == pathname) {
+ /* empty */
} else {
basename++;
}
-
return basename;
-#else
- return pathname;
-#endif
+}
+
+/*
+ * print or write output to trace file
+ */
+static void pt_out(char *buf)
+{
+ /*
+ * Used the "trace on" command in the console to turn on
+ * output to the trace file. "trace off" will close the file.
+ */
+ if (trace) {
+ if (!trace_fd) {
+ char fn[200];
+ bsnprintf(fn, sizeof(fn), "%s/%s.trace", working_directory ? working_directory : "./", my_name);
+ trace_fd = fopen(fn, "a+b");
+ }
+ if (trace_fd) {
+ fputs(buf, trace_fd);
+ fflush(trace_fd);
+ return;
+ } else {
+ /* Some problem, turn off tracing */
+ trace = false;
+ }
+ }
+ /* not tracing */
+ fputs(buf, stdout);
+ fflush(stdout);
}
/*********************************************************************
*
* If the level is negative, the details of file and line number
* are not printed.
+ *
*/
void
-d_msg(const char *file, int line, int level, const char *fmt,...)
+vd_msg(const char *file, int line, int64_t level, const char *fmt, va_list arg_ptr)
{
char buf[5000];
- int len;
- va_list arg_ptr;
+ int len = 0; /* space used in buf */
bool details = true;
+ utime_t mtime;
if (level < 0) {
details = false;
level = -level;
}
- if (level <= debug_level) {
+ if (chk_dbglvl(level)) {
+ if (dbg_timestamp) {
+ mtime = time(NULL);
+ bstrftimes(buf+len, sizeof(buf)-len, mtime);
+ len = strlen(buf);
+ buf[len++] = ' ';
+ }
+
#ifdef FULL_LOCATION
if (details) {
- len = bsnprintf(buf, sizeof(buf), "%s: %s:%d ", my_name, get_basename(file), line);
- } else {
- len = 0;
+ if (dbg_thread) {
+ len += bsnprintf(buf+len, sizeof(buf)-len, "%s[%lld]: %s:%d-%u ",
+ my_name, bthread_get_thread_id(),
+ get_basename(file), line, get_jobid_from_tsd());
+ } else {
+ len += bsnprintf(buf+len, sizeof(buf)-len, "%s: %s:%d-%u ",
+ my_name, get_basename(file), line, get_jobid_from_tsd());
+ }
}
-#else
- len = 0;
#endif
- va_start(arg_ptr, fmt);
bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
- va_end(arg_ptr);
- /*
- * Used the "trace on" command in the console to turn on
- * output to the trace file. "trace off" will close the file.
- */
- if (trace) {
- if (!trace_fd) {
- char fn[200];
- bsnprintf(fn, sizeof(fn), "%s/bacula.trace", working_directory ? working_directory : ".");
- trace_fd = fopen(fn, "a+b");
- }
- if (trace_fd) {
- fputs(buf, trace_fd);
- fflush(trace_fd);
- } else {
- /* Some problem, turn off tracing */
- trace = false;
- }
- } else { /* not tracing */
- fputs(buf, stdout);
- }
+ pt_out(buf);
}
}
+void
+d_msg(const char *file, int line, int64_t level, const char *fmt,...)
+{
+ va_list arg_ptr;
+ va_start(arg_ptr, fmt);
+ vd_msg(file, line, level, fmt, arg_ptr); /* without tags */
+ va_end(arg_ptr);
+}
+
+
/*
* Set trace flag on/off. If argument is negative, there is no change
*/
}
}
+void set_hangup(int hangup_value)
+{
+ if (hangup_value < 0) {
+ return;
+ } else {
+ hangup = hangup_value;
+ }
+}
+
+int get_hangup(void)
+{
+ return hangup;
+}
+
+void set_blowup(int blowup_value)
+{
+ if (blowup_value < 0) {
+ return;
+ } else {
+ blowup = blowup_value;
+ }
+}
+
+int get_blowup(void)
+{
+ return blowup;
+}
+
+
bool get_trace(void)
{
return trace;
p_msg(const char *file, int line, int level, const char *fmt,...)
{
char buf[5000];
- int len;
+ int len = 0; /* space used in buf */
va_list arg_ptr;
+ if (dbg_timestamp) {
+ utime_t mtime = time(NULL);
+ bstrftimes(buf+len, sizeof(buf)-len, mtime);
+ len = strlen(buf);
+ buf[len++] = ' ';
+ }
+
#ifdef FULL_LOCATION
if (level >= 0) {
- len = bsnprintf(buf, sizeof(buf), "%s: %s:%d ", my_name, get_basename(file), line);
- } else {
- len = 0;
+ len += bsnprintf(buf+len, sizeof(buf)-len, "%s: %s:%d-%u ",
+ my_name, get_basename(file), line, get_jobid_from_tsd());
}
-#else
- len = 0;
#endif
+
va_start(arg_ptr, fmt);
bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
va_end(arg_ptr);
- fputs(buf, stdout);
+
+ pt_out(buf);
}
* are not printed.
*/
void
-t_msg(const char *file, int line, int level, const char *fmt,...)
+t_msg(const char *file, int line, int64_t level, const char *fmt,...)
{
char buf[5000];
int len;
va_list arg_ptr;
int details = TRUE;
+ level = level & ~DT_ALL; /* level should be tag free */
+
if (level < 0) {
details = FALSE;
level = -level;
if (level <= debug_level) {
if (!trace_fd) {
- bsnprintf(buf, sizeof(buf), "%s/bacula.trace", working_directory);
+ bsnprintf(buf, sizeof(buf), "%s/%s.trace", working_directory ? working_directory : ".", my_name);
trace_fd = fopen(buf, "a+b");
}
}
}
-
-
/* *********************************************************
*
* print an error message
bvsnprintf(buf+len, sizeof(buf)-len, (char *)fmt, arg_ptr);
va_end(arg_ptr);
+ pt_out(buf);
dispatch_message(NULL, type, 0, buf);
if (type == M_ABORT) {
*
*/
void
-Jmsg(JCR *jcr, int type, time_t mtime, const char *fmt,...)
+Jmsg(JCR *jcr, int type, utime_t mtime, const char *fmt,...)
{
char rbuf[5000];
va_list arg_ptr;
int len;
MSGS *msgs;
- const char *job;
+ uint32_t JobId = 0;
Dmsg1(850, "Enter Jmsg type=%d\n", type);
dir->msglen = bvsnprintf(dir->msg, sizeof_pool_memory(dir->msg),
fmt, arg_ptr);
va_end(arg_ptr);
- bnet_send(jcr->dir_bsock);
+ jcr->dir_bsock->send();
+ return;
+ }
+
+ /* The watchdog thread can't use Jmsg directly, we always queued it */
+ if (is_watchdog()) {
+ va_start(arg_ptr, fmt);
+ bvsnprintf(rbuf, sizeof(rbuf), fmt, arg_ptr);
+ va_end(arg_ptr);
+ Qmsg(jcr, type, mtime, "%s", rbuf);
return;
}
msgs = NULL;
- job = NULL;
+ if (!jcr) {
+ jcr = get_jcr_from_tsd();
+ }
if (jcr) {
+ if (!jcr->dequeuing_msgs) { /* Avoid recursion */
+ /* Dequeue messages to keep the original order */
+ dequeue_messages(jcr);
+ }
msgs = jcr->jcr_msgs;
- job = jcr->Job;
+ JobId = jcr->JobId;
}
if (!msgs) {
msgs = daemon_msgs; /* if no jcr, we use daemon handler */
}
- if (!job) {
- job = ""; /* Set null job name if none */
- }
/*
* Check if we have a message destination defined.
len = bsnprintf(rbuf, sizeof(rbuf), _("%s ERROR TERMINATION\n"), my_name);
break;
case M_FATAL:
- len = bsnprintf(rbuf, sizeof(rbuf), _("%s: %s Fatal error: "), my_name, job);
+ len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Fatal error: "), my_name, JobId);
if (jcr) {
- set_jcr_job_status(jcr, JS_FatalError);
+ jcr->setJobStatus(JS_FatalError);
+ }
+ if (jcr && jcr->JobErrors == 0) {
+ jcr->JobErrors = 1;
}
break;
case M_ERROR:
- len = bsnprintf(rbuf, sizeof(rbuf), _("%s: %s Error: "), my_name, job);
+ len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Error: "), my_name, JobId);
if (jcr) {
- jcr->Errors++;
+ jcr->JobErrors++;
}
break;
case M_WARNING:
- len = bsnprintf(rbuf, sizeof(rbuf), _("%s: %s Warning: "), my_name, job);
+ len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Warning: "), my_name, JobId);
+ if (jcr) {
+ jcr->JobWarnings++;
+ }
break;
case M_SECURITY:
- len = bsnprintf(rbuf, sizeof(rbuf), _("%s: %s Security violation: "), my_name, job);
+ len = bsnprintf(rbuf, sizeof(rbuf), _("%s JobId %u: Security violation: "),
+ my_name, JobId);
break;
default:
- len = bsnprintf(rbuf, sizeof(rbuf), "%s: ", my_name);
+ len = bsnprintf(rbuf, sizeof(rbuf), "%s JobId %u: ", my_name, JobId);
break;
}
if (type == M_ABORT){
char *p = 0;
+ printf("Bacula forced SEG FAULT to obtain traceback.\n");
+ syslog(LOG_DAEMON|LOG_ERR, "Bacula forced SEG FAULT to obtain traceback.\n");
p[0] = 0; /* generate segmentation violation */
}
if (type == M_ERROR_TERM) {
* If we come here, prefix the message with the file:line-number,
* then pass it on to the normal Jmsg routine.
*/
-void j_msg(const char *file, int line, JCR *jcr, int type, time_t mtime, const char *fmt,...)
+void j_msg(const char *file, int line, JCR *jcr, int type, utime_t mtime, const char *fmt,...)
{
va_list arg_ptr;
int i, len, maxlen;
POOLMEM *pool_buf;
+ va_start(arg_ptr, fmt);
+ vd_msg(file, line, 0, fmt, arg_ptr);
+ va_end(arg_ptr);
+
pool_buf = get_pool_memory(PM_EMSG);
i = Mmsg(pool_buf, "%s:%d ", get_basename(file), line);
}
-static pthread_mutex_t msg_queue_mutex = PTHREAD_MUTEX_INITIALIZER;
-
/*
* We queue messages rather than print them directly. This
* is generally used in low level routines (msg handler, bnet)
* sending a message, it is a bit messy to recursively call
* yourself when the bnet packet is not reentrant).
*/
-void Qmsg(JCR *jcr, int type, time_t mtime, const char *fmt,...)
+void Qmsg(JCR *jcr, int type, utime_t mtime, const char *fmt,...)
{
va_list arg_ptr;
int len, maxlen;
item->type = type;
item->mtime = time(NULL);
strcpy(item->msg, pool_buf);
- /* If no jcr or dequeuing send to daemon to avoid recursion */
- if (!jcr || jcr->dequeuing) {
- /* jcr==NULL => daemon message, safe to send now */
- Jmsg(NULL, item->type, item->mtime, "%s", item->msg);
+ if (!jcr) {
+ jcr = get_jcr_from_tsd();
+ }
+
+ if (jcr && type==M_FATAL) {
+ // TODO ASX MUST use a lock to protect access jcr->JobStatus from another thread
+ jcr->setJobStatus(JS_FatalError);
+ }
+
+ /* If no jcr or no queue or dequeuing send to syslog */
+ if (!jcr || !jcr->msg_queue || jcr->dequeuing_msgs) {
+ syslog(LOG_DAEMON|LOG_ERR, "%s", item->msg);
free(item);
} else {
/* Queue message for later sending */
- P(msg_queue_mutex);
+ P(jcr->msg_queue_mutex);
jcr->msg_queue->append(item);
- V(msg_queue_mutex);
+ V(jcr->msg_queue_mutex);
}
free_memory(pool_buf);
}
void dequeue_messages(JCR *jcr)
{
MQUEUE_ITEM *item;
- P(msg_queue_mutex);
if (!jcr->msg_queue) {
- goto bail_out;
+ return;
}
- jcr->dequeuing = true;
+ P(jcr->msg_queue_mutex);
+ jcr->dequeuing_msgs = true;
foreach_dlist(item, jcr->msg_queue) {
Jmsg(jcr, item->type, item->mtime, "%s", item->msg);
}
+ /* Remove messages just sent */
jcr->msg_queue->destroy();
- jcr->dequeuing = false;
-
-bail_out:
- V(msg_queue_mutex);
+ jcr->dequeuing_msgs = false;
+ V(jcr->msg_queue_mutex);
}
* If we come here, prefix the message with the file:line-number,
* then pass it on to the normal Qmsg routine.
*/
-void q_msg(const char *file, int line, JCR *jcr, int type, time_t mtime, const char *fmt,...)
+void q_msg(const char *file, int line, JCR *jcr, int type, utime_t mtime, const char *fmt,...)
{
va_list arg_ptr;
int i, len, maxlen;
POOLMEM *pool_buf;
pool_buf = get_pool_memory(PM_EMSG);
- i = Mmsg(pool_buf, "%s:%d ", file, line);
+ i = Mmsg(pool_buf, "%s:%d ", get_basename(file), line);
for (;;) {
maxlen = sizeof_pool_memory(pool_buf) - i - 1;
Qmsg(jcr, type, mtime, "%s", pool_buf);
free_memory(pool_buf);
}
+
+
+/* not all in alphabetical order. New commands are added after existing commands with similar letters
+ to prevent breakage of existing user scripts. */
+struct debugtags {
+ const char *tag; /* command */
+ int64_t bit; /* bit to set */
+ const char *help; /* main purpose */
+};
+
+/* setdebug tag=all,-plugin */
+static struct debugtags debug_tags[] = {
+ { NT_("lock"), DT_LOCK, _("Debug lock information")},
+ { NT_("network"), DT_NETWORK, _("Debug network information")},
+ { NT_("plugin"), DT_PLUGIN, _("Debug plugin information")},
+ { NT_("volume"), DT_VOLUME, _("Debug volume information")},
+ { NT_("sql"), DT_SQL, _("Debug SQL queries")},
+ { NT_("bvfs"), DT_BVFS, _("Debug BVFS queries")},
+ { NT_("memory"), DT_MEMORY, _("Debug memory allocation")},
+ { NT_("scheduler"), DT_SCHEDULER,_("Debug scheduler information")},
+ { NT_("protocol"), DT_PROTOCOL, _("Debug protocol information")},
+ { NT_("snapshot"), DT_SNAPSHOT, _("Debug snapshots")},
+ { NT_("asx"), DT_ASX, _("ASX personal's debugging")},
+ { NT_("all"), DT_ALL, _("Debug all information")},
+ { NULL, 0, NULL}
+};
+
+#define MAX_TAG (sizeof(debug_tags) / sizeof(struct debugtags))
+
+const char *debug_get_tag(uint32_t pos, const char **desc)
+{
+ if (pos < MAX_TAG) {
+ if (desc) {
+ *desc = debug_tags[pos].help;
+ }
+ return debug_tags[pos].tag;
+ }
+ return NULL;
+}
+
+/* Allow +-, */
+bool debug_find_tag(const char *tagname, bool add, int64_t *current_level)
+{
+ Dmsg3(010, "add=%d tag=%s level=%lld\n", add, tagname, *current_level);
+ if (!*tagname) {
+ /* Nothing in the buffer */
+ return true;
+ }
+ for (int i=0; debug_tags[i].tag ; i++) {
+ if (strcasecmp(debug_tags[i].tag, tagname) == 0) {
+ if (add) {
+ *current_level |= debug_tags[i].bit;
+ } else {
+ *current_level &= ~(debug_tags[i].bit);
+ }
+ return true;
+ }
+ }
+ return false;
+}
+
+bool debug_parse_tags(const char *options, int64_t *current_level)
+{
+ bool operation; /* + => true, - false */
+ char *p, *t, tag[256];
+ int max = sizeof(tag) - 1;
+ bool ret=true;
+ int64_t level= *current_level;
+
+ t = tag;
+ *tag = 0;
+ operation = true; /* add by default */
+
+ if (!options) {
+ Dmsg0(100, "No options for tags\n");
+ return false;
+ }
+
+ for (p = (char *)options; *p ; p++) {
+ if (*p == ',' || *p == '+' || *p == '-' || *p == '!') {
+ /* finish tag keyword */
+ *t = 0;
+ /* handle tag */
+ ret &= debug_find_tag(tag, operation, &level);
+
+ if (*p == ',') {
+ /* reset tag */
+ t = tag;
+ *tag = 0;
+ operation = true;
+
+ } else {
+ /* reset tag */
+ t = tag;
+ *tag = 0;
+ operation = (*p == '+');
+ }
+
+ } else if (isalpha(*p) && (t - tag) < max) {
+ *t++ = *p;
+
+ } else { /* not isalpha or too long */
+ Dmsg1(010, "invalid %c\n", *p);
+ return false;
+ }
+ }
+
+ /* At the end, finish the string and look it */
+ *t = 0;
+ if (t > tag) { /* something found */
+ /* handle tag */
+ ret &= debug_find_tag(tag, operation, &level);
+ }
+
+ *current_level = level;
+ return ret;
+}
+
+int generate_daemon_event(JCR *jcr, const char *event) { return 0; }
projects / bacula / bacula / blobdiff