Use timevals, not time_t, when expiring circuits.

We've got millisecond timers now, we might as well use them.

This change won't actually make circuits get expiered with microsecond
precision, since we only call the expiry functions once per second.
Still, it should avoid the situation where we have a circuit get
expired too early because of rounding.

A couple of the expiry functions now call tor_gettimeofday: this
should be cheap since we're only doing it once per second.  If it gets
to be called more often, though, we should onsider having the current
time be an argument again.

diff --git a/changes/cbt_hi_res b/changes/cbt_hi_res
new file mode 100644 (file)
index 0000000..c0df118
--- /dev/null
+++ b/changes/cbt_hi_res
@@ -0,0 +1,7 @@
+  o Minor features
+    - When expiring circuits, use microsecond timers rather than one-second
+      timers.  This can avoid an unpleasant situation where a circuit is
+      launched near the end of one second and expired right near the
+      beginning of the next, and prevent fluctuations in circuit timeout
+      values.
+

diff --git a/src/or/circuitbuild.c b/src/or/circuitbuild.c
index 83ac7a5a19846a4f82bb548cea9f840958b056ed..37b761f99b58258a16bea0a8a3a428334a9e4834 100644 (file)
--- a/src/or/circuitbuild.c
+++ b/src/or/circuitbuild.c
@@ -2041,7 +2041,7 @@ circuit_send_next_onion_skin(origin_circuit_t *circ)
         struct timeval end;
         long timediff;
         tor_gettimeofday(&end);
-        timediff = tv_mdiff(&circ->_base.highres_created, &end);
+        timediff = tv_mdiff(&circ->_base.timestamp_created, &end);
 
         /*
          * If the circuit build time is much greater than we would have cut

diff --git a/src/or/circuitlist.c b/src/or/circuitlist.c
index b4f5f45615cb3db1cc5b733f1cf3965db42270c1..d1fea37c2518d47ff5fa6867a2d9f33e5f2d7720 100644 (file)
--- a/src/or/circuitlist.c
+++ b/src/or/circuitlist.c
@@ -398,8 +398,7 @@ circuit_initial_package_window(void)
 static void
 init_circuit_base(circuit_t *circ)
 {
-  circ->timestamp_created = time(NULL);
-  tor_gettimeofday(&circ->highres_created);
+  tor_gettimeofday(&circ->timestamp_created);
 
   circ->package_window = circuit_initial_package_window();
   circ->deliver_window = CIRCWINDOW_START;
@@ -609,9 +608,10 @@ circuit_dump_details(int severity, circuit_t *circ, int conn_array_index,
                      const char *type, int this_circid, int other_circid)
 {
   log(severity, LD_CIRC, "Conn %d has %s circuit: circID %d (other side %d), "
-      "state %d (%s), born %d:",
+      "state %d (%s), born %ld:",
       conn_array_index, type, this_circid, other_circid, circ->state,
-      circuit_state_to_string(circ->state), (int)circ->timestamp_created);
+      circuit_state_to_string(circ->state),
+      (long)circ->timestamp_created.tv_sec);
   if (CIRCUIT_IS_ORIGIN(circ)) { /* circ starts at this node */
     circuit_log_path(severity, LD_CIRC, TO_ORIGIN_CIRCUIT(circ));
   }

diff --git a/src/or/circuituse.c b/src/or/circuituse.c
index 8d9d1158639841515263b9514fbb30de572fcdeb..ac4bba51f8cbd7c254aa501407d7e1f9c1a4783a 100644 (file)
--- a/src/or/circuituse.c
+++ b/src/or/circuituse.c
@@ -31,7 +31,7 @@ extern circuit_t *global_circuitlist; /* from circuitlist.c */
 
 /********* END VARIABLES ************/
 
-static void circuit_expire_old_circuits_clientside(time_t now);
+static void circuit_expire_old_circuits_clientside(void);
 static void circuit_increment_failure_count(void);
 
 /** Return 1 if <b>circ</b> could be returned by circuit_get_best().
@@ -162,7 +162,7 @@ circuit_is_better(circuit_t *a, circuit_t *b, uint8_t purpose)
           return 1;
       } else {
         if (a->timestamp_dirty ||
-            a->timestamp_created > b->timestamp_created)
+            timercmp(&a->timestamp_created, &b->timestamp_created, >))
           return 1;
         if (CIRCUIT_IS_ORIGIN(b) &&
             TO_ORIGIN_CIRCUIT(b)->build_state->is_internal)
@@ -223,7 +223,7 @@ circuit_get_best(edge_connection_t *conn, int must_be_open, uint8_t purpose,
 #define REND_PARALLEL_INTRO_DELAY 15
     if (purpose == CIRCUIT_PURPOSE_C_INTRODUCE_ACK_WAIT &&
              !must_be_open && circ->state != CIRCUIT_STATE_OPEN &&
-             circ->timestamp_created + REND_PARALLEL_INTRO_DELAY < now) {
+             circ->timestamp_created.tv_sec + REND_PARALLEL_INTRO_DELAY < now) {
       intro_going_on_but_too_old = 1;
       continue;
     }
@@ -275,22 +275,38 @@ circuit_conforms_to_options(const origin_circuit_t *circ,
  * at least CircuitBuildTimeout seconds ago.
  */
 void
