Fix typos and comments, plus two bugs

A) We were considering a circuit had timed out in the special cases
where we close rendezvous circuits because the final rendezvous
circuit couldn't be built in time.
B) We were looking at the wrong timestamp_created when considering
a timeout.

doc/spec/proposals/151-path-selection-improvements.txt

@@ -90,7 +90,7 @@ Implementation
     changes in the timeout characteristics.
 
     We assume that we've had network connectivity loss if 3 circuits
-    timeout and we've recieved no cells or TLS handshakes since those
+    timeout and we've received no cells or TLS handshakes since those
     circuits began. We then set the timeout to 60 seconds and stop
     counting timeouts.
 
@@ -100,7 +100,7 @@ Implementation
 
     To detect changing network conditions, we keep a history of
     the timeout or non-timeout status of the past RECENT_CIRCUITS (20)
-    that successfully completed more than one hop. If more than 75%
+    that successfully completed at least one hop. If more than 75%
     of these circuits timeout, we discard all buildtimes history,
     reset the timeout to 60, and then begin recomputing the timeout.
 

src/or/circuitbuild.c

@@ -135,7 +135,7 @@ circuit_build_times_get_initial_timeout(void)
 /**
  * Reset the build time state.
  *
- * Leave estimated parameters, timeout and network liveness in tact
+ * Leave estimated parameters, timeout and network liveness intact
  * for future use.
  */
 void
@@ -690,20 +690,25 @@ circuit_build_times_network_is_live(circuit_build_times_t *cbt)
 }
 
 /**
- * Called to indicate that we completed a circuit
+ * Called to indicate that we completed a circuit. Because this circuit
+ * succeeded, it doesn't count as a timeout-after-the-first-hop.
  */
 void
 circuit_build_times_network_circ_success(circuit_build_times_t *cbt)
 {
-  cbt->liveness.onehop_timeouts[cbt->liveness.onehop_idx] = 0;
-  cbt->liveness.onehop_idx++;
-  cbt->liveness.onehop_idx %= RECENT_CIRCUITS;
+  cbt->liveness.timeouts_after_firsthop[cbt->liveness.after_firsthop_idx] = 0;
+  cbt->liveness.after_firsthop_idx++;
+  cbt->liveness.after_firsthop_idx %= RECENT_CIRCUITS;
 }
 
 /**
- * Count a circuit that timed out with no network activity at all
+ * A circuit just timed out. If there has been no recent network activity
+ * at all, but this circuit was launched back when we thought the network
+ * was live, increment the number of "nonlive" circuit timeouts.
+ *
+ * Also distinguish between whether it failed before the first hop.
  */
