Merge remote-tracking branch 'public/bug8387_diagnostic'

4 files changed, 66 insertions, 0 deletions

diff --git a/changes/diagnose_8387 b/changes/diagnose_8387
new file mode 100644
index 000000000..3dfc84578
--- /dev/null
+++ b/changes/diagnose_8387
@@ -0,0 +1,4 @@
+  o Minor features (diagnostic):
+    - When we log a heartbeat, log how many one-hop circuits we have that
+      are at least 30 minutes old, and log status information about a
+      few of them. This is an attempt to track down bug 8387.
diff --git a/src/or/circuituse.c b/src/or/circuituse.c
index d10430668..9d2decf57 100644
--- a/src/or/circuituse.c
+++ b/src/or/circuituse.c
@@ -783,6 +783,64 @@ circuit_expire_building(void)
   }
 }
 
+/**
+ * As a diagnostic for bug 8387, log information about how many one-hop
+ * circuits we have around that have been there for at least <b>age</b>
+ * seconds. Log a few of them.
+ */
+void
+circuit_log_ancient_one_hop_circuits(int age)
+{
+#define MAX_ANCIENT_ONEHOP_CIRCUITS_TO_LOG 10
+  time_t cutoff = time(NULL) - age;
+  int n_found = 0;
+  smartlist_t *log_these = smartlist_new();
+  const circuit_t *circ;
+
+  TOR_LIST_FOREACH(circ, circuit_get_global_list(), head) {
+    const origin_circuit_t *ocirc;
+    if (! CIRCUIT_IS_ORIGIN(circ))
+      continue;
+    if (circ->timestamp_created.tv_sec >= cutoff)
+      continue;
+    ocirc = CONST_TO_ORIGIN_CIRCUIT(circ);
+
+    if (ocirc->build_state && ocirc->build_state->onehop_tunnel) {
+      ++n_found;
+
+      if (smartlist_len(log_these) < MAX_ANCIENT_ONEHOP_CIRCUITS_TO_LOG)
+        smartlist_add(log_these, (origin_circuit_t*) ocirc);
+    }
+  }
+
+  if (n_found == 0)
+    goto done;
+
+  log_notice(LD_HEARTBEAT,
+             "Diagnostic for issue 8387: Found %d one-hop circuits more "
+             "than %d seconds old! Logging %d...",
+             n_found, age, smartlist_len(log_these));
+
+  SMARTLIST_FOREACH_BEGIN(log_these, const origin_circuit_t *, ocirc) {
+    char created[ISO_TIME_LEN+1];
+    circ = TO_CIRCUIT(ocirc);
+    format_local_iso_time(created,
+                          circ->timestamp_created.tv_sec);
+
+    log_notice(LD_HEARTBEAT, "  #%d created at %s. %s, %s. %s for close. "
+               "%s for new conns.",
+               ocirc_sl_idx,
+               created,
+               circuit_state_to_string(circ->state),
+               circuit_purpose_to_string(circ->purpose),
+               circ->marked_for_close ? "Marked" : "Not marked",
+               ocirc->unusable_for_new_conns ? "Not usable" : "usable");
+  } SMARTLIST_FOREACH_END(ocirc);
+
+ done:
+  smartlist_free(log_these);
+}
+
 /** Remove any elements in <b>needed_ports</b> that are handled by an
  * open or in-progress circuit.
  */
diff --git a/src/or/circuituse.h b/src/or/circuituse.h
index 11e5a6416..f228a6758 100644
--- a/src/or/circuituse.h
+++ b/src/or/circuituse.h
@@ -16,6 +16,7 @@ void circuit_expire_building(void);
 void circuit_remove_handled_ports(smartlist_t *needed_ports);
 int circuit_stream_is_being_handled(entry_connection_t *conn, uint16_t port,
                                     int min);
+void circuit_log_ancient_one_hop_circuits(int age);
 #if 0
 int circuit_conforms_to_options(const origin_circuit_t *circ,
                                 const or_options_t *options);
diff --git a/src/or/status.c b/src/or/status.c
index 7e2afbce8..afaa9de84 100644
--- a/src/or/status.c
+++ b/src/or/status.c
@@ -9,6 +9,7 @@
 #define STATUS_PRIVATE
 
 #include "or.h"
+#include "circuituse.h"
 #include "config.h"
 #include "status.h"
 #include "nodelist.h"
@@ -135,6 +136,8 @@ log_heartbeat(time_t now)
   if (public_server_mode(options))
     rep_hist_log_circuit_handshake_stats(now);
 
+  circuit_log_ancient_one_hop_circuits(1800);
+
   tor_free(uptime);
   tor_free(bw_sent);
   tor_free(bw_rcvd);