-const char errlog_rcs[] = "$Id: errlog.c,v 1.36 2002/03/26 22:29:54 swa Exp $";
/*********************************************************************
*
* File : $Source: /cvsroot/ijbswa/current/errlog.c,v $
* Purpose : Log errors to a designated destination in an elegant,
* printf-like fashion.
*
- * Copyright : Written by and Copyright (C) 2001 the SourceForge
- * Privoxy team. http://www.privoxy.org/
+ * Copyright : Written by and Copyright (C) 2001-2014 the
+ * Privoxy team. https://www.privoxy.org/
*
* Based on the Internet Junkbuster originally written
- * by and Copyright (C) 1997 Anonymous Coders and
+ * by and Copyright (C) 1997 Anonymous Coders and
* Junkbusters Corporation. http://www.junkbusters.com
*
- * This program is free software; you can redistribute it
+ * This program is free software; you can redistribute it
* and/or modify it under the terms of the GNU General
* Public License as published by the Free Software
* Foundation; either version 2 of the License, or (at
* or write to the Free Software Foundation, Inc., 59
* Temple Place - Suite 330, Boston, MA 02111-1307, USA.
*
- * Revisions :
- * $Log: errlog.c,v $
- * Revision 1.36 2002/03/26 22:29:54 swa
- * we have a new homepage!
- *
- * Revision 1.35 2002/03/24 15:23:33 jongfoster
- * Name changes
- *
- * Revision 1.34 2002/03/24 13:25:43 swa
- * name change related issues
- *
- * Revision 1.33 2002/03/13 00:27:04 jongfoster
- * Killing warnings
- *
- * Revision 1.32 2002/03/07 03:46:17 oes
- * Fixed compiler warnings
- *
- * Revision 1.31 2002/03/06 23:02:57 jongfoster
- * Removing tabs
- *
- * Revision 1.30 2002/03/05 22:43:45 david__schmidt
- * - Better error reporting on OS/2
- * - Fix double-slash comment (oops)
- *
- * Revision 1.29 2002/03/04 23:45:13 jongfoster
- * Printing thread ID if using Win32 native threads
- *
- * Revision 1.28 2002/03/04 17:59:59 oes
- * Deleted deletePidFile(), cosmetics
- *
- * Revision 1.27 2002/03/04 02:08:01 david__schmidt
- * Enable web editing of actions file on OS/2 (it had been broken all this time!)
- *
- * Revision 1.26 2002/01/09 19:05:45 steudten
- * Fix big memory leak.
- *
- * Revision 1.25 2002/01/09 14:32:08 oes
- * Added support for gmtime_r and localtime_r.
- *
- * Revision 1.24 2001/12/30 14:07:32 steudten
- * - Add signal handling (unix)
- * - Add SIGHUP handler (unix)
- * - Add creation of pidfile (unix)
- * - Add action 'top' in rc file (RH)
- * - Add entry 'SIGNALS' to manpage
- * - Add exit message to logfile (unix)
- *
- * Revision 1.23 2001/11/07 00:02:13 steudten
- * Add line number in error output for lineparsing for
- * actionsfile and configfile.
- * Special handling for CLF added.
- *
- * Revision 1.22 2001/11/05 23:43:05 steudten
- * Add time+date to log files.
- *
- * Revision 1.21 2001/10/25 03:40:47 david__schmidt
- * Change in porting tactics: OS/2's EMX porting layer doesn't allow multiple
- * threads to call select() simultaneously. So, it's time to do a real, live,
- * native OS/2 port. See defines for __EMX__ (the porting layer) vs. __OS2__
- * (native). Both versions will work, but using __OS2__ offers multi-threading.
- *
- * Revision 1.20 2001/09/16 23:04:34 jongfoster
- * Fixing a warning
- *
- * Revision 1.19 2001/09/13 20:08:06 jongfoster
- * Adding support for LOG_LEVEL_CGI
- *
- * Revision 1.18 2001/09/10 11:27:24 oes
- * Declaration of w32_socket_strerr now conditional
- *
- * Revision 1.17 2001/09/10 10:17:13 oes
- * Removed unused variable; Fixed sprintf format
- *
- * Revision 1.16 2001/07/30 22:08:36 jongfoster
- * Tidying up #defines:
- * - All feature #defines are now of the form FEATURE_xxx
- * - Permanently turned off WIN_GUI_EDIT
- * - Permanently turned on WEBDAV and SPLIT_PROXY_ARGS
- *
- * Revision 1.15 2001/07/29 17:41:10 jongfoster
- * Now prints thread ID for each message (pthreads only)
- *
- * Revision 1.14 2001/07/19 19:03:48 haroon
- * - Added case for LOG_LEVEL_POPUPS
- *
- * Revision 1.13 2001/07/13 13:58:58 oes
- * - Added case for LOG_LEVEL_DEANIMATE
- * - Removed all #ifdef PCRS
- *
- * Revision 1.12 2001/06/09 10:55:28 jongfoster
- * Changing BUFSIZ ==> BUFFER_SIZE
- *
- * Revision 1.11 2001/06/01 18:14:49 jongfoster
- * Changing the calls to strerr() to check HAVE_STRERR (which is defined
- * in config.h if appropriate) rather than the NO_STRERR macro.
- *
- * Revision 1.10 2001/05/29 11:52:21 oes
- * Conditional compilation of w32_socket_error
- *
- * Revision 1.9 2001/05/28 16:15:17 jongfoster
- * Improved reporting of errors under Win32.
- *
- * Revision 1.8 2001/05/26 17:25:14 jongfoster
- * Added support for CLF (Common Log Format) and fixed LOG_LEVEL_LOG
- *
- * Revision 1.7 2001/05/26 15:21:28 jongfoster
- * Activity animation in Win32 GUI now works even if debug==0
- *
- * Revision 1.6 2001/05/25 21:55:08 jongfoster
- * Now cleans up properly on FATAL (removes taskbar icon etc)
- *
- * Revision 1.5 2001/05/22 18:46:04 oes
- *
- * - Enabled filtering banners by size rather than URL
- * by adding patterns that replace all standard banner
- * sizes with the "Junkbuster" gif to the re_filterfile
- *
- * - Enabled filtering WebBugs by providing a pattern
- * which kills all 1x1 images
- *
- * - Added support for PCRE_UNGREEDY behaviour to pcrs,
- * which is selected by the (nonstandard and therefore
- * capital) letter 'U' in the option string.
- * It causes the quantifiers to be ungreedy by default.
- * Appending a ? turns back to greedy (!).
- *
- * - Added a new interceptor ijb-send-banner, which
- * sends back the "Junkbuster" gif. Without imagelist or
- * MSIE detection support, or if tinygif = 1, or the
- * URL isn't recognized as an imageurl, a lame HTML
- * explanation is sent instead.
- *
- * - Added new feature, which permits blocking remote
- * script redirects and firing back a local redirect
- * to the browser.
- * The feature is conditionally compiled, i.e. it
- * can be disabled with --disable-fast-redirects,
- * plus it must be activated by a "fast-redirects"
- * line in the config file, has its own log level
- * and of course wants to be displayed by show-proxy-args
- * Note: Boy, all the #ifdefs in 1001 locations and
- * all the fumbling with configure.in and acconfig.h
- * were *way* more work than the feature itself :-(
- *
- * - Because a generic redirect template was needed for
- * this, tinygif = 3 now uses the same.
- *
- * - Moved GIFs, and other static HTTP response templates
- * to project.h
- *
- * - Some minor fixes
- *
- * - Removed some >400 CRs again (Jon, you really worked
- * a lot! ;-)
- *
- * Revision 1.4 2001/05/21 19:32:54 jongfoster
- * Added another #ifdef _WIN_CONSOLE
- *
- * Revision 1.3 2001/05/20 01:11:40 jongfoster
- * Added support for LOG_LEVEL_FATAL
- * Renamed LOG_LEVEL_FRC to LOG_LEVEL_FORCE,
- * and LOG_LEVEL_REF to LOG_LEVEL_RE_FILTER
- *
- * Revision 1.2 2001/05/17 22:42:01 oes
- * - Cleaned CRLF's from the sources and related files
- * - Repaired logging for REF and FRC
- *
- * Revision 1.1.1.1 2001/05/15 13:58:51 oes
- * Initial import of version 2.9.3 source tree
- *
- *
*********************************************************************/
-\f
-#include "config.h"
-#include "miscutil.h"
#include <stdlib.h>
#include <stdio.h>
#include <stdarg.h>
#include <string.h>
+#include <ctype.h>
+
+#include "config.h"
+#include "miscutil.h"
+
+/* For gettimeofday() */
+#include <sys/time.h>
-#if !defined(_WIN32) && !defined(__OS2__)
+#if !defined(_WIN32)
#include <unistd.h>
-#endif /* !defined(_WIN32) && !defined(__OS2__) */
+#endif /* !defined(_WIN32) */
#include <errno.h>
#include <assert.h>
-#ifdef FEATURE_PTHREAD
-#include <pthread.h>
-#endif /* def FEATURE_PTHREAD */
#ifdef _WIN32
+#ifndef STRICT
+#define STRICT
+#endif
#include <windows.h>
#ifndef _WIN_CONSOLE
#include "w32log.h"
#endif /* ndef _WIN_CONSOLE */
#endif /* def _WIN32 */
-
-#ifdef __OS2__
-#include <sys/socket.h> /* For sock_errno */
-#define INCL_DOS
-#include <os2.h>
-#endif
+#ifdef _MSC_VER
+#define inline __inline
+#endif /* def _MSC_VER */
#include "errlog.h"
#include "project.h"
#include "jcc.h"
-
-const char errlog_h_rcs[] = ERRLOG_H_VERSION;
-
+#ifdef FEATURE_EXTERNAL_FILTERS
+#include "jbsockets.h"
+#endif
/*
* LOG_LEVEL_FATAL cannot be turned off. (There are
/* where to log (default: stderr) */
static FILE *logfp = NULL;
-/* logging detail level. */
-static 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);
/* static functions */
static void fatal_error(const char * error_message);
static char *w32_socket_strerr(int errcode, char *tmp_buf);
#endif
+#ifdef MUTEX_LOCKS_AVAILABLE
+static inline void lock_logfile(void)
+{
+ privoxy_mutex_lock(&log_mutex);
+}
+static inline void unlock_logfile(void)
+{
+ privoxy_mutex_unlock(&log_mutex);
+}
+static inline void lock_loginit(void)
+{
+ privoxy_mutex_lock(&log_init_mutex);
+}
+static inline void unlock_loginit(void)
+{
+ privoxy_mutex_unlock(&log_init_mutex);
+}
+#else /* ! MUTEX_LOCKS_AVAILABLE */
+/*
+ * 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
*
- * Description : Displays a fatal error to standard error (or, on
- * a WIN32 GUI, to a dialog box), and exits
- * JunkBuster with status code 1.
+ * Description : Displays a fatal error to standard error (or, on
+ * a WIN32 GUI, to a dialog box), and exits Privoxy
+ * with status code 1.
*
* Parameters :
* 1 : error_message = The error message to display.
* Returns : Does not return.
*
*********************************************************************/
-static void fatal_error(const char * error_message)
+static void fatal_error(const char *error_message)
{
-#if defined(_WIN32) && !defined(_WIN_CONSOLE)
- MessageBox(g_hwndLogFrame, error_message, "Privoxy Error",
- MB_OK | MB_ICONERROR | MB_TASKMODAL | MB_SETFOREGROUND | MB_TOPMOST);
+ if (logfp != NULL)
+ {
+ fputs(error_message, logfp);
+ }
- /* Cleanup - remove taskbar icon etc. */
- TermLogWindow();
+#if defined(_WIN32) && !defined(_WIN_CONSOLE)
+ {
+ /* Skip timestamp and thread id for the message box. */
+ const char *box_message = strstr(error_message, "Fatal error");
+ if (NULL == box_message)
+ {
+ /* Shouldn't happen but ... */
+ box_message = error_message;
+ }
+ MessageBox(g_hwndLogFrame, box_message, "Privoxy Error",
+ MB_OK | MB_ICONERROR | MB_TASKMODAL | MB_SETFOREGROUND | MB_TOPMOST);
-#else /* if !defined(_WIN32) || defined(_WIN_CONSOLE) */
- fputs(error_message, stderr);
+ /* Cleanup - remove taskbar icon etc. */
+ TermLogWindow();
+ }
#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.
+ *
+ *********************************************************************/
+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(void)
+{
+ lock_logfile();
+ logfp = stderr;
+ unlock_logfile();
+ set_debug_level(debug);
+}
+
+
+/*********************************************************************
+ *
+ * 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 first 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)
+{
+#ifdef FUZZ
+ if (LOG_LEVEL_STFU == debug_level)
+ {
+ debug = LOG_LEVEL_STFU;
+ }
+ if (LOG_LEVEL_STFU == debug)
+ {
+ return;
+ }
+#endif
+
+ debug = debug_level | LOG_LEVEL_MINIMUM;
+}
+
+
+/*********************************************************************
+ *
+ * Function : debug_level_is_enabled
+ *
+ * Description : Checks if a certain debug level is enabled.
+ *
+ * Parameters : 1: debug_level = The debug level to check.
+ *
+ * Returns : Nothing.
+ *
+ *********************************************************************/
+int debug_level_is_enabled(int debug_level)
+{
+ return (0 != (debug & debug_level));
+}
+
+
+/*********************************************************************
+ *
+ * Function : disable_logging
+ *
+ * Description : Disables logging.
+ *
+ * Parameters : None.
+ *
+ * Returns : Nothing.
+ *
+ *********************************************************************/
+void disable_logging(void)
+{
+ if (logfp != NULL)
+ {
+ log_error(LOG_LEVEL_INFO,
+ "No logfile configured. Please enable it before reporting any problems.");
+ lock_logfile();
+ 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.
- * 2 : logfname = The logfile name, or NULL for stderr.
- * 3 : debuglevel = The debugging level.
+ * 2 : logfname = The logfile to (re)open.
*
* 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();
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-)Opening logfile \'%s\'", logfname);
}
- logfp = stderr;
/* set the designated log file */
- if( logfname )
+ fp = fopen(logfname, "a");
+ if ((NULL == fp) && (logfp != NULL))
{
- if( NULL == (fp = fopen(logfname, "a")) )
- {
- log_error(LOG_LEVEL_FATAL, "init_error_log(): can't open logfile: %s", logfname);
- }
-
- /* set logging to be completely unbuffered */
- setbuf(fp, NULL);
+ /*
+ * Some platforms (like OS/2 (XXX: no longer supported)) 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 reload 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");
+ }
- logfp = fp;
+ if (NULL == fp)
+ {
+ log_error(LOG_LEVEL_FATAL, "init_error_log(): can't open logfile: \'%s\'", logfname);
}
- log_error(LOG_LEVEL_INFO, "Privoxy version " VERSION);
- if (prog_name != NULL)
+#ifdef FEATURE_EXTERNAL_FILTERS
+ mark_socket_for_close_on_execute(3);
+#endif
+
+ /* set logging to be completely unbuffered */
+ setbuf(fp, NULL);
+
+ lock_logfile();
+ if (logfp != NULL)
{
- log_error(LOG_LEVEL_INFO, "Program name: %s", prog_name);
+ fclose(logfp);
+ }
+#ifdef unix
+ if (daemon_mode && (logfp == stderr))
+ {
+ if (dup2(1, 2) == -1)
+ {
+ /*
+ * We only use fatal_error() to clear the pid
+ * file and to exit. Given that stderr has just
+ * been closed, the user will not see the error
+ * message.
+ */
+ fatal_error("Failed to reserve fd 2.");
+ }
}
+#endif
+ logfp = fp;
+ unlock_logfile();
+
+ show_version(prog_name);
- /* FIXME RACE HAZARD: should end critical section error_log_use here */
+ unlock_loginit();
} /* init_error_log */
/*********************************************************************
*
- * Function : log_error
+ * Function : get_thread_id
*
- * Description : This is the error-reporting and logging function.
+ * Description : Returns a number that is different for each thread.
*
- * 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).
+ * XXX: Should be moved elsewhere (miscutil.c?)
*
- * Returns : N/A
+ * Parameters : None
+ *
+ * Returns : thread_id
*
*********************************************************************/
-void log_error(int loglevel, char *fmt, ...)
+static long get_thread_id(void)
{
- va_list ap;
- char *outbuf= NULL;
- static char *outbuf_save = NULL;
- char * src = fmt;
- int outc = 0;
- long this_thread = 1; /* was: pthread_t this_thread;*/
-#ifdef __OS2__
- PTIB ptib;
- APIRET ulrc;
-#endif /* __OS2__ */
-
-#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 if loglevel applies to current settings and bail out if negative */
- if ((loglevel & debug) == 0)
- {
- return;
- }
+ long this_thread;
/* 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 unique
+ * value at the lowest order 4 bytes of pthread_self()'s return value, a pthread_t,
+ * so trim the three lowest-order bytes from the value (16^3).
+ */
+ this_thread = this_thread / 4096;
+#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;
+#else
+ /* Forking instead of threading. */
+ this_thread = 1;
#endif /* def FEATURE_PTHREAD */
- if ( !outbuf_save )
+ 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;
+ now = tv_now.tv_sec;
+
+#ifdef HAVE_LOCALTIME_R
+ tm_now = *localtime_r(&now, &tm_now);
+#elif defined(MUTEX_LOCKS_AVAILABLE)
+ privoxy_mutex_lock(&localtime_mutex);
+ tm_now = *localtime(&now);
+ privoxy_mutex_unlock(&localtime_mutex);
+#else
+ tm_now = *localtime(&now);
+#endif
+
+ length = strftime(buffer, buffer_size, "%Y-%m-%d %H:%M:%S", &tm_now);
+ if (length > (size_t)0)
{
- outbuf_save = outbuf = (char*)malloc(BUFFER_SIZE);
- assert(outbuf);
+ msecs_length = snprintf(buffer+length, buffer_size - length, ".%.3ld", msecs);
}
- outbuf = outbuf_save;
-
- {
- /*
- * Write timestamp into tempbuf.
- *
- * Complex because not all OSs have tm_gmtoff or
- * the %z field in strftime()
- */
- time_t now;
- struct tm tm_now;
- time (&now);
+ if (msecs_length > 0)
+ {
+ length += (size_t)msecs_length;
+ }
+ else
+ {
+ 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);
+ gmt = *privoxy_gmtime_r(&now, &gmt);
#ifdef HAVE_LOCALTIME_R
- tm_now = *localtime_r(&now, &tm_now);
+ tm_now = localtime_r(&now, &dummy);
+#elif defined(MUTEX_LOCKS_AVAILABLE)
+ privoxy_mutex_lock(&localtime_mutex);
+ tm_now = localtime(&now);
#else
- tm_now = *localtime (&now);
+ tm_now = localtime(&now);
#endif
- strftime(outbuf, BUFFER_SIZE-6, "%b %d %H:%M:%S ", &tm_now);
- outbuf += strlen( outbuf );
- }
+ 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 !defined(HAVE_LOCALTIME_R) && defined(MUTEX_LOCKS_AVAILABLE)
+ privoxy_mutex_unlock(&localtime_mutex);
+#endif
+
+ if (length > (size_t)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:
- outc = sprintf(outbuf, "Privoxy(%ld) Error: ", this_thread);
+ log_level_string = "Error";
break;
case LOG_LEVEL_FATAL:
- outc = sprintf(outbuf, "Privoxy(%ld) Fatal error: ", this_thread);
+ log_level_string = "Fatal error";
break;
- case LOG_LEVEL_GPC:
- outc = sprintf(outbuf, "Privoxy(%ld) Request: ", this_thread);
+ case LOG_LEVEL_REQUEST:
+ log_level_string = "Request";
break;
case LOG_LEVEL_CONNECT:
- outc = sprintf(outbuf, "Privoxy(%ld) Connect: ", this_thread);
+ log_level_string = "Connect";
+ break;
+ case LOG_LEVEL_WRITING:
+ log_level_string = "Writing";
break;
- case LOG_LEVEL_LOG:
- outc = sprintf(outbuf, "Privoxy(%ld) Writing: ", this_thread);
+ case LOG_LEVEL_RECEIVED:
+ log_level_string = "Received";
break;
case LOG_LEVEL_HEADER:
- outc = sprintf(outbuf, "Privoxy(%ld) Header: ", this_thread);
+ log_level_string = "Header";
break;
case LOG_LEVEL_INFO:
- outc = sprintf(outbuf, "Privoxy(%ld) Info: ", this_thread);
+ log_level_string = "Info";
break;
case LOG_LEVEL_RE_FILTER:
- outc = sprintf(outbuf, "Privoxy(%ld) Re-Filter: ", this_thread);
+ log_level_string = "Re-Filter";
break;
#ifdef FEATURE_FORCE_LOAD
case LOG_LEVEL_FORCE:
- outc = sprintf(outbuf, "Privoxy(%ld) Force: ", this_thread);
+ log_level_string = "Force";
break;
#endif /* def FEATURE_FORCE_LOAD */
-#ifdef FEATURE_FAST_REDIRECTS
case LOG_LEVEL_REDIRECTS:
- outc = sprintf(outbuf, "Privoxy(%ld) Redirect: ", this_thread);
+ log_level_string = "Redirect";
break;
-#endif /* def FEATURE_FAST_REDIRECTS */
case LOG_LEVEL_DEANIMATE:
- outc = sprintf(outbuf, "Privoxy(%ld) Gif-Deanimate: ", this_thread);
+ log_level_string = "Gif-Deanimate";
break;
- case LOG_LEVEL_CLF:
- outbuf = outbuf_save;
- outc = 0;
- outbuf[0] = '\0';
+ case LOG_LEVEL_CRUNCH:
+ log_level_string = "Crunch";
break;
-#ifdef FEATURE_KILL_POPUPS
- case LOG_LEVEL_POPUPS:
- outc = sprintf(outbuf, "Privoxy(%ld) Kill-Popups: ", this_thread);
- break;
-#endif /* def FEATURE_KILL_POPUPS */
case LOG_LEVEL_CGI:
- outc = sprintf(outbuf, "Privoxy(%ld) CGI: ", this_thread);
+ log_level_string = "CGI";
+ break;
+ case LOG_LEVEL_ACTIONS:
+ log_level_string = "Actions";
break;
default:
- outc = sprintf(outbuf, "Privoxy(%ld) UNKNOWN LOG TYPE(%d): ", this_thread, loglevel);
+ log_level_string = "Unknown log level";
break;
}
-
+ assert(NULL != log_level_string);
+
+ return log_level_string;
+}
+
+
+#define LOG_BUFFER_SIZE BUFFER_SIZE
+/*********************************************************************
+ *
+ * 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[LOG_BUFFER_SIZE+1];
+ char tempbuf[LOG_BUFFER_SIZE];
+ size_t length = 0;
+ const char * src = fmt;
+ long thread_id;
+ char timestamp[30];
+ const size_t log_buffer_size = LOG_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_REQUEST) || (loglevel == LOG_LEVEL_CRUNCH))
+ {
+ 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))
+#ifndef _WIN32
+ || (logfp == NULL)
+#endif
+ )
+ {
+#ifdef FUZZ
+ if (debug == LOG_LEVEL_STFU)
+ {
+ return;
+ }
+#endif
+ if (loglevel == LOG_LEVEL_FATAL)
+ {
+ fatal_error("Fatal error. You're not supposed to"
+ "see this message. Please file a bug report.");
+ }
+ return;
+ }
+
+ thread_id = get_thread_id();
+ get_log_timestamp(timestamp, sizeof(timestamp));
+
+ /*
+ * Memsetting the whole buffer to zero (in theory)
+ * makes things easier later on.
+ */
+ memset(outbuf, 0, sizeof(outbuf));
+
+ /* Add prefix for everything but Common Log Format messages */
+ if (loglevel != LOG_LEVEL_CLF)
+ {
+ 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. */
- va_start( ap, fmt );
+ va_start(ap, fmt);
/* build formatted message from fmt and var-args */
- while ((*src) && (outc < BUFFER_SIZE-2))
+ while ((*src) && (length < log_buffer_size-2))
{
- char tempbuf[BUFFER_SIZE];
- char *sval = NULL;
- int ival;
- unsigned uval;
- long lval;
- unsigned long ulval;
- int oldoutc;
+ 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 != '%' )
+ if (ch != '%')
{
- outbuf[outc++] = ch;
+ outbuf[length++] = ch;
+ /*
+ * XXX: Only necessary on platforms where multiple threads
+ * can write to the buffer at the same time because we
+ * don't support mutexes.
+ * XXX: Are there any such platforms left now that OS/2 is gone?
+ */
+ outbuf[length] = '\0';
continue;
}
-
+ outbuf[length] = '\0';
ch = *src++;
switch (ch) {
case '%':
- outbuf[outc++] = '%';
+ tempbuf[0] = '%';
+ tempbuf[1] = '\0';
break;
case 'd':
- ival = va_arg( ap, int );
- oldoutc = outc;
- outc += sprintf(tempbuf, "%d", ival);
- if (outc < BUFFER_SIZE-1)
- {
- strcpy(outbuf + oldoutc, tempbuf);
- }
- else
- {
- outbuf[oldoutc] = '\0';
- }
+ ival = va_arg(ap, int);
+ snprintf(tempbuf, sizeof(tempbuf), "%d", ival);
break;
case 'u':
- uval = va_arg( ap, unsigned );
- oldoutc = outc;
- outc += sprintf(tempbuf, "%u", uval);
- if (outc < BUFFER_SIZE-1)
- {
- strcpy(outbuf + oldoutc, tempbuf);
- }
- else
- {
- outbuf[oldoutc] = '\0';
- }
+ 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 */
+ /* this is a modifier that must be followed by u, lu, or d */
ch = *src++;
if (ch == 'd')
{
- lval = va_arg( ap, long );
- oldoutc = outc;
- outc += sprintf(tempbuf, "%ld", lval);
+ lval = va_arg(ap, long);
+ snprintf(tempbuf, sizeof(tempbuf), "%ld", lval);
}
else if (ch == 'u')
{
- ulval = va_arg( ap, unsigned long );
- oldoutc = outc;
- outc += sprintf(tempbuf, "%lu", ulval);
+ ulval = va_arg(ap, unsigned long);
+ snprintf(tempbuf, sizeof(tempbuf), "%lu", ulval);
}
- else
+ else if ((ch == 'l') && (*src == 'u'))
{
- /* Error */
- sprintf(outbuf, "Privoxy(%ld) 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;
- }
- if (outc < BUFFER_SIZE-1)
- {
- strcpy(outbuf + oldoutc, tempbuf);
+ unsigned long long lluval = va_arg(ap, unsigned long long);
+ snprintf(tempbuf, sizeof(tempbuf), "%llu", lluval);
+ src++;
}
else
{
- outbuf[oldoutc] = '\0';
+ 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
+ * Note that char parameters are converted to int, so we need to
* pass "int" to va_arg. (See K&R, 2nd ed, section A7.3.2, page 202)
*/
- outbuf[outc++] = (char) va_arg( ap, int );
+ tempbuf[0] = (char) va_arg(ap, int);
+ tempbuf[1] = '\0';
break;
case 's':
- sval = va_arg( ap, char * );
- oldoutc = outc;
- outc += strlen(sval);
- if (outc < BUFFER_SIZE-1)
+ format_string = va_arg(ap, char *);
+ if (format_string == NULL)
{
- strcpy(outbuf + oldoutc, sval);
- }
- else
- {
- outbuf[oldoutc] = '\0';
+ format_string = "[null]";
}
break;
case 'N':
- /* Non-standard: Print a counted string. Takes 2 parameters:
- * int length, const char * string
+ /*
+ * Non-standard: Print a counted unterminated string,
+ * replacing unprintable bytes with their hex value.
+ * Takes 2 parameters: int length, const char * string.
*/
- ival = va_arg( ap, int );
- sval = va_arg( ap, char * );
- if (ival < 0)
- {
- ival = 0;
- }
- oldoutc = outc;
- outc += ival;
- if (outc < BUFFER_SIZE-1)
- {
- memcpy(outbuf + oldoutc, sval, (size_t) ival);
- }
- else
+ ival = va_arg(ap, int);
+ assert(ival >= 0);
+ sval = va_arg(ap, char *);
+ assert(sval != NULL);
+
+ while ((ival-- > 0) && (length < log_buffer_size - 6))
{
- outbuf[oldoutc] = '\0';
+ if (isprint((int)*sval) && (*sval != '\\'))
+ {
+ outbuf[length++] = *sval;
+ outbuf[length] = '\0';
+ }
+ else
+ {
+ int ret = snprintf(outbuf + length,
+ log_buffer_size - length - 2, "\\x%.2x", (unsigned char)*sval);
+ assert(ret == 4);
+ length += 4;
+ }
+ sval++;
}
+ /*
+ * XXX: In case of printable characters at the end of
+ * the %N string, we're not using the whole buffer.
+ */
+ format_string = (length < log_buffer_size - 6) ? "" : "[too long]";
break;
case 'E':
/* Non-standard: Print error code from errno */
#ifdef _WIN32
ival = WSAGetLastError();
- sval = w32_socket_strerr(ival, tempbuf);
-#elif __OS2__
- ival = sock_errno();
- if (ival == 0)
- ival = errno;
- sval = strerror(ival);
+ format_string = w32_socket_strerr(ival, tempbuf);
#else /* ifndef _WIN32 */
- ival = errno;
+ ival = errno;
#ifdef HAVE_STRERROR
- sval = strerror(ival);
+ format_string = strerror(ival);
#else /* ifndef HAVE_STRERROR */
- sval = NULL;
+ format_string = NULL;
#endif /* ndef HAVE_STRERROR */
if (sval == NULL)
{
- sprintf(tempbuf, "(errno = %d)", ival);
- sval = tempbuf;
+ snprintf(tempbuf, sizeof(tempbuf), "(errno = %d)", ival);
}
#endif /* ndef _WIN32 */
- oldoutc = outc;
- outc += strlen(sval);
- if (outc < BUFFER_SIZE-1)
- {
- strcpy(outbuf + oldoutc, sval);
- }
- else
- {
- outbuf[oldoutc] = '\0';
- }
break;
case 'T':
/* Non-standard: Print a Common Log File timestamp */
- {
- /*
- * Write timestamp into tempbuf.
- *
- * 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;
- time (&now);
-#ifdef HAVE_GMTIME_R
- gmt = *gmtime_r(&now, &gmt);
-#else
- gmt = *gmtime(&now);
-#endif
-#ifdef HAVE_LOCALTIME_R
- tm_now = localtime_r(&now, &dummy);
-#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;
- strftime (tempbuf, BUFFER_SIZE-6, "%d/%b/%Y:%H:%M:%S ", tm_now);
- sprintf (tempbuf + strlen(tempbuf), "%+03d%02d", mins / 60, abs(mins) % 60);
- }
- oldoutc = outc;
- outc += strlen(tempbuf);
- if (outc < BUFFER_SIZE-1)
- {
- strcpy(outbuf + oldoutc, tempbuf);
- }
- else
- {
- outbuf[oldoutc] = '\0';
- }
+ get_clf_timestamp(tempbuf, sizeof(tempbuf));
break;
default:
- sprintf(outbuf, "Privoxy(%ld) 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 */
- fatal_error(outbuf_save);
- /* Never get here */
+ snprintf(tempbuf, sizeof(tempbuf), "Bad format string: \"%s\"", fmt);
+ loglevel = LOG_LEVEL_FATAL;
break;
+ }
- } /* switch( p ) */
-
- } /* for( p ... ) */
-
- /* done with var. args */
- va_end( ap );
-
- if (outc >= BUFFER_SIZE-2)
- {
- /* insufficient room for newline and trailing null. */
-
- static const char warning[] = "... [too long, truncated]\n";
+ assert(length < log_buffer_size);
+ length += strlcpy(outbuf + length, format_string, log_buffer_size - length);
- if (outc < BUFFER_SIZE)
+ if (length >= log_buffer_size-2)
{
- /* Need to add terminating null in this case. */
- outbuf[outc] = '\0';
- }
+ static const char warning[] = "... [too long, truncated]";
- /* Truncate output */
- outbuf[BUFFER_SIZE - sizeof(warning)] = '\0';
+ length = log_buffer_size - sizeof(warning) - 1;
+ length += strlcpy(outbuf + length, warning, log_buffer_size - length);
+ assert(length < log_buffer_size);
- /* Append warning */
- strcat(outbuf, warning);
- }
- else
- {
- /* Add terminating newline and null */
- outbuf[outc++] = '\n';
- outbuf[outc] = '\0';
+ break;
+ }
}
- /* FIXME RACE HAZARD: should start critical section error_log_use here */
+ /* done with var. args */
+ va_end(ap);
+
+ assert(length < log_buffer_size);
+ length += strlcpy(outbuf + length, "\n", log_buffer_size - length);
- /* deal with glibc stupidity - it won't let you initialize logfp */
- if( !logfp )
+ /* Some sanity checks */
+ if ((length >= log_buffer_size)
+ || (outbuf[log_buffer_size-1] != '\0')
+ || (outbuf[log_buffer_size] != '\0')
+ )
{
- logfp = stderr;
+ /* 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 %08lx Fatal error: log_error()'s sanity checks failed."
+ "length: %d. Exiting.",
+ timestamp, thread_id, (int)length);
+ loglevel = LOG_LEVEL_FATAL;
}
- fputs(outbuf_save, logfp);
+#ifndef _WIN32
+ /*
+ * On Windows this is acceptable in case
+ * we are logging to the GUI window only.
+ */
+ assert(NULL != logfp);
+#endif
+
+ lock_logfile();
if (loglevel == LOG_LEVEL_FATAL)
{
- fatal_error(outbuf_save);
+ fatal_error(outbuf);
/* Never get here */
}
-
- /* FIXME RACE HAZARD: should end critical section error_log_use here */
+ if (logfp != NULL)
+ {
+ fputs(outbuf, logfp);
+ }
#if defined(_WIN32) && !defined(_WIN_CONSOLE)
/* Write to display */
- LogPutString(outbuf_save);
+ LogPutString(outbuf);
#endif /* defined(_WIN32) && !defined(_WIN_CONSOLE) */
+ unlock_logfile();
+
}
+/*********************************************************************
+ *
+ * Function : jb_err_to_string
+ *
+ * Description : Translates JB_ERR_FOO codes into strings.
+ *
+ * Parameters :
+ * 1 : jb_error = a valid jb_err code
+ *
+ * Returns : A string with the jb_err translation
+ *
+ *********************************************************************/
+const char *jb_err_to_string(jb_err jb_error)
+{
+ switch (jb_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";
+ }
+ assert(0);
+ return "Internal error";
+}
+
#ifdef _WIN32
/*********************************************************************
*