When in daemon mode, close stderr after the configuration file has been
[privoxy.git] / errlog.c
index 4a3cfe7..1e65865 100644 (file)
--- a/errlog.c
+++ b/errlog.c
@@ -1,4 +1,4 @@
-const char errlog_rcs[] = "$Id: errlog.c,v 1.39 2002/04/03 17:15:27 gliptak Exp $";
+const char errlog_rcs[] = "$Id: errlog.c,v 1.54 2007/09/22 16:15:34 fabiankeil Exp $";
 /*********************************************************************
  *
  * File        :  $Source: /cvsroot/ijbswa/current/errlog.c,v $
@@ -6,7 +6,7 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.39 2002/04/03 17:15:27 gliptak Exp
  * Purpose     :  Log errors to a designated destination in an elegant,
  *                printf-like fashion.
  *
- * Copyright   :  Written by and Copyright (C) 2001 the SourceForge
+ * Copyright   :  Written by and Copyright (C) 2001-2007 the SourceForge
  *                Privoxy team. http://www.privoxy.org/
  *
  *                Based on the Internet Junkbuster originally written
@@ -33,6 +33,82 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.39 2002/04/03 17:15:27 gliptak Exp
  *
  * Revisions   :
  *    $Log: errlog.c,v $
+ *    Revision 1.54  2007/09/22 16:15:34  fabiankeil
+ *    - Let it compile with pcc.
+ *    - Move our includes below system includes to prevent macro conflicts.
+ *
+ *    Revision 1.53  2007/08/05 13:53:14  fabiankeil
+ *    #1763173 from Stefan Huehner: declare some more functions
+ *    static and use void instead of empty parameter lists.
+ *
+ *    Revision 1.52  2007/07/14 07:28:47  fabiankeil
+ *    Add translation function for JB_ERR_FOO codes.
+ *
+ *    Revision 1.51  2007/05/11 11:51:34  fabiankeil
+ *    Fix a type mismatch warning.
+ *
+ *    Revision 1.50  2007/04/11 10:55:44  fabiankeil
+ *    Enforce some assertions that could be triggered
+ *    on mingw32 and other systems where we use threads
+ *    but no locks.
+ *
+ *    Revision 1.49  2007/04/08 16:44:15  fabiankeil
+ *    We need <sys/time.h> for gettimeofday(), not <time.h>.
+ *
+ *    Revision 1.48  2007/03/31 13:33:28  fabiankeil
+ *    Add alternative log_error() with timestamps
+ *    that contain milliseconds and without using
+ *    strcpy(), strcat() or sprintf().
+ *
+ *    Revision 1.47  2006/11/28 15:25:15  fabiankeil
+ *    Only unlink the pidfile if it's actually used.
+ *
+ *    Revision 1.46  2006/11/13 19:05:51  fabiankeil
+ *    Make pthread mutex locking more generic. Instead of
+ *    checking for OSX and OpenBSD, check for FEATURE_PTHREAD
+ *    and use mutex locking unless there is an _r function
+ *    available. Better safe than sorry.
+ *
+ *    Fixes "./configure --disable-pthread" and should result
+ *    in less threading-related problems on pthread-using platforms,
+ *    but it still doesn't fix BR#1122404.
+ *
+ *    Revision 1.45  2006/08/21 11:15:54  david__schmidt
+ *    MS Visual C++ build updates
+ *
+ *    Revision 1.44  2006/08/18 16:03:16  david__schmidt
+ *    Tweak for OS/2 build happiness.
+ *
+ *    Revision 1.43  2006/08/03 02:46:41  david__schmidt
+ *    Incorporate Fabian Keil's patch work:
+ *    http://www.fabiankeil.de/sourcecode/privoxy/
+ *
+ *    Revision 1.42  2006/07/18 14:48:46  david__schmidt
+ *    Reorganizing the repository: swapping out what was HEAD (the old 3.1 branch)
+ *    with what was really the latest development (the v_3_0_branch branch)
+ *
+ *    Revision 1.40.2.4  2005/04/03 20:10:50  david__schmidt
+ *    Thanks to Jindrich Makovicka for a race condition fix for the log
+ *    file.  The race condition remains for non-pthread implementations.
+ *    Reference patch #1175720.
+ *
+ *    Revision 1.40.2.3  2003/03/07 03:41:04  david__schmidt
+ *    Wrapping all *_r functions (the non-_r versions of them) with mutex 
+ *    semaphores for OSX.  Hopefully this will take care of all of those pesky
+ *    crash reports.
+ *
+ *    Revision 1.40.2.2  2002/09/28 00:30:57  david__schmidt
+ *    Update error logging to give sane values for thread IDs on Mach kernels.
+ *    It's still a hack, but at least it looks farily normal.  We print the
+ *    absolute value of the first 4 bytes of the pthread_t modded with 1000.
+ *
+ *    Revision 1.40.2.1  2002/09/25 12:47:42  oes
+ *    Make log_error safe against NULL string arguments
+ *
+ *    Revision 1.40  2002/05/22 01:27:27  david__schmidt
+ *
+ *    Add os2_socket_strerr mirroring w32_socket_strerr.
+ *
  *    Revision 1.39  2002/04/03 17:15:27  gliptak
  *    zero padding thread ids in log
  *
@@ -214,23 +290,26 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.39 2002/04/03 17:15:27 gliptak Exp
  *********************************************************************/
 \f
 
