collect and log statistics about onionskins received/processed

we skip onionskins that came from non-relays, so we're less likely to
run into privacy troubles.

starts to implement ticket 9658.

6 files changed, 64 insertions, 2 deletions

diff --git a/changes/ticket9658 b/changes/ticket9658
new file mode 100644
index 0000000000..a8db2efba8
--- /dev/null
+++ b/changes/ticket9658
@@ -0,0 +1,4 @@
+  o Minor features:
+    - Track how many "TAP" and "NTor" circuit handshake requests we get,
+      and how many we complete, and log it every hour to help relay
+      operators follow trends in network load. Addresses ticket 9658.
diff --git a/src/or/command.c b/src/or/command.c
index 876ff526a6..699b02fb47 100644
--- a/src/or/command.c
+++ b/src/or/command.c
@@ -29,6 +29,7 @@
 #include "hibernate.h"
 #include "nodelist.h"
 #include "onion.h"
+#include "rephist.h"
 #include "relay.h"
 #include "router.h"
 #include "routerlist.h"
@@ -277,6 +278,8 @@ command_process_create_cell(cell_t *cell, channel_t *chan)
 
   if (create_cell->handshake_type != ONION_HANDSHAKE_TYPE_FAST) {
     /* hand it off to the cpuworkers, and then return. */
+    if (connection_or_digest_is_known_relay(chan->identity_digest))
+      rep_hist_note_circuit_handshake_requested(create_cell->handshake_type);
     if (assign_onionskin_to_cpuworker(NULL, circ, create_cell) < 0) {
       log_debug(LD_GENERAL,"Failed to hand off onionskin. Closing.");
       circuit_mark_for_close(TO_CIRCUIT(circ), END_CIRC_REASON_RESOURCELIMIT);
diff --git a/src/or/cpuworker.c b/src/or/cpuworker.c
index 61f9faa394..ecf0d2035d 100644
--- a/src/or/cpuworker.c
+++ b/src/or/cpuworker.c
@@ -19,9 +19,11 @@
 #include "circuitlist.h"
 #include "config.h"
 #include "connection.h"
+#include "connection_or.h"
 #include "cpuworker.h"
 #include "main.h"
 #include "onion.h"
+#include "rephist.h"
 #include "router.h"
 
 /** The maximum number of cpuworker processes we will keep around. */
@@ -683,6 +685,9 @@ assign_onionskin_to_cpuworker(connection_t *cpuworker,
       return -1;
     }
 
+    if (connection_or_digest_is_known_relay(circ->p_chan->identity_digest))
+      rep_hist_note_circuit_handshake_completed(onionskin->handshake_type);
+
     should_time = should_time_request(onionskin->handshake_type);
     memset(&req, 0, sizeof(req));
     req.magic = CPUWORKER_REQUEST_MAGIC;
diff --git a/src/or/main.c b/src/or/main.c
index bd23141b97..deed798e80 100644
--- a/src/or/main.c
+++ b/src/or/main.c
@@ -1353,6 +1353,11 @@ run_scheduled_events(time_t now)
         next_time_to_write_stats_files = next_write;
     }
     time_to_write_stats_files = next_time_to_write_stats_files;
+
+    /* Also commandeer this opportunity to log how our circuit handshake
+     * stats have been doing. */
+    if (public_server_mode(options))
+      rep_hist_log_circuit_handshake_stats(now);
   }
 
   /* 1h. Check whether we should write bridge statistics to disk.
diff --git a/src/or/rephist.c b/src/or/rephist.c
index 55f321d5ff..131e531b19 100644
--- a/src/or/rephist.c
+++ b/src/or/rephist.c
@@ -3011,6 +3011,47 @@ rep_hist_conn_stats_write(time_t now)
   return start_of_conn_stats_interval + WRITE_STATS_INTERVAL;
 }
 
+/** Internal statistics to track how many requests of each type of
+ * handshake we've received, and how many we've completed. Useful for
+ * seeing trends in cpu load.
+ * @{ */
+static int onion_handshakes_requested[MAX_ONION_HANDSHAKE_TYPE+1] = {0};
+static int onion_handshakes_completed[MAX_ONION_HANDSHAKE_TYPE+1] = {0};
+/**@}*/
+
+/** A new onionskin (using the <b>type</b> handshake) has arrived. */
+void
+rep_hist_note_circuit_handshake_requested(uint16_t type)
+{
+  if (type <= MAX_ONION_HANDSHAKE_TYPE)
+    onion_handshakes_requested[type]++;
+}
+
+/** We've sent an onionskin (using the <b>type</b> handshake) to a
+ * cpuworker. */
+void
+rep_hist_note_circuit_handshake_completed(uint16_t type)
+{
+  if (type <= MAX_ONION_HANDSHAKE_TYPE)
+    onion_handshakes_completed[type]++;
+}
+
+/** Log our onionskin statistics since the last time we were called. */
+void
+rep_hist_log_circuit_handshake_stats(time_t now)
+{
+  (void)now;
+  /* XXX024 maybe quiet this log message before 0.2.4 goes stable for real */
+  log_notice(LD_HIST, "Circuit handshake stats since last time: "
+             "%d/%d TAP, %d/%d NTor.",
+             onion_handshakes_completed[ONION_HANDSHAKE_TYPE_TAP],
+             onion_handshakes_requested[ONION_HANDSHAKE_TYPE_TAP],
+             onion_handshakes_completed[ONION_HANDSHAKE_TYPE_NTOR],
+             onion_handshakes_requested[ONION_HANDSHAKE_TYPE_NTOR]);
+  memset(onion_handshakes_completed, 0, sizeof(onion_handshakes_completed));
+  memset(onion_handshakes_requested, 0, sizeof(onion_handshakes_requested));
+}
+
 /** Free all storage held by the OR/link history caches, by the
  * bandwidth history arrays, by the port history, or by statistics . */
 void
diff --git a/src/or/rephist.h b/src/or/rephist.h
index 811cd8d450..de824749b4 100644
--- a/src/or/rephist.h
+++ b/src/or/rephist.h
@@ -64,8 +64,6 @@ int rep_hist_circbuilding_dormant(time_t now);
 void note_crypto_pk_op(pk_op_t operation);
 void dump_pk_ops(int severity);
 
-void rep_hist_free_all(void);
-
 void rep_hist_exit_stats_init(time_t now);
 void rep_hist_reset_exit_stats(time_t now);
 void rep_hist_exit_stats_term(void);
@@ -98,5 +96,11 @@ char *rep_hist_format_conn_stats(time_t now);
 time_t rep_hist_conn_stats_write(time_t now);
 void rep_hist_conn_stats_term(void);
 
+void rep_hist_note_circuit_handshake_requested(uint16_t type);
+void rep_hist_note_circuit_handshake_completed(uint16_t type);
+void rep_hist_log_circuit_handshake_stats(time_t now);
+
+void rep_hist_free_all(void);
+
 #endif