]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/lib/message.c
Backport new lock calls + debug for SD
[bacula/bacula] / bacula / src / lib / message.c
index 8cccb87339104c318b753925a384e72b5e7ab5e6..3ae4d37c0565516dab4e9b203f6207e20d47e973 100644 (file)
@@ -1,12 +1,12 @@
 /*
    Bacula® - The Network Backup Solution
 
-   Copyright (C) 2000-2007 Free Software Foundation Europe e.V.
+   Copyright (C) 2000-2012 Free Software Foundation Europe e.V.
 
    The main author of Bacula is Kern Sibbald, with contributions from
    many others, a complete list can be found in the file AUTHORS.
    This program is Free Software; you can redistribute it and/or
-   modify it under the terms of version two of the GNU General Public
+   modify it under the terms of version three of the GNU Affero General Public
    License as published by the Free Software Foundation and included
    in the file LICENSE.
 
    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
    General Public License for more details.
 
-   You should have received a copy of the GNU General Public License
+   You should have received a copy of the GNU Affero General Public License
    along with this program; if not, write to the Free Software
    Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
    02110-1301, USA.
 
-   Bacula® is a registered trademark of John Walker.
+   Bacula® is a registered trademark of Kern Sibbald.
    The licensor of Bacula is the Free Software Foundation Europe
    (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
    Switzerland, email:ftf@fsfeurope.org.
 /*
  * Bacula message handling routines
  *
- *   Kern Sibbald, April 2000
+ * 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.
  *
- *   Version $Id$
+ *   Kern Sibbald, April 2000
  *
  */
 
-
 #include "bacula.h"
 #include "jcr.h"
 
-sql_query p_sql_query = NULL;
-sql_escape p_sql_escape = NULL;
+sql_query_func p_sql_query = NULL;
+sql_escape_func p_sql_escape = NULL;
 
 #define FULL_LOCATION 1               /* set for file:line in Debug messages */
 
@@ -48,11 +50,17 @@ sql_escape p_sql_escape = NULL;
  *    daemons include this file.
  */
 const char *working_directory = NULL;       /* working directory path stored here */
+const char *assert_msg = (char *)NULL; /* ASSERT2 error message */
 int verbose = 0;                      /* increase User messages */
-int debug_level = 1;                  /* debug level */
-time_t daemon_start_time = 0;         /* Daemon start time */
+int debug_level = 0;                  /* debug level */
+bool dbg_timestamp = false;           /* print timestamp in debug output */
+bool prt_kaboom = false;              /* Print kaboom output */
+utime_t daemon_start_time = 0;        /* Daemon start time */
 const char *version = VERSION " (" BDATE ")";
-char my_name[30];                     /* daemon name is stored here */
+const char *dist_name = DISTNAME " " DISTVER;
+int beef = BEEF;
+char my_name[30] = {0};               /* daemon name is stored here */
+char host_name[50] = {0};             /* host machine name */
 char *exepath = (char *)NULL;
 char *exename = (char *)NULL;
 int console_msg_pending = false;
@@ -60,29 +68,113 @@ char con_fname[500];                  /* Console filename */
 FILE *con_fd = NULL;                  /* Console file descriptor */
 brwlock_t con_lock;                   /* Console lock structure */
 
+/* Forward referenced functions */
+
+/* Imported functions */
+void create_jcr_key();
+
+/* Static storage */
+
+/* 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 char *catalog_db = NULL;       /* database type */
 static void (*message_callback)(int type, char *msg) = NULL;
-
-const char *host_os = HOST_OS;
-const char *distname = DISTNAME;
-const char *distver = DISTVER;
 static FILE *trace_fd = NULL;
 #if defined(HAVE_WIN32)
 static bool trace = true;
 #else
 static bool trace = false;
 #endif
+static int hangup = 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 register_message_callback(void msg_callback(int type, char *msg))
 {
@@ -106,6 +198,9 @@ void my_name_is(int argc, char *argv[], const char *name)
    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 */
@@ -119,7 +214,7 @@ void my_name_is(int argc, char *argv[], const char *name)
       } else {
          l = argv[0];
 #if defined(HAVE_WIN32)
-         /* On Windows allow c: junk */
+         /* On Windows allow c: drive specification */
          if (l[1] == ':') {
             l += 2;
          }
@@ -151,12 +246,6 @@ void my_name_is(int argc, char *argv[], const char *name)
    }
 }
 
-const char *
-get_db_type(void)
-{
-   return catalog_db != NULL ? catalog_db : "unknown";
-}
-
 void
 set_db_type(const char *name)
 {
@@ -182,6 +271,10 @@ init_msg(JCR *jcr, MSGS *msg)
 
    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);
    }
 
 #if !defined(HAVE_WIN32)
@@ -250,6 +343,7 @@ init_msg(JCR *jcr, MSGS *msg)
       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);
 
 }
@@ -360,10 +454,10 @@ static void make_unique_mail_filename(JCR *jcr, POOLMEM *&name, DEST *d)
 {
    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);
 }
