Log what fraction of EXTEND cells have died for being non-early

diff --git a/src/or/relay.c b/src/or/relay.c
index 60d439aca953f55274eec5d4a765291255c34379..fdc26006a0998e48c681b7f29e0eb4672d818cde 100644 (file)
--- a/src/or/relay.c
+++ b/src/or/relay.c
@@ -1188,7 +1188,9 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ,
         connection_mark_and_flush(TO_CONN(conn));
       }
       return 0;
-    case RELAY_COMMAND_EXTEND:
+    case RELAY_COMMAND_EXTEND: {
+      static uint64_t total_n_extend=0, total_nonearly=0;
+      total_n_extend++;
       if (conn) {
         log_fn(LOG_PROTOCOL_WARN, domain,
                "'extend' cell received for non-zero stream. Dropping.");
@@ -1200,10 +1202,15 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ,
           RATELIM_INIT(EARLY_WARNING_INTERVAL);
         char *m;
         if (cell->command == CELL_RELAY) {
+          ++total_nonearly;
           if ((m = rate_limit_log(&early_warning_limit, approx_time()))) {
             /* XXXX make this a protocol_warn once we're happier with it*/
+            double percentage = ((double)total_nonearly)/total_n_extend;
+            percentage *= 100;
             log_fn(LOG_WARN, domain, "EXTEND cell received, "
                    "but not via RELAY_EARLY. Dropping.%s", m);
+            log_fn(LOG_WARN, domain, "  (We have dropped %.02f%% of all "
+                   "EXTEND cells for this reason)", percentage);
             tor_free(m);
           }
         } else {
@@ -1214,6 +1221,7 @@ connection_edge_process_relay_cell(cell_t *cell, circuit_t *circ,
         return 0;
       }
       return circuit_extend(cell, circ);
+    }
     case RELAY_COMMAND_EXTENDED:
       if (!layer_hint) {
         log_fn(LOG_PROTOCOL_WARN, LD_PROTOCOL,