1 files changed, 145 insertions, 39 deletions
diff --git a/src/or/circuituse.c b/src/or/circuituse.c
index 827c4bbf2..e9335b18d 100644
--- a/src/or/circuituse.c
+++ b/src/or/circuituse.c
@@ -10,6 +10,20 @@
  **/
 
 #include "or.h"
+#include "circuitbuild.h"
+#include "circuitlist.h"
+#include "circuituse.h"
+#include "config.h"
+#include "connection.h"
+#include "connection_edge.h"
+#include "control.h"
+#include "policies.h"
+#include "rendclient.h"
+#include "rendcommon.h"
+#include "rendservice.h"
+#include "rephist.h"
+#include "router.h"
+#include "routerlist.h"
 
 /********* START VARIABLES **********/
 
@@ -20,6 +34,8 @@ extern circuit_t *global_circuitlist; /* from circuitlist.c */
 static void circuit_expire_old_circuits_clientside(time_t now);
 static void circuit_increment_failure_count(void);
 
+long int lround(double x);
+
 /** Return 1 if <b>circ</b> could be returned by circuit_get_best().
  * Else return 0.
  */
@@ -113,7 +129,7 @@ circuit_is_acceptable(circuit_t *circ, edge_connection_t *conn,
         return 0;
       }
     }