-circuit_expire_building(time_t now)
+circuit_expire_building(void)
 {
   circuit_t *victim, *next_circ = global_circuitlist;
   /* circ_times.timeout_ms and circ_times.close_ms are from
    * circuit_build_times_get_initial_timeout() if we haven't computed
    * custom timeouts yet */
-  time_t general_cutoff = now - tor_lround(circ_times.timeout_ms/1000);
-  time_t begindir_cutoff = now - tor_lround(circ_times.timeout_ms/2000);
-  time_t fourhop_cutoff = now - tor_lround(4*circ_times.timeout_ms/3000);
-  time_t cannibalize_cutoff = now - tor_lround(circ_times.timeout_ms/2000);
-  time_t close_cutoff = now - tor_lround(circ_times.close_ms/1000);
-  time_t introcirc_cutoff = begindir_cutoff;
+  struct timeval general_cutoff, begindir_cutoff, fourhop_cutoff,
+    cannibalize_cutoff, close_cutoff, extremely_old_cutoff;
+  struct timeval now;
+  struct timeval introcirc_cutoff;
   cpath_build_state_t *build_state;
 
+  tor_gettimeofday(&now);
+#define SET_CUTOFF(target, msec) do {                       \
+    long ms = tor_lround(msec);                             \
+    struct timeval diff;                                    \
+    diff.tv_sec = ms / 1000;                                \
+    diff.tv_usec = (ms % 1000) * 1000;                      \
+    timersub(&now, &diff, &target);                         \
+  } while (0)
+
+  SET_CUTOFF(general_cutoff, circ_times.timeout_ms);
+  SET_CUTOFF(begindir_cutoff, circ_times.timeout_ms / 2.0);
+  SET_CUTOFF(fourhop_cutoff, circ_times.timeout_ms * (4/3.0));
+  SET_CUTOFF(cannibalize_cutoff, circ_times.timeout_ms / 2.0);
+  SET_CUTOFF(close_cutoff, circ_times.close_ms);
+  SET_CUTOFF(extremely_old_cutoff, circ_times.close_ms*2 + 1000);
+
+  introcirc_cutoff = begindir_cutoff;
+
   while (next_circ) {
-    time_t cutoff;
+    struct timeval cutoff;
     victim = next_circ;
     next_circ = next_circ->next;
     if (!CIRCUIT_IS_ORIGIN(victim) || /* didn't originate here */
@@ -312,7 +328,7 @@ circuit_expire_building(time_t now)
     else
       cutoff = general_cutoff;
 
-    if (victim->timestamp_created > cutoff)
+    if (timercmp(&victim->timestamp_created, &cutoff, >))
       continue; /* it's still young, leave it alone */
 
 #if 0
@@ -358,7 +374,7 @@ circuit_expire_building(time_t now)
            * because that's set when they switch purposes
            */
           if (TO_ORIGIN_CIRCUIT(victim)->rend_data ||
-              victim->timestamp_dirty > cutoff)
+              victim->timestamp_dirty > cutoff.tv_sec)
             continue;
           break;
         case CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED:
@@ -367,7 +383,7 @@ circuit_expire_building(time_t now)
            * make an introduction attempt. so timestamp_dirty
            * will reflect the time since the last attempt.
            */
-          if (victim->timestamp_dirty > cutoff)
+          if (victim->timestamp_dirty > cutoff.tv_sec)
             continue;
           break;
       }
@@ -407,15 +423,15 @@ circuit_expire_building(time_t now)
          * it off at, we probably had a suspend event along this codepath,
          * and we should discard the value.
          */