-void
+static void
 circuit_build_times_network_timeout(circuit_build_times_t *cbt,
                                     int did_onehop, time_t start_time)
 {
@@ -718,9 +723,9 @@ circuit_build_times_network_timeout(circuit_build_times_t *cbt,
 
   /* Check for one-hop timeout */
   if (did_onehop) {
-    cbt->liveness.onehop_timeouts[cbt->liveness.onehop_idx] = 1;
-    cbt->liveness.onehop_idx++;
-    cbt->liveness.onehop_idx %= RECENT_CIRCUITS;
+    cbt->liveness.timeouts_after_firsthop[cbt->liveness.after_firsthop_idx]=1;
+    cbt->liveness.after_firsthop_idx++;
+    cbt->liveness.after_firsthop_idx %= RECENT_CIRCUITS;
   }
 }
 
@@ -738,9 +743,10 @@ circuit_build_times_network_check_live(circuit_build_times_t *cbt)
   if (cbt->liveness.nonlive_timeouts >= NETWORK_NONLIVE_DISCARD_COUNT) {
     if (!cbt->liveness.nonlive_discarded) {
       cbt->liveness.nonlive_discarded = 1;
-      log_notice(LD_CIRC, "Network is no longer live. Dead for %ld seconds.",
-             (long int)(now - cbt->liveness.network_last_live));
-      /* Only discard NETWORK_NONLIVE_TIMEOUT_COUNT-1 because we stoped
+      log_notice(LD_CIRC, "Network is no longer live (too many recent "
+                "circuit timeouts). Dead for %ld seconds.",
+                (long int)(now - cbt->liveness.network_last_live));
+      /* Only discard NETWORK_NONLIVE_TIMEOUT_COUNT-1 because we stopped
        * counting after that */
       circuit_build_times_rewind_history(cbt, NETWORK_NONLIVE_TIMEOUT_COUNT-1);
     }
@@ -763,8 +769,8 @@ circuit_build_times_network_check_live(circuit_build_times_t *cbt)
 
 /**
  * Returns true if we have seen more than MAX_RECENT_TIMEOUT_COUNT of
- * the past RECENT_CIRCUITS time out. Used to detect if the network
- * connection has changed significantly.
+ * the past RECENT_CIRCUITS time out after the first hop. Used to detect
+ * if the network connection has changed significantly.
  *
  * Also resets the entire timeout history in this case and causes us
  * to restart the process of building test circuits and estimating a
@@ -777,21 +783,22 @@ circuit_build_times_network_check_changed(circuit_build_times_t *cbt)
   int timeout_count=0;
   int i;
 
+  /* how many of our recent circuits made it to the first hop but then
+   * timed out? */
   for (i = 0; i < RECENT_CIRCUITS; i++) {
-    timeout_count += cbt->liveness.onehop_timeouts[i];
+    timeout_count += cbt->liveness.timeouts_after_firsthop[i];
   }
 
-  /* If more than 80% of our recent circuits are timing out,
-   * we need to re-estimate a new initial alpha and timeout */
+  /* If 75% of our recent circuits are timing out after the first hop,
+   * we need to re-estimate a new initial alpha and timeout. */
   if (timeout_count < MAX_RECENT_TIMEOUT_COUNT) {
     return 0;
   }
 
-  /* Reset build history */
   circuit_build_times_reset(cbt);
-  memset(cbt->liveness.onehop_timeouts, 0,
-          sizeof(cbt->liveness.onehop_timeouts));
-  cbt->liveness.onehop_idx = 0;
+  memset(cbt->liveness.timeouts_after_firsthop, 0,
+          sizeof(cbt->liveness.timeouts_after_firsthop));
+  cbt->liveness.after_firsthop_idx = 0;
 
   /* Check to see if this has happened before. If so, double the timeout
    * to give people on abysmally bad network connections a shot at access */
@@ -803,7 +810,7 @@ circuit_build_times_network_check_changed(circuit_build_times_t *cbt)
 
   log_notice(LD_CIRC,
             "Network connection speed appears to have changed. Resetting "
-            "timeout to %lds after %d one-hop timeouts and %d buildtimes",
+            "timeout to %lds after %d timeouts and %d buildtimes.",
             lround(cbt->timeout_ms/1000), timeout_count, total_build_times);
 
   return 1;

src/or/circuituse.c

@@ -265,7 +265,7 @@ circuit_conforms_to_options(const origin_circuit_t *circ,
 void
 circuit_expire_building(time_t now)
 {
-  circuit_t *victim, *circ = global_circuitlist;
+  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);
@@ -273,10 +273,10 @@ circuit_expire_building(time_t now)
   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;
@@ -347,6 +347,12 @@ 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 (circuit_build_times_add_timeout(&circ_times, first_hop_succeeded,
+                                          victim->timestamp_created))
+        circuit_build_times_set_timeout(&circ_times);
     }
 
     if (victim->n_conn)
@@ -362,13 +368,6 @@ circuit_expire_building(time_t now)
 
     circuit_log_path(LOG_INFO,LD_CIRC,TO_ORIGIN_CIRCUIT(victim));
     circuit_mark_for_close(victim, END_CIRC_REASON_TIMEOUT);
-
-    if (circuit_build_times_add_timeout(&circ_times,
-       TO_ORIGIN_CIRCUIT(circ)->cpath
-              && TO_ORIGIN_CIRCUIT(circ)->cpath->state == CPATH_STATE_OPEN,
-                                         circ->timestamp_created)) {
-      circuit_build_times_set_timeout(&circ_times);
-    }
   }
 }
 

src/or/or.h

@@ -2937,11 +2937,11 @@ typedef struct {
   int nonlive_timeouts;
   /** If the network is not live, have we yet discarded our history? */
   int nonlive_discarded;
-  /** Circular array of circuits that have made it past 1 hop. Slot is
+  /** Circular array of circuits that have made it to the first hop. Slot is
    * 1 if circuit timed out, 0 if circuit succeeded */
-  int8_t onehop_timeouts[RECENT_CIRCUITS];
+  int8_t timeouts_after_firsthop[RECENT_CIRCUITS];
   /** Index into circular array. */
-  int onehop_idx;
+  int after_firsthop_idx;
 } network_liveness_t;
 
 /** Structure for circuit build times history */
@@ -3004,8 +3004,6 @@ int circuit_build_times_network_check_changed(circuit_build_times_t *cbt);
 /* Network liveness functions */
 void circuit_build_times_network_is_live(circuit_build_times_t *cbt);
 int circuit_build_times_network_check_live(circuit_build_times_t *cbt);
-void circuit_build_times_network_timeout(circuit_build_times_t *cbt,
-                                         int did_onehop, time_t start_time);
 void circuit_build_times_network_circ_success(circuit_build_times_t *cbt);
 
 /********************************* circuitlist.c ***********************/

src/or/test.c

@@ -3560,8 +3560,9 @@ test_circuit_timeout(void)
       }
     }
 
-    test_assert(estimate.liveness.onehop_idx == 0);
-    test_assert(final.liveness.onehop_idx == MAX_RECENT_TIMEOUT_COUNT-1);
+    test_assert(estimate.liveness.after_firsthop_idx == 0);
+    test_assert(final.liveness.after_firsthop_idx ==
+                MAX_RECENT_TIMEOUT_COUNT-1);
 
     test_assert(circuit_build_times_network_check_live(&estimate));
     test_assert(circuit_build_times_network_check_live(&final));