-    if (exitrouter && !connection_ap_can_use_exit(conn, exitrouter)) {
+    if (exitrouter && !connection_ap_can_use_exit(conn, exitrouter, 0)) {
       /* can't exit from this router */
       return 0;
     }
@@ -263,16 +279,19 @@ circuit_conforms_to_options(const origin_circuit_t *circ,
 void
 circuit_expire_building(time_t now)
 {
-  circuit_t *victim, *circ = global_circuitlist;
-  time_t general_cutoff = now - get_options()->CircuitBuildTimeout;
-  time_t begindir_cutoff = now - get_options()->CircuitBuildTimeout/2;
+  circuit_t *victim, *next_circ = global_circuitlist;
+  /* circ_times.timeout is BUILD_TIMEOUT_INITIAL_VALUE if we haven't
+   * decided on a customized one yet */
+  time_t general_cutoff = now - lround(circ_times.timeout_ms/1000);
+  time_t begindir_cutoff = now - lround(circ_times.timeout_ms/2000);
+  time_t close_cutoff = now - lround(circ_times.close_ms/1000);
   time_t introcirc_cutoff = begindir_cutoff;
   cpath_build_state_t *build_state;
 
-  while (circ) {
+  while (next_circ) {
     time_t cutoff;
-    victim = circ;
-    circ = circ->next;
+    victim = next_circ;
+    next_circ = next_circ->next;
     if (!CIRCUIT_IS_ORIGIN(victim) || /* didn't originate here */
         victim->marked_for_close) /* don't mess with marked circs */
       continue;
@@ -282,8 +301,11 @@ circuit_expire_building(time_t now)
       cutoff = begindir_cutoff;
     else if (victim->purpose == CIRCUIT_PURPOSE_C_INTRODUCING)
       cutoff = introcirc_cutoff;
+    else if (victim->purpose == CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT)
+      cutoff = close_cutoff;
     else
       cutoff = general_cutoff;
+
     if (victim->timestamp_created > cutoff)
       continue; /* it's still young, leave it alone */
 
@@ -343,6 +365,43 @@ circuit_expire_building(time_t now)
             continue;
           break;
       }
+    } else { /* circuit not open, consider recording failure as timeout */
+      int first_hop_succeeded = TO_ORIGIN_CIRCUIT(victim)->cpath &&
+            TO_ORIGIN_CIRCUIT(victim)->cpath->state == CPATH_STATE_OPEN;
+
+      if (TO_ORIGIN_CIRCUIT(victim)->p_streams != NULL) {
+        log_warn(LD_BUG, "Circuit %d (purpose %d) has timed out, "
+                 "yet has attached streams!",
+                 TO_ORIGIN_CIRCUIT(victim)->global_identifier,
+                 victim->purpose);
+        tor_fragile_assert();
+        continue;
+      }
+
+      /* circuits are allowed to last longer for measurement.
+       * Switch their purpose and wait. */
+      if (victim->purpose != CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT) {
+        victim->purpose = CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT;
+        circuit_build_times_count_timeout(&circ_times,
+                                          first_hop_succeeded);
+        continue;
+      }
+
+      /*
+       * If the circuit build time is much greater than we would have cut
+       * it off at, we probably had a suspend event along this codepath,
+       * and we should discard the value.
+       */
+      if (now - victim->timestamp_created > 2*circ_times.close_ms/1000+1) {
+        log_notice(LD_CIRC,
+                   "Extremely large value for circuit build timeout: %lds. "
+                   "Assuming clock jump.",
+                   (long)(now - victim->timestamp_created));
+      } else if (circuit_build_times_count_close(&circ_times,
+                                          first_hop_succeeded,
+                                          victim->timestamp_created)) {
+        circuit_build_times_set_timeout(&circ_times);
+      }
     }
 
     if (victim->n_conn)
@@ -414,7 +473,7 @@ circuit_stream_is_being_handled(edge_connection_t *conn,
       if (exitrouter && (!need_uptime || build_state->need_uptime)) {
         int ok;
         if (conn) {
-          ok = connection_ap_can_use_exit(conn, exitrouter);
+          ok = connection_ap_can_use_exit(conn, exitrouter, 0);
         } else {
           addr_policy_result_t r = compare_addr_to_addr_policy(
               0, port, exitrouter->exit_policy);
@@ -431,11 +490,11 @@ circuit_stream_is_being_handled(edge_connection_t *conn,
 }
 
 /** Don't keep more than this many unused open circuits around. */
-#define MAX_UNUSED_OPEN_CIRCUITS 12
+#define MAX_UNUSED_OPEN_CIRCUITS 14
 
 /** Figure out how many circuits we have open that are clean. Make
  * sure it's enough for all the upcoming behaviors we predict we'll have.
- * But if we have too many, close the not-so-useful ones.
+ * But put an upper bound on the total number of circuits.
  */
 static void
 circuit_predict_and_launch_new(void)
@@ -517,6 +576,19 @@ circuit_predict_and_launch_new(void)
     circuit_launch_by_router(CIRCUIT_PURPOSE_C_GENERAL, NULL, flags);
     return;
   }
+
+  /* Finally, check to see if we still need more circuits to learn
+   * a good build timeout. But if we're close to our max number we
+   * want, don't do another -- we want to leave a few slots open so
+   * we can still build circuits preemptively as needed. */
+  if (num < MAX_UNUSED_OPEN_CIRCUITS-2 &&
+      circuit_build_times_needs_circuits_now(&circ_times)) {
+    flags = CIRCLAUNCH_NEED_CAPACITY;
+    log_info(LD_CIRC,
+             "Have %d clean circs need another buildtime test circ.", num);
+    circuit_launch_by_router(CIRCUIT_PURPOSE_C_GENERAL, NULL, flags);
+    return;
+  }
 }
 
 /** Build a new test circuit every 5 minutes */
@@ -624,6 +696,11 @@ circuit_detach_stream(circuit_t *circ, edge_connection_t *conn)
   tor_fragile_assert();
 }
 
+/** If we haven't yet decided on a good timeout value for circuit
+ * building, we close idles circuits aggressively so we can get more
+ * data points. */
+#define IDLE_TIMEOUT_WHILE_LEARNING (10*60)
+
 /** Find each circuit that has been unused for too long, or dirty
  * for too long and has no streams on it: mark it for close.
  */
@@ -631,10 +708,18 @@ static void
 circuit_expire_old_circuits_clientside(time_t now)
 {
   circuit_t *circ;
-  time_t cutoff = now - get_options()->CircuitIdleTimeout;
+  time_t cutoff;
+
+  if (circuit_build_times_needs_circuits(&circ_times)) {
+    /* Circuits should be shorter lived if we need more of them
+     * for learning a good build timeout */
+    cutoff = now - IDLE_TIMEOUT_WHILE_LEARNING;
+  } else {
+    cutoff = now - get_options()->CircuitIdleTimeout;
+  }
 
   for (circ = global_circuitlist; circ; circ = circ->next) {
-    if (circ->marked_for_close || ! CIRCUIT_IS_ORIGIN(circ))
+    if (circ->marked_for_close || !CIRCUIT_IS_ORIGIN(circ))
       continue;
     /* If the circuit has been dirty for too long, and there are no streams
      * on it, mark it for close.
@@ -647,14 +732,38 @@ circuit_expire_old_circuits_clientside(time_t now)
                 circ->n_circ_id, (int)(now - circ->timestamp_dirty),
                 circ->purpose);
       circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED);
-    } else if (!circ->timestamp_dirty &&
-               circ->state == CIRCUIT_STATE_OPEN &&
-               circ->purpose == CIRCUIT_PURPOSE_C_GENERAL) {
+    } else if (!circ->timestamp_dirty && circ->state == CIRCUIT_STATE_OPEN) {
       if (circ->timestamp_created < cutoff) {
-        log_debug(LD_CIRC,
-                  "Closing circuit that has been unused for %d seconds.",
-                  (int)(now - circ->timestamp_created));
-        circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED);
+        if (circ->purpose == CIRCUIT_PURPOSE_C_GENERAL ||
+                circ->purpose == CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT ||
+                circ->purpose == CIRCUIT_PURPOSE_S_ESTABLISH_INTRO ||
+                circ->purpose == CIRCUIT_PURPOSE_TESTING ||
+                (circ->purpose >= CIRCUIT_PURPOSE_C_INTRODUCING &&
+                circ->purpose <= CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED) ||
+                circ->purpose == CIRCUIT_PURPOSE_S_CONNECT_REND) {
+          log_debug(LD_CIRC,
+                    "Closing circuit that has been unused for %ld seconds.",
+                    (long)(now - circ->timestamp_created));
+          circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED);
+        } else if (!TO_ORIGIN_CIRCUIT(circ)->is_ancient) {
+          /* Server-side rend joined circuits can end up really old, because
+           * they are reused by clients for longer than normal. The client
+           * controls their lifespan. (They never become dirty, because
+           * connection_exit_begin_conn() never marks anything as dirty.)
+           * Similarly, server-side intro circuits last a long time. */
+          if (circ->purpose != CIRCUIT_PURPOSE_S_REND_JOINED &&
+              circ->purpose != CIRCUIT_PURPOSE_S_INTRO) {
+            log_notice(LD_CIRC,
+                       "Ancient non-dirty circuit %d is still around after "
+                       "%ld seconds. Purpose: %d",
+                       TO_ORIGIN_CIRCUIT(circ)->global_identifier,
+                       (long)(now - circ->timestamp_created),
+                       circ->purpose);
+            /* FFFF implement a new circuit_purpose_to_string() so we don't
+             * just print out a number for circ->purpose */
+            TO_ORIGIN_CIRCUIT(circ)->is_ancient = 1;
+          }
+        }
       }
     }
   }
@@ -853,6 +962,9 @@ circuit_build_failed(origin_circuit_t *circ)
                "(%s:%d). I'm going to try to rotate to a better connection.",
                n_conn->_base.address, n_conn->_base.port);
       n_conn->is_bad_for_new_circs = 1;
