return 0;
}
-/** Our clock just jumped by <b>seconds_elapsed</b>. Assume
- * something has also gone wrong with our network: notify the user,
- * and abandon all not-yet-used circuits. */
+/** Our clock just jumped by <b>seconds_elapsed</b>. If <b>was_idle</b> is
+ * true, then the monotonic time matches; otherwise it doesn't. Assume
+ * something has also gone wrong with our network: notify the user, and
+ * abandon all not-yet-used circuits. */
void
-circuit_note_clock_jumped(int seconds_elapsed)
+circuit_note_clock_jumped(int seconds_elapsed, bool was_idle)
{
int severity = server_mode(get_options()) ? LOG_WARN : LOG_NOTICE;
- tor_log(severity, LD_GENERAL, "Your system clock just jumped %d seconds %s; "
- "assuming established circuits no longer work.",
- seconds_elapsed >=0 ? seconds_elapsed : -seconds_elapsed,
- seconds_elapsed >=0 ? "forward" : "backward");
- control_event_general_status(LOG_WARN, "CLOCK_JUMPED TIME=%d",
- seconds_elapsed);
+ if (was_idle) {
+ tor_log(severity, LD_GENERAL, "Tor has been idle for %d seconds; "
+ "assuming established circuits no longer work.",
+ seconds_elapsed);
+ } else {
+ tor_log(severity, LD_GENERAL,
+ "Your system clock just jumped %d seconds %s; "
+ "assuming established circuits no longer work.",
+ seconds_elapsed >=0 ? seconds_elapsed : -seconds_elapsed,
+ seconds_elapsed >=0 ? "forward" : "backward");
+ }
+ control_event_general_status(LOG_WARN, "CLOCK_JUMPED TIME=%d IDLE=%d",
+ seconds_elapsed, was_idle?1:0);
/* so we log when it works again */
note_that_we_maybe_cant_complete_circuits();
control_event_client_status(severity, "CIRCUIT_NOT_ESTABLISHED REASON=%s",
int inform_testing_reachability(void);
int circuit_timeout_want_to_count_circ(const origin_circuit_t *circ);
int circuit_send_next_onion_skin(origin_circuit_t *circ);
-void circuit_note_clock_jumped(int seconds_elapsed);
+void circuit_note_clock_jumped(int seconds_elapsed, bool was_idle);
int circuit_extend(cell_t *cell, circuit_t *circ);
int circuit_init_cpath_crypto(crypt_path_t *cpath,
const char *key_data, size_t key_data_len,
/** Last time that update_current_time was called. */
static time_t current_second = 0;
+/** Last time that update_current_time updated current_second. */
+static monotime_coarse_t current_second_last_changed;
/**
* Set the current time to "now", which should be the value returned by
const time_t seconds_elapsed = current_second ? (now - current_second) : 0;
-/** If more than this many seconds have elapsed, probably the clock
- * jumped: doesn't count. */
+ /* Check the wall clock against the monotonic clock, so we can
+ * better tell idleness from clock jumps and/or other shenanigans. */
+ monotime_coarse_t last_updated;
+ memcpy(&last_updated, ¤t_second_last_changed, sizeof(last_updated));
+ monotime_coarse_get(¤t_second_last_changed);
+
+ /** How much clock jumping do we tolerate? */
#define NUM_JUMPED_SECONDS_BEFORE_WARN 100
- if (seconds_elapsed < -NUM_JUMPED_SECONDS_BEFORE_WARN ||
- seconds_elapsed >= NUM_JUMPED_SECONDS_BEFORE_WARN) {
- circuit_note_clock_jumped(seconds_elapsed);
+ /** How much idleness do we tolerate? */
+#define NUM_IDLE_SECONDS_BEFORE_WARN 3600
+
+ if (seconds_elapsed < -NUM_JUMPED_SECONDS_BEFORE_WARN) {
+ // moving back in time is always a bad sign.
+ circuit_note_clock_jumped(seconds_elapsed, false);
+ } else if (seconds_elapsed >= NUM_JUMPED_SECONDS_BEFORE_WARN) {
+ /* Compare the monotonic clock to the result of time(). */
+ const int32_t monotime_msec_passed =
+ monotime_coarse_diff_msec32(&last_updated,
+ ¤t_second_last_changed);
+ const int monotime_sec_passed = monotime_msec_passed / 1000;
+ const int discrepency = monotime_sec_passed - seconds_elapsed;
+ /* If the monotonic clock deviates from time(NULL), we have a couple of
+ * possibilities. On some systems, this means we have been suspended or
+ * sleeping. Everywhere, it can mean that the wall-clock time has
+ * been changed -- for example, with settimeofday().
+ *
+ * On the other hand, if the monotonic time matches with the wall-clock
+ * time, we've probably just been idle for a while, with no events firing.
+ * we tolerate much more of that.
+ */
+ const bool clock_jumped = abs(discrepency) > 2;
+
+ if (clock_jumped || seconds_elapsed >= NUM_IDLE_SECONDS_BEFORE_WARN) {
+ circuit_note_clock_jumped(seconds_elapsed, ! clock_jumped);
+ }
} else if (seconds_elapsed > 0) {
stats_n_seconds_working += seconds_elapsed;
}
heartbeat_callback_first_time = 1;
n_libevent_errors = 0;
current_second = 0;
+ memset(¤t_second_last_changed, 0,
+ sizeof(current_second_last_changed));
if (!postfork) {
release_lockfile();
#include "or.h"
#include "main.h"
+static const uint64_t BILLION = 1000000000;
+
static void
test_mainloop_update_time_normal(void *arg)
{
(void)arg;
+ monotime_enable_test_mocking();
+ /* This is arbitrary */
+ uint64_t mt_now = U64_LITERAL(7493289274986);
/* This time is in the past as of when this test was written. */
time_t now = 1525272090;
+ monotime_coarse_set_mock_time_nsec(mt_now);
reset_uptime();
update_current_time(now);
tt_int_op(approx_time(), OP_EQ, now);
tt_int_op(get_uptime(), OP_EQ, 0);
now += 1;
+ mt_now += BILLION;
+ monotime_coarse_set_mock_time_nsec(mt_now);
update_current_time(now);
tt_int_op(approx_time(), OP_EQ, now);
tt_int_op(get_uptime(), OP_EQ, 1);
now += 2; // two-second jump is unremarkable.
+ mt_now += 2*BILLION;
update_current_time(now);
+ monotime_coarse_set_mock_time_nsec(mt_now);
tt_int_op(approx_time(), OP_EQ, now);
tt_int_op(get_uptime(), OP_EQ, 3);
tt_int_op(get_uptime(), OP_EQ, 3); // but it doesn't roll back our uptime
done:
- ;
+ monotime_disable_test_mocking();
}
static void
{
(void)arg;
+ monotime_enable_test_mocking();
+ /* This is arbitrary */
+ uint64_t mt_now = U64_LITERAL(7493289274986);
/* This time is in the past as of when this test was written. */
time_t now = 220897152;
+ monotime_coarse_set_mock_time_nsec(mt_now);
reset_uptime();
update_current_time(now);
tt_int_op(approx_time(), OP_EQ, now);
/* Put some uptime on the clock.. */
now += 3;
+ mt_now += 3*BILLION;
+ monotime_coarse_set_mock_time_nsec(mt_now);
update_current_time(now);
tt_int_op(approx_time(), OP_EQ, now);
tt_int_op(get_uptime(), OP_EQ, 3);
- /* Now try jumping forward. */
+ /* Now try jumping forward and backward, without updating the monotonic
+ * clock. */
setup_capture_of_logs(LOG_NOTICE);
- now += 3600;
+ now += 1800;
update_current_time(now);
expect_single_log_msg_containing(
- "Your system clock just jumped 3600 seconds forward");
+ "Your system clock just jumped 1800 seconds forward");
tt_int_op(approx_time(), OP_EQ, now);
tt_int_op(get_uptime(), OP_EQ, 3); // no uptime change.
mock_clean_saved_logs();
"Your system clock just jumped 600 seconds backward");
tt_int_op(approx_time(), OP_EQ, now);
tt_int_op(get_uptime(), OP_EQ, 3); // no uptime change.
+ mock_clean_saved_logs();
/* uptime tracking should go normally now if the clock moves sensibly. */
now += 2;
+ mt_now += 2*BILLION;
+ update_current_time(now);
+ tt_int_op(approx_time(), OP_EQ, now);
+ tt_int_op(get_uptime(), OP_EQ, 5);
+
+ /* If we skip forward by a few minutes but the monotonic clock agrees,
+ * we've just been idle: that counts as not worth warning about. */
+ now += 1800;
+ mt_now += 1800*BILLION;
+ monotime_coarse_set_mock_time_nsec(mt_now);
+ update_current_time(now);
+ expect_no_log_entry();
+ tt_int_op(approx_time(), OP_EQ, now);
+ tt_int_op(get_uptime(), OP_EQ, 5); // this doesn't count to uptime, though.
+
+ /* If we skip forward by a long time, even if the clock agrees, it's
+ * idnless that counts. */
+ now += 4000;
+ mt_now += 4000*BILLION;
+ monotime_coarse_set_mock_time_nsec(mt_now);
update_current_time(now);
+ expect_single_log_msg_containing("Tor has been idle for 4000 seconds");
tt_int_op(approx_time(), OP_EQ, now);
tt_int_op(get_uptime(), OP_EQ, 5);
done:
teardown_capture_of_logs();
+ monotime_disable_test_mocking();
}
#define MAINLOOP_TEST(name) \
projects / thirdparty / tor.git / commitdiff
