X-Git-Url: http://www.privoxy.org/gitweb/?p=privoxy.git;a=blobdiff_plain;f=errlog.c;h=dc1584503ea737eb1bdd83f0026baf0789dfb25f;hp=0e672a767cb87d94579a5909259cb920bb0a58e4;hb=56e77f644a0b3a8324dd24a02eca75789e3c8999;hpb=cf00a1febf05c13975594dc5a2b7e23572cc1177 diff --git a/errlog.c b/errlog.c index 0e672a76..dc158450 100644 --- a/errlog.c +++ b/errlog.c @@ -1,4 +1,4 @@ -const char errlog_rcs[] = "$Id: errlog.c,v 1.60 2007/11/03 19:03:31 fabiankeil Exp $"; +const char errlog_rcs[] = "$Id: errlog.c,v 1.91 2009/03/18 21:56:30 fabiankeil Exp $"; /********************************************************************* * * File : $Source: /cvsroot/ijbswa/current/errlog.c,v $ @@ -6,7 +6,7 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.60 2007/11/03 19:03:31 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,126 @@ const char errlog_rcs[] = "$Id: errlog.c,v 1.60 2007/11/03 19:03:31 fabiankeil E * * Revisions : * $Log: errlog.c,v $ + * Revision 1.91 2009/03/18 21:56:30 fabiankeil + * In init_error_log(), suppress the "(Re-)Opening logfile" message if + * we're still logging to stderr. This restores the "silent mode", but + * with LOG_LEVEL_INFO enabled, the show_version() info is written to + * the logfile as intended. + * + * Revision 1.90 2009/03/18 20:43:19 fabiankeil + * Don't enable LOG_LEVEL_INFO by default and don't apply the user's + * debug settings until the logfile has been opened (if there is one). + * Patch submitted by Roland in #2624120. + * + * Revision 1.89 2009/03/07 12:56:12 fabiankeil + * Add log_error() support for unsigned long long (%lld). + * + * Revision 1.88 2009/03/07 11:34:36 fabiankeil + * Omit timestamp and thread id in the mingw32 message box. + * + * Revision 1.87 2009/03/01 18:28:24 fabiankeil + * Help clang understand that we aren't dereferencing + * NULL pointers here. + * + * Revision 1.86 2009/02/09 21:21:15 fabiankeil + * Now that init_log_module() is called earlier, call show_version() + * later on from main() directly so it doesn't get called for --help + * or --version. + * + * 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. + * + * Revision 1.61 2007/11/04 19:03:01 fabiankeil + * Fix another deadlock Hal spotted and that mysteriously didn't affect FreeBSD. + * * Revision 1.60 2007/11/03 19:03:31 fabiankeil * - Prevent the Windows GUI from showing the version two times in a row. * - Stop using the imperative in the "(Re-)Open logfile" message. @@ -368,8 +488,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); @@ -380,24 +500,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 @@ -414,8 +534,8 @@ 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. + * a WIN32 GUI, to a dialog box), and exits Privoxy + * with status code 1. * * Parameters : * 1 : error_message = The error message to display. @@ -423,19 +543,28 @@ 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", + /* 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); /* Cleanup - remove taskbar icon etc. */ TermLogWindow(); - -#else /* if !defined(_WIN32) || defined(_WIN_CONSOLE) */ - fputs(error_message, logfp); #endif /* defined(_WIN32) && !defined(_WIN_CONSOLE) */ + if (logfp != NULL) + { + fputs(error_message, logfp); + } + #if defined(unix) if (pidfile) { @@ -459,7 +588,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) @@ -483,13 +612,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); } @@ -501,7 +629,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. @@ -530,7 +658,8 @@ void disable_logging(void) { if (logfp != NULL) { - log_error(LOG_LEVEL_INFO, "No logfile configured. Logging disabled."); + log_error(LOG_LEVEL_INFO, + "No logfile configured. Please enable it before reporting any problems."); lock_logfile(); fclose(logfp); logfp = NULL; @@ -549,8 +678,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 * @@ -563,13 +691,44 @@ void init_error_log(const char *prog_name, const char *logfname) lock_loginit(); - if (logfp != NULL) + if ((logfp != NULL) && (logfp != stderr)) { log_error(LOG_LEVEL_INFO, "(Re-)Opening logfile \'%s\'", 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); @@ -586,18 +745,7 @@ void init_error_log(const char *prog_name, const char *logfname) logfp = fp; unlock_logfile(); -#if !defined(_WIN32) - /* - * 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. - * - * This means mingw32 users will never see the version in their - * log file, but I assume they wouldn't look for it there anyway - * and simply use the "Help/About Privoxy" menu. - */ show_version(prog_name); -#endif /* def unix */ unlock_loginit(); @@ -680,15 +828,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); } @@ -738,18 +886,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 @@ -759,7 +907,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); @@ -834,11 +982,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; @@ -889,7 +1035,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(); } @@ -900,8 +1046,17 @@ void log_error(int loglevel, const char *fmt, ...) * settings and that logging is enabled. * Bail out otherwise. */ - if ((0 == (loglevel & debug)) || (logfp == NULL)) + 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; } @@ -917,12 +1072,10 @@ 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); - assert(NULL != logfp); - fputs(tempbuf, logfp); - unlock_logfile(); + "%s %08lx Fatal error: Out of memory in log_error().", + timestamp, thread_id); fatal_error(tempbuf); /* Exit */ + return; } } outbuf = outbuf_save; @@ -936,8 +1089,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. */ @@ -959,9 +1112,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; @@ -982,7 +1135,7 @@ void log_error(int loglevel, const char *fmt, ...) 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') { @@ -994,6 +1147,12 @@ void log_error(int loglevel, const char *fmt, ...) ulval = va_arg( ap, unsigned long ); snprintf(tempbuf, sizeof(tempbuf), "%lu", ulval); } + else if ((ch == 'l') && (*src == 'u')) + { + unsigned long long lluval = va_arg(ap, unsigned long long); + snprintf(tempbuf, sizeof(tempbuf), "%llu", lluval); + ch = *src++; + } else { snprintf(tempbuf, sizeof(tempbuf), "Bad format string: \"%s\"", fmt); @@ -1042,7 +1201,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. @@ -1118,9 +1277,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 */ @@ -1134,27 +1293,37 @@ 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; } +#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 */ } - fputs(outbuf_save, logfp); - - 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(); + }