@@ -382,17 +476,16 @@ static BPIPE *open_mail_pipe(JCR *jcr, POOLMEM *&cmd, DEST *d)
    }
    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"),
+      delivery_error(_("open mail pipe %s failed: ERR=%s\n"),
          cmd, be.bstrerror());
    }
-
-   /* If we had to use sendmail, add subject */
-   if (!d->mail_cmd) {
-       fprintf(bpipe->wfd, "Subject: %s\r\n\r\n", _("Bacula Message"));
-   }
-
    return bpipe;
 }
 
@@ -412,7 +505,6 @@ void close_msg(JCR *jcr)
 
    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;
@@ -420,6 +512,20 @@ void close_msg(JCR *jcr)
    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; ) {
@@ -439,20 +545,39 @@ void close_msg(JCR *jcr)
             if (!d->fd) {
                break;
             }
-            if (
-                (d->dest_code == MD_MAIL_ON_ERROR && jcr &&
-                 jcr->JobStatus == JS_Terminated) 
-                ||
-                (d->dest_code == MD_MAIL_ON_SUCCESS && jcr &&
-                 jcr->JobStatus == JS_ErrorTerminated)
-                ){
-               goto rem_temp_file;
+
+            switch (d->dest_code) {
+            case MD_MAIL_ON_ERROR:
+               if (jcr) {
+                  switch (jcr->JobStatus) {
+                  case JS_Terminated:
+                  case JS_Warnings:
+                     goto rem_temp_file;
+                  default:
+                     break;
+                  }
+               }
+               break;
+            case MD_MAIL_ON_SUCCESS:
+               if (jcr) {
+                  switch (jcr->JobStatus) {
+                  case JS_Terminated:
+                  case JS_Warnings:
+                     break;
+                  default:
+                     goto rem_temp_file;
+                  }
+               }
+               break;
+            default:
+               break;
             }
 
             if (!(bpipe=open_mail_pipe(jcr, cmd, d))) {
                Pmsg0(000, _("open mail pipe failed.\n"));
                goto rem_temp_file;
             }
+
             Dmsg0(850, "Opened mail pipe\n");
             len = d->max_len+10;
             line = get_memory(len);
@@ -473,7 +598,7 @@ void close_msg(JCR *jcr)
             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);
                }
             }
 
@@ -482,18 +607,23 @@ void close_msg(JCR *jcr)
                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.bstrerror());
+               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);
-            d->fd = NULL;
-            unlink(d->mail_filename);
-            free_pool_memory(d->mail_filename);
-            d->mail_filename = NULL;
+            if (d->fd) {
+               fclose(d->fd);
+               d->fd = NULL;
+            }
+            if (d->mail_filename) {
+               /* Exclude spaces in 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:
@@ -509,7 +639,7 @@ rem_temp_file:
       free_msgs_res(msgs);
       msgs = NULL;
    } else {
-      V(mutex);
+      msgs->clear_closing();
    }
    Dmsg0(850, "===End close msg resource\n");
 }
@@ -580,19 +710,38 @@ static bool open_dest_file(JCR *jcr, DEST *d, const char *mode)
    d->fd = fopen(d->where, mode);
    if (!d->fd) {
       berrno be;
-      d->fd = stdout;
-      Qmsg2(jcr, M_ERROR, 0, _("fopen %s failed: ERR=%s\n"), d->where,
-            be.bstrerror());
-      d->fd = NULL;
+      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];
@@ -600,7 +749,7 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg)
     int len, dtlen;
     MSGS *msgs;
     BPIPE *bpipe;
-    char *mode;
+    const char *mode;
 
     Dmsg2(850, "Enter dispatch_msg type=%d msg=%s", type, msg);
 
@@ -608,7 +757,7 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *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);
@@ -616,6 +765,7 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg)
     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);
@@ -629,21 +779,40 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg)
        return;
     }
 
+    /* For serious errors make sure message is printed or logged */
     if (type == M_ABORT || type == M_ERROR_TERM) {
        fputs(dt, stdout);
-       fputs(msg, stdout);         /* print this here to INSURE that it is printed */
+       fputs(msg, stdout);
        fflush(stdout);
+       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)) {
           switch (d->dest_code) {
@@ -657,13 +826,17 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg)
                    POOLMEM *esc_msg = get_pool_memory(PM_MESSAGE);
                    
                    int len = strlen(msg) + 1;
-                   esc_msg = check_pool_memory_size(esc_msg, len*2+1);
-                   p_sql_escape(jcr, jcr->db, esc_msg, msg, len);
-
-                   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);
-                   p_sql_query(jcr, cmd);
+                   esc_msg = check_pool_memory_size(esc_msg, len * 2 + 1);
+                   if (p_sql_escape(jcr, jcr->db, esc_msg, msg, len)) {
+                      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);
+                      if (!p_sql_query(jcr, cmd)) {
+                         delivery_error(_("Msg delivery error: Unable to store data in database.\n"));
+                      }
+                   } else {
+                      delivery_error(_("Msg delivery error: Unable to store data in database.\n"));
+                   }
                    
                    free_pool_memory(cmd);
                    free_pool_memory(esc_msg);
