Now that init_log_module() is called earlier, call show_version()
[privoxy.git] / errlog.c
index c6c9b28..138d7e9 100644 (file)
--- a/errlog.c
+++ b/errlog.c
@@ -1,4 +1,4 @@
-const char errlog_rcs[] = "$Id: errlog.c,v 1.62 2007/11/30 15:33:46 fabiankeil Exp $";
+const char errlog_rcs[] = "$Id: errlog.c,v 1.85 2009/02/06 17:51:38 fabiankeil Exp $";
 /*********************************************************************
  *
  * File        :  $Source: /cvsroot/ijbswa/current/errlog.c,v $
@@ -6,7 +6,7 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.62 2007/11/30 15:33:46 fabiankeil E
  * Purpose     :  Log errors to a designated destination in an elegant,
  *                printf-like fashion.
  *
- * Copyright   :  Written by and Copyright (C) 2001-2007 the SourceForge
+ * Copyright   :  Written by and Copyright (C) 2001-2009 the SourceForge
  *                Privoxy team. http://www.privoxy.org/
  *
  *                Based on the Internet Junkbuster originally written
@@ -33,6 +33,93 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.62 2007/11/30 15:33:46 fabiankeil E
  *
  * Revisions   :
  *    $Log: errlog.c,v $
+ *    Revision 1.85  2009/02/06 17:51:38  fabiankeil
+ *    Be prepared if I break the log module initialization again.
+ *
+ *    Revision 1.84  2008/12/14 15:46:22  fabiankeil
+ *    Give crunched requests their own log level.
+ *
+ *    Revision 1.83  2008/12/04 18:14:32  fabiankeil
+ *    Fix some cparser warnings.
+ *
+ *    Revision 1.82  2008/11/23 16:06:58  fabiankeil
+ *    Update a log message I missed in 1.80.
+ *
+ *    Revision 1.81  2008/11/23 15:59:27  fabiankeil
+ *    - Update copyright range.
+ *    - Remove stray line breaks in a log message
+ *      nobody is supposed to see anyway.
+ *
+ *    Revision 1.80  2008/11/23 15:49:49  fabiankeil
+ *    In log_error(), don't surround the thread id with "Privoxy(" and ")".
+ *
+ *    Revision 1.79  2008/10/20 17:09:25  fabiankeil
+ *    Update init_error_log() description to match reality.
+ *
+ *    Revision 1.78  2008/09/07 16:59:31  fabiankeil
+ *    Update a comment to reflect that we
+ *    have mutex support on mingw32 now.
+ *
+ *    Revision 1.77  2008/09/07 12:43:44  fabiankeil
+ *    Move the LogPutString() call in log_error() into the locked
+ *    region so the Windows GUI log is consistent with the logfile.
+ *
+ *    Revision 1.76  2008/09/07 12:35:05  fabiankeil
+ *    Add mutex lock support for _WIN32.
+ *
+ *    Revision 1.75  2008/09/04 08:13:58  fabiankeil
+ *    Prepare for critical sections on Windows by adding a
+ *    layer of indirection before the pthread mutex functions.
+ *
+ *    Revision 1.74  2008/08/06 18:33:36  fabiankeil
+ *    If the "close fd first" workaround doesn't work,
+ *    the fatal error message will be lost, so we better
+ *    explain the consequences while we still can.
+ *
+ *    Revision 1.73  2008/08/04 19:06:55  fabiankeil
+ *    Add a lame workaround for the "can't open an already open
+ *    logfile on OS/2" problem reported by Maynard in #2028842
+ *    and describe what a real solution would look like.
+ *
+ *    Revision 1.72  2008/07/27 12:04:28  fabiankeil
+ *    Fix a comment typo.
+ *
+ *    Revision 1.71  2008/06/28 17:17:15  fabiankeil
+ *    Remove another stray semicolon.
+ *
+ *    Revision 1.70  2008/06/28 17:10:29  fabiankeil
+ *    Remove stray semicolon in get_log_timestamp().
+ *    Reported by Jochen Voss in #2005221.
+ *
+ *    Revision 1.69  2008/05/30 15:55:25  fabiankeil
+ *    Declare variable "debug" static and complain about its name.
+ *
+ *    Revision 1.68  2008/04/27 16:50:46  fabiankeil
+ *    Remove an incorrect assertion. The value of debug may change if
+ *    the configuration is reloaded in another thread. While we could
+ *    cache the initial value, the assertion doesn't seem worth it.
+ *
+ *    Revision 1.67  2008/03/27 18:27:23  fabiankeil
+ *    Remove kill-popups action.
+ *
+ *    Revision 1.66  2008/01/31 15:38:14  fabiankeil
+ *    - Make the logfp assertion more strict. As of 1.63, the "||" could
+ *      have been an "&&", which means we can use two separate assertions
+ *      and skip on of them on Windows.
+ *    - Break a long commit message line in two.
+ *
+ *    Revision 1.65  2008/01/31 14:44:33  fabiankeil
+ *    Use (a != b) instead of !(a == b) so the sanity check looks less insane.
+ *
+ *    Revision 1.64  2008/01/21 18:56:46  david__schmidt
+ *    Swap #def from negative to positive, re-joined it so it didn't
+ *    span an assertion (compilation failure on OS/2)
+ *
+ *    Revision 1.63  2007/12/15 19:49:32  fabiankeil
+ *    Stop overloading logfile to control the mingw32 log window as well.
+ *    It's no longer necessary now that we disable all debug lines by default
+ *    and at least one user perceived it as a regression (added in 1.55).
+ *
  *    Revision 1.62  2007/11/30 15:33:46  fabiankeil
  *    Unbreak LOG_LEVEL_FATAL. It wasn't fatal with logging disabled
  *    and on mingw32 fatal log messages didn't end up in the log file.
@@ -375,8 +462,8 @@ const char errlog_h_rcs[] = ERRLOG_H_VERSION;
 /* where to log (default: stderr) */
 static FILE *logfp = NULL;
 
