Refactor path use bias code into own function.

Also, improve and log some failure cases.

7 files changed, 112 insertions, 85 deletions

diff --git a/src/or/circuitbuild.c b/src/or/circuitbuild.c
index 8304ad8b8..af36cb2c3 100644
--- a/src/or/circuitbuild.c
+++ b/src/or/circuitbuild.c
@@ -60,7 +60,10 @@ static int onion_extend_cpath(origin_circuit_t *circ);
 static int count_acceptable_nodes(smartlist_t *routers);
 static int onion_append_hop(crypt_path_t **head_ptr, extend_info_t *choice);
 static int entry_guard_inc_first_hop_count(entry_guard_t *guard);
-static void pathbias_count_success(origin_circuit_t *circ);
+static void pathbias_count_build_success(origin_circuit_t *circ);
+static void pathbias_count_successful_close(origin_circuit_t *circ);
+static void pathbias_count_collapse(origin_circuit_t *circ);
+static void pathbias_count_unusable(origin_circuit_t *circ);
 
 /** This function tries to get a channel to the specified endpoint,
  * and then calls command_setup_channel() to give it the right
@@ -731,7 +734,7 @@ circuit_send_next_onion_skin(origin_circuit_t *circ)
         }
       }
 
-      pathbias_count_success(circ);
+      pathbias_count_build_success(circ);
       circuit_rep_hist_note_result(circ);
       circuit_has_opened(circ); /* do other actions as necessary */
 
@@ -1129,8 +1132,10 @@ pathbias_state_to_string(path_state_t state)
       return "new";
     case PATH_STATE_DID_FIRST_HOP:
       return "first hop";
-    case PATH_STATE_SUCCEEDED:
-      return "succeeded";
+    case PATH_STATE_BUILD_SUCCEEDED:
+      return "build succeeded";
+    case PATH_STATE_USE_SUCCEEDED:
+      return "use succeeded";
   }
 
   return "unknown";
@@ -1216,7 +1221,7 @@ pathbias_count_first_hop(origin_circuit_t *circ)
       }
     }
 