-#include "config.h"
-#include "miscutil.h"
-
 #include <stdlib.h>
 #include <stdio.h>
 #include <stdarg.h>
 #include <string.h>
 
+#include "config.h"
+#include "miscutil.h"
+
+#if defined(HAVE_STRLCPY) && defined(HAVE_GETTIMEOFDAY)
+#define USE_NEW_LOG_ERROR
+/* For gettimeofday() */
+#include <sys/time.h>
+#endif /* defined(HAVE_STRLCPY) && defined(HAVE_GETTIMEOFDAY) */
+
 #if !defined(_WIN32) && !defined(__OS2__)
 #include <unistd.h>
 #endif /* !defined(_WIN32) && !defined(__OS2__) */
 
 #include <errno.h>
 #include <assert.h>
-#ifdef FEATURE_PTHREAD
-#include <pthread.h>
-#endif /* def FEATURE_PTHREAD */
 
 #ifdef _WIN32
 #ifndef STRICT
@@ -241,6 +320,9 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.39 2002/04/03 17:15:27 gliptak Exp
 #include "w32log.h"
 #endif /* ndef _WIN_CONSOLE */
 #endif /* def _WIN32 */
+#ifdef _MSC_VER
+#define inline __inline
+#endif /* def _MSC_VER */
 
 #ifdef __OS2__
 #include <sys/socket.h> /* For sock_errno */
@@ -266,7 +348,7 @@ const char errlog_h_rcs[] = ERRLOG_H_VERSION;
 static FILE *logfp = NULL;
 
 /* logging detail level.  */
-static int debug = (LOG_LEVEL_FATAL | LOG_LEVEL_ERROR | LOG_LEVEL_INFO);  
+int debug = (LOG_LEVEL_FATAL | LOG_LEVEL_ERROR | LOG_LEVEL_INFO);  
 
 /* static functions */
 static void fatal_error(const char * error_message);
@@ -277,6 +359,35 @@ static char *w32_socket_strerr(int errcode, char *tmp_buf);
 static char *os2_socket_strerr(int errcode, char *tmp_buf);
 #endif
 
+#ifdef FEATURE_PTHREAD
+static inline void lock_logfile(void)
+{
+   pthread_mutex_lock(&log_mutex);
+}
+static inline void unlock_logfile(void)
+{
+   pthread_mutex_unlock(&log_mutex);
+}
+static inline void lock_loginit(void)
+{
+   pthread_mutex_lock(&log_init_mutex);
+}
+static inline void unlock_loginit(void)
+{
+   pthread_mutex_unlock(&log_init_mutex);
+}
+#else /* ! FEATURE_PTHREAD */
+/*
+ * FIXME we need a cross-platform locking mechanism.
+ * The locking/unlocking functions below should be 
+ * fleshed out for non-pthread implementations.
+ */ 
+static inline void lock_logfile() {}
+static inline void unlock_logfile() {}
+static inline void lock_loginit() {}
+static inline void unlock_loginit() {}
+#endif
+
 /*********************************************************************
  *
  * Function    :  fatal_error
@@ -301,23 +412,118 @@ static void fatal_error(const char * error_message)
    TermLogWindow();
 
 #else /* if !defined(_WIN32) || defined(_WIN_CONSOLE) */
-   fputs(error_message, stderr);
+   fputs(error_message, logfp);
 #endif /* defined(_WIN32) && !defined(_WIN_CONSOLE) */
 
 #if defined(unix)
-   unlink(pidfile);
+   if (pidfile)
+   {
+      unlink(pidfile);
+   }
 #endif /* unix */
 
    exit(1);
 }
 
 
+/*********************************************************************
+ *
+ * Function    :  show_version
+ *
+ * Description :  Logs the Privoxy version and the program name.
+ *
+ * Parameters  :
+ *          1  :  prog_name = The program name.
+ *
+ * Returns     :  Nothing.
+ *
+ *********************************************************************/
+static void show_version(const char *prog_name)
+{
+   log_error(LOG_LEVEL_INFO, "Privoxy version " VERSION);
+   if (prog_name != NULL)
+   {
+      log_error(LOG_LEVEL_INFO, "Program name: %s", prog_name);
+   }
+}
+
+
+/*********************************************************************
+ *
+ * Function    :  init_log_module
+ *
+ * Description :  Initializes the logging module to log to stderr.
+ *                Can only be called while stderr hasn't been closed
+ *                yet and is only supposed to be called once.
+ *
+ * Parameters  :
+ *          1  :  prog_name = The program name.
+ *
+ * Returns     :  Nothing.
+ *
+ *********************************************************************/
+void init_log_module(const char *prog_name)
+{
+   lock_logfile();
+   logfp = stderr;
+   unlock_logfile();
+   set_debug_level(debug);
+   show_version(prog_name);
+}
+
+
+/*********************************************************************
+ *
+ * Function    :  set_debug_level
+ *
+ * Description :  Sets the debug level to the provided value
+ *                plus LOG_LEVEL_MINIMUM.
+ *
+ *                XXX: we should only use the LOG_LEVEL_MINIMUM
+ *                until the frist time the configuration file has
+ *                been parsed.
+ *                
+ * Parameters  :  1: debug_level = The debug level to set.
+ *
+ * Returns     :  Nothing.
+ *
+ *********************************************************************/
+void set_debug_level(int debug_level)
+{
+   debug = debug_level | LOG_LEVEL_MINIMUM;
+}
+
+
+/*********************************************************************
+ *
+ * Function    :  disable_logging
+ *
+ * Description :  Disables logging.
+ *                
+ * Parameters  :  None.
+ *
+ * Returns     :  Nothing.
+ *
+ *********************************************************************/
+void disable_logging(void)
+{
+   lock_logfile();
+   if (logfp != NULL)
+   {
+      fclose(logfp);
+   }
+   logfp = NULL;
+   unlock_logfile();
+}
+
+
 /*********************************************************************
  *
  * Function    :  init_error_log
  *
- * Description :  Initializes the logging module.  Must call before
- *                calling log_error.
+ * Description :  Initializes the logging module to log to a file.
+ *
+ *                XXX: should be renamed.
  *
  * Parameters  :
  *          1  :  prog_name  = The program name.
@@ -327,46 +533,615 @@ static void fatal_error(const char * error_message)
  * Returns     :  N/A
  *
  *********************************************************************/
