Move accounting code into hibernate; start adding logic to track bandwidth-per-seconds-active

svn:r2680

src/or/hibernate.c

@@ -28,23 +28,288 @@ hibernating, phase 2:
 
 #define SHUTDOWN_WAIT_LENGTH 30 /* seconds */
 
-int hibernate_state = HIBERNATE_STATE_LIVE;
-time_t hibernate_timeout = 0;
+extern or_options_t options;
+
+static int hibernate_state = HIBERNATE_STATE_LIVE;
+static time_t hibernate_timeout = 0;
+
+/** How many bytes have we read/written in this accounting interval? */
+static uint64_t n_bytes_read_in_interval = 0;
+static uint64_t n_bytes_written_in_interval = 0;
+static uint32_t n_seconds_active_in_interval = 0;
+/** When did this accounting interval start? */
+static time_t interval_start_time = 0;
+/** When will this accounting interval end? */
+static time_t interval_end_time = 0;
+/** How far into the accounting interval should we hibernate? */
+static time_t interval_wakeup_time = 0;
+
+static int read_bandwidth_usage(void);
+static int record_bandwidth_usage(time_t now);
+static time_t start_of_accounting_period_after(time_t now);
+static time_t start_of_accounting_period_containing(time_t now);
+static void accounting_set_wakeup_time(void);
+
+/* ************
+ * Functions for bandwidth accounting.
+ * ************/
+
+void accounting_add_bytes(size_t n_read, size_t n_written, int seconds)
+{
+  n_bytes_read_in_interval += n_read;
+  n_bytes_written_in_interval += n_written;
+  /* If we haven't been called in 10 seconds, we're probably jumping
+   * around in time. */
+  n_seconds_active_in_interval += (seconds < 10) ? seconds : 0;
+}
+
+static time_t start_of_accounting_period_containing(time_t now)
+{
+  struct tm *tm;
+  /* Only months are supported. */
+  tm = gmtime(&now);
+  /* If this is before the Nth, we want the Nth of last month. */
+  if (tm->tm_mday < options.AccountingStart) {
+    if (--tm->tm_mon < 0) {
+      tm->tm_mon = 11;
+      --tm->tm_year;
+    }
+  }
+  /* Otherwise, the month and year are correct.*/
+
+  tm->tm_mday = options.AccountingStart;
+  tm->tm_hour = 0;
+  tm->tm_min = 0;
+  tm->tm_sec = 0;
+  return tor_timegm(tm);
+}
+static time_t start_of_accounting_period_after(time_t now)
+{
+  time_t start;
+  struct tm *tm;
+  start = start_of_accounting_period_containing(now);
+
+  tm = gmtime(&start);
+  if (++tm->tm_mon > 11) {
+    tm->tm_mon = 0;
+    ++tm->tm_year;
+  }
+  return tor_timegm(tm);
+}
+
+void configure_accounting(time_t now)
+{
+  if (!interval_start_time)
+    read_bandwidth_usage(); /* XXXX009 check warning? */
+  if (!interval_start_time ||
+      start_of_accounting_period_after(interval_start_time) <= now) {
+    /* We start a new interval. */
+    log_fn(LOG_INFO, "Starting new accounting interval.");
+    interval_start_time = start_of_accounting_period_containing(now);
+    interval_end_time = start_of_accounting_period_after(interval_start_time);
+    n_bytes_read_in_interval = 0;
+    n_bytes_written_in_interval = 0;
+  } if (interval_start_time ==
+        start_of_accounting_period_containing(interval_start_time)) {
+    log_fn(LOG_INFO, "Continuing accounting interval.");
+    /* We are in the interval we thought we were in. Do nothing.*/
+  } else {
+    /* XXXX009 We are in an incompatible interval; we must have
+     * changed our configuration.  Do we reset the interval, or
+     * what? */
+    log_fn(LOG_INFO, "Mismatched accounting interval.");
+  }
+  accounting_set_wakeup_time();
+}
+
+static INLINE int time_to_record_bandwidth_usage(time_t now)
+{
+  /* Note every 5 minutes */
+#define NOTE_INTERVAL (5*60)
+  /* Or every 20 megabytes */
+#define NOTE_BYTES 20*(1024*1024)
+  static uint64_t last_read_bytes_noted = 0;
+  static uint64_t last_written_bytes_noted = 0;
+  static time_t last_time_noted = 0;
+
+  if ((options.AccountingMaxKB || 1)&&
+      (last_time_noted + NOTE_INTERVAL <= now ||
+       last_read_bytes_noted + NOTE_BYTES <= n_bytes_read_in_interval ||
+       last_written_bytes_noted + NOTE_BYTES <=
+           n_bytes_written_in_interval ||
+       (interval_end_time && interval_end_time <= now))) {
+    last_time_noted = now;
+    last_read_bytes_noted = n_bytes_read_in_interval;
+    last_written_bytes_noted = n_bytes_written_in_interval;
+    return 1;
+  }
+  return 0;
+}
+
+void accounting_run_housekeeping(time_t now)
+{
+  if (now >= interval_end_time) {
+    configure_accounting(now);
+  }
+  if (time_to_record_bandwidth_usage(now)) {
+    if (record_bandwidth_usage(now)) {
+      log_fn(LOG_WARN, "Couldn't record bandwidth usage!");
+      /* XXXX009 should this exit? */
+    }
+  }
+}
+
+void accounting_set_wakeup_time(void)
+{
+  struct tm *tm;
+  char buf[ISO_TIME_LEN+1];
+  char digest[DIGEST_LEN];
+  crypto_digest_env_t *d;
+  int n_days_in_interval;
+
+  format_iso_time(buf, interval_start_time);
+  crypto_pk_get_digest(get_identity_key(), digest);
+
+  d = crypto_new_digest_env();
+  crypto_digest_add_bytes(d, buf, ISO_TIME_LEN);
+  crypto_digest_add_bytes(d, digest, DIGEST_LEN);
+  crypto_digest_get_digest(d, digest, DIGEST_LEN);
+  crypto_free_digest_env(d);
+
+  /* XXXX009 This logic is  wrong.  Instead of choosing randomly
+   * from the days in the interval, we should avoid days so close to the end
+   * that we won't use up all our bandwidth.  This could potentially waste
+   * 50% of all donated bandwidth.
+   */
+  tm = gmtime(&interval_start_time);
+  if (++tm->tm_mon > 11) { tm->tm_mon = 0; ++tm->tm_year; }
+  n_days_in_interval = (tor_timegm(tm)-interval_start_time+1)/(24*60*60);
+
+  while (((unsigned char)digest[0]) > n_days_in_interval)
+    crypto_digest(digest, digest, DIGEST_LEN);
+
+  interval_wakeup_time = interval_start_time +
+    24*60*60 * (unsigned char)digest[0];
+}
+
+static int record_bandwidth_usage(time_t now)
+{
+  char buf[128];
+  char fname[512];
+  char *cp = buf;
+
+  *cp++ = '0';
+  *cp++ = ' ';
+  format_iso_time(cp, interval_start_time);
+  cp += ISO_TIME_LEN;
+  *cp++ = ' ';
+  format_iso_time(cp, now);
+  cp += ISO_TIME_LEN;
+  tor_snprintf(cp, sizeof(buf)-ISO_TIME_LEN*2-3,
+               " "U64_FORMAT" "U64_FORMAT" %lu\n",
+               U64_PRINTF_ARG(n_bytes_read_in_interval),
+               U64_PRINTF_ARG(n_bytes_written_in_interval),
+               (unsigned long)n_seconds_active_in_interval);
+  tor_snprintf(fname, sizeof(fname), "%s/bw_accounting",
+               get_data_directory(&options));
+
+  return write_str_to_file(fname, buf, 0);
+}
+
+static int read_bandwidth_usage(void)
+{
+  char *s = NULL;
+  char fname[512];
+  time_t scratch_time;
+  unsigned long sec;
+
+  /*
+  if (!options.AccountingMaxKB)
+    return 0;
+  */
+  tor_snprintf(fname, sizeof(fname), "%s/bw_accounting",
+               get_data_directory(&options));
+  if (!(s = read_file_to_str(fname, 0))) {
+    return 0;
+  }
+  /* version, space, time, space, time, space, bw, space, bw, nl. */
+  if (strlen(s) < ISO_TIME_LEN*2+6) {
+    log_fn(LOG_WARN,
+           "Recorded bandwidth usage file seems truncated or corrupted");
+    goto err;
+  }
+  if (s[0] != '0' || s[1] != ' ') {
+    log_fn(LOG_WARN, "Unrecognized version on bandwidth usage file");
+    goto err;
+  }
+  if (parse_iso_time(s+2, &interval_start_time)) {
+    log_fn(LOG_WARN, "Error parsing bandwidth usage start time.");
+    goto err;
+  }
+  if (s[ISO_TIME_LEN+2] != ' ') {
+    log_fn(LOG_WARN, "Expected space after start time.");
+    goto err;
+  }
+  if (parse_iso_time(s+ISO_TIME_LEN+3, &scratch_time)) {
+    log_fn(LOG_WARN, "Error parsing bandwidth usage last-written time");
+    goto err;
+  }
+  if (s[ISO_TIME_LEN+3+ISO_TIME_LEN] != ' ') {
+    log_fn(LOG_WARN, "Expected space after last-written time.");
+    goto err;
+  }
+  if (sscanf(s+ISO_TIME_LEN*2+4, U64_FORMAT" "U64_FORMAT" %lu",
+             U64_SCANF_ARG(&n_bytes_read_in_interval),
+             U64_SCANF_ARG(&n_bytes_written_in_interval),
+             &sec)<2) {
+    log_fn(LOG_WARN, "Error reading bandwidth usage.");
+    goto err;
+  }
+  n_seconds_active_in_interval = (uint32_t)sec;
+
+  tor_free(s);
+  accounting_set_wakeup_time();
+  return 0;
+ err:
+  tor_free(s);
+  return -1;
+}
+
+static int hibernate_hard_limit_reached(void)
+{
+  uint64_t hard_limit = options.AccountingMaxKB<<10;
+  if (!hard_limit)
+    return 0;
+  return n_bytes_read_in_interval >= hard_limit
+    || n_bytes_written_in_interval >= hard_limit;
+}
 