+    } else {
+      log_info(LD_OR,
+               "Our circuit died before the first hop with no connection");
     }
     if (n_conn_id) {
       entry_guard_register_connect_status(n_conn_id, 0, 1, time(NULL));
@@ -936,8 +1048,8 @@ circuit_launch_by_router(uint8_t purpose,
   if (exit)
     info = extend_info_from_router(exit);
   circ = circuit_launch_by_extend_info(purpose, info, flags);
-  if (info)
-    extend_info_free(info);
+
+  extend_info_free(info);
   return circ;
 }
 
@@ -1082,13 +1194,13 @@ circuit_get_open_circ_or_launch(edge_connection_t *conn,
        * as loudly. the user doesn't even know it's happening. */
       if (options->UseBridges && bridges_known_but_down()) {
         log_fn(severity, LD_APP|LD_DIR,
-               "Application request when we're believed to be "
-               "offline. Optimistically trying known bridges again.");
+               "Application request when we haven't used client functionality "
+               "lately. Optimistically trying known bridges again.");
         bridges_retry_all();
       } else if (!options->UseBridges || any_bridge_descriptors_known()) {
         log_fn(severity, LD_APP|LD_DIR,
-               "Application request when we're believed to be "
-               "offline. Optimistically trying directory fetches again.");
+               "Application request when we haven't used client functionality "
+               "lately. Optimistically trying directory fetches again.");
         routerlist_retry_directory_downloads(time(NULL));
       }
     }