@@ -700,7 +873,7 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg)
                 /*
                  * 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);
@@ -714,7 +887,7 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *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.bstrerror());
                    }
@@ -725,17 +898,20 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg)
              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,
+                      delivery_error(_("Msg delivery error: fopen %s failed: ERR=%s\n"), name,
                             be.bstrerror());
-                      d->fd = NULL;
                       free_pool_memory(name);
+                      msgs->clear_in_use();
                       break;
                    }
                    d->mail_filename = name;
@@ -746,6 +922,7 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg)
                    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);
@@ -755,7 +932,12 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg)
                 Dmsg1(850, "FILE for following msg: %s", msg);
                 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);
@@ -769,12 +951,15 @@ send_to_file:
                       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:
@@ -800,27 +985,52 @@ send_to_file:
 
 /*********************************************************************
  *
- *  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);
 }
 
 /*********************************************************************
@@ -840,6 +1050,7 @@ d_msg(const char *file, int line, int level, const char *fmt,...)
     int       len;
     va_list   arg_ptr;
     bool      details = true;
+    utime_t   mtime;
 
     if (level < 0) {
        details = false;
@@ -847,10 +1058,19 @@ d_msg(const char *file, int line, int level, const char *fmt,...)
     }
 
     if (level <= debug_level) {
+       if (dbg_timestamp) {
+          mtime = time(NULL);
+          bstrftimes(buf, sizeof(buf), mtime);
+          len = strlen(buf);
+          buf[len++] = ' ';
+          buf[len] = 0;
+          pt_out(buf);
+       }
+    
 #ifdef FULL_LOCATION
        if (details) {
-          len = bsnprintf(buf, sizeof(buf), "%s: %s:%d jid=%u ", 
-                my_name, get_basename(file), line, get_jobid_from_tid());
+          len = bsnprintf(buf, sizeof(buf), "%s: %s:%d-%u ", 
+                my_name, get_basename(file), line, get_jobid_from_tsd());
        } else {
           len = 0;
        }
@@ -861,27 +1081,7 @@ d_msg(const char *file, int line, int level, const char *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/%s.trace", working_directory ? working_directory : ".", my_name);
-             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);
-          fflush(stdout);
-       }
+       pt_out(buf);
     }
 }
 
@@ -905,6 +1105,20 @@ void set_trace(int trace_flag)
    }
 }
 
+void set_hangup(int hangup_value)
+{
+   if (hangup_value < 0) {
+      return;
+   } else {
+      hangup = hangup_value;
+   }
+}
+
+int get_hangup(void)
+{
+   return hangup;
+}
+
 bool get_trace(void)
 {
    return trace;
@@ -926,18 +1140,20 @@ p_msg(const char *file, int line, int level, const char *fmt,...)
 
 #ifdef FULL_LOCATION
     if (level >= 0) {
-       len = bsnprintf(buf, sizeof(buf), "%s: %s:%d ", my_name, get_basename(file), line);
+       len = bsnprintf(buf, sizeof(buf), "%s: %s:%d-%u ", 
+             my_name, get_basename(file), line, get_jobid_from_tsd());
     } else {
        len = 0;
     }
 #else
-    len = 0;
+       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);
-    fflush(stdout);
+
+    pt_out(buf);     
 }
 
 
@@ -989,8 +1205,6 @@ t_msg(const char *file, int line, int level, const char *fmt,...)
    }
 }
 
-
-
 /* *********************************************************
  *
  * print an error message
@@ -1064,13 +1278,13 @@ e_msg(const char *file, int line, int type, int level, const char *fmt,...)
  *
  */
 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);
@@ -1089,18 +1303,30 @@ Jmsg(JCR *jcr, int type, time_t mtime, const char *fmt,...)
        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.
@@ -1118,25 +1344,32 @@ Jmsg(JCR *jcr, int type, time_t mtime, const char *fmt,...)
        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;
     }
 
@@ -1161,7 +1394,7 @@ Jmsg(JCR *jcr, int type, time_t mtime, const char *fmt,...)
  * 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;
@@ -1295,8 +1528,6 @@ int Mmsg(POOL_MEM &pool_buf, const char *fmt, ...)
 }
 
 
-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)
@@ -1304,7 +1535,7 @@ static pthread_mutex_t msg_queue_mutex = PTHREAD_MUTEX_INITIALIZER;
  *  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;
@@ -1328,16 +1559,18 @@ void Qmsg(JCR *jcr, int type, time_t mtime, const char *fmt,...)
    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 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);
 }
@@ -1348,19 +1581,18 @@ void Qmsg(JCR *jcr, int type, time_t mtime, const char *fmt,...)
 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);
 }
 
 
@@ -1368,14 +1600,14 @@ bail_out:
  * 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;