-    /* Don't count cannibalized circs for path bias */
+    /* Don't re-count cannibalized circs.. */
     if (!circ->has_opened) {
       entry_guard_t *guard = NULL;
 
@@ -1291,7 +1296,7 @@ pathbias_count_first_hop(origin_circuit_t *circ)
  * Also check for several potential error cases for bug #6475.
  */
 static void
-pathbias_count_success(origin_circuit_t *circ)
+pathbias_count_build_success(origin_circuit_t *circ)
 {
 #define SUCCESS_NOTICE_INTERVAL (600)
   static ratelim_t success_notice_limit =
@@ -1303,7 +1308,8 @@ pathbias_count_success(origin_circuit_t *circ)
     return;
   }
 
-  /* Don't count cannibalized/reused circs for path bias */
+  /* Don't count cannibalized/reused circs for path bias 
+   * build success.. They get counted under use success */
   if (!circ->has_opened) {
     if (circ->cpath && circ->cpath->extend_info) {
       guard = entry_guard_get_by_id_digest(
@@ -1312,7 +1318,7 @@ pathbias_count_success(origin_circuit_t *circ)
 
     if (guard) {
       if (circ->path_state == PATH_STATE_DID_FIRST_HOP) {
-        circ->path_state = PATH_STATE_SUCCEEDED;
+        circ->path_state = PATH_STATE_BUILD_SUCCEEDED;
         guard->circuit_successes++;
 
         log_info(LD_CIRC, "Got success count %u/%u for guard %s=%s",
@@ -1354,7 +1360,7 @@ pathbias_count_success(origin_circuit_t *circ)
       }
     }
   } else {
-    if (circ->path_state != PATH_STATE_SUCCEEDED) {
+    if (circ->path_state < PATH_STATE_BUILD_SUCCEEDED) {
       if ((rate_msg = rate_limit_log(&success_notice_limit,
               approx_time()))) {
         log_info(LD_BUG,
@@ -1371,9 +1377,70 @@ pathbias_count_success(origin_circuit_t *circ)
 }
 
 /**
- * Count a successfully closed circuit.
+ * Check if a circuit was used and/or closed successfully.
  */
 void
+pathbias_check_close(origin_circuit_t *ocirc, int reason)
+{
+  circuit_t *circ = &ocirc->base_;
+
+  if (ocirc->path_state == PATH_STATE_BUILD_SUCCEEDED) {
+    if (circ->timestamp_dirty) {
+      // XXX: May open up attacks if the adversary can force connections
+      // on unresponsive hosts to use new circs. Vidalia displayes a "Retrying"
+      // state.. Can we use that? Does optimistic data change this?
+      // XXX: For the hidserv side, we could only care about INTRODUCING purposes
+      // for server+client, and REND purposes for the server... Can we
+      // somehow only count those?
+      /* Any circuit where there were attempted streams but no successful
+       * streams could be bias */
+      log_info(LD_CIRC,
+            "Circuit closed without successful use for reason %d. "
+            "Circuit is a %s currently %s.",
+            reason, circuit_purpose_to_string(circ->purpose),
+            circuit_state_to_string(circ->state));
+      pathbias_count_unusable(ocirc);
+    } else {
+      if (reason & END_CIRC_REASON_FLAG_REMOTE) {
+        /* Unused remote circ close reasons all could be bias */
+        // XXX: We hit this a lot for hidserv circs with purposes:
+        // CIRCUIT_PURPOSE_S_CONNECT_REND (reasons: 514,517,520)
+        // CIRCUIT_PURPOSE_S_REND_JOINED (reasons: 514,517,520)
+        //  == reasons: 2,3,8. Client-side timeouts?
+        log_info(LD_CIRC,
+            "Circuit remote-closed without successful use for reason %d. "
+            "Circuit is a %s currently %s.",
+            reason, circuit_purpose_to_string(circ->purpose),
+            circuit_state_to_string(circ->state));
+        pathbias_count_collapse(ocirc);
+      } else if ((reason & ~END_CIRC_REASON_FLAG_REMOTE)
+                  == END_CIRC_REASON_CHANNEL_CLOSED &&
+                 circ->n_chan &&
+                 circ->n_chan->reason_for_closing 
+                  != CHANNEL_CLOSE_REQUESTED) {
+        /* If we didn't close the channel ourselves, it could be bias */
+        /* FIXME: Only count bias if the network is live?
+         * What about clock jumps/suspends? */
+        log_info(LD_CIRC,
+            "Circuit's channel closed without successful use for reason %d, "
+            "channel reason %d. Circuit is a %s currently %s.",
+            reason, circ->n_chan->reason_for_closing,
+            circuit_purpose_to_string(circ->purpose),
+            circuit_state_to_string(circ->state));
+        pathbias_count_collapse(ocirc);
+      } else {
+        pathbias_count_successful_close(ocirc);
+      }
+    }
+  } else if (ocirc->path_state == PATH_STATE_USE_SUCCEEDED) {
+    pathbias_count_successful_close(ocirc);
+  }
+}
+
+/**
+ * Count a successfully closed circuit.
+ */
+static void
 pathbias_count_successful_close(origin_circuit_t *circ)
 {
   entry_guard_t *guard = NULL;
@@ -1411,7 +1478,7 @@ pathbias_count_successful_close(origin_circuit_t *circ)
  * circuit after it has successfully completed. Right now, this is
  * used for purely informational/debugging purposes.
  */
-void
+static void
 pathbias_count_collapse(origin_circuit_t *circ)
 {
   entry_guard_t *guard = NULL;
@@ -1439,7 +1506,7 @@ pathbias_count_collapse(origin_circuit_t *circ)
   }
 }
 
-void
+static void
 pathbias_count_unusable(origin_circuit_t *circ)
 {
   entry_guard_t *guard = NULL;
@@ -1511,7 +1578,7 @@ pathbias_get_closed_count(entry_guard_t *guard)
     if(!ocirc->cpath || !ocirc->cpath->extend_info)
       continue;
 
-    if (ocirc->path_state == PATH_STATE_SUCCEEDED &&
+    if (ocirc->path_state >= PATH_STATE_BUILD_SUCCEEDED &&
         (memcmp(guard->identity,
                 ocirc->cpath->extend_info->identity_digest,
                 DIGEST_LEN)
@@ -2371,6 +2438,11 @@ circuit_extend_to_new_exit(origin_circuit_t *circ, extend_info_t *exit)
     circuit_mark_for_close(TO_CIRCUIT(circ), -err_reason);
     return -1;
   }
+
+  /* Set timestamp_dirty, so we can check it for path use bias */
+  if (!circ->base_.timestamp_dirty)
+    circ->base_.timestamp_dirty = time(NULL);
+
   return 0;
 }
 
diff --git a/src/or/circuitbuild.h b/src/or/circuitbuild.h
index 2d9eac121..53c9fe5c0 100644
--- a/src/or/circuitbuild.h
+++ b/src/or/circuitbuild.h
@@ -56,8 +56,6 @@ const node_t *choose_good_entry_server(uint8_t purpose,
 double pathbias_get_extreme_rate(const or_options_t *options);
 int pathbias_get_dropguards(const or_options_t *options);
 void pathbias_count_timeout(origin_circuit_t *circ);
-void pathbias_count_successful_close(origin_circuit_t *circ);
-void pathbias_count_collapse(origin_circuit_t *circ);
-void pathbias_count_unusable(origin_circuit_t *circ);
+void pathbias_check_close(origin_circuit_t *circ, int reason);
 
 #endif
diff --git a/src/or/circuitlist.c b/src/or/circuitlist.c
index 7163c351c..6fab4920a 100644
--- a/src/or/circuitlist.c
+++ b/src/or/circuitlist.c
@@ -1354,53 +1354,7 @@ circuit_mark_for_close_(circuit_t *circ, int reason, int line,
   }
   
   if (CIRCUIT_IS_ORIGIN(circ)) {
-    origin_circuit_t *ocirc = TO_ORIGIN_CIRCUIT(circ);
-
-    if (ocirc->path_state == PATH_STATE_SUCCEEDED) {
-      int pathbias_is_normal_close = 1;
-
-      /* FIXME: Is timestamp_dirty the right thing for these two checks? 
-       * Should we use isolation_any_streams_attached instead? 
-       * isolation_any_streams_attached is not used for hidservs.. */
-      if (!circ->timestamp_dirty) {
-        if (orig_reason & END_CIRC_REASON_FLAG_REMOTE) {
-          /* Unused remote circ close reasons all could be bias */
-          // XXX: We hit this a lot for hidserv circs with purposes:
-          // CIRCUIT_PURPOSE_S_CONNECT_REND (reasons: 514,517,520)
-          // CIRCUIT_PURPOSE_S_REND_JOINED (reasons: 514,517,520)
-          //  == reasons: 2,3,8. Client-side timeouts?
-          pathbias_is_normal_close = 0;
-          pathbias_count_collapse(ocirc);
-        } else if ((reason & ~END_CIRC_REASON_FLAG_REMOTE)
-                    == END_CIRC_REASON_CHANNEL_CLOSED &&
-                   circ->n_chan &&
-                   circ->n_chan->reason_for_closing 
-                    != CHANNEL_CLOSE_REQUESTED) {
-          /* If we didn't close the channel ourselves, it could be bias */
-          /* FIXME: Only count bias if the network is live?
-           * What about clock jumps/suspends? */
-          pathbias_is_normal_close = 0;
-          pathbias_count_collapse(ocirc);
-        }
-      } else if (circ->timestamp_dirty && !ocirc->any_streams_succeeded) {
-        // XXX: May open up attacks if the adversary can force connections
-        // on unresponsive hosts to use new circs. Vidalia displayes a "Retrying"
-        // state.. Can we use that? Does optimistic data change this?
-        // XXX: For the hidserv side, we could only care about INTRODUCING purposes
-        // for server+client, and REND purposes for the server... Can we
-        // somehow only count those?
-        /* Any circuit where there were attempted streams but no successful
-         * streams could be bias */
-        /* FIXME: This may be better handled by limiting the number of retries
-         * per stream? */
-        pathbias_is_normal_close = 0;
-        pathbias_count_unusable(ocirc);
-      }
-
-      if (pathbias_is_normal_close) {
-        pathbias_count_successful_close(ocirc);
-      }
-    }
+    pathbias_check_close(TO_ORIGIN_CIRCUIT(circ), reason);
 
     /* We don't send reasons when closing circuits at the origin. */
     reason = END_CIRC_REASON_NONE;
diff --git a/src/or/connection_edge.c b/src/or/connection_edge.c
index 31ff90093..79bb54cbb 100644
--- a/src/or/connection_edge.c
+++ b/src/or/connection_edge.c
@@ -2181,10 +2181,14 @@ connection_ap_handshake_socks_reply(entry_connection_t *conn, char *reply,
   if (status == SOCKS5_SUCCEEDED) {
     if(!conn->edge_.on_circuit ||
        !CIRCUIT_IS_ORIGIN(conn->edge_.on_circuit)) {
-      // XXX: Weird. We hit this a lot, and yet have no unusable_circs
-      log_warn(LD_BUG, "No origin circuit for successful SOCKS stream");
+      // XXX: Weird. We hit this a lot, and yet have no unusable_circs.
+      // Maybe during addrmaps/resolves?
+      log_warn(LD_BUG,
+               "(Harmless.) No origin circuit for successful SOCKS stream. "
+               "Reason: %d", endreason);
     } else {
-      TO_ORIGIN_CIRCUIT(conn->edge_.on_circuit)->any_streams_succeeded = 1;
+      TO_ORIGIN_CIRCUIT(conn->edge_.on_circuit)->path_state
+          = PATH_STATE_USE_SUCCEEDED;
     }
   }
 
@@ -2457,7 +2461,7 @@ connection_exit_begin_conn(cell_t *cell, circuit_t *circ)
     connection_exit_connect(n_stream);
 
     /* For path bias: This circuit was used successfully */
-    origin_circ->any_streams_succeeded = 1;
+    origin_circ->path_state = PATH_STATE_USE_SUCCEEDED;
 
     tor_free(address);
     return 0;
diff --git a/src/or/or.h b/src/or/or.h
index d165705e9..c8ea12f2c 100644
--- a/src/or/or.h
+++ b/src/or/or.h
@@ -2768,9 +2768,17 @@ typedef enum {
     /** This circuit has completed a first hop, and has been counted by
      * the path bias logic. */
     PATH_STATE_DID_FIRST_HOP = 1,
-    /** This circuit has been completely built, and has been counted as
-     * successful by the path bias logic. */
-    PATH_STATE_SUCCEEDED = 2,
+    /** This circuit has been completely built */
+    PATH_STATE_BUILD_SUCCEEDED = 2,
+    /** Did any SOCKS streams or hidserv introductions actually succeed on
+      * this circuit?
+      *
+      * Note: If we ever implement end-to-end stream timing through test
+      * stream probes (#5707), we must *not* set this for those probes
+      * (or any other automatic streams) because the adversary could
+      * just tag at a later point.
+      */
+    PATH_STATE_USE_SUCCEEDED = 3,
 } path_state_t;
 
 /** An origin_circuit_t holds data necessary to build and use a circuit.
@@ -2872,16 +2880,6 @@ typedef struct origin_circuit_t {
    */
   unsigned int isolation_any_streams_attached : 1;
 
-  /**
-   * Did any SOCKS streams or hidserv introductions actually succeed on
-   * this circuit?
-   *
-   * Note: If we ever implement end-to-end stream timing through test
-   * stream probes (#5707), we must *not* set this for those probes
-   * (or any other automatic streams).
-   */
-  unsigned int any_streams_succeeded : 1;
-
   /** A bitfield of ISO_* flags for every isolation field such that this
    * circuit has had streams with more than one value for that field
    * attached to it. */
diff --git a/src/or/rendclient.c b/src/or/rendclient.c
index 1d473dec0..3393e0f62 100644
--- a/src/or/rendclient.c
+++ b/src/or/rendclient.c
@@ -363,7 +363,7 @@ rend_client_introduction_acked(origin_circuit_t *circ,
 
   /* For path bias: This circuit was used successfully. Valid
    * nacks and acks count. */
-  circ->any_streams_succeeded = 1;
+  circ->path_state = PATH_STATE_USE_SUCCEEDED;
 
   if (request_len == 0) {
     /* It's an ACK; the introduction point relayed our introduction request. */
diff --git a/src/or/rendservice.c b/src/or/rendservice.c
index 74e4bada9..fbf14e934 100644
--- a/src/or/rendservice.c
+++ b/src/or/rendservice.c
@@ -1383,9 +1383,9 @@ rend_service_introduce(origin_circuit_t *circuit, const uint8_t *request,
   if (circuit_init_cpath_crypto(cpath,keys+DIGEST_LEN,1)<0)
     goto err;
   memcpy(cpath->handshake_digest, keys, DIGEST_LEN);
-          
-  /* For path bias: This circuit was used successfully */
-  circuit->any_streams_succeeded = 1;
+   
+  /* For path bias: This intro circuit was used successfully */
+  circuit->path_state = PATH_STATE_USE_SUCCEEDED;
 
   goto done;
 
@@ -2586,7 +2586,8 @@ rend_service_rendezvous_has_opened(origin_circuit_t *circuit)
   tor_assert(circuit->rend_data);
 
   /* Declare the circuit dirty to avoid reuse, and for path-bias */
-  circuit->base_.timestamp_dirty = time(NULL);
+  if(!circuit->base_.timestamp_dirty)
+    circuit->base_.timestamp_dirty = time(NULL);
 
   hop = circuit->build_state->service_pending_final_cpath_ref->cpath;