Skip to content
Merged
Show file tree
Hide file tree
Changes from all 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
7 changes: 7 additions & 0 deletions crates/test/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,13 @@ use tokio::sync::mpsc;
#[cfg(target_os = "linux")]
pub mod xdp_util;

/// Upper bound for waiting on a packet that is expected to arrive.
///
/// Generous on purpose: shared CI runners have been observed stalling every
/// test process on the machine for ~500ms while sandboxes spin up, and this is
/// only a guard against hanging forever, not a latency assertion.
pub const RECV_TIMEOUT: u64 = 10_000;

pub const MAX_WAIT: std::time::Duration = std::time::Duration::from_secs(5);

#[inline]
Expand Down
18 changes: 13 additions & 5 deletions crates/test/tests/mesh.rs
Original file line number Diff line number Diff line change
Expand Up @@ -118,7 +118,11 @@ trace_test!(relay_routing, {

assert_eq!(
"hello",
sandbox.timeout(1000, server_rx.recv()).await.0.unwrap()
sandbox
.timeout(RECV_TIMEOUT, server_rx.recv())
.await
.0
.unwrap()
);

tracing::info!(%token, "received packet");
Expand Down Expand Up @@ -217,7 +221,7 @@ trace_test!(datacenter_discovery, {

loop {
let rt = sandbox
.timeout(10000, proxy_delta_rx.recv())
.timeout(RECV_TIMEOUT, proxy_delta_rx.recv())
.await
.0
.unwrap();
Expand All @@ -233,7 +237,7 @@ trace_test!(datacenter_discovery, {
}
loop {
let rt = sandbox
.timeout(10000, proxy_delta_rx.recv())
.timeout(RECV_TIMEOUT, proxy_delta_rx.recv())
.await
.0
.unwrap();
Expand Down Expand Up @@ -335,7 +339,7 @@ trace_test!(filter_update, {
let mut updates = 0x0;
while (updates & 0x11) != 0x11 {
let rt = sandbox
.timeout(10000, proxy_delta_rx.recv())
.timeout(RECV_TIMEOUT, proxy_delta_rx.recv())
.await
.0
.unwrap();
Expand All @@ -356,7 +360,11 @@ trace_test!(filter_update, {
tracing::info!(len = token.len(), "received packet");
assert_eq!(
"hello",
sandbox.timeout(10000, server_rx.recv()).await.0.unwrap()
sandbox
.timeout(RECV_TIMEOUT, server_rx.recv())
.await
.0
.unwrap()
);

tracing::info!(len = token.len(), "sending bad packet");
Expand Down
20 changes: 14 additions & 6 deletions crates/test/tests/proxy.rs
Original file line number Diff line number Diff line change
Expand Up @@ -27,14 +27,14 @@ trace_test!(server, {
client.send_to(msg.as_bytes(), addr).await.unwrap();
assert_eq!(
msg,
sb.timeout(100, server1_rx.recv())
sb.timeout(RECV_TIMEOUT, server1_rx.recv())
.await
.0
.expect("should get a packet")
);
assert_eq!(
msg,
sb.timeout(100, server2_rx.recv())
sb.timeout(RECV_TIMEOUT, server2_rx.recv())
.await
.0
.expect("should get a packet")
Expand All @@ -56,7 +56,10 @@ trace_test!(client, {
let msg = "hello";
tracing::debug!(%local_addr, "sending packet");
client.send_to(msg.as_bytes(), local_addr).await.unwrap();
assert_eq!(msg, sb.timeout(100, dest_rx.recv()).await.0.unwrap(),);
assert_eq!(
msg,
sb.timeout(RECV_TIMEOUT, dest_rx.recv()).await.0.unwrap(),
);
});

trace_test!(with_filter, {
Expand All @@ -81,7 +84,7 @@ trace_test!(with_filter, {
client.send_to(msg.as_bytes(), local_addr).await.unwrap();

// search for the filter strings.
let result = sb.timeout(1000, rx.recv()).await.0.unwrap();
let result = sb.timeout(RECV_TIMEOUT, rx.recv()).await.0.unwrap();
assert!(result.starts_with(&format!("{msg}:odr:[::1]:")));
});

Expand Down Expand Up @@ -130,6 +133,7 @@ trace_test!(uring_receiver, {
sessions: quilkin::net::sessions::SessionPool::new(
vec![pending_sends.0.clone()],
config.dyn_cfg.cached_filter_chain().unwrap(),
config.dyn_cfg.clusters().cloned(),
usize::MAX,
backend,
4,
Expand All @@ -149,7 +153,10 @@ trace_test!(uring_receiver, {
let msg = "hello-downstream";
tracing::debug!("sending packet");
socket.send_to(msg.as_bytes(), addr).await.unwrap();
assert_eq!(msg, sb.timeout(200, packet_rx.recv()).await.0.unwrap());
assert_eq!(
msg,
sb.timeout(RECV_TIMEOUT, packet_rx.recv()).await.0.unwrap()
);
});

trace_test!(
Expand Down Expand Up @@ -196,6 +203,7 @@ trace_test!(
let sessions = net::SessionPool::new(
pending_sends.iter().map(|ps| ps.0.clone()).collect(),
config.dyn_cfg.cached_filter_chain().unwrap(),
config.dyn_cfg.clusters().cloned(),
usize::MAX,
backend,
64,
Expand Down Expand Up @@ -224,7 +232,7 @@ trace_test!(
for _ in 0..WORKER_COUNT {
assert_eq!(
msg,
sb.timeout(20, packet_rx.recv())
sb.timeout(RECV_TIMEOUT, packet_rx.recv())
.await
.0
.expect("should receive a packet")
Expand Down
11 changes: 6 additions & 5 deletions crates/test/tests/uring.rs
Original file line number Diff line number Diff line change
Expand Up @@ -34,21 +34,21 @@ trace_test!(fan_out, {
client.send_to(msg.as_bytes(), addr).await.unwrap();
assert_eq!(
msg,
sb.timeout(100, server1_rx.recv())
sb.timeout(RECV_TIMEOUT, server1_rx.recv())
.await
.0
.expect("should get a packet")
);
assert_eq!(
msg,
sb.timeout(100, server2_rx.recv())
sb.timeout(RECV_TIMEOUT, server2_rx.recv())
.await
.0
.expect("should get a packet")
);
assert_eq!(
msg,
sb.timeout(100, server3_rx.recv())
sb.timeout(RECV_TIMEOUT, server3_rx.recv())
.await
.0
.expect("should get a packet")
Expand Down Expand Up @@ -83,7 +83,7 @@ trace_test!(refreshes_recv_ring, {
client.send_to(&i.to_ne_bytes(), addr).await.unwrap();

let (len, _addr) = sb
.timeout(100, client.recv_from(&mut buf))
.timeout(RECV_TIMEOUT, client.recv_from(&mut buf))
.await
.0
.expect("should have received packet");
Expand All @@ -98,7 +98,7 @@ trace_test!(refreshes_recv_ring, {
.expect("failed to send debug request");
let mut buf = [0u8; 8];
let (len, _addr) = sb
.timeout(100, client.recv_from(&mut buf))
.timeout(RECV_TIMEOUT, client.recv_from(&mut buf))
.await
.0
.expect("should have debug response packet");
Expand Down Expand Up @@ -164,6 +164,7 @@ trace_test!(requeues_recv, {
sessions: quilkin::net::sessions::SessionPool::new(
vec![pending_sends.0.clone()],
config.dyn_cfg.cached_filter_chain().unwrap(),
config.dyn_cfg.clusters().cloned(),
usize::MAX,
backend,
4,
Expand Down
9 changes: 9 additions & 0 deletions crates/xds/src/locality.rs
Original file line number Diff line number Diff line change
Expand Up @@ -75,6 +75,15 @@ impl Locality {
self.buffer.as_str().to_owned()
}

/// The full colon separated locality, borrowed.
///
/// Unlike [`Self::colon_separated_string`] this doesn't allocate, which
/// matters where it's used as a metric label on the packet path.
#[inline]
pub fn as_str(&self) -> &str {
self.buffer.as_str()
}

#[inline]
pub fn region(&self) -> &str {
&self.buffer[..self.region]
Expand Down
146 changes: 130 additions & 16 deletions docs/src/deployment/metrics.md
Original file line number Diff line number Diff line change
Expand Up @@ -5,8 +5,9 @@ The following are metrics that Quilkin provides while in Proxy Mode.
# ASN Maxmind Information

If Quilkin is provided a a MaxmindDB GeoIP database, Quilkin will log the
following information in the `maxmind information` log, as well as populate
the following fields in any metrics with matching labels.
following information in the `maxmind information` log. Only `country_code`, on
`quilkin_session_active`, and `asn`, on the connection quality metrics below, are
exported as labels; the rest are too high in cardinality to be.

| Field | Description |
|-----------------|-----------------------------------------------|
Expand All @@ -31,12 +32,24 @@ The proxy exposes the following general metrics:
* `read`: when the proxy receives data from a downstream connection on the listening port.
* `write`: when the proxy sends data to a downstream connection via the listening port.

* `quilkin_packets_dropped_total{reason, asn, ip_prefix}` (Counter)

The total number of packets (not associated with any session) that were dropped by proxy.
Not that packets reflected by this metric were dropped at an earlier stage before they were associated with any session. For session based metrics, see the list of [session metrics][session-metrics] instead.
* `reason = NoConfiguredEndpoints`
* `NoConfiguredEndpoints`: No upstream endpoints were available to send the packet to. This can occur e.g if the endpoints cluster was scaled down to zero and the proxy is configured via a control plane.
* `quilkin_packets_dropped_total{event, reason, filter, destination}` (Counter)

The total number of packets that were dropped by the proxy.
* The `reason` label is a closed set, so a breakdown built on it survives a
filter being renamed or an `errno` producing different text:
* `no_endpoint_match`: no upstream endpoint was available, or none matched the packet's routing token.
* `filter_drop`: a filter chose to drop the packet, ie the chain worked as configured.
* `filter_error`: a filter failed to process the packet.
* `socket_error`: the socket refused the packet, or the packet couldn't be built for it.
* `queue_full`: a send or receive queue was full.
* `invalid_packet`: the packet couldn't be parsed as a datagram Quilkin handles. The specific parse failure is logged rather than labelled.
* `session_limit`: the session limit was reached, so no session could be established.
* `internal`: Quilkin lost track of state it needed to forward the packet.
* The `filter` label is the filter responsible, and is empty when the drop
wasn't a filter's decision.
* The `destination` label is described under
[`quilkin_bytes_total`](#general-metrics), and is empty for packets dropped
before they were routed.

* `quilkin_cluster_active`

Expand All @@ -47,27 +60,46 @@ The proxy exposes the following general metrics:
The number of currently active upstream endpoints. Note that this tracks the number of endpoints that the proxy
knows of rather than those that it is connected to (see [Session Metrics][session-metrics] instead for those)

* `quilkin_bytes_total{event, asn, ip_prefix}`
* `quilkin_bytes_total{event, destination}`

The total number of bytes sent or received
* The `event` label is either:
* `read`: when the proxy receives data from a downstream connection on the listening port.
* `write`: when the proxy sends data to a downstream connection via the listening port.
* The `destination` label is the cluster the packet was routed to, so traffic
can be attributed to a gameserver fleet rather than only counted in aggregate.
It carries the same values as `quilkin_active_endpoints`, so the two can be
joined.

The cluster comes from the routing decision itself, not from looking the
address up afterwards, so it is the cluster the packet actually went through
even when the same endpoint is configured in more than one. It is empty when
the destination didn't come from a cluster with a locality, which includes
destinations a filter decoded from the packet rather than selecting from the
cluster map. Note that `event=write` traffic carries the cluster of the
gameserver that sent it, not of the client it is going to.

* `quilkin_packets_total{event, asn, ip_prefix}`
* `quilkin_packets_total{event, destination}`

The total number of packets sent or recieved.
* The `event` label is either:
* `read`: when the proxy receives data from a downstream connection on the listening port.
* `write`: when the proxy sends data to a downstream connection via the listening port.
* The labels are the same as [`quilkin_bytes_total`](#general-metrics).

* `quilkin_packet_jitter{event}`

* `quilkin_packet_jitter{event, asn, ip_prefix}`
The time between packets arriving at an I/O loop (in nanoseconds). This covers
every session the loop serves, so it is a whole-proxy figure; for the
distribution across players use `quilkin_session_jitter_seconds`.

The time between receiving new packets (in nanoseconds).
The series stops being exported when no packet arrived during an aggregation
interval, rather than continuing to publish the last value the proxy saw.

* `quilkin_errors_total{event, asn, ip_prefix}`
* `quilkin_errors_total{event, reason}`

The total number of errors encountered while reading a packet from the upstream endpoint.
* The `reason` label is a closed set, replacing the previous free-text `display`
label. For I/O errors it names the `errno`, eg `invalid_input`,
`no_buffer_space` or `message_too_long`, rather than interpolating the
platform's error string.

* `quilkin_game_traffic_tasks`

Expand Down Expand Up @@ -97,6 +129,88 @@ The proxy exposes the following metrics around sessions:

The total number of sessions that have been created.

* `quilkin_sessions_closed_total{reason}` (Counter)

The total number of sessions that have ended, by why they ended. A fall in
session count otherwise looks the same whether players left or their endpoints
vanished.
* `idle_timeout`: no traffic within the session TTL. UDP has no close, so this
is what a player leaving normally looks like.
* `endpoint_gone`: the endpoint the session was routed to is no longer in the
cluster map. Only reported for destinations that were in the cluster map when
the session was created, so an endpoint configured by name is never
misattributed here.
* `shutdown`: the proxy is shutting down.

## Connection Quality Metrics

A player's jitter and their ISP are per-player facts, so neither can be a metric
label: concurrent sessions and the thousands of ASNs seen in a day of traffic both
blow up cardinality. Instead the proxy tracks quality per session internally and
periodically exports a projection whose series count is bounded by configuration
rather than by traffic. See the `--service.udp.metrics.*` options for the
tunables.

Note the division of labour. Whether an individual *session* is having a bad time
is a judgement the proxy makes, because it is the only thing holding that
session's packet timing. Whether an *ISP* is having a bad time is left to the
consumer of these metrics: a proxy carries on the order of a hundred concurrent
sessions spread over thousands of ASNs, so no single one sees enough of any ASN to
threshold on. The proxy exports the numerator and the denominator per ASN and
expects them to be summed across the fleet before any conclusion is drawn.

Interarrival jitter is measured against a monotonic clock, and gaps longer than a
second are treated as the stream restarting rather than as jitter, so a player
pausing doesn't register as a player with a bad connection.

Sessions the proxy saw no traffic for during an interval are counted, but
contribute no quality judgement.

* `quilkin_session_jitter_seconds` (Histogram)

The distribution of per-session interarrival jitter of downstream packets, as
the RFC 3550 estimator. A histogram rather than a mean, because a mean of 0.5 ms
is compatible with a few percent of players at 80 ms, and those are the players
worth knowing about — `histogram_quantile` over this answers "what does the 99th
percentile player at this proxy see".

Only jitter is exported per session. Loss and round-trip time on the client's
leg need either packet sequence numbers or a client-side timestamp, and the
proxy has neither.

* `quilkin_sessions_active_by_asn{asn}` (Gauge)

Active sessions by the client's ASN, for the largest
`--service.udp.metrics.top-asns` ASNs at this proxy, and the denominator for the
metric below.

Sessions belonging to any other ASN are counted under `asn="other"`, so the
breakdown always sums to the session total. Sessions whose client IP resolved to
no ASN are counted under `asn="unknown"`. Setting `--top-asns` to 0 disables
per-ASN reporting entirely.

* `quilkin_client_sessions_degraded{asn, reason}` (Gauge)

The number of sessions breaching a quality threshold, by the client's ASN. Only
ASNs currently breaching are exported, so a healthy proxy publishes nothing
here and the series count follows the number of ISPs actually in trouble.
* `reason = jitter`: sessions at or above `--service.udp.metrics.jitter-threshold-ms`.

This is a count, not a verdict. For the affected share of an ISP, divide by
`quilkin_sessions_active_by_asn` — summing both across proxies first, since one
proxy's view of a single ASN is too small a sample to threshold on:

```promql
sum by (asn) (quilkin_client_sessions_degraded{reason="jitter"})
/ sum by (asn) (quilkin_sessions_active_by_asn)
```

* `quilkin_client_sessions_degraded_total{reason}` (Counter)

The total number of times a session was observed breaching a threshold, for
alerting on a rate without depending on a share the proxy would have to pick a
cut-off for.

## Filter Metrics
Quilkin's filters use a set of generic metric keys, to make it easier to build visualisations that can account for
a dynamic set of filters that can be added, removed, or updated at runtime with different configurations. All of
Expand Down
Loading
Loading