github-personal/firezone
1
0
Fork 0
mirror of https://github.com/outbackdingo/firezone.git synced 2026-01-27 10:18:54 +00:00
Code Issues Packages Projects Releases Wiki Activity

chore(snownet): advance backoff after accessing interval (#8175)

Browse Source 
When we detect timed-out request to a relay, we print the duration we
were waiting for. Currently, this is offset by one "backoff tick"
because we advance the backoff too early.

Here is a log-output of a test prior to the change:

```
snownet::allocation: Sending BINDING requests to pick active socket relay_socket=V4(127.0.0.1:3478)
handle_timeout{active_socket=None}: snownet::allocation: Request timed out after 1.5s, re-sending id=TransactionId(0x0BFA13E983FEF36EE4877719) method=binding dst=127.0.0.1:3478
handle_timeout{active_socket=None}: snownet::allocation: Request timed out after 2.25s, re-sending id=TransactionId(0x0BFA13E983FEF36EE4877719) method=binding dst=127.0.0.1:3478
handle_timeout{active_socket=None}: snownet::allocation: Request timed out after 3.375s, re-sending id=TransactionId(0x0BFA13E983FEF36EE4877719) method=binding dst=127.0.0.1:3478
handle_timeout{active_socket=None}: snownet::allocation: Request timed out after 3.375s, re-sending id=TransactionId(0x0BFA13E983FEF36EE4877719) method=binding dst=127.0.0.1:3478
handle_timeout{active_socket=None}: snownet::allocation: Backoff expired, giving up id=TransactionId(0x0BFA13E983FEF36EE4877719) method=binding dst=127.0.0.1:3478
```

and with this change:

```
snownet::allocation: Sending BINDING requests to pick active socket relay_socket=V4(127.0.0.1:3478)
handle_timeout{active_socket=None}: snownet::allocation: Request timed out after 1s, re-sending id=TransactionId(0x6C79DD3607DF96806C4A7D8C) method=binding dst=127.0.0.1:3478
handle_timeout{active_socket=None}: snownet::allocation: Request timed out after 1.5s, re-sending id=TransactionId(0x6C79DD3607DF96806C4A7D8C) method=binding dst=127.0.0.1:3478
handle_timeout{active_socket=None}: snownet::allocation: Request timed out after 2.25s, re-sending id=TransactionId(0x6C79DD3607DF96806C4A7D8C) method=binding dst=127.0.0.1:3478
handle_timeout{active_socket=None}: snownet::allocation: Request timed out after 3.375s, re-sending id=TransactionId(0x6C79DD3607DF96806C4A7D8C) method=binding dst=127.0.0.1:3478
handle_timeout{active_socket=None}: snownet::allocation: Backoff expired, giving up id=TransactionId(0x6C79DD3607DF96806C4A7D8C) method=binding dst=127.0.0.1:3478
t
```

There is no functional difference, we were just logging the wrong
duration.
This commit is contained in:
Thomas Eizinger
2025-02-18 17:12:52 +11:00
committed by GitHub
parent 28f00089b9
commit 287068396f
1 changed files with 2 additions and 2 deletions
Download Patch File Download Diff File Expand all files Collapse all files

4
rust/connlib/snownet/src/allocation.rs
View File

@@ -682,11 +682,11 @@ impl Allocation {
.remove(&timed_out_request)
.expect("ID is from list");
backoff.handle_timeout(now); // Must update timeout here to avoid an endless loop.
let backoff_duration = backoff.interval();
let method = request.method();
backoff.handle_timeout(now); // Must update timeout here to avoid an endless loop.
tracing::debug!(id = ?request.transaction_id(), %method, %dst, "Request timed out after {backoff_duration:?}, re-sending");
let needs_auth = method != BINDING;