-/* logging detail level.  */
-int debug = (LOG_LEVEL_FATAL | LOG_LEVEL_ERROR | LOG_LEVEL_INFO);  
+/* logging detail level. XXX: stupid name. */
+static int debug = (LOG_LEVEL_FATAL | LOG_LEVEL_ERROR | LOG_LEVEL_INFO);  
 
 /* static functions */
 static void fatal_error(const char * error_message);
@@ -387,24 +474,24 @@ static char *w32_socket_strerr(int errcode, char *tmp_buf);
 static char *os2_socket_strerr(int errcode, char *tmp_buf);
 #endif
 
-#ifdef FEATURE_PTHREAD
+#ifdef MUTEX_LOCKS_AVAILABLE
 static inline void lock_logfile(void)
 {
-   pthread_mutex_lock(&log_mutex);
+   privoxy_mutex_lock(&log_mutex);
 }
 static inline void unlock_logfile(void)
 {
-   pthread_mutex_unlock(&log_mutex);
+   privoxy_mutex_unlock(&log_mutex);
 }
 static inline void lock_loginit(void)
 {
-   pthread_mutex_lock(&log_init_mutex);
+   privoxy_mutex_lock(&log_init_mutex);
 }
 static inline void unlock_loginit(void)
 {
-   pthread_mutex_unlock(&log_init_mutex);
+   privoxy_mutex_unlock(&log_init_mutex);
 }
-#else /* ! FEATURE_PTHREAD */
+#else /* ! MUTEX_LOCKS_AVAILABLE */
 /*
  * FIXME we need a cross-platform locking mechanism.
  * The locking/unlocking functions below should be 
@@ -468,7 +555,7 @@ static void fatal_error(const char * error_message)
  * Returns     :  Nothing.
  *
  *********************************************************************/
