X-Git-Url: http://www.privoxy.org/gitweb/?p=privoxy.git;a=blobdiff_plain;f=errlog.c;h=f493ac6ec9af26ee19f88dfa3b6e364456f00c6e;hp=7fc78a3853b4920f5200d164c092deac92a412fa;hb=777f23fd554b0811d16bc2323ced6fe9dc0cff72;hpb=8e6654d4494d7179debea23adfc44d58a1701bdd diff --git a/errlog.c b/errlog.c index 7fc78a38..f493ac6e 100644 --- a/errlog.c +++ b/errlog.c @@ -1,4 +1,4 @@ -const char errlog_rcs[] = "$Id: errlog.c,v 1.44 2006/08/18 16:03:16 david__schmidt Exp $"; +const char errlog_rcs[] = "$Id: errlog.c,v 1.121 2014/06/03 10:24:00 fabiankeil Exp $"; /********************************************************************* * * File : $Source: /cvsroot/ijbswa/current/errlog.c,v $ @@ -6,14 +6,14 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.44 2006/08/18 16:03:16 david__schmi * 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-2014 the * Privoxy team. http://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 @@ -31,229 +31,20 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.44 2006/08/18 16:03:16 david__schmi * 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.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 - * - * Revision 1.38 2002/03/31 17:18:59 jongfoster - * Win32 only: Enabling STRICT to fix a VC++ compile warning. - * - * Revision 1.37 2002/03/27 14:32:43 david__schmidt - * More compiler warning message maintenance - * - * 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 - * - * *********************************************************************/ - -#include "config.h" -#include "miscutil.h" #include #include #include #include +#include + +#include "config.h" +#include "miscutil.h" + +/* For gettimeofday() */ +#include #if !defined(_WIN32) && !defined(__OS2__) #include @@ -261,9 +52,6 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.44 2006/08/18 16:03:16 david__schmi #include #include -#ifdef FEATURE_PTHREAD -#include -#endif /* def FEATURE_PTHREAD */ #ifdef _WIN32 #ifndef STRICT @@ -287,6 +75,9 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.44 2006/08/18 16:03:16 david__schmi #include "errlog.h" #include "project.h" #include "jcc.h" +#ifdef FEATURE_EXTERNAL_FILTERS +#include "jbsockets.h" +#endif const char errlog_h_rcs[] = ERRLOG_H_VERSION; @@ -301,8 +92,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); /* static functions */ static void fatal_error(const char * error_message); @@ -313,29 +104,29 @@ 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() +#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() +static inline void unlock_logfile(void) { - pthread_mutex_unlock(&log_mutex); + privoxy_mutex_unlock(&log_mutex); } -static inline void lock_loginit() +static inline void lock_loginit(void) { - pthread_mutex_lock(&log_init_mutex); + privoxy_mutex_lock(&log_init_mutex); } -static inline void unlock_loginit() +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 + * 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() {} @@ -346,9 +137,9 @@ static inline void unlock_loginit() {} * * 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. @@ -356,84 +147,248 @@ static inline void unlock_loginit() {} * 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) +{ + 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; - lock_loginit(); + 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"); - lock_logfile(); - fclose(logfp); - } else { - lock_logfile(); + log_error(LOG_LEVEL_INFO, "(Re-)Opening logfile \'%s\'", logfname); } - logfp = stderr; - unlock_logfile(); /* 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) 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(); - logfp = fp; + fclose(logfp); + logfp = NULL; unlock_logfile(); + fp = fopen(logfname, "a"); } - log_error(LOG_LEVEL_INFO, "Privoxy version " VERSION); - if (prog_name != NULL) + if (NULL == fp) { - log_error(LOG_LEVEL_INFO, "Program name: %s", prog_name); + log_error(LOG_LEVEL_FATAL, "init_error_log(): can't open logfile: \'%s\'", logfname); } +#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) + { + 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); + unlock_loginit(); } /* init_error_log */ @@ -441,52 +396,26 @@ void init_error_log(const char *prog_name, const char *logfname, int debuglevel) /********************************************************************* * - * 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;*/ + long this_thread; + #ifdef __OS2__ PTIB ptib; - APIRET ulrc; + APIRET ulrc; /* XXX: I have no clue what this does */ #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; - } - - /* 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(); @@ -505,184 +434,378 @@ void log_error(int loglevel, char *fmt, ...) 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); + } + if (msecs_length > 0) + { + length += (size_t)msecs_length; + } + else + { + length = 0; } - 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); + 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 - tm_now = *localtime_r(&now, &tm_now); -#elif OSX_DARWIN - pthread_mutex_lock(&localtime_mutex); - tm_now = *localtime (&now); - pthread_mutex_unlock(&localtime_mutex); + 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 defined(MUTEX_LOCKS_AVAILABLE) + privoxy_mutex_lock(&gmtime_mutex); + gmt = *gmtime(&now); + privoxy_mutex_unlock(&gmtime_mutex); #else - tm_now = *localtime (&now); + gmt = *gmtime(&now); #endif - strftime(outbuf, BUFFER_SIZE-6, "%b %d %H:%M:%S ", &tm_now); - outbuf += strlen( outbuf ); - } +#ifdef HAVE_LOCALTIME_R + tm_now = localtime_r(&now, &dummy); +#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 + 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 > (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(%08lx) Error: ", this_thread); + log_level_string = "Error"; break; case LOG_LEVEL_FATAL: - outc = sprintf(outbuf, "Privoxy(%08lx) Fatal error: ", this_thread); + log_level_string = "Fatal error"; break; case LOG_LEVEL_GPC: - outc = sprintf(outbuf, "Privoxy(%08lx) Request: ", this_thread); + log_level_string = "Request"; break; case LOG_LEVEL_CONNECT: - outc = sprintf(outbuf, "Privoxy(%08lx) 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(%08lx) Writing: ", this_thread); + case LOG_LEVEL_RECEIVED: + log_level_string = "Received"; break; case LOG_LEVEL_HEADER: - outc = sprintf(outbuf, "Privoxy(%08lx) Header: ", this_thread); + log_level_string = "Header"; break; case LOG_LEVEL_INFO: - outc = sprintf(outbuf, "Privoxy(%08lx) Info: ", this_thread); + log_level_string = "Info"; break; case LOG_LEVEL_RE_FILTER: - outc = sprintf(outbuf, "Privoxy(%08lx) Re-Filter: ", this_thread); + log_level_string = "Re-Filter"; break; #ifdef FEATURE_FORCE_LOAD case LOG_LEVEL_FORCE: - outc = sprintf(outbuf, "Privoxy(%08lx) 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(%08lx) Redirect: ", this_thread); + log_level_string = "Redirect"; break; -#endif /* def FEATURE_FAST_REDIRECTS */ case LOG_LEVEL_DEANIMATE: - outc = sprintf(outbuf, "Privoxy(%08lx) 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(%08lx) Kill-Popups: ", this_thread); - break; -#endif /* def FEATURE_KILL_POPUPS */ case LOG_LEVEL_CGI: - outc = sprintf(outbuf, "Privoxy(%08lx) CGI: ", this_thread); + log_level_string = "CGI"; + break; + case LOG_LEVEL_ACTIONS: + log_level_string = "Actions"; break; default: - outc = sprintf(outbuf, "Privoxy(%08lx) 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 = NULL; + static char *outbuf_save = NULL; + char tempbuf[LOG_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 = 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_GPC) || (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 + ) + { + 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)); + + /* 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) + { + snprintf(tempbuf, sizeof(tempbuf), + "%s %08lx Fatal error: Out of memory in log_error().", + timestamp, thread_id); + fatal_error(tempbuf); /* Exit */ + return; + } + } + outbuf = outbuf_save; + + /* + * Memsetting the whole buffer to zero (in theory) + * makes things easier later on. + */ + memset(outbuf, 0, log_buffer_size); + + /* 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 (OS/2 for example). + */ + 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); - } - else - { - /* Error */ - sprintf(outbuf, "Privoxy(%08lx) Error: log_error(): Bad format string:\n" - "Format = \"%s\"\n" - "Exiting.", this_thread, fmt); - if( !logfp ) - { - logfp = stderr; - } - fputs(outbuf, logfp); - fatal_error(outbuf); - /* Never get here */ - break; + ulval = va_arg(ap, unsigned long); + snprintf(tempbuf, sizeof(tempbuf), "%lu", ulval); } - if (outc < BUFFER_SIZE-1) + else if ((ch == 'l') && (*src == 'u')) { - 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': @@ -690,210 +813,199 @@ void log_error(int loglevel, char *fmt, ...) * 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) */ - 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 * ); - if (sval == NULL) - { - sval = "[null]"; - } - 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 (sval == NULL) - { - sval = "[null]"; - } - 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); + format_string = w32_socket_strerr(ival, tempbuf); #elif __OS2__ ival = sock_errno(); if (ival != 0) - sval = os2_socket_strerr(ival, tempbuf); + { + format_string = os2_socket_strerr(ival, tempbuf); + } else { - ival = errno; - sval = strerror(ival); + ival = errno; + format_string = strerror(ival); } #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); -#elif OSX_DARWIN - 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 OSX_DARWIN - 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; - 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(%08lx) Error: log_error(): Bad format string:\n" - "Format = \"%s\"\n" - "Exiting.", this_thread, fmt); - if( !logfp ) - { - logfp = stderr; - } - fputs(outbuf_save, logfp); - unlock_logfile(); - fatal_error(outbuf_save); - /* Never get here */ + 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); - } /* for( p ... ) */ - - /* done with var. args */ - va_end( ap ); - - if (outc >= BUFFER_SIZE-2) - { - /* insufficient room for newline and trailing null. */ + if (length >= log_buffer_size-2) + { + static const char warning[] = "... [too long, truncated]"; - static const char warning[] = "... [too long, truncated]\n"; + length = log_buffer_size - sizeof(warning) - 1; + length += strlcpy(outbuf + length, warning, log_buffer_size - length); + assert(length < log_buffer_size); - if (outc < BUFFER_SIZE) - { - /* Need to add terminating null in this case. */ - outbuf[outc] = '\0'; + break; } + } - /* Truncate output */ - outbuf[BUFFER_SIZE - sizeof(warning)] = '\0'; + /* done with var. args */ + va_end(ap); - /* Append warning */ - strcat(outbuf, warning); - } - else - { - /* Add terminating newline and null */ - outbuf[outc++] = '\n'; - outbuf[outc] = '\0'; - } + 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 if (loglevel == LOG_LEVEL_FATAL) { fatal_error(outbuf_save); /* Never get here */ } - - unlock_logfile(); + if (logfp != NULL) + { + fputs(outbuf_save, logfp); + } #if defined(_WIN32) && !defined(_WIN_CONSOLE) /* Write to display */ LogPutString(outbuf_save); #endif /* defined(_WIN32) && !defined(_WIN_CONSOLE) */ + unlock_logfile(); + } +/********************************************************************* + * + * 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 : jb_error = a valid jb_err code + * + * Returns : A string with the jb_err translation + * + *********************************************************************/ +const char *jb_err_to_string(int 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 /********************************************************************* *