r11860@catbus: nickm | 2007-02-21 00:56:15 -0500

Another optimization suggested by Shark output: shave off >90% of uses of logv by cutting down on calls to log_debug when log actually debugging.  This is showing up in some profiles bug not others, and might be as much as 2.5%.


svn:r9612

ChangeLog

@@ -56,6 +56,9 @@ Changes in version 0.1.2.8-alpha - 2007-??-??
   o Minor bugfixes (performance):
     - Call router_have_min_dir_info half as often.  (This is showing up in
       some profiles, but not others.)
+    - When using GCC, make log_debug and never get called at all, and its
+      arguments never get evaluated, when no debug logs are configured.
+      (This is showing up in some profiles, but not others.)
 
   o Minor features:
     - Remove some never-implemented options.  Mark PathlenCoinWeight as

src/common/log.c

@@ -86,6 +86,9 @@ static logfile_t *logfiles = NULL;
 static int syslog_count = 0;
 #endif
 
+/* What's the lowest log level anybody cares about? */
+int _log_global_min_severity = LOG_NOTICE;
+
 static void delete_log(logfile_t *victim);
 static void close_log(logfile_t *victim);
 
@@ -405,6 +408,8 @@ add_stream_log(int loglevelMin, int loglevelMax,
   lf->file = stream;
   lf->next = logfiles;
   logfiles = lf;
+
+  _log_global_min_severity = get_min_log_level();
 }
 
 /** Add a log handler to receive messages during startup (before the real
@@ -415,6 +420,8 @@ add_temp_log(void)
 {
   add_stream_log(LOG_NOTICE, LOG_ERR, "<temp>", stdout);
   logfiles->is_temporary = 1;
+
+  _log_global_min_severity = get_min_log_level();
 }
 
 /**
@@ -433,6 +440,8 @@ add_callback_log(int loglevelMin, int loglevelMax, log_callback cb)
   lf->callback = cb;
   lf->next = logfiles;
   logfiles = lf;
+
+  _log_global_min_severity = get_min_log_level();
   return 0;
 }
 
@@ -449,6 +458,8 @@ change_callback_log_severity(int loglevelMin, int loglevelMax,
       lf->max_loglevel = loglevelMax;
     }
   }
+
+  _log_global_min_severity = get_min_log_level();
 }
 
 /** Close any log handlers added by add_temp_log or marked by mark_logs_temp */
@@ -468,6 +479,8 @@ close_temp_logs(void)
       p = &((*p)->next);
     }
   }
+
+  _log_global_min_severity = get_min_log_level();
 }
 
 /** Make all currently temporary logs (set to be closed by close_temp_logs)
@@ -506,6 +519,7 @@ add_file_log(int loglevelMin, int loglevelMax, const char *filename)
   if (log_tor_version(logfiles, 0) < 0) {
     delete_log(logfiles);
   }
+  _log_global_min_severity = get_min_log_level();
   return 0;
 }
 
@@ -528,6 +542,8 @@ add_syslog_log(int loglevelMin, int loglevelMax)
   lf->is_syslog = 1;
   lf->next = logfiles;
   logfiles = lf;
+
+  _log_global_min_severity = get_min_log_level();
   return 0;
 }
 #endif

src/common/log.h

@@ -120,6 +120,8 @@ void _log(int severity, uint32_t domain, const char *format, ...)
 #define log _log /* hack it so we don't conflict with log() as much */
 
 #ifdef __GNUC__
+extern int _log_global_min_severity;
+
 void _log_fn(int severity, uint32_t domain,
              const char *funcname, const char *format, ...)
   CHECK_PRINTF(4,5);
@@ -127,8 +129,11 @@ void _log_fn(int severity, uint32_t domain,
  * of the current function name. */
 #define log_fn(severity, domain, args...)               \
   _log_fn(severity, domain, __PRETTY_FUNCTION__, args)
-#define log_debug(domain, args...)                          \
-  _log_fn(LOG_DEBUG, domain, __PRETTY_FUNCTION__, args)
+#define log_debug(domain, args...)                              \
+  do {                                                          \
+    if (PREDICT(_log_global_min_severity == LOG_DEBUG, 0))      \
+      _log_fn(LOG_DEBUG, domain, __PRETTY_FUNCTION__, args);    \
+  } while (0)
 #define log_info(domain, args...)                           \
   _log_fn(LOG_INFO, domain, __PRETTY_FUNCTION__, args)
 #define log_notice(domain, args...)                         \
@@ -155,13 +160,6 @@ void _log_err(uint32_t domain, const char *format, ...);
 #define log_notice _log_notice
 #define log_warn _log_warn
 #define log_err _log_err
-/*
-#define debug _debug
-#define info _info
-#define notice _notice
-#define warn _warn
-#define err _err
-*/
 #else
 /* We don't have GCC's varargs macros, so use a global variable to pass the
  * function name to log_fn */
@@ -175,13 +173,6 @@ extern const char *_log_fn_function_name;
 #define log_notice (_log_fn_function_name=__func__),_log_notice
 #define log_warn (_log_fn_function_name=__func__),_log_warn
 #define log_err (_log_fn_function_name=__func__),_log_err
-/*
-#define debug (_log_fn_function_name=__func__),_debug
-#define info (_log_fn_function_name=__func__),_info
-#define notice (_log_fn_function_name=__func__),_notice
-#define warn (_log_fn_function_name=__func__),_warn
-#define err (_log_fn_function_name=__func__),_err
-*/
 #endif
 
 #endif /* !GNUC */