-/** Returns 1 if the bandwidth soft limit has been reached, else 0. */
-static int hibernate_soft_limit_reached(void) {
-  return accounting_soft_limit_reached();
+static int hibernate_soft_limit_reached(void)
+{
+  uint64_t soft_limit = (uint64_t) ((options.AccountingMaxKB<<10) * .99);
+  if (!soft_limit)
+    return 0;
+  return n_bytes_read_in_interval >= soft_limit
+    || n_bytes_written_in_interval >= soft_limit;
 }
 
-/** Returns 1 if the bandwidth hard limit has been reached, else 0. */
-static int hibernate_hard_limit_reached(void) {
-  return accounting_hard_limit_reached();
+static time_t hibernate_calc_wakeup_time(void)
+{
+  if (interval_wakeup_time > time(NULL))
+    return interval_wakeup_time;
+  else
+    /*XXXX009 this means that callers must check for wakeup time again
+    * at the start of the next interval.  Not right! */
+    return interval_end_time;
 }
 
-/** Return the time when we should stop being dormant. */
-static time_t hibernate_calc_wakeup_time(void) {
-  return accounting_get_wakeup_time();
+#if 0
+static int accounting_should_hibernate(void)
+{
+  return hibernate_limit_reached() || interval_wakeup_time > time(NULL);
 }
+#endif
+
 
 /** Called when we get a SIGINT, or when bandwidth soft limit
  * is reached. */

src/or/main.c

@@ -13,12 +13,6 @@
 
 static void dumpstats(int severity); /* log stats */
 static int init_from_config(int argc, char **argv);
-static int read_bandwidth_usage(void);
-static int record_bandwidth_usage(time_t now);
-static void configure_accounting(time_t now);
-static time_t start_of_accounting_period_after(time_t now);
-static time_t start_of_accounting_period_containing(time_t now);
-static void accounting_set_wakeup_time(void);
 
 /********* START VARIABLES **********/
 
@@ -40,16 +34,6 @@ long stats_n_seconds_uptime = 0;
 /** When do we next download a directory? */
 static time_t time_to_fetch_directory = 0;
 
-/** How many bytes have we read/written in this accounting interval? */
-static uint64_t stats_n_bytes_read_in_interval = 0;
-static uint64_t stats_n_bytes_written_in_interval = 0;
-/** When did this accounting interval start? */
-static time_t interval_start_time = 0;
-/** When will this accounting interval end? */
-static time_t interval_end_time = 0;
-/** How far into the accounting interval should we hibernate? */
-static time_t interval_wakeup_time = 0;
-
 /** Array of all open connections; each element corresponds to the element of
  * poll_array in the same position.  The first nfds elements are valid. */
 static connection_t *connection_array[MAXCONNECTIONS] =
@@ -387,236 +371,6 @@ void directory_has_arrived(time_t now) {
   }
 }
 
-/* ************
- * Functions for bandwidth accounting.
- * ************/
-static time_t start_of_accounting_period_containing(time_t now)
-{
-  struct tm *tm;
-  /* Only months are supported. */
-  tm = gmtime(&now);
-  /* If this is before the Nth, we want the Nth of last month. */
-  if (tm->tm_mday < options.AccountingStart) {
-    if (--tm->tm_mon < 0) {
-      tm->tm_mon = 11;
-      --tm->tm_year;
-    }
-  }
-  /* Otherwise, the month and year are correct.*/
-
-  tm->tm_mday = options.AccountingStart;
-  tm->tm_hour = 0;
-  tm->tm_min = 0;
-  tm->tm_sec = 0;
-  return tor_timegm(tm);
-}
-static time_t start_of_accounting_period_after(time_t now)
-{
-  time_t start;
-  struct tm *tm;
-  start = start_of_accounting_period_containing(now);
-
-  tm = gmtime(&start);
-  if (++tm->tm_mon > 11) {
-    tm->tm_mon = 0;
-    ++tm->tm_year;
-  }
-  return tor_timegm(tm);
-}
-
-static void configure_accounting(time_t now)
-{
-  if (!interval_start_time)
-    read_bandwidth_usage(); /* XXXX009 check warning? */
-  if (!interval_start_time ||
-      start_of_accounting_period_after(interval_start_time) <= now) {
-    /* We start a new interval. */
-    log_fn(LOG_INFO, "Starting new accounting interval.");
-    interval_start_time = start_of_accounting_period_containing(now);
-    interval_end_time = start_of_accounting_period_after(interval_start_time);
-    stats_n_bytes_read_in_interval = 0;
-    stats_n_bytes_written_in_interval = 0;
-  } if (interval_start_time ==
-        start_of_accounting_period_containing(interval_start_time)) {
-    log_fn(LOG_INFO, "Continuing accounting interval.");
-    /* We are in the interval we thought we were in. Do nothing.*/
-  } else {
-    /* XXXX009 We are in an incompatible interval; we must have
-     * changed our configuration.  Do we reset the interval, or
-     * what? */
-    log_fn(LOG_INFO, "Mismatched accounting interval.");
-  }
-  accounting_set_wakeup_time();
-}
-
-static INLINE int time_to_record_bandwidth_usage(time_t now)
-{
-  /* Note every 5 minutes */
-#define NOTE_INTERVAL (5*60)
-  /* Or every 20 megabytes */
-#define NOTE_BYTES 20*(1024*1024)
-  static uint64_t last_read_bytes_noted = 0;
-  static uint64_t last_written_bytes_noted = 0;
-  static time_t last_time_noted = 0;
-
-  if ((options.AccountingMaxKB || 1)&&
-      (last_time_noted + NOTE_INTERVAL <= now ||
-       last_read_bytes_noted + NOTE_BYTES <= stats_n_bytes_read_in_interval ||
-       last_written_bytes_noted + NOTE_BYTES <=
-           stats_n_bytes_written_in_interval ||
-       (interval_end_time && interval_end_time <= now))) {
-    last_time_noted = now;
-    last_read_bytes_noted = stats_n_bytes_read_in_interval;
-    last_written_bytes_noted = stats_n_bytes_written_in_interval;
-    return 1;
-  }
-  return 0;
-}
-
-void accounting_set_wakeup_time(void)
-{
-  struct tm *tm;
-  char buf[ISO_TIME_LEN+1];
-  char digest[DIGEST_LEN];
-  crypto_digest_env_t *d;
-  int n_days_in_interval;
-
-  format_iso_time(buf, interval_start_time);
-  crypto_pk_get_digest(get_identity_key(), digest);
-
-  d = crypto_new_digest_env();
-  crypto_digest_add_bytes(d, buf, ISO_TIME_LEN);
-  crypto_digest_add_bytes(d, digest, DIGEST_LEN);
-  crypto_digest_get_digest(d, digest, DIGEST_LEN);
-  crypto_free_digest_env(d);
-
-  /* XXXX009 This logic is  wrong.  Instead of choosing randomly
-   * from the days in the interval, we should avoid days so close to the end
-   * that we won't use up all our bandwidth.  This could potentially waste
-   * 50% of all donated bandwidth.
-   */
-  tm = gmtime(&interval_start_time);
-  if (++tm->tm_mon > 11) { tm->tm_mon = 0; ++tm->tm_year; }
-  n_days_in_interval = (tor_timegm(tm)-interval_start_time+1)/(24*60*60);
-
-  while (((unsigned char)digest[0]) > n_days_in_interval)
-    crypto_digest(digest, digest, DIGEST_LEN);
-
-  interval_wakeup_time = interval_start_time +
-    24*60*60 * (unsigned char)digest[0];
-}
-
-static int record_bandwidth_usage(time_t now)
-{
-  char buf[128];
-  char fname[512];
-  char *cp = buf;
-
-  *cp++ = '0';
-  *cp++ = ' ';
-  format_iso_time(cp, interval_start_time);
-  cp += ISO_TIME_LEN;
-  *cp++ = ' ';
-  format_iso_time(cp, now);
-  cp += ISO_TIME_LEN;
-  tor_snprintf(cp, sizeof(buf)-ISO_TIME_LEN*2-3,
-               " "U64_FORMAT" "U64_FORMAT"\n",
-               U64_PRINTF_ARG(stats_n_bytes_read_in_interval),
-               U64_PRINTF_ARG(stats_n_bytes_written_in_interval));
-  tor_snprintf(fname, sizeof(fname), "%s/bw_accounting",
-               get_data_directory(&options));
-
-  return write_str_to_file(fname, buf, 0);
-}
-
-static int read_bandwidth_usage(void)
-{
-  char *s = NULL;
-  char fname[512];
-  time_t scratch_time;
-
-  /*
-  if (!options.AccountingMaxKB)
-    return 0;
-  */
-  tor_snprintf(fname, sizeof(fname), "%s/bw_accounting",
-               get_data_directory(&options));
-  if (!(s = read_file_to_str(fname, 0))) {
-    return 0;
-  }
-  /* version, space, time, space, time, space, bw, space, bw, nl. */
-  if (strlen(s) < ISO_TIME_LEN*2+6) {
-    log_fn(LOG_WARN,
-           "Recorded bandwidth usage file seems truncated or corrupted");
-    goto err;
-  }
-  if (s[0] != '0' || s[1] != ' ') {
-    log_fn(LOG_WARN, "Unrecognized version on bandwidth usage file");
-    goto err;
-  }
-  if (parse_iso_time(s+2, &interval_start_time)) {
-    log_fn(LOG_WARN, "Error parsing bandwidth usage start time.");
-    goto err;
-  }
-  if (s[ISO_TIME_LEN+2] != ' ') {
-    log_fn(LOG_WARN, "Expected space after start time.");
-    goto err;
-  }
-  if (parse_iso_time(s+ISO_TIME_LEN+3, &scratch_time)) {
-    log_fn(LOG_WARN, "Error parsing bandwidth usage last-written time");
-    goto err;
-  }
-  if (s[ISO_TIME_LEN+3+ISO_TIME_LEN] != ' ') {
-    log_fn(LOG_WARN, "Expected space after last-written time.");
-    goto err;
-  }
-  if (sscanf(s+ISO_TIME_LEN*2+4, U64_FORMAT" "U64_FORMAT,
-             U64_SCANF_ARG(&stats_n_bytes_read_in_interval),
-             U64_SCANF_ARG(&stats_n_bytes_written_in_interval))<2) {
-    log_fn(LOG_WARN, "Error reading bandwidth usage.");
-    goto err;
-  }
-
-  tor_free(s);
-  accounting_set_wakeup_time();
-  return 0;
- err:
-  tor_free(s);
-  return -1;
-}
-
-int accounting_hard_limit_reached(void)
-{
-  uint64_t hard_limit = options.AccountingMaxKB<<10;
-  if (!hard_limit)
-    return 0;
-  return stats_n_bytes_read_in_interval >= hard_limit
-    || stats_n_bytes_written_in_interval >= hard_limit;
-}
-
-int accounting_soft_limit_reached(void)
-{
-  uint64_t soft_limit = (uint64_t) ((options.AccountingMaxKB<<10) * .99);
-  if (!soft_limit)
-    return 0;
-  return stats_n_bytes_read_in_interval >= soft_limit
-    || stats_n_bytes_written_in_interval >= soft_limit;
-}
-
-time_t accounting_get_wakeup_time(void)
-{
-  if (interval_wakeup_time > time(NULL))
-    return interval_wakeup_time;
-  else
-    /*XXXX009 this means that callers must check for wakeup time again
-    * at the start of the next interval.  Not right! */
-    return interval_end_time;
-}
-
-int accounting_should_hibernate(void)
-{
-  return accounting_hard_limit_reached() || interval_wakeup_time > time(NULL);
-}
 
 /** Perform regular maintenance tasks for a single connection.  This
  * function gets run once per second per connection by run_housekeeping.
@@ -782,15 +536,7 @@ static void run_scheduled_events(time_t now) {
 
   /** 1c. If we have to change the accounting interval or record
    * bandwidth used in this accounting interval, do so. */
-  if (now >= interval_end_time) {
-    configure_accounting(now);
-  }
-  if (time_to_record_bandwidth_usage(now)) {
-    if (record_bandwidth_usage(now)) {
-      log_fn(LOG_WARN, "Couldn't record bandwidth usage!");
-      /* XXXX009 should this exit? */
-    }
-  }
+  accounting_run_housekeeping(now);
 
   /** 2. Every DirFetchPostPeriod seconds, we get a new directory and upload
    *    our descriptor (if we've passed our internal checks). */
@@ -901,20 +647,20 @@ static int prepare_for_poll(void) {
     /* the second has rolled over. check more stuff. */
     size_t bytes_written;
     size_t bytes_read;
+    int seconds_elapsed;
     bytes_written = stats_prev_global_write_bucket - global_write_bucket;
     bytes_read = stats_prev_global_read_bucket - global_read_bucket;
+    seconds_elapsed = current_second ? (now.tv_sec - current_second) : 0;
     stats_n_bytes_read += bytes_read;
-    stats_n_bytes_read_in_interval += bytes_read;
     stats_n_bytes_written += bytes_written;
-    stats_n_bytes_written_in_interval += bytes_written;
+    accounting_add_bytes(bytes_read, bytes_written, seconds_elapsed);
     control_event_bandwidth_used((uint32_t)bytes_read,(uint32_t)bytes_written);
 
     connection_bucket_refill(&now);
     stats_prev_global_read_bucket = global_read_bucket;
     stats_prev_global_write_bucket = global_write_bucket;
 
-    if(current_second)
-      stats_n_seconds_uptime += (now.tv_sec - current_second);
+    stats_n_seconds_uptime += seconds_elapsed;
 
     assert_all_pending_dns_resolves_ok();
     run_scheduled_events(now.tv_sec);

src/or/or.h

@@ -1097,6 +1097,8 @@ void exit_policy_free(struct exit_policy_t *p);
 const char *get_data_directory(or_options_t *options);
 struct config_line_t *config_get_assigned_option(or_options_t *options,
                                                  const char *key);
+struct config_line_t *config_line_prepend(struct config_line_t *front,
+                                          const char *key, const char *val);
 
 /********************************* connection.c ***************************/
 
@@ -1301,6 +1303,9 @@ int dns_resolve(connection_t *exitconn);
 
 /********************************* hibernate.c **********************/
 
+void configure_accounting(time_t now);
+void accounting_run_housekeeping(time_t now);
+void accounting_add_bytes(size_t n_read, size_t n_written, int seconds);
 void hibernate_begin_shutdown(void);
 int we_are_hibernating(void);
 void consider_hibernation(time_t now);
@@ -1332,11 +1337,6 @@ int proxy_mode(void);
 void handle_signals(int is_parent);
 void tor_cleanup(void);
 
-int accounting_hard_limit_reached(void);
-int accounting_soft_limit_reached(void);
-time_t accounting_get_wakeup_time(void);
-int accounting_should_hibernate(void);
-
 int tor_main(int argc, char *argv[]);
 
 /********************************* onion.c ***************************/