-        if (now - victim->timestamp_created > 2*circ_times.close_ms/1000+1) {
+        if (timercmp(&victim->timestamp_created, &extremely_old_cutoff, <)) {
           log_notice(LD_CIRC,
                      "Extremely large value for circuit build timeout: %lds. "
                      "Assuming clock jump. Purpose %d",
-                     (long)(now - victim->timestamp_created),
+                     (long)(now.tv_sec - victim->timestamp_created.tv_sec),
                       victim->purpose);
         } else if (circuit_build_times_count_close(&circ_times,
                                             first_hop_succeeded,
-                                            victim->timestamp_created)) {
+                                            victim->timestamp_created.tv_sec)) {
           circuit_build_times_set_timeout(&circ_times);
         }
       }
@@ -636,7 +652,7 @@ circuit_build_needed_circs(time_t now)
     time_to_new_circuit = now + options->NewCircuitPeriod;
     if (proxy_mode(get_options()))
       addressmap_clean(now);
-    circuit_expire_old_circuits_clientside(now);
+    circuit_expire_old_circuits_clientside();
 
 #if 0 /* disable for now, until predict-and-launch-new can cull leftovers */
     circ = circuit_get_youngest_clean_open(CIRCUIT_PURPOSE_C_GENERAL);
@@ -725,17 +741,20 @@ circuit_detach_stream(circuit_t *circ, edge_connection_t *conn)
  * for too long and has no streams on it: mark it for close.
  */
 static void
