]> git.sur5r.net Git - bacula/bacula/blobdiff - bacula/src/lib/message.c
Add jobid to Pmsg output
[bacula/bacula] / bacula / src / lib / message.c
index 5791f6b51b95a43be565ad351630d7e48dd24029..53f72c98a33195847992e3fa152bfed5ae5c32db 100644 (file)
@@ -1,12 +1,12 @@
 /*
    Bacula® - The Network Backup Solution
 
-   Copyright (C) 2000-2009 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.
 
@@ -15,7 +15,7 @@
    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 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
  *
  */
@@ -35,8 +40,8 @@
 #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 */
 
@@ -51,8 +56,10 @@ 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 */
-char host_name[50];                   /* host machine name */
+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;
@@ -67,6 +74,9 @@ 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 */
@@ -78,12 +88,92 @@ static bool trace = true;
 #else
 static bool trace = false;
 #endif
+static int hangup = 0;
 
 /* Constants */
 const char *host_os = HOST_OS;
 const char *distname = DISTNAME;
 const char *distver = DISTVER;
 
+/*
+ * 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);
+}
+
+void MSGS::unlock()
+{
+   V(fides_mutex);
+}
+
+/*
+ * 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))
 {
@@ -123,7 +213,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;
          }
@@ -155,12 +245,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)
 {
@@ -258,6 +342,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);
 
 }
@@ -397,7 +482,7 @@ static BPIPE *open_mail_pipe(JCR *jcr, POOLMEM *&cmd, DEST *d)
       }
    } 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());
    }
    return bpipe;
@@ -426,7 +511,20 @@ void close_msg(JCR *jcr)
    if (msgs == NULL) {
       return;
    }
-   P(fides_mutex);
+
+   /* 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; ) {
@@ -446,20 +544,39 @@ void close_msg(JCR *jcr)
             if (!d->fd) {
                break;
             }
-            if (
-                (d->dest_code == MD_MAIL_ON_ERROR && jcr &&
-                  (jcr->JobStatus == JS_Terminated || jcr->JobStatus == JS_Warnings)) 
-                ||
-                (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);
@@ -480,7 +597,7 @@ void close_msg(JCR *jcr)
             if (msgs != daemon_msgs) {
                /* read what mail prog returned -- should be nothing */
                while (fgets(line, len, bpipe->rfd)) {
-                  Qmsg1(jcr, M_INFO, 0, _("Mail prog: %s"), line);
+                  delivery_error(_("Mail prog: %s"), line);
                }
             }
 
@@ -489,18 +606,23 @@ void close_msg(JCR *jcr)
                berrno be;
                be.set_errno(stat);
                Dmsg1(850, "Calling emsg. CMD=%s\n", cmd);
-               Qmsg2(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:
@@ -510,12 +632,13 @@ rem_temp_file:
       }
       d = d->next;                    /* point to next buffer */
    }
-   V(fides_mutex);
    free_pool_memory(cmd);
    Dmsg0(850, "Done walking message chain.\n");
    if (jcr) {
       free_msgs_res(msgs);
       msgs = NULL;
+   } else {
+      msgs->clear_closing();
    }
    Dmsg0(850, "===End close msg resource\n");
 }
@@ -586,14 +709,34 @@ 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
  */
@@ -635,11 +778,14 @@ void dispatch_message(JCR *jcr, int type, utime_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);
-       syslog(LOG_DAEMON|LOG_ERR, "%s", msg);
+       if (type == M_ABORT) {
+          syslog(LOG_DAEMON|LOG_ERR, "%s", msg);
+       }
     }
 
 
@@ -654,6 +800,18 @@ void dispatch_message(JCR *jcr, int type, utime_t mtime, char *msg)
     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) {
@@ -667,13 +825,17 @@ void dispatch_message(JCR *jcr, int type, utime_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);
@@ -710,7 +872,7 @@ void dispatch_message(JCR *jcr, int type, utime_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);
@@ -724,7 +886,7 @@ void dispatch_message(JCR *jcr, int type, utime_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());
                    }
@@ -735,19 +897,20 @@ void dispatch_message(JCR *jcr, int type, utime_t mtime, char *msg)
              case MD_MAIL_ON_ERROR:
              case MD_MAIL_ON_SUCCESS:
                 Dmsg1(850, "MAIL for following msg: %s", msg);
-                P(fides_mutex);
+                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);
-                      V(fides_mutex);
+                      msgs->clear_in_use();
                       break;
                    }
                    d->mail_filename = name;
@@ -758,7 +921,7 @@ void dispatch_message(JCR *jcr, int type, utime_t mtime, char *msg)
                    d->max_len = len;      /* keep max line length */
                 }
                 fputs(msg, d->fd);
-                V(fides_mutex);
+                msgs->clear_in_use();
                 break;
              case MD_APPEND:
                 Dmsg1(850, "APPEND for following msg: %s", msg);
@@ -768,9 +931,12 @@ void dispatch_message(JCR *jcr, int type, utime_t mtime, char *msg)
                 Dmsg1(850, "FILE for following msg: %s", msg);
                 mode = "w+b";
 send_to_file:
-                P(fides_mutex);
+                if (msgs->is_closing()) {
+                   break;
+                }
+                msgs->set_in_use();
                 if (!d->fd && !open_dest_file(jcr, d, mode)) {
-                   V(fides_mutex);
+                   msgs->clear_in_use();
                    break;
                 }
                 fputs(dt, d->fd);
@@ -784,7 +950,7 @@ send_to_file:
                       fputs(msg, d->fd);
                    }
                 }
-                V(fides_mutex);
+                msgs->clear_in_use();
                 break;
              case MD_DIRECTOR:
                 Dmsg1(850, "DIRECTOR for following msg: %s", msg);
@@ -818,27 +984,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);
 }
 
 /*********************************************************************
@@ -872,7 +1063,7 @@ d_msg(const char *file, int line, int level, const char *fmt,...)
           len = strlen(buf);
           buf[len++] = ' ';
           buf[len] = 0;
-          fputs(buf, stdout);
+          pt_out(buf);
        }
     
 #ifdef FULL_LOCATION
@@ -889,27 +1080,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);
     }
 }
 
@@ -933,6 +1104,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;
@@ -954,18 +1139,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);     
 }
 
 
@@ -1115,11 +1302,24 @@ Jmsg(JCR *jcr, int type, utime_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;
     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;
        JobId = jcr->JobId;
     }
@@ -1145,7 +1345,10 @@ Jmsg(JCR *jcr, int type, utime_t mtime, const char *fmt,...)
     case M_FATAL:
        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:
@@ -1403,7 +1606,7 @@ void q_msg(const char *file, int line, JCR *jcr, int type, utime_t mtime, const
    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;