diff --git a/changes/log-ratelim b/changes/log-ratelim new file mode 100644 index 0000000000..612a510fdf --- /dev/null +++ b/changes/log-ratelim @@ -0,0 +1,7 @@ + o Minor bugfixes + - Rate-limit "Failed to hand off onionskin" warnings. + + o Minor features + - When logging a rate-limited warning, we now mention how many messages + got suppressed since the last warning. + diff --git a/src/common/util.c b/src/common/util.c index 6830ef3aa4..2781fa35d6 100644 --- a/src/common/util.c +++ b/src/common/util.c @@ -1577,6 +1577,49 @@ ftime_definitely_before(time_t now, time_t when) return (now + ftime_skew + ftime_slop) < when; } +/* ===== + * Rate limiting + * ===== */ + +/** If the rate-limiter lim is ready at now, return the number + * of calls to rate_limit_is_ready (including this one!) since the last time + * rate_limit_is_ready returned nonzero. Otherwise return 0. */ +static int +rate_limit_is_ready(ratelim_t *lim, time_t now) +{ + if (lim->rate + lim->last_allowed <= now) { + int res = lim->n_calls_since_last_time + 1; + lim->last_allowed = now; + lim->n_calls_since_last_time = 0; + return res; + } else { + ++lim->n_calls_since_last_time; + return 0; + } +} + +/** If the rate-limiter lim is ready at now, return a newly + * allocated string indicating how many messages were suppressed, suitable to + * append to a log message. Otherwise return NULL. */ +char * +rate_limit_log(ratelim_t *lim, time_t now) +{ + int n; + if ((n = rate_limit_is_ready(lim, now))) { + if (n == 1) { + return tor_strdup(""); + } else { + char *cp=NULL; + tor_asprintf(&cp, + " [%d similar message(s) suppressed in last %d seconds]", + n-1, lim->rate); + return cp; + } + } else { + return NULL; + } +} + /* ===== * File helpers * ===== */ diff --git a/src/common/util.h b/src/common/util.h index ba38f4c7ed..3a3a87378a 100644 --- a/src/common/util.h +++ b/src/common/util.h @@ -252,6 +252,33 @@ int ftime_maybe_before(time_t now, time_t when); int ftime_definitely_after(time_t now, time_t when); int ftime_definitely_before(time_t now, time_t when); +/* Rate-limiter */ + +/** A ratelim_t remembers how often an event is occurring, and how often + * it's allowed to occur. Typical usage is something like: + * +
+ if (possibly_very_frequent_event()) {
+ const int INTERVAL = 300;
+ static ratelim_t warning_limit = RATELIM_INIT(INTERVAL);
+ char *m;
+ if ((m = rate_limit_log(&warning_limit, approx_time()))) {
+ log_warn(LD_GENERAL, "The event occurred!%s", m);
+ tor_free(m);
+ }
+ }
+
+ */
+typedef struct ratelim_t {
+ int rate;
+ time_t last_allowed;
+ int n_calls_since_last_time;
+} ratelim_t;
+
+#define RATELIM_INIT(r) { (r), 0, 0 }
+
+char *rate_limit_log(ratelim_t *lim, time_t now);
+
/* File helpers */
ssize_t write_all(int fd, const char *buf, size_t count, int isSocket);
ssize_t read_all(int fd, char *buf, size_t count, int isSocket);
diff --git a/src/or/command.c b/src/or/command.c
index 0460e25c25..ea0bbea1e5 100644
--- a/src/or/command.c
+++ b/src/or/command.c
@@ -288,7 +288,14 @@ command_process_create_cell(cell_t *cell, or_connection_t *conn)
/* hand it off to the cpuworkers, and then return. */
if (assign_onionskin_to_cpuworker(NULL, circ, onionskin) < 0) {
- log_warn(LD_GENERAL,"Failed to hand off onionskin. Closing.");
+#define WARN_HANDOFF_FAILURE_INTERVAL (6*60*60)
+ static ratelim_t handoff_warning =
+ RATELIM_INIT(WARN_HANDOFF_FAILURE_INTERVAL);
+ char *m;
+ if ((m = rate_limit_log(&handoff_warning, approx_time()))) {
+ log_warn(LD_GENERAL,"Failed to hand off onionskin. Closing.%s",m);
+ tor_free(m);
+ }
circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_INTERNAL);
return;
}
diff --git a/src/or/connection.c b/src/or/connection.c
index c040be041e..91ce74b5b0 100644
--- a/src/or/connection.c
+++ b/src/or/connection.c
@@ -839,13 +839,13 @@ static void
warn_too_many_conns(void)
{
#define WARN_TOO_MANY_CONNS_INTERVAL (6*60*60)
- static time_t last_warned = 0;
- time_t now = time(NULL);
- int n_conns = get_n_open_sockets();
- if (last_warned + WARN_TOO_MANY_CONNS_INTERVAL < now) {
+ static ratelim_t last_warned = RATELIM_INIT(WARN_TOO_MANY_CONNS_INTERVAL);
+ char *m;
+ if ((m = rate_limit_log(&last_warned, approx_time()))) {
+ int n_conns = get_n_open_sockets();
log_warn(LD_NET,"Failing because we have %d connections already. Please "
- "raise your ulimit -n.", n_conns);
- last_warned = now;
+ "raise your ulimit -n.%s", n_conns, m);
+ tor_free(m);
control_event_general_status(LOG_WARN, "TOO_MANY_CONNECTIONS CURRENT=%d",
n_conns);
}
diff --git a/src/or/onion.c b/src/or/onion.c
index ebc3583648..fa001656e6 100644
--- a/src/or/onion.c
+++ b/src/or/onion.c
@@ -63,15 +63,16 @@ onion_pending_add(or_circuit_t *circ, char *onionskin)
if (ol_length >= get_options()->MaxOnionsPending) {
#define WARN_TOO_MANY_CIRC_CREATIONS_INTERVAL (60)
- static time_t last_warned = 0;
- time_t now = time(NULL);
- if (last_warned + WARN_TOO_MANY_CIRC_CREATIONS_INTERVAL < now) {
+ static ratelim_t last_warned =
+ RATELIM_INIT(WARN_TOO_MANY_CIRC_CREATIONS_INTERVAL);
+ char *m;
+ if ((m = rate_limit_log(&last_warned, approx_time()))) {
log_warn(LD_GENERAL,
"Your computer is too slow to handle this many circuit "
"creation requests! Please consider using the "
"MaxAdvertisedBandwidth config option or choosing a more "
- "restricted exit policy.");
- last_warned = now;
+ "restricted exit policy.%s",m);
+ tor_free(m);
}
tor_free(tmp);
return -1;