-static void show_version(const char *prog_name)
+void show_version(const char *prog_name)
 {
    log_error(LOG_LEVEL_INFO, "Privoxy version " VERSION);
    if (prog_name != NULL)
@@ -492,13 +579,12 @@ static void show_version(const char *prog_name)
  * Returns     :  Nothing.
  *
  *********************************************************************/
-void init_log_module(const char *prog_name)
+void init_log_module(void)
 {
    lock_logfile();
    logfp = stderr;
    unlock_logfile();
    set_debug_level(debug);
-   show_version(prog_name);
 }
 
 
@@ -510,7 +596,7 @@ void init_log_module(const char *prog_name)
  *                plus LOG_LEVEL_MINIMUM.
  *
  *                XXX: we should only use the LOG_LEVEL_MINIMUM
- *                until the frist time the configuration file has
+ *                until the first time the configuration file has
  *                been parsed.
  *                
  * Parameters  :  1: debug_level = The debug level to set.
@@ -559,8 +645,7 @@ void disable_logging(void)
  *
  * Parameters  :
  *          1  :  prog_name  = The program name.
- *          2  :  logfname   = The logfile name, or NULL for stderr.
- *          3  :  debuglevel = The debugging level.
+ *          2  :  logfname   = The logfile to (re)open.
  *
  * Returns     :  N/A
  *
@@ -580,6 +665,37 @@ void init_error_log(const char *prog_name, const char *logfname)
 
    /* set the designated log file */
    fp = fopen(logfname, "a");
+   if ((NULL == fp) && (logfp != NULL))
+   {
+      /*
+       * Some platforms (like OS/2) don't allow us to open
+       * the same file twice, therefore we give it another
+       * shot after closing the old file descriptor first.
+       *
+       * We don't do it right away because it prevents us
+       * from logging the "can't open logfile" message to
+       * the old logfile.
+       *
+       * XXX: this is a lame workaround and once the next
+       * release is out we should stop bothering reopening
+       * the logfile unless we have to.
+       *
+       * Currently we reopen it every time the config file
+       * has been reloaded, but actually we only have to
+       * reopen it if the file name changed or if the
+       * configuration reloas was caused by a SIGHUP.
+       */
+      log_error(LOG_LEVEL_INFO, "Failed to reopen logfile: \'%s\'. "
+         "Retrying after closing the old file descriptor first. If that "
+         "doesn't work, Privoxy will exit without being able to log a message.",
+         logfname);
+      lock_logfile();
+      fclose(logfp);
+      logfp = NULL;
+      unlock_logfile();
+      fp = fopen(logfname, "a");
+   }
+
    if (NULL == fp)
    {
       log_error(LOG_LEVEL_FATAL, "init_error_log(): can't open logfile: \'%s\'", logfname);
@@ -600,7 +716,7 @@ void init_error_log(const char *prog_name, const char *logfname)
    /*
     * Prevent the Windows GUI from showing the version two
     * times in a row on startup. It already displayed the show_version()
-    * call from init_log_module() that other systems write to stderr.
+    * call from main() that other systems write to stderr.
     *
     * This means mingw32 users will never see the version in their
     * log file, but I assume they wouldn't look for it there anyway
@@ -690,15 +806,15 @@ static inline size_t get_log_timestamp(char *buffer, size_t buffer_size)
 #ifdef HAVE_LOCALTIME_R
    tm_now = *localtime_r(&now, &tm_now);
 #elif FEATURE_PTHREAD
-   pthread_mutex_lock(&localtime_mutex);
+   privoxy_mutex_lock(&localtime_mutex);
    tm_now = *localtime(&now); 
-   pthread_mutex_unlock(&localtime_mutex);
+   privoxy_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);
+   if (length > (size_t)0)
    {
       msecs_length = snprintf(buffer+length, buffer_size - length, ".%.3ld", msecs);               
    }
@@ -748,18 +864,18 @@ static inline size_t get_clf_timestamp(char *buffer, size_t buffer_size)
 #ifdef HAVE_GMTIME_R
    gmt = *gmtime_r(&now, &gmt);
 #elif FEATURE_PTHREAD
-   pthread_mutex_lock(&gmtime_mutex);
+   privoxy_mutex_lock(&gmtime_mutex);
    gmt = *gmtime(&now);
-   pthread_mutex_unlock(&gmtime_mutex);
+   privoxy_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);
+   privoxy_mutex_lock(&localtime_mutex);
    tm_now = localtime(&now); 
-   pthread_mutex_unlock(&localtime_mutex);
+   privoxy_mutex_unlock(&localtime_mutex);
 #else
    tm_now = localtime(&now); 
 #endif
@@ -769,7 +885,7 @@ static inline size_t get_clf_timestamp(char *buffer, size_t buffer_size)
 
    length = strftime(buffer, buffer_size, "%d/%b/%Y:%H:%M:%S ", tm_now);
 
-   if (length > 0);
+   if (length > (size_t)0)
    {
       tz_length = snprintf(buffer+length, buffer_size-length,
                      "%+03d%02d", mins / 60, abs(mins) % 60);
@@ -844,11 +960,9 @@ static inline const char *get_log_level_string(int loglevel)
       case LOG_LEVEL_DEANIMATE:
          log_level_string = "Gif-Deanimate";
          break;
-#ifdef FEATURE_KILL_POPUPS
-      case LOG_LEVEL_POPUPS:
-         log_level_string = "Kill-Popups";
+      case LOG_LEVEL_CRUNCH:
+         log_level_string = "Crunch";
          break;
-#endif /* def FEATURE_KILL_POPUPS */
       case LOG_LEVEL_CGI:
          log_level_string = "CGI";
          break;
@@ -899,7 +1013,7 @@ void log_error(int loglevel, const char *fmt, ...)
     * the taskbar icon animate.  (There is an option to disable
     * this but checking that is handled inside LogShowActivity()).
     */
-   if (loglevel == LOG_LEVEL_GPC)
+   if ((loglevel == LOG_LEVEL_GPC) || (loglevel == LOG_LEVEL_CRUNCH))
    {
       LogShowActivity();
    }
@@ -916,6 +1030,11 @@ void log_error(int loglevel, const char *fmt, ...)
 #endif
       )
    {
+      if (loglevel == LOG_LEVEL_FATAL)
+      {
+         fatal_error("Fatal error. You're not supposed to"
+            "see this message. Please file a bug report.");
+      }
       return;
    }
 
@@ -931,8 +1050,8 @@ void log_error(int loglevel, const char *fmt, ...)
       if (NULL == outbuf_save)
       {
          snprintf(tempbuf, sizeof(tempbuf),
-            "%s Privoxy(%08lx) Fatal error: log_error() failed to allocate buffer memory.\n"
-            "\nExiting.", timestamp, thread_id);
+            "%s %08lx Fatal error: Out of memory in log_error().",
+            timestamp, thread_id);
          fatal_error(tempbuf); /* Exit */
       }
    }
