From d0927b664602a68844b4a91e10af6d6350048397 Mon Sep 17 00:00:00 2001 From: teor Date: Sat, 4 Mar 2017 22:42:59 +1100 Subject: [PATCH 1/4] Create function to log service introduction point creation limits Depends on 21594, part of 21622. (Resolved merge conflict in static function declarations. --- src/or/rendservice.c | 40 ++++++++++++++++++++++++++++++++++++++++ 1 file changed, 40 insertions(+) diff --git a/src/or/rendservice.c b/src/or/rendservice.c index eeccd4347b..8f978d0096 100644 --- a/src/or/rendservice.c +++ b/src/or/rendservice.c @@ -83,6 +83,7 @@ static const smartlist_t* rend_get_service_list( const smartlist_t* substitute_service_list); static smartlist_t* rend_get_service_list_mutable( smartlist_t* substitute_service_list); +static int rend_max_intro_circs_per_period(unsigned int n_intro_points_wanted); /** Represents the mapping from a virtual port of a rendezvous service to * a real port on some IP. @@ -1025,6 +1026,45 @@ rend_service_del_ephemeral(const char *service_id) return 0; } +/* There can be 1 second's delay due to second_elapsed_callback, and perhaps + * another few seconds due to blocking calls. */ +#define INTRO_CIRC_RETRY_PERIOD_SLOP 10 + +/** Log information about the intro point creation rate and current intro + * points for service, upgrading the log level from min_severity to warn if + * we have stopped launching new intro point circuits. */ +static void +rend_log_intro_limit(const rend_service_t *service, int min_severity) +{ + int exceeded_limit = (service->n_intro_circuits_launched >= + rend_max_intro_circs_per_period( + service->n_intro_points_wanted)); + int severity = min_severity; + /* We stopped creating circuits */ + if (exceeded_limit) { + severity = LOG_WARN; + } + time_t intro_period_elapsed = time(NULL) - service->intro_period_started; + tor_assert_nonfatal(intro_period_elapsed >= 0); + /* We delayed resuming circuits longer than expected */ + int exceeded_elapsed = (intro_period_elapsed > INTRO_CIRC_RETRY_PERIOD + + INTRO_CIRC_RETRY_PERIOD_SLOP); + if (exceeded_elapsed) { + severity = LOG_WARN; + } + log_fn(severity, LD_REND, "Hidden service %s %s %d intro points in the last " + "%d seconds%s. Intro circuit launches are limited to %d per %d " + "seconds.", + service->service_id, + exceeded_limit ? "exceeded launch limit with" : "launched", + service->n_intro_circuits_launched, + (int)intro_period_elapsed, + exceeded_elapsed ? " (delayed)" : "", + rend_max_intro_circs_per_period(service->n_intro_points_wanted), + INTRO_CIRC_RETRY_PERIOD); + rend_service_dump_stats(severity); +} + /** Replace the old value of service-\>desc with one that reflects * the other fields in service. */ From c99d0e742adbe878d8126a49573e83462a61742e Mon Sep 17 00:00:00 2001 From: teor Date: Sat, 4 Mar 2017 22:44:21 +1100 Subject: [PATCH 2/4] Log more info when a service descriptor has the wrong number of intro points Depends on 21598, part of 21622. --- src/or/rendservice.c | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/or/rendservice.c b/src/or/rendservice.c index 8f978d0096..2b7c6bfb69 100644 --- a/src/or/rendservice.c +++ b/src/or/rendservice.c @@ -1134,7 +1134,8 @@ rend_service_update_descriptor(rend_service_t *service) "descriptor was updated with %d instead.", service->service_id, service->n_intro_points_wanted, have_intro); - rend_service_dump_stats(severity); + /* Now log an informative message about how we might have got here. */ + rend_log_intro_limit(service, severity); } } From c34411d9cb1c264ad5ccc149ea07f1fdc826010a Mon Sep 17 00:00:00 2001 From: teor Date: Sat, 4 Mar 2017 22:46:19 +1100 Subject: [PATCH 3/4] Log info about intro point limits when they are reached and reset Depends on 21594, part of 21622. --- src/or/rendservice.c | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/or/rendservice.c b/src/or/rendservice.c index 2b7c6bfb69..82e31377cf 100644 --- a/src/or/rendservice.c +++ b/src/or/rendservice.c @@ -4136,8 +4136,12 @@ rend_consider_services_intro_points(void) /* This retry period is important here so we don't stress circuit * creation. */ + if (now > service->intro_period_started + INTRO_CIRC_RETRY_PERIOD) { - /* One period has elapsed; we can try building circuits again. */ + /* One period has elapsed: + * - if we stopped, we can try building circuits again, + * - if we haven't, we reset the circuit creation counts. */ + rend_log_intro_limit(service, LOG_INFO); service->intro_period_started = now; service->n_intro_circuits_launched = 0; } else if (service->n_intro_circuits_launched >= @@ -4145,6 +4149,7 @@ rend_consider_services_intro_points(void) service->n_intro_points_wanted)) { /* We have failed too many times in this period; wait for the next * one before we try to initiate any more connections. */ + rend_log_intro_limit(service, LOG_WARN); continue; } From f1dd64bb00d4c755a9045e08a2a354fd453b79c8 Mon Sep 17 00:00:00 2001 From: teor Date: Sat, 4 Mar 2017 22:57:13 +1100 Subject: [PATCH 4/4] Changes file for feature 21622 --- changes/feature21622 | 8 ++++++++ 1 file changed, 8 insertions(+) create mode 100644 changes/feature21622 diff --git a/changes/feature21622 b/changes/feature21622 new file mode 100644 index 0000000000..163b90b724 --- /dev/null +++ b/changes/feature21622 @@ -0,0 +1,8 @@ + o Minor feature (hidden services): + - Log a message when a hidden service reaches its introduction point + circuit limit, and when that limit is reset. + Follow up to ticket 21594, closes ticket 21622. + - Add more information to the message logged when a hidden service + descriptor has fewer introduction points than specified in + HiddenServiceNumIntroductionPoints. + Follow up to tickets 21598 and 21599, closes ticket 21622.