@@ -1111,7 +1223,7 @@ circuit_get_open_circ_or_launch(edge_connection_t *conn,
                                                 need_uptime)) {
         log_notice(LD_APP,
                    "No Tor server allows exit to %s:%d. Rejecting.",
-                   safe_str(conn->socks_request->address),
+                   safe_str_client(conn->socks_request->address),
                    conn->socks_request->port);
         return -1;
       }
@@ -1119,7 +1231,7 @@ circuit_get_open_circ_or_launch(edge_connection_t *conn,
       /* XXXX022 Duplicates checks in connection_ap_handshake_attach_circuit */
       routerinfo_t *router = router_get_by_nickname(conn->chosen_exit_name, 1);
       int opt = conn->chosen_exit_optional;
-      if (router && !connection_ap_can_use_exit(conn, router)) {
+      if (router && !connection_ap_can_use_exit(conn, router, 0)) {
         log_fn(opt ? LOG_INFO : LOG_WARN, LD_APP,
                "Requested exit point '%s' would refuse request. %s.",
                conn->chosen_exit_name, opt ? "Trying others" : "Closing");
@@ -1152,19 +1264,14 @@ circuit_get_open_circ_or_launch(edge_connection_t *conn,
       if (!extend_info) {
         log_info(LD_REND,
                  "No intro points for '%s': re-fetching service descriptor.",
-                 safe_str(conn->rend_data->onion_address));
-        /* Fetch both, v0 and v2 rend descriptors in parallel. Use whichever
-         * arrives first. Exception: When using client authorization, only
-         * fetch v2 descriptors.*/
+                 safe_str_client(conn->rend_data->onion_address));
         rend_client_refetch_v2_renddesc(conn->rend_data);
-        if (conn->rend_data->auth_type == REND_NO_AUTH)
-          rend_client_refetch_renddesc(conn->rend_data->onion_address);
         conn->_base.state = AP_CONN_STATE_RENDDESC_WAIT;
         return 0;
       }
       log_info(LD_REND,"Chose '%s' as intro point for '%s'.",
                extend_info->nickname,
-               safe_str(conn->rend_data->onion_address));
+               safe_str_client(conn->rend_data->onion_address));
     }
 
     /* If we have specified a particular exit node for our
@@ -1193,7 +1300,7 @@ circuit_get_open_circ_or_launch(edge_connection_t *conn,
             }
             if (tor_addr_from_str(&addr, conn->socks_request->address) < 0) {
               log_info(LD_DIR, "Broken address %s on tunnel conn. Closing.",
-                       escaped_safe_str(conn->socks_request->address));
+                       escaped_safe_str_client(conn->socks_request->address));
               return -1;
             }
             extend_info = extend_info_alloc(conn->chosen_exit_name+1,
@@ -1235,8 +1342,7 @@ circuit_get_open_circ_or_launch(edge_connection_t *conn,
                                            flags);
     }
 
-    if (extend_info)
-      extend_info_free(extend_info);
+    extend_info_free(extend_info);
 
     if (desired_circuit_purpose != CIRCUIT_PURPOSE_C_GENERAL) {
       /* help predict this next time */
@@ -1418,7 +1524,7 @@ connection_ap_handshake_attach_circuit(edge_connection_t *conn)
       LOG_INFO : LOG_NOTICE;
     log_fn(severity, LD_APP,
            "Tried for %d seconds to get a connection to %s:%d. Giving up.",
-           conn_age, safe_str(conn->socks_request->address),
+           conn_age, safe_str_client(conn->socks_request->address),
            conn->socks_request->port);
     return -1;
   }
@@ -1445,7 +1551,7 @@ connection_ap_handshake_attach_circuit(edge_connection_t *conn)
         }
         return -1;
       }
-      if (router && !connection_ap_can_use_exit(conn, router)) {
+      if (router && !connection_ap_can_use_exit(conn, router, 0)) {
         log_fn(opt ? LOG_INFO : LOG_WARN, LD_APP,
                "Requested exit point '%s' would refuse request. %s.",
                conn->chosen_exit_name, opt ? "Trying others" : "Closing");