@@ -947,8 +1066,8 @@ void log_error(int loglevel, const char *fmt, ...)
    /* 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));
+      length = (size_t)snprintf(outbuf, log_buffer_size, "%s %08lx %s: ",
+         timestamp, thread_id, get_log_level_string(loglevel));
    }
 
    /* get ready to scan var. args. */
@@ -970,9 +1089,9 @@ void log_error(int loglevel, const char *fmt, ...)
       {
          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.
+          * XXX: Only necessary on platforms where multiple threads
+          * can write to the buffer at the same time because we
+          * don't support mutexes (OS/2 for example).
           */
          outbuf[length] = '\0';
          continue;
@@ -1053,7 +1172,7 @@ void log_error(int loglevel, const char *fmt, ...)
                   format_string = "[counted string lenght < 0]";
                }
             }
-            else if (ival >= sizeof(tempbuf))
+            else if ((size_t)ival >= sizeof(tempbuf))
             {
                /*
                 * String is too long, copy as much as possible.
@@ -1129,9 +1248,9 @@ void log_error(int loglevel, const char *fmt, ...)
    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')
+   if ((length >= log_buffer_size)
+    || (outbuf[log_buffer_size-1] != '\0')
+    || (outbuf[log_buffer_size] != '\0')
       )
    {
       /* Repeat as assertions */
@@ -1145,16 +1264,19 @@ void log_error(int loglevel, const char *fmt, ...)
       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);
+         "%s %08lx Fatal error: log_error()'s sanity checks failed."
+         "length: %d. Exiting.",
+         timestamp, thread_id, (int)length);
       loglevel = LOG_LEVEL_FATAL;
    }
 
-   assert(
 #ifndef _WIN32
-          (NULL != logfp) ||
+   /*
+    * On Windows this is acceptable in case
+    * we are logging to the GUI window only.
+    */
+   assert(NULL != logfp);
 #endif
-          (loglevel & debug));
 
    if (loglevel == LOG_LEVEL_FATAL)
    {
@@ -1165,13 +1287,14 @@ void log_error(int loglevel, const char *fmt, ...)
    {
       fputs(outbuf_save, logfp);
    }
-   unlock_logfile();
 
 #if defined(_WIN32) && !defined(_WIN_CONSOLE)
    /* Write to display */
    LogPutString(outbuf_save);
 #endif /* defined(_WIN32) && !defined(_WIN_CONSOLE) */
 
+   unlock_logfile();
+
 }