commit f269e0f9a51ecc7f22e62bde302afd8574d2f96f Author: Nick Mathewson <nickm@torproject.org> Date: Wed Dec 26 10:51:58 2012 -0500 Wrapper function for the common rate-limited-log pattern. --- changes/easy.ratelim | 3 ++ src/common/log.c | 69 +++++++++++++++++++++++++++++++++++++++---------- src/common/torlog.h | 15 +++++++++++ src/common/util.h | 9 ++++++ 4 files changed, 82 insertions(+), 14 deletions(-) diff --git a/changes/easy.ratelim b/changes/easy.ratelim new file mode 100644 index 0000000..cadd1e4 --- /dev/null +++ b/changes/easy.ratelim @@ -0,0 +1,3 @@ + o Code simplification and refactoring: + - Add a wrapper function for the common "log a message with a rate-limit" + case. diff --git a/src/common/log.c b/src/common/log.c index 5bf12cf..15df2e0 100644 --- a/src/common/log.c +++ b/src/common/log.c @@ -140,11 +140,12 @@ static char *domain_to_string(log_domain_mask_t domain, char *buf, size_t buflen); static INLINE char *format_msg(char *buf, size_t buf_len, log_domain_mask_t domain, int severity, const char *funcname, + const char *suffix, const char *format, va_list ap, size_t *msg_len_out) - CHECK_PRINTF(6,0); + CHECK_PRINTF(7,0); static void logv(int severity, log_domain_mask_t domain, const char *funcname, - const char *format, va_list ap) - CHECK_PRINTF(4,0); + const char *suffix, const char *format, va_list ap) + CHECK_PRINTF(5,0); /** Name of the application: used to generate the message we write at the * start of each new log. */ @@ -251,6 +252,7 @@ log_tor_version(logfile_t *lf, int reset) static INLINE char * format_msg(char *buf, size_t buf_len, log_domain_mask_t domain, int severity, const char *funcname, + const char *suffix, const char *format, va_list ap, size_t *msg_len_out) { size_t n; @@ -312,6 +314,13 @@ format_msg(char *buf, size_t buf_len, n = buf_len; } else { n += r; + if (suffix) { + size_t suffix_len = strlen(suffix); + if (buf_len-n >= suffix_len) { + memcpy(buf+n, suffix, suffix_len); + n += suffix_len; + } + } } buf[n]='\n'; buf[n+1]='\0'; @@ -325,7 +334,7 @@ format_msg(char *buf, size_t buf_len, */ static void logv(int severity, log_domain_mask_t domain, const char *funcname, - const char *format, va_list ap) + const char *suffix, const char *format, va_list ap) { char buf[10024]; size_t msg_len = 0; @@ -361,8 +370,8 @@ logv(int severity, log_domain_mask_t domain, const char *funcname, if (!formatted) { end_of_prefix = - format_msg(buf, sizeof(buf), domain, severity, funcname, format, ap, - &msg_len); + format_msg(buf, sizeof(buf), domain, severity, funcname, suffix, + format, ap, &msg_len); formatted = 1; } @@ -426,7 +435,7 @@ tor_log(int severity, log_domain_mask_t domain, const char *format, ...) if (severity > log_global_min_severity_) return; va_start(ap,format); - logv(severity, domain, NULL, format, ap); + logv(severity, domain, NULL, NULL, format, ap); va_end(ap); } @@ -443,8 +452,24 @@ log_fn_(int severity, log_domain_mask_t domain, const char *fn, if (severity > log_global_min_severity_) return; va_start(ap,format); - logv(severity, domain, fn, format, ap); + logv(severity, domain, fn, NULL, format, ap); + va_end(ap); +} +void +log_fn_ratelim_(ratelim_t *ratelim, int severity, log_domain_mask_t domain, + const char *fn, const char *format, ...) +{ + va_list ap; + char *m; + if (severity > log_global_min_severity_) + return; + m = rate_limit_log(ratelim, approx_time()); + if (m == NULL) + return; + va_start(ap, format); + logv(severity, domain, fn, m, format, ap); va_end(ap); + tor_free(m); } #else /** @{ */ @@ -460,11 +485,27 @@ log_fn_(int severity, log_domain_mask_t domain, const char *format, ...) if (severity > log_global_min_severity_) return; va_start(ap,format); - logv(severity, domain, log_fn_function_name_, format, ap); + logv(severity, domain, log_fn_function_name_, NULL, format, ap); va_end(ap); log_fn_function_name_ = NULL; } void +log_fn_ratelim_(ratelim_t *ratelim, int severity, log_domain_mask_t domain, + const char *format, ...) +{ + va_list ap; + char *m; + if (severity > log_global_min_severity_) + return; + m = rate_limit_log(ratelim, approx_time()); + if (m == NULL) + return; + va_start(ap, format); + logv(severity, domain, log_fn_function_name_, m, format, ap); + va_end(ap); + tor_free(m); +} +void log_debug_(log_domain_mask_t domain, const char *format, ...) { va_list ap; @@ -472,7 +513,7 @@ log_debug_(log_domain_mask_t domain, const char *format, ...) if (PREDICT_LIKELY(LOG_DEBUG > log_global_min_severity_)) return; va_start(ap,format); - logv(LOG_DEBUG, domain, log_fn_function_name_, format, ap); + logv(LOG_DEBUG, domain, log_fn_function_name_, NULL, format, ap); va_end(ap); log_fn_function_name_ = NULL; } @@ -483,7 +524,7 @@ log_info_(log_domain_mask_t domain, const char *format, ...) if (LOG_INFO > log_global_min_severity_) return; va_start(ap,format); - logv(LOG_INFO, domain, log_fn_function_name_, format, ap); + logv(LOG_INFO, domain, log_fn_function_name_, NULL, format, ap); va_end(ap); log_fn_function_name_ = NULL; } @@ -494,7 +535,7 @@ log_notice_(log_domain_mask_t domain, const char *format, ...) if (LOG_NOTICE > log_global_min_severity_) return; va_start(ap,format); - logv(LOG_NOTICE, domain, log_fn_function_name_, format, ap); + logv(LOG_NOTICE, domain, log_fn_function_name_, NULL, format, ap); va_end(ap); log_fn_function_name_ = NULL; } @@ -505,7 +546,7 @@ log_warn_(log_domain_mask_t domain, const char *format, ...) if (LOG_WARN > log_global_min_severity_) return; va_start(ap,format); - logv(LOG_WARN, domain, log_fn_function_name_, format, ap); + logv(LOG_WARN, domain, log_fn_function_name_, NULL, format, ap); va_end(ap); log_fn_function_name_ = NULL; } @@ -516,7 +557,7 @@ log_err_(log_domain_mask_t domain, const char *format, ...) if (LOG_ERR > log_global_min_severity_) return; va_start(ap,format); - logv(LOG_ERR, domain, log_fn_function_name_, format, ap); + logv(LOG_ERR, domain, log_fn_function_name_, NULL, format, ap); va_end(ap); log_fn_function_name_ = NULL; } diff --git a/src/common/torlog.h b/src/common/torlog.h index ab97f9c..cc1fa64 100644 --- a/src/common/torlog.h +++ b/src/common/torlog.h @@ -161,10 +161,20 @@ extern int log_global_min_severity_; void log_fn_(int severity, log_domain_mask_t domain, const char *funcname, const char *format, ...) CHECK_PRINTF(4,5); +struct ratelim_t; +void log_fn_ratelim_(struct ratelim_t *ratelim, int severity, + log_domain_mask_t domain, const char *funcname, + const char *format, ...) + CHECK_PRINTF(5,6); /** Log a message at level <b>severity</b>, using a pretty-printed version * of the current function name. */ #define log_fn(severity, domain, args...) \ log_fn_(severity, domain, __PRETTY_FUNCTION__, args) +/** As log_fn, but use <b>ratelim</b> (an instance of ratelim_t) to control + * the frequency at which messages can appear. + */ +#define log_fn_ratelim(ratelim, severity, domain, args...) \ + log_fn_ratelim_(ratelim, severity, domain, __PRETTY_FUNCTION__, args) #define log_debug(domain, args...) \ STMT_BEGIN \ if (PREDICT_UNLIKELY(log_global_min_severity_ == LOG_DEBUG)) \ @@ -182,6 +192,9 @@ void log_fn_(int severity, log_domain_mask_t domain, #else /* ! defined(__GNUC__) */ void log_fn_(int severity, log_domain_mask_t domain, const char *format, ...); +struct ratelim_t; +void log_fn_ratelim_(struct ratelim_t *ratelim, int severity, + log_domain_mask_t domain, const char *format, ...); void log_debug_(log_domain_mask_t domain, const char *format, ...); void log_info_(log_domain_mask_t domain, const char *format, ...); void log_notice_(log_domain_mask_t domain, const char *format, ...); @@ -191,6 +204,7 @@ void log_err_(log_domain_mask_t domain, const char *format, ...); #if defined(_MSC_VER) && _MSC_VER < 1300 /* MSVC 6 and earlier don't have __func__, or even __LINE__. */ #define log_fn log_fn_ +#define log_fn_ratelim log_fn_ratelim_ #define log_debug log_debug_ #define log_info log_info_ #define log_notice log_notice_ @@ -204,6 +218,7 @@ extern const char *log_fn_function_name_; * do {...} while (0) trick to wrap this macro, since the macro can't take * arguments. */ #define log_fn (log_fn_function_name_=__func__),log_fn_ +#define log_fn_ratelim (log_fn_function_name_=__func__),log_fn_ratelim_ #define log_debug (log_fn_function_name_=__func__),log_debug_ #define log_info (log_fn_function_name_=__func__),log_info_ #define log_notice (log_fn_function_name_=__func__),log_notice_ diff --git a/src/common/util.h b/src/common/util.h index fabfdb1..005a3f3 100644 --- a/src/common/util.h +++ b/src/common/util.h @@ -284,6 +284,15 @@ void update_approx_time(time_t now); } } </pre> + + As a convenience wrapper for logging, you can replace the above with: + <pre> + if (possibly_very_frequent_event()) { + static ratelim_t warning_limit = RATELIM_INIT(300); + log_fn_ratelim(&warning_limit, LOG_WARN, LD_GENERAL, + "The event occurred!"); + } + </pre> */ typedef struct ratelim_t { int rate;