-void init_error_log(const char *prog_name, const char *logfname, int debuglevel)
+void init_error_log(const char *prog_name, const char *logfname)
 {
    FILE *fp;
 
-   /* FIXME RACE HAZARD: should start critical section error_log_use here */
+   assert(NULL != logfname);
 
-   /* set the logging detail level */
-   debug = debuglevel | LOG_LEVEL_MINIMUM;
+   lock_loginit();
+   lock_logfile();
 
    if ((logfp != NULL) && (logfp != stderr))
    {
-      log_error(LOG_LEVEL_INFO, "(Re-)Open logfile %s", logfname ? logfname : "none");
-      fclose(logfp);
+      log_error(LOG_LEVEL_INFO, "(Re-)Open logfile \'%s\'", logfname ? logfname : "none");
    }
-   logfp = stderr;
 
    /* set the designated log file */
-   if( logfname )
+   fp = fopen(logfname, "a");
+   if (NULL == fp)
+   {
+      log_error(LOG_LEVEL_FATAL, "init_error_log(): can't open logfile: \'%s\'", logfname);
+   }
+
+   /* set logging to be completely unbuffered */
+   setbuf(fp, NULL);
+
+   if (logfp != NULL)
+   {
+      fclose(logfp);
+   }
+   logfp = fp;
+   unlock_logfile();
+
+   show_version(prog_name);
+
+   unlock_loginit();
+
+} /* init_error_log */
+
+
+#if defined(USE_NEW_LOG_ERROR)
+/*
+ * Use an alternative log_error version and its helper functions.
+ *
+ * The code is mostly copied from the old log_error
+ * function but it's divided into multiple functions,
+ * doesn't use strcpy, strcat or sprintf and compiles
+ * with gcc43 without warnings (on FreeBSD that is).
+ *
+ * It should behave like the old log_error function with
+ * two exceptions:
+ *
+ * - too long format strings are logged truncated instead
+ *   of completely replaced with the truncation warning,
+ * - its time stamps contain milliseconds.
+ */
+
+/*********************************************************************
+ *
+ * Function    :  get_thread_id
+ *
+ * Description :  Returns a number that is different for each thread.
+ *
+ *                XXX: Should be moved elsewhere (miscutil.c?)
+ *                
+ * Parameters  :  None
+ *
+ * Returns     :  thread_id
+ *
+ *********************************************************************/
+static long get_thread_id(void)
+{
+   long this_thread = 1;  /* was: pthread_t this_thread;*/
+
+#ifdef __OS2__
+   PTIB     ptib;
+   APIRET   ulrc; /* XXX: I have no clue what this does */
+#endif /* __OS2__ */
+
+   /* FIXME get current thread id */
+#ifdef FEATURE_PTHREAD
+   this_thread = (long)pthread_self();
+#ifdef __MACH__
+   /*
+    * Mac OSX (and perhaps other Mach instances) doesn't have a debuggable
+    * value at the first 4 bytes of pthread_self()'s return value, a pthread_t.
+    * pthread_t is supposed to be opaque... but it's fairly random, though, so
+    * we make it mostly presentable.
+    */
+   this_thread = abs(this_thread % 1000);
+#endif /* def __MACH__ */
+#elif defined(_WIN32)
+   this_thread = GetCurrentThreadId();
+#elif defined(__OS2__)
+   ulrc = DosGetInfoBlocks(&ptib, NULL);
+   if (ulrc == 0)
+     this_thread = ptib -> tib_ptib2 -> tib2_ultid;
+#endif /* def FEATURE_PTHREAD */
+
+   return this_thread;
+}
+
+
+/*********************************************************************
+ *
+ * Function    :  get_log_timestamp
+ *
+ * Description :  Generates the time stamp for the log message prefix.
+ *
+ * Parameters  :
+ *          1  :  buffer = Storage buffer
+ *          2  :  buffer_size = Size of storage buffer
+ *
+ * Returns     :  Number of written characters or 0 for error.
+ *
+ *********************************************************************/
+static inline size_t get_log_timestamp(char *buffer, size_t buffer_size)
+{
+   size_t length;
+   time_t now; 
+   struct tm tm_now;
+   struct timeval tv_now; /* XXX: stupid name */
+   long msecs;
+   int msecs_length = 0;
+
+   gettimeofday(&tv_now, NULL);
+   msecs = tv_now.tv_usec / 1000;
+
+   time(&now);
+
+#ifdef HAVE_LOCALTIME_R
+   tm_now = *localtime_r(&now, &tm_now);
+#elif FEATURE_PTHREAD
+   pthread_mutex_lock(&localtime_mutex);
+   tm_now = *localtime(&now); 
+   pthread_mutex_unlock(&localtime_mutex);
+#else
+   tm_now = *localtime(&now); 
+#endif
+
+   length = strftime(buffer, buffer_size, "%b %d %H:%M:%S", &tm_now);
+   if (length > 0);
+   {
+      msecs_length = snprintf(buffer+length, buffer_size - length, ".%.3ld", msecs);               
+   }
+   if (msecs_length > 0)
+   {
+      length += (size_t)msecs_length;
+   }
+   else
    {
-      if( NULL == (fp = fopen(logfname, "a")) )
+      length = 0;
+   }
+
+   return length;
+}
+
+
+/*********************************************************************
+ *
+ * Function    :  get_clf_timestamp
+ *
+ * Description :  Generates a Common Log Format time string.
+ *
+ * Parameters  :
+ *          1  :  buffer = Storage buffer
+ *          2  :  buffer_size = Size of storage buffer
+ *
+ * Returns     :  Number of written characters or 0 for error.
+ *
+ *********************************************************************/
+static inline size_t get_clf_timestamp(char *buffer, size_t buffer_size)
+{
+   /*
+    * Complex because not all OSs have tm_gmtoff or
+    * the %z field in strftime()
+    */
+   time_t now;
+   struct tm *tm_now; 
+   struct tm gmt;
+#ifdef HAVE_LOCALTIME_R
+   struct tm dummy;
+#endif
+   int days, hrs, mins;
+   size_t length;
+   int tz_length = 0;
+
+   time (&now); 
+#ifdef HAVE_GMTIME_R
+   gmt = *gmtime_r(&now, &gmt);
+#elif FEATURE_PTHREAD
+   pthread_mutex_lock(&gmtime_mutex);
+   gmt = *gmtime(&now);
+   pthread_mutex_unlock(&gmtime_mutex);
+#else
+   gmt = *gmtime(&now);
+#endif
+#ifdef HAVE_LOCALTIME_R
+   tm_now = localtime_r(&now, &dummy);
+#elif FEATURE_PTHREAD
+   pthread_mutex_lock(&localtime_mutex);
+   tm_now = localtime(&now); 
+   pthread_mutex_unlock(&localtime_mutex);
+#else
+   tm_now = localtime(&now); 
+#endif
+   days = tm_now->tm_yday - gmt.tm_yday; 
+   hrs = ((days < -1 ? 24 : 1 < days ? -24 : days * 24) + tm_now->tm_hour - gmt.tm_hour); 
+   mins = hrs * 60 + tm_now->tm_min - gmt.tm_min; 
+
+   length = strftime(buffer, buffer_size, "%d/%b/%Y:%H:%M:%S ", tm_now);
+
+   if (length > 0);
+   {
+      tz_length = snprintf(buffer+length, buffer_size-length,
+                     "%+03d%02d", mins / 60, abs(mins) % 60);
+   }
+   if (tz_length > 0)
+   {
+      length += (size_t)tz_length;
+   }
+   else
+   {
+      length = 0;
+   }
+
+   return length;
+}
+
+
+/*********************************************************************
+ *
+ * Function    :  get_log_level_string
+ *
+ * Description :  Translates a numerical loglevel into a string.
+ *
+ * Parameters  :  
+ *          1  :  loglevel = LOG_LEVEL_FOO
+ *
+ * Returns     :  Log level string.
+ *
+ *********************************************************************/
+static inline const char *get_log_level_string(int loglevel)
+{
+   char *log_level_string = NULL;
+
+   assert(0 < loglevel);
+
+   switch (loglevel)
+   {
+      case LOG_LEVEL_ERROR:
+         log_level_string = "Error";
+         break;
+      case LOG_LEVEL_FATAL:
+         log_level_string = "Fatal error";
+         break;
+      case LOG_LEVEL_GPC:
+         log_level_string = "Request";
+         break;
+      case LOG_LEVEL_CONNECT:
+         log_level_string = "Connect";
+         break;
+      case LOG_LEVEL_LOG:
+         log_level_string = "Writing";
+         break;
+      case LOG_LEVEL_HEADER:
+         log_level_string = "Header";
+         break;
+      case LOG_LEVEL_INFO:
+         log_level_string = "Info";
+         break;
+      case LOG_LEVEL_RE_FILTER:
+         log_level_string = "Re-Filter";
+         break;
+#ifdef FEATURE_FORCE_LOAD
+      case LOG_LEVEL_FORCE:
+         log_level_string = "Force";
+         break;
+#endif /* def FEATURE_FORCE_LOAD */
+#ifdef FEATURE_FAST_REDIRECTS
+      case LOG_LEVEL_REDIRECTS:
+         log_level_string = "Redirect";
+         break;
+#endif /* def FEATURE_FAST_REDIRECTS */
+      case LOG_LEVEL_DEANIMATE:
+         log_level_string = "Gif-Deanimate";
+         break;
+#ifdef FEATURE_KILL_POPUPS
+      case LOG_LEVEL_POPUPS:
+         log_level_string = "Kill-Popups";
+         break;
+#endif /* def FEATURE_KILL_POPUPS */
+      case LOG_LEVEL_CGI:
+         log_level_string = "CGI";
+         break;
+      default:
+         log_level_string = "Unknown log level";
+         break;
+   }
+   assert(NULL != log_level_string);
+
+   return log_level_string;
+}
+
+
+/*********************************************************************
+ *
+ * Function    :  log_error
+ *
+ * Description :  This is the error-reporting and logging function.
+ *
+ * Parameters  :
+ *          1  :  loglevel  = the type of message to be logged
+ *          2  :  fmt       = the main string we want logged, printf-like
+ *          3  :  ...       = arguments to be inserted in fmt (printf-like).
+ *
+ * Returns     :  N/A
+ *
+ *********************************************************************/
+void log_error(int loglevel, const char *fmt, ...)
+{
+   va_list ap;
+   char *outbuf = NULL;
+   static char *outbuf_save = NULL;
+   char tempbuf[BUFFER_SIZE];
+   size_t length = 0;
+   const char * src = fmt;
+   long thread_id;
+   char timestamp[30];
+   /*
+    * XXX: Make this a config option,
+    * why else do we allocate instead of using
+    * an array?
+    */
+   size_t log_buffer_size = BUFFER_SIZE;
+
+#if defined(_WIN32) && !defined(_WIN_CONSOLE)
+   /*
+    * Irrespective of debug setting, a GET/POST/CONNECT makes
+    * the taskbar icon animate.  (There is an option to disable
+    * this but checking that is handled inside LogShowActivity()).
+    */
+   if (loglevel == LOG_LEVEL_GPC)
+   {
+      LogShowActivity();
+   }
+#endif /* defined(_WIN32) && !defined(_WIN_CONSOLE) */
+
+   /*
+    * verify that the loglevel applies to current
+    * settings and that logging is enabled.
+    * Bail out otherwise.
+    */
+   if ((0 == (loglevel & debug)) || (logfp == NULL))
+   {
+      return;
+   }
+
+   thread_id = get_thread_id();
+   get_log_timestamp(timestamp, sizeof(timestamp));
+
+   /* protect the whole function because of the static buffer (outbuf) */
+   lock_logfile();
+
+   if (NULL == outbuf_save) 
+   {
+      outbuf_save = (char*)zalloc(log_buffer_size + 1); /* +1 for paranoia */
+      if (NULL == outbuf_save)
       {
-         log_error(LOG_LEVEL_FATAL, "init_error_log(): can't open logfile: %s", logfname);
+         snprintf(tempbuf, sizeof(tempbuf),
+            "%s Privoxy(%08lx) Fatal error: log_error() failed to allocate buffer memory.\n"
+            "\nExiting.", timestamp, thread_id);
+         assert(NULL != logfp);
+         fputs(tempbuf, logfp);
+         unlock_logfile();
+         fatal_error(tempbuf); /* Exit */
       }
+   }
+   outbuf = outbuf_save;
 
-      /* set logging to be completely unbuffered */
-      setbuf(fp, NULL);
+   /*
+    * Memsetting the whole buffer to zero (in theory)
+    * makes things easier later on.
+    */
+   memset(outbuf, 0, log_buffer_size);
 
-      logfp = fp;
+   /* Add prefix for everything but Common Log Format messages */
+   if (loglevel != LOG_LEVEL_CLF)
+   {
+      length = (size_t)snprintf(outbuf, log_buffer_size, "%s Privoxy(%08lx) %s: ",
+                                timestamp, thread_id, get_log_level_string(loglevel));
    }
 
-   log_error(LOG_LEVEL_INFO, "Privoxy version " VERSION);
-   if (prog_name != NULL)
+   /* get ready to scan var. args. */
+   va_start(ap, fmt);
+
+   /* build formatted message from fmt and var-args */
+   while ((*src) && (length < log_buffer_size-2))
    {
-      log_error(LOG_LEVEL_INFO, "Program name: %s", prog_name);
+      const char *sval = NULL; /* %N string  */
+      int ival;                /* %N string length or an error code */
+      unsigned uval;           /* %u value */
+      long lval;               /* %l value */
+      unsigned long ulval;     /* %ul value */
+      char ch;
+      const char *format_string = tempbuf;
+
+      ch = *src++;
+      if (ch != '%')
+      {
+         outbuf[length++] = ch;
+         /*
+          * XXX: Only necessary on platforms which don't use pthread
+          * mutexes (mingw32 for example), where multiple threads can
+          * write to the buffer at the same time.
+          */
+         outbuf[length] = '\0';
+         continue;
+      }
+      outbuf[length] = '\0';
+      ch = *src++;
+      switch (ch) {
+         case '%':
+            tempbuf[0] = '%';
+            tempbuf[1] = '\0';
+            break;
+         case 'd':
+            ival = va_arg( ap, int );
+            snprintf(tempbuf, sizeof(tempbuf), "%d", ival);
+            break;
+         case 'u':
+            uval = va_arg( ap, unsigned );
+            snprintf(tempbuf, sizeof(tempbuf), "%u", uval);
+            break;
+         case 'l':
+            /* this is a modifier that must be followed by u or d */
+            ch = *src++;
+            if (ch == 'd')
+            {
+               lval = va_arg( ap, long );
+               snprintf(tempbuf, sizeof(tempbuf), "%ld", lval);
+            }
+            else if (ch == 'u')
+            {
+               ulval = va_arg( ap, unsigned long );
+               snprintf(tempbuf, sizeof(tempbuf), "%lu", ulval);
+            }
+            else
+            {
+               snprintf(tempbuf, sizeof(tempbuf), "Bad format string: \"%s\"", fmt);
+               loglevel = LOG_LEVEL_FATAL;
+            }
+            break;
+         case 'c':
+            /*
+             * Note that char paramaters are converted to int, so we need to
+             * pass "int" to va_arg.  (See K&R, 2nd ed, section A7.3.2, page 202)
+             */
+            tempbuf[0] = (char) va_arg(ap, int);
+            tempbuf[1] = '\0';
+            break;
+         case 's':
+            format_string = va_arg(ap, char *);
+            if (format_string == NULL)
+            {
+               format_string = "[null]";
+            }
+            break;
+         case 'N':
+            /*
+             * Non-standard: Print a counted unterminated string.
+             * Takes 2 parameters: int length, const char * string.
+             */
+            ival = va_arg(ap, int);
+            sval = va_arg(ap, char *);
+            if (sval == NULL)
+            {
+               format_string = "[null]";
+            }
+            else if (ival <= 0)
+            {
+               if (0 == ival)
+               {
+                  /* That's ok (but stupid) */
+                  tempbuf[0] = '\0';
+               }
+               else
+               {
+                  /*
+                   * That's not ok (and even more stupid)
+                   */
+                  assert(ival >= 0);
+                  format_string = "[counted string lenght < 0]";
+               }
+            }
+            else if (ival >= sizeof(tempbuf))
+            {
+               /*
+                * String is too long, copy as much as possible.
+                * It will be further truncated later.
+                */
+               memcpy(tempbuf, sval, sizeof(tempbuf)-1);
+               tempbuf[sizeof(tempbuf)-1] = '\0';
+            }
+            else
+            {
+               memcpy(tempbuf, sval, (size_t) ival);
+               tempbuf[ival] = '\0';
+            }
+            break;
+         case 'E':
+            /* Non-standard: Print error code from errno */
+#ifdef _WIN32
+            ival = WSAGetLastError();
+            format_string = w32_socket_strerr(ival, tempbuf);
+#elif __OS2__
+            ival = sock_errno();
+            if (ival != 0)
+            {
+               format_string = os2_socket_strerr(ival, tempbuf);
+            }
+            else
+            {
+               ival = errno;
+               format_string = strerror(ival);
+            }
+#else /* ifndef _WIN32 */
+            ival = errno; 
+#ifdef HAVE_STRERROR
+            format_string = strerror(ival);
+#else /* ifndef HAVE_STRERROR */
+            format_string = NULL;
+#endif /* ndef HAVE_STRERROR */
+            if (sval == NULL)
+            {
+               snprintf(tempbuf, sizeof(tempbuf), "(errno = %d)", ival);
+            }
+#endif /* ndef _WIN32 */
+            break;
+         case 'T':
+            /* Non-standard: Print a Common Log File timestamp */
+            get_clf_timestamp(tempbuf, sizeof(tempbuf));
+            break;
+         default:
+            snprintf(tempbuf, sizeof(tempbuf), "Bad format string: \"%s\"", fmt);
+            loglevel = LOG_LEVEL_FATAL;
+            break;
+      } /* switch( p ) */
+
+      assert(length < log_buffer_size);
+      length += strlcpy(outbuf + length, format_string, log_buffer_size - length);
+
+      if (length >= log_buffer_size-2)
+      {
+         static char warning[] = "... [too long, truncated]";
+
+         length = log_buffer_size - sizeof(warning) - 1;
+         length += strlcpy(outbuf + length, warning, log_buffer_size - length);
+         assert(length < log_buffer_size);
+
+         break;
+      }
+   } /* for( p ... ) */
+
+   /* done with var. args */
+   va_end(ap);
+
+   assert(length < log_buffer_size);
+   length += strlcpy(outbuf + length, "\n", log_buffer_size - length);
+
+   /* Some sanity checks */
+   if (!(length < log_buffer_size)
+    || !(outbuf[log_buffer_size-1] == '\0')
+    || !(outbuf[log_buffer_size] == '\0')
+      )
+   {
+      /* Repeat as assertions */
+      assert(length < log_buffer_size);
+      assert(outbuf[log_buffer_size-1] == '\0');
+      /*
+       * outbuf's real size is log_buffer_size+1,
+       * so while this looks like an off-by-one,
+       * we're only checking our paranoia byte.
+       */
+      assert(outbuf[log_buffer_size] == '\0');
+
+      snprintf(outbuf, log_buffer_size,
+         "%s Privoxy(%08lx) Fatal error: log_error()'s sanity checks failed. length: %d\n"
+         "Exiting.", timestamp, thread_id, (int)length);
+      loglevel = LOG_LEVEL_FATAL;
    }
 
-   /* FIXME RACE HAZARD: should end critical section error_log_use here */
+   assert(NULL != logfp);
 
-} /* init_error_log */
+   if (loglevel == LOG_LEVEL_FATAL)
+   {
+      fatal_error(outbuf_save);
+      /* Never get here */
+   }
+   fputs(outbuf_save, logfp);
+
+   unlock_logfile();
+
+#if defined(_WIN32) && !defined(_WIN_CONSOLE)
+   /* Write to display */
+   LogPutString(outbuf_save);
+#endif /* defined(_WIN32) && !defined(_WIN_CONSOLE) */
 