-circuit_expire_old_circuits_clientside(time_t now)
+circuit_expire_old_circuits_clientside(void)
 {
   circuit_t *circ;
-  time_t cutoff;
+  struct timeval cutoff, now;
+
+  tor_gettimeofday(&now);
+  cutoff = now;
 
   if (circuit_build_times_needs_circuits(&circ_times)) {
     /* Circuits should be shorter lived if we need more of them
      * for learning a good build timeout */
-    cutoff = now - IDLE_TIMEOUT_WHILE_LEARNING;
+    cutoff.tv_sec -= IDLE_TIMEOUT_WHILE_LEARNING;
   } else {
-    cutoff = now - get_options()->CircuitIdleTimeout;
+    cutoff.tv_sec -= get_options()->CircuitIdleTimeout;
   }
 
   for (circ = global_circuitlist; circ; circ = circ->next) {
@@ -745,15 +764,15 @@ circuit_expire_old_circuits_clientside(time_t now)
      * on it, mark it for close.
      */
     if (circ->timestamp_dirty &&
-        circ->timestamp_dirty + get_options()->MaxCircuitDirtiness < now &&
+        circ->timestamp_dirty + get_options()->MaxCircuitDirtiness < now.tv_sec &&
         !TO_ORIGIN_CIRCUIT(circ)->p_streams /* nothing attached */ ) {
-      log_debug(LD_CIRC, "Closing n_circ_id %d (dirty %d secs ago, "
+      log_debug(LD_CIRC, "Closing n_circ_id %d (dirty %ld sec ago, "
                 "purpose %d)",
-                circ->n_circ_id, (int)(now - circ->timestamp_dirty),
+                circ->n_circ_id, (long)(now.tv_sec - circ->timestamp_dirty),
                 circ->purpose);
       circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED);
     } else if (!circ->timestamp_dirty && circ->state == CIRCUIT_STATE_OPEN) {
-      if (circ->timestamp_created < cutoff) {
+      if (timercmp(&circ->timestamp_created, &cutoff, <)) {
         if (circ->purpose == CIRCUIT_PURPOSE_C_GENERAL ||
                 circ->purpose == CIRCUIT_PURPOSE_C_MEASURE_TIMEOUT ||
                 circ->purpose == CIRCUIT_PURPOSE_S_ESTABLISH_INTRO ||
@@ -762,8 +781,8 @@ circuit_expire_old_circuits_clientside(time_t now)
                 circ->purpose <= CIRCUIT_PURPOSE_C_REND_READY_INTRO_ACKED) ||
                 circ->purpose == CIRCUIT_PURPOSE_S_CONNECT_REND) {
           log_debug(LD_CIRC,
-                    "Closing circuit that has been unused for %ld seconds.",
-                    (long)(now - circ->timestamp_created));
+                    "Closing circuit that has been unused for %ld msec.",
+                    tv_mdiff(&circ->timestamp_created, &now));
           circuit_mark_for_close(circ, END_CIRC_REASON_FINISHED);
         } else if (!TO_ORIGIN_CIRCUIT(circ)->is_ancient) {
           /* Server-side rend joined circuits can end up really old, because
@@ -775,9 +794,9 @@ circuit_expire_old_circuits_clientside(time_t now)
               circ->purpose != CIRCUIT_PURPOSE_S_INTRO) {
             log_notice(LD_CIRC,
                        "Ancient non-dirty circuit %d is still around after "
-                       "%ld seconds. Purpose: %d",
+                       "%ld milliseconds. Purpose: %d",
                        TO_ORIGIN_CIRCUIT(circ)->global_identifier,
-                       (long)(now - circ->timestamp_created),
+                       tv_mdiff(&circ->timestamp_created, &now),
                        circ->purpose);
             /* FFFF implement a new circuit_purpose_to_string() so we don't
              * just print out a number for circ->purpose */
@@ -1123,7 +1142,7 @@ circuit_launch_by_extend_info(uint8_t purpose,
       /* reset the birth date of this circ, else expire_building
        * will see it and think it's been trying to build since it
        * began. */
-      circ->_base.timestamp_created = time(NULL);
+      tor_gettimeofday(&circ->_base.timestamp_created);
       switch (purpose) {
         case CIRCUIT_PURPOSE_C_ESTABLISH_REND:
         case CIRCUIT_PURPOSE_S_ESTABLISH_INTRO:

diff --git a/src/or/circuituse.h b/src/or/circuituse.h
index 1a604b415ffe0f4b20119f92a9ef288aa5b06e09..a121099aca805ae5369442ece316513a9a03c9f7 100644 (file)
--- a/src/or/circuituse.h
+++ b/src/or/circuituse.h
@@ -12,7 +12,7 @@
 #ifndef _TOR_CIRCUITUSE_H
 #define _TOR_CIRCUITUSE_H
 
-void circuit_expire_building(time_t now);
+void circuit_expire_building(void);
 void circuit_remove_handled_ports(smartlist_t *needed_ports);
 int circuit_stream_is_being_handled(edge_connection_t *conn, uint16_t port,
                                     int min);

diff --git a/src/or/main.c b/src/or/main.c
index 214a4fad5da01e4d41f7efb77f33f7cb2ca9b647..83d1e1e5173eb449b8651b220132d40a2ecf5c6c 100644 (file)
--- a/src/or/main.c
+++ b/src/or/main.c
@@ -1150,7 +1150,9 @@ run_scheduled_events(time_t now)
    *    We do this before step 4, so it can try building more if
    *    it's not comfortable with the number of available circuits.
    */
-  circuit_expire_building(now);
+  /* XXXX022 If our circuit build timeout is much lower than a second, maybe
+     we should do this more often? */
+  circuit_expire_building();
 
   /** 3b. Also look at pending streams and prune the ones that 'began'
    *     a long time ago but haven't gotten a 'connected' yet.

diff --git a/src/or/or.h b/src/or/or.h
index e3e01cff55787e7d0cb6243e5eec9dd516ff452d..3cadd3173ee8d5bae345963f82812e16e9cb3692 100644 (file)
--- a/src/or/or.h
+++ b/src/or/or.h
@@ -2126,10 +2126,9 @@ typedef struct circuit_t {
     * length ONIONSKIN_CHALLENGE_LEN. */
   char *n_conn_onionskin;
 
-  time_t timestamp_created; /**< When was this circuit created? */
+  struct timeval timestamp_created; /**< When was the circuit created? */
   time_t timestamp_dirty; /**< When the circuit was first used, or 0 if the
                            * circuit is clean. */
-  struct timeval highres_created; /**< When exactly was the circuit created? */
 
   uint16_t marked_for_close; /**< Should we close this circuit at the end of
                               * the main loop? (If true, holds the line number

diff --git a/src/or/rephist.c b/src/or/rephist.c
index 58e8ff0a05c974debbef7c059b28538e0997be46..06704cf8170b96a4317671865dc17fc373106ea0 100644 (file)
--- a/src/or/rephist.c
+++ b/src/or/rephist.c
@@ -2356,9 +2356,9 @@ rep_hist_buffer_stats_add_circ(circuit_t *circ, time_t end_of_interval)
     return;
   if (!circuits_for_buffer_stats)
     circuits_for_buffer_stats = smartlist_create();
-  start_of_interval = circ->timestamp_created >
+  start_of_interval = circ->timestamp_created.tv_sec >
       start_of_buffer_stats_interval ?
-        circ->timestamp_created :
+        circ->timestamp_created.tv_sec :
         start_of_buffer_stats_interval;
   interval_length = (int) (end_of_interval - start_of_interval);
   stat = tor_malloc_zero(sizeof(circ_buffer_stats_t));