Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: Use monotonic time for timeouts #284

Merged
merged 8 commits into from
Jun 17, 2020
Merged
Show file tree
Hide file tree
Changes from 7 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 2 additions & 4 deletions src/sentry_core.c
Original file line number Diff line number Diff line change
Expand Up @@ -124,11 +124,9 @@ sentry_shutdown(void)
if (options) {
if (options->transport) {
// TODO: make this configurable
// Ideally, it should default to 2s as per
// Defaults to 2s as per
// https://docs.sentry.io/error-reporting/configuration/?platform=rust#shutdown-timeout
// but we hit that timeout in our own integration tests, so rather
// increase it to 5s, as it was before.
if (!sentry__transport_shutdown(options->transport, 5000)) {
if (!sentry__transport_shutdown(options->transport, 2000)) {
Swatinem marked this conversation as resolved.
Show resolved Hide resolved
SENTRY_DEBUG("transport did not shut down cleanly");
}
}
Expand Down
6 changes: 3 additions & 3 deletions src/sentry_ratelimiter.c
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ sentry__rate_limiter_update_from_header(
return false;
}
retry_after *= 1000;
retry_after += sentry__msec_time();
retry_after += sentry__monotonic_time();

if (!sentry__slice_consume_if(&slice, ':')) {
return false;
Expand Down Expand Up @@ -77,14 +77,14 @@ sentry__rate_limiter_update_from_http_retry_after(
uint64_t eta = 60;
sentry__slice_consume_uint64(&slice, &eta);
rl->disabled_until[SENTRY_RL_CATEGORY_ANY]
= sentry__msec_time() + eta * 1000;
= sentry__monotonic_time() + eta * 1000;
return true;
}

bool
sentry__rate_limiter_is_disabled(const sentry_rate_limiter_t *rl, int category)
{
uint64_t now = sentry__msec_time();
uint64_t now = sentry__monotonic_time();
return rl->disabled_until[SENTRY_RL_CATEGORY_ANY] > now
|| rl->disabled_until[category] > now;
}
Expand Down
5 changes: 2 additions & 3 deletions src/sentry_sync.c
Original file line number Diff line number Diff line change
Expand Up @@ -133,8 +133,7 @@ sentry__bgworker_shutdown(sentry_bgworker_t *bgw, uint64_t timeout)
/* submit a task to shut down the queue */
sentry__bgworker_submit(bgw, shutdown_task, NULL, bgw);

/* TODO: this is dangerous and should be monotonic time */
uint64_t started = sentry__msec_time();
uint64_t started = sentry__monotonic_time();
while (true) {
sentry__mutex_lock(&bgw->task_lock);
bool done = bgw->task_count == 0 && !bgw->running;
Expand All @@ -147,7 +146,7 @@ sentry__bgworker_shutdown(sentry_bgworker_t *bgw, uint64_t timeout)
sentry__cond_wait_timeout(
&bgw->done_signal, &bgw->done_signal_lock, 250);
sentry__mutex_unlock(&bgw->done_signal_lock);
uint64_t now = sentry__msec_time();
uint64_t now = sentry__monotonic_time();
if (now > started && now - started > timeout) {
return 1;
}
Expand Down
37 changes: 37 additions & 0 deletions src/sentry_utils.h
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
# include <winnt.h>
#else
# include <sys/time.h>
# include <time.h>
#endif

/**
Expand Down Expand Up @@ -108,6 +109,42 @@ sentry__msec_time(void)
#endif
}

/**
* Returns a monotonic millisecond resolution time.
*
* This should be used for timeouts and similar.
* For timestamps, use `sentry__msec_time` instead.
*/
static inline uint64_t
sentry__monotonic_time(void)
{
#ifdef SENTRY_PLATFORM_WINDOWS
Swatinem marked this conversation as resolved.
Show resolved Hide resolved
static LARGE_INTEGER qpc_frequency = { 0 };

if (!qpc_frequency.QuadPart) {
QueryPerformanceFrequency(&qpc_frequency);
}

// Fallback to GetTickCount() on QPC fail
if (!qpc_frequency.QuadPart) {
# if _WIN32_WINNT >= 0x0600
return GetTickCount64();
# else
return GetTickCount();
# endif
}

LARGE_INTEGER qpc_counter;
QueryPerformanceCounter(&qpc_counter);
return qpc_counter.QuadPart * 1000 / qpc_frequency.QuadPart;
#else
struct timespec tv;
return (clock_gettime(CLOCK_MONOTONIC, &tv) == 0)
? (uint64_t)tv.tv_sec * 1000 + tv.tv_nsec / 1000000
: 0;
#endif
}

/**
* Formats a timestamp (milliseconds since epoch) into ISO8601 format.
*/
Expand Down
5 changes: 5 additions & 0 deletions src/transports/sentry_transport_winhttp.c
Original file line number Diff line number Diff line change
Expand Up @@ -120,6 +120,8 @@ task_exec_func(void *data)
struct task_state *ts = data;
winhttp_transport_state_t *state = ts->transport_state;

uint64_t started = sentry__monotonic_time();

sentry_prepared_http_request_t *req
= sentry__prepare_http_request(ts->envelope, state->rl);
if (!req) {
Expand Down Expand Up @@ -226,6 +228,9 @@ task_exec_func(void *data)
sentry_free(url);
sentry_free(headers);
sentry__prepared_http_request_free(req);

uint64_t now = sentry__monotonic_time();
SENTRY_TRACEF("request handled in %llums", now - started);
}

static void
Expand Down
12 changes: 5 additions & 7 deletions tests/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -13,14 +13,12 @@

def make_dsn(httpserver, auth="uiaeosnrtdy", id=123456):
url = urllib.parse.urlsplit(httpserver.url_for("/{}".format(id)))
# We explicitly use `127.0.0.1` here, because on Windows, `localhost` will
# first try `::1` (the ipv6 loopback), retry a couple times and give up
# after a timeout of 2 seconds, falling back to the ipv4 loopback instead.
host = url.netloc.replace("localhost", "127.0.0.1")
return urllib.parse.urlunsplit(
(
url.scheme,
"{}@{}".format(auth, url.netloc),
url.path,
url.query,
url.fragment,
)
(url.scheme, "{}@{}".format(auth, host), url.path, url.query, url.fragment,)
)


Expand Down
2 changes: 1 addition & 1 deletion tests/unit/test_ratelimiter.c
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@

SENTRY_TEST(rate_limit_parsing)
{
uint64_t now = sentry__msec_time();
uint64_t now = sentry__monotonic_time();
sentry_rate_limiter_t *rl = sentry__rate_limiter_new();
TEST_CHECK(sentry__rate_limiter_update_from_header(
rl, "120:error:project, 60:session:foo, 30::bar, 120:invalid:invalid"));
Expand Down