+}
+
+#else /* use traditional log_error version */
 
 /*********************************************************************
  *
@@ -382,12 +1157,12 @@ void init_error_log(const char *prog_name, const char *logfname, int debuglevel)
  * Returns     :  N/A
  *
  *********************************************************************/
-void log_error(int loglevel, char *fmt, ...)
+void log_error(int loglevel, const char *fmt, ...)
 {
    va_list ap;
    char *outbuf= NULL;
    static char *outbuf_save = NULL;
-   char * src = fmt;
+   const char * src = fmt;
    int outc = 0;
    long this_thread = 1;  /* was: pthread_t this_thread;*/
 #ifdef __OS2__
@@ -413,9 +1188,21 @@ void log_error(int loglevel, char *fmt, ...)
       return;
    }
 
+   /* protect the whole function because of the static buffer (outbuf) */
+   lock_logfile();
+
    /* FIXME get current thread id */
 #ifdef FEATURE_PTHREAD
    this_thread = (long)pthread_self();
+#ifdef __MACH__
+   /*
+    * Mac OSX (and perhaps other Mach instances) doesn't have a debuggable
+    * value at the first 4 bytes of pthread_self()'s return value, a pthread_t.
+    * pthread_t is supposed to be opaque... but it's fairly random, though, so
+    * we make it mostly presentable.
+    */
+   this_thread = abs(this_thread % 1000);
+#endif /* def __MACH__ */
 #elif defined(_WIN32)
    this_thread = GetCurrentThreadId();
 #elif defined(__OS2__)
@@ -427,7 +1214,10 @@ void log_error(int loglevel, char *fmt, ...)
    if ( !outbuf_save ) 
    {
       outbuf_save = outbuf = (char*)malloc(BUFFER_SIZE);
-      assert(outbuf);
+      if (NULL == outbuf_save)
+      {
+         fatal_error("Privoxy failed to allocate log buffer.");
+      }
    }
    outbuf = outbuf_save;
 
@@ -443,6 +1233,10 @@ void log_error(int loglevel, char *fmt, ...)
        time (&now);
 #ifdef HAVE_LOCALTIME_R
        tm_now = *localtime_r(&now, &tm_now);
+#elif FEATURE_PTHREAD
+       pthread_mutex_lock(&localtime_mutex);
+       tm_now = *localtime (&now); 
+       pthread_mutex_unlock(&localtime_mutex);
 #else
        tm_now = *localtime (&now); 
 #endif
@@ -452,41 +1246,41 @@ void log_error(int loglevel, char *fmt, ...)
    switch (loglevel)
    {
       case LOG_LEVEL_ERROR:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Error: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Error: ", this_thread);
          break;
       case LOG_LEVEL_FATAL:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Fatal error: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Fatal error: ", this_thread);
          break;
       case LOG_LEVEL_GPC:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Request: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Request: ", this_thread);
          break;
       case LOG_LEVEL_CONNECT:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Connect: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Connect: ", this_thread);
          break;
       case LOG_LEVEL_LOG:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Writing: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Writing: ", this_thread);
          break;
       case LOG_LEVEL_HEADER:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Header: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Header: ", this_thread);
          break;
       case LOG_LEVEL_INFO:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Info: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Info: ", this_thread);
          break;
       case LOG_LEVEL_RE_FILTER:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Re-Filter: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Re-Filter: ", this_thread);
          break;
 #ifdef FEATURE_FORCE_LOAD
       case LOG_LEVEL_FORCE:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Force: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Force: ", this_thread);
          break;
 #endif /* def FEATURE_FORCE_LOAD */
 #ifdef FEATURE_FAST_REDIRECTS
       case LOG_LEVEL_REDIRECTS:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Redirect: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Redirect: ", this_thread);
          break;
 #endif /* def FEATURE_FAST_REDIRECTS */
       case LOG_LEVEL_DEANIMATE:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Gif-Deanimate: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Gif-Deanimate: ", this_thread);
          break;
       case LOG_LEVEL_CLF:
          outbuf = outbuf_save;
@@ -495,14 +1289,14 @@ void log_error(int loglevel, char *fmt, ...)
          break;
 #ifdef FEATURE_KILL_POPUPS
       case LOG_LEVEL_POPUPS:
-         outc = sprintf(outbuf, "Privoxy(%05ld) Kill-Popups: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) Kill-Popups: ", this_thread);
          break;
 #endif /* def FEATURE_KILL_POPUPS */
       case LOG_LEVEL_CGI:
-         outc = sprintf(outbuf, "Privoxy(%05ld) CGI: ", this_thread);
+         outc = sprintf(outbuf, "Privoxy(%08lx) CGI: ", this_thread);
          break;
       default:
-         outc = sprintf(outbuf, "Privoxy(%05ld) UNKNOWN LOG TYPE(%d): ", this_thread, loglevel);
+         outc = sprintf(outbuf, "Privoxy(%08lx) UNKNOWN LOG TYPE(%d): ", this_thread, loglevel);
          break;
    }
    
@@ -577,16 +1371,14 @@ void log_error(int loglevel, char *fmt, ...)
             else
             {
                /* Error */
-               sprintf(outbuf, "Privoxy(%ld) Error: log_error(): Bad format string:\n"
+               sprintf(outbuf, "Privoxy(%08lx) Error: log_error(): Bad format string:\n"
                                "Format = \"%s\"\n"
                                "Exiting.", this_thread, fmt);
-               /* FIXME RACE HAZARD: should start critical section error_log_use here */
                if( !logfp )
                {
                   logfp = stderr;
                }
                fputs(outbuf, logfp);
-               /* FIXME RACE HAZARD: should end critical section error_log_use here */
                fatal_error(outbuf);
                /* Never get here */
                break;
@@ -609,6 +1401,10 @@ void log_error(int loglevel, char *fmt, ...)
             break;
          case 's':
             sval = va_arg( ap, char * );
+            if (sval == NULL)
+            {
+               sval = "[null]";
+            }
             oldoutc = outc;
             outc += strlen(sval);
             if (outc < BUFFER_SIZE-1) 
@@ -626,6 +1422,10 @@ void log_error(int loglevel, char *fmt, ...)
              */
             ival = va_arg( ap, int );
             sval = va_arg( ap, char * );
+            if (sval == NULL)
+            {
+               sval = "[null]";
+            }
             if (ival < 0)
             {
                ival = 0;
@@ -698,11 +1498,19 @@ void log_error(int loglevel, char *fmt, ...)
                time (&now); 
 #ifdef HAVE_GMTIME_R
                gmt = *gmtime_r(&now, &gmt);
+#elif FEATURE_PTHREAD
+               pthread_mutex_lock(&gmtime_mutex);
+               gmt = *gmtime(&now);
+               pthread_mutex_unlock(&gmtime_mutex);
 #else
                gmt = *gmtime(&now);
 #endif
 #ifdef HAVE_LOCALTIME_R
                tm_now = localtime_r(&now, &dummy);
+#elif FEATURE_PTHREAD
+               pthread_mutex_lock(&localtime_mutex);
+               tm_now = localtime (&now); 
+               pthread_mutex_unlock(&localtime_mutex);
 #else
                tm_now = localtime (&now); 
 #endif
@@ -724,16 +1532,15 @@ void log_error(int loglevel, char *fmt, ...)
             }
             break;
          default:
-            sprintf(outbuf, "Privoxy(%ld) Error: log_error(): Bad format string:\n"
+            sprintf(outbuf, "Privoxy(%08lx) Error: log_error(): Bad format string:\n"
                             "Format = \"%s\"\n"
                             "Exiting.", this_thread, fmt);
-            /* FIXME RACE HAZARD: should start critical section error_log_use here */
             if( !logfp )
             {
                logfp = stderr;
             }
             fputs(outbuf_save, logfp);
-            /* FIXME RACE HAZARD: should end critical section error_log_use here */
+            unlock_logfile();
             fatal_error(outbuf_save);
             /* Never get here */
             break;
@@ -770,8 +1577,6 @@ void log_error(int loglevel, char *fmt, ...)
       outbuf[outc] = '\0';
    }
 
-   /* FIXME RACE HAZARD: should start critical section error_log_use here */
-
    /* deal with glibc stupidity - it won't let you initialize logfp */
    if( !logfp )
    {
@@ -786,7 +1591,7 @@ void log_error(int loglevel, char *fmt, ...)
       /* Never get here */
    }
 
-   /* FIXME RACE HAZARD: should end critical section error_log_use here */
+   unlock_logfile();
 
 #if defined(_WIN32) && !defined(_WIN_CONSOLE)
    /* Write to display */
@@ -794,7 +1599,50 @@ void log_error(int loglevel, char *fmt, ...)
 #endif /* defined(_WIN32) && !defined(_WIN_CONSOLE) */
 
 }
+#endif /* defined(USE_NEW_LOG_ERROR) */
+
 
+/*********************************************************************
+ *
+ * Function    :  jb_err_to_string
+ *
+ * Description :  Translates JB_ERR_FOO codes into strings.
+ *
+ *                XXX: the type of error codes is jb_err
+ *                but the typedef'inition is currently not
+ *                visible to all files that include errlog.h.
+ *
+ * Parameters  :
+ *          1  :  error = a valid jb_err code
+ *
+ * Returns     :  A string with the jb_err translation
+ *
+ *********************************************************************/
+const char *jb_err_to_string(int error)
+{
+   switch (error)
+   {
+      case JB_ERR_OK:
+         return "Success, no error";
+      case JB_ERR_MEMORY:
+         return "Out of memory";
+      case JB_ERR_CGI_PARAMS:
+         return "Missing or corrupt CGI parameters";
+      case JB_ERR_FILE:
+         return "Error opening, reading or writing a file";
+      case JB_ERR_PARSE:
+         return "Parse error";
+      case JB_ERR_MODIFIED:
+         return "File has been modified outside of the CGI actions editor.";
+      case JB_ERR_COMPRESS:
+         return "(De)compression failure";
+      default:
+         assert(0);
+         return "Unknown error";
+   }
+   assert(0);
+   return "Internal error";
+}
 
 #ifdef _WIN32
 /*********************************************************************