Compare commits
5
Commits
bc40773964
...
17a88043ff
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
17a88043ff | ||
|
|
9c4964ae27 | ||
|
|
1e362fee3e | ||
|
|
f6b2d3ea9a | ||
|
|
e727d53b85 |
No files matched your search
@@ -61,6 +61,13 @@ tracing-subscriber = { version = "0.3.23", features = ["env-filter"] }
|
|||||||
url = { version = "2.5.8", features = ["serde"] }
|
url = { version = "2.5.8", features = ["serde"] }
|
||||||
zip = { version = "6", default-features = false, features = ["deflate"] }
|
zip = { version = "6", default-features = false, features = ["deflate"] }
|
||||||
|
|
||||||
|
[profile.release]
|
||||||
|
# Per-request cost in the web server is JSON decode and template render, both
|
||||||
|
# CPU-bound and spread across crates; whole-program LTO and one codegen unit
|
||||||
|
# buy a slice of that for a longer release build (tests use the dev profile).
|
||||||
|
lto = "fat"
|
||||||
|
codegen-units = 1
|
||||||
|
|
||||||
[dev-dependencies]
|
[dev-dependencies]
|
||||||
figment = { version = "0.10.19", features = ["test", "toml", "env"] }
|
figment = { version = "0.10.19", features = ["test", "toml", "env"] }
|
||||||
roxmltree = "0.21.1"
|
roxmltree = "0.21.1"
|
||||||
|
|||||||
@@ -468,31 +468,55 @@ internet (e-readers tap these links). The OPDS catalog rides on the same host.
|
|||||||
The login throttle's `SmartIpKeyExtractor` keys on the first entry of
|
The login throttle's `SmartIpKeyExtractor` keys on the first entry of
|
||||||
`X-Forwarded-For`, so nginx must *set* that header from the connection's peer
|
`X-Forwarded-For`, so nginx must *set* that header from the connection's peer
|
||||||
address rather than appending to whatever the client sent — otherwise anyone
|
address rather than appending to whatever the client sent — otherwise anyone
|
||||||
can mint a fresh throttle bucket per attempt by sending their own header. With
|
can mint a fresh throttle bucket per attempt by sending their own header. (The
|
||||||
Cloudflare in front, the connection's peer is Cloudflare, so `real_ip` has to
|
original config appended with `$proxy_add_x_forwarded_for`; that was the
|
||||||
rewrite `$remote_addr` from `CF-Connecting-IP` first (see the snippet below).
|
spoofable version.) The whole arrangement is only safe because the configured
|
||||||
The whole arrangement is only safe because the configured bind address is
|
bind address is loopback and nginx is the only process that can reach it.
|
||||||
loopback and nginx is the only process that can reach it.
|
|
||||||
|
|
||||||
The site is served through Cloudflare; `docs/runbooks/cdn-rollout.md` covers the
|
Nothing sits in front of nginx. The site ran behind the Cloudflare proxy for one
|
||||||
zone setup and cache rules. The nginx side of it is the `set_real_ip_from`
|
day (2026-09-04 to 2026-09-05) and was taken back out: measured from Boston, the
|
||||||
snippet and the `X-Forwarded-For` line below.
|
proxied signed-in page took 70 ms after the TLS handshake against 27 ms direct,
|
||||||
|
and at this traffic the edge cache is cold for anonymous readers anyway. The zone
|
||||||
|
still lives on Cloudflare's nameservers, so re-proxying is a one-click toggle;
|
||||||
|
`docs/runbooks/cdn-rollout.md` keeps the zone settings, cache rules and the
|
||||||
|
nginx additions (the `set_real_ip_from` snippet) that the proxied setup needs.
|
||||||
|
|
||||||
```nginx
|
```nginx
|
||||||
|
# One pool of idle connections to the app, so a request does not pay a fresh
|
||||||
|
# loopback TCP connect (and leave a TIME-WAIT socket) every time.
|
||||||
|
upstream daily_epub {
|
||||||
|
server 127.0.0.1:3499;
|
||||||
|
keepalive 8;
|
||||||
|
}
|
||||||
|
|
||||||
server {
|
server {
|
||||||
listen 443 ssl http2;
|
# HTTP/3 (nginx ≥ 1.25 built --with-http_v3_module; nginx.org packages
|
||||||
listen [::]:443 ssl http2;
|
# are). QUIC folds the TCP and TLS handshakes into one round trip. UDP 443
|
||||||
|
# must be open in the firewall. `reuseport` goes on exactly one quic
|
||||||
|
# listener per address; other server blocks on this host share it.
|
||||||
|
listen 443 quic reuseport;
|
||||||
|
listen [::]:443 quic reuseport;
|
||||||
|
listen 443 ssl;
|
||||||
|
listen [::]:443 ssl;
|
||||||
|
http2 on;
|
||||||
|
http3 on;
|
||||||
server_name daily.hallada.net;
|
server_name daily.hallada.net;
|
||||||
|
# Tell an HTTP/2 client that HTTP/3 is available on the same port; the
|
||||||
|
# browser switches on its next connection and remembers for a day.
|
||||||
|
add_header Alt-Svc 'h3=":443"; ma=86400' always;
|
||||||
|
|
||||||
ssl_certificate /etc/letsencrypt/live/daily.hallada.net/fullchain.pem;
|
ssl_certificate /etc/letsencrypt/live/daily.hallada.net/fullchain.pem;
|
||||||
ssl_certificate_key /etc/letsencrypt/live/daily.hallada.net/privkey.pem;
|
ssl_certificate_key /etc/letsencrypt/live/daily.hallada.net/privkey.pem;
|
||||||
ssl_trusted_certificate /etc/letsencrypt/live/daily.hallada.net/fullchain.pem;
|
ssl_trusted_certificate /etc/letsencrypt/live/daily.hallada.net/fullchain.pem;
|
||||||
|
|
||||||
include /etc/nginx/snippets/security-headers.conf;
|
# TLS 1.3 0-RTT: a returning browser sends its first request inside the
|
||||||
|
# handshake and saves a round trip. Safe only because the app answers 425
|
||||||
|
# to any non-GET that arrives as early data (the Early-Data header below).
|
||||||
|
# Applies to the TCP listener; over QUIC, nginx needs OpenSSL ≥ 3.5.1 for
|
||||||
|
# early data, and the nginx.org build links the distro's OpenSSL.
|
||||||
|
ssl_early_data on;
|
||||||
|
|
||||||
# Trust Cloudflare's edge for the client address: $remote_addr becomes the
|
include /etc/nginx/snippets/security-headers.conf;
|
||||||
# visitor, not the proxy. Must come before the X-Forwarded-For line below.
|
|
||||||
include /etc/nginx/snippets/cloudflare-real-ip.conf;
|
|
||||||
|
|
||||||
# The global `gzip on` only covers text/html. The stylesheet is ~12 KB of
|
# The global `gzip on` only covers text/html. The stylesheet is ~12 KB of
|
||||||
# plain CSS again — the Newsreader faces are separate .woff2 URLs, not
|
# plain CSS again — the Newsreader faces are separate .woff2 URLs, not
|
||||||
@@ -514,14 +538,21 @@ server {
|
|||||||
proxy_max_temp_file_size 0;
|
proxy_max_temp_file_size 0;
|
||||||
|
|
||||||
location / {
|
location / {
|
||||||
proxy_pass http://127.0.0.1:3499;
|
proxy_pass http://daily_epub;
|
||||||
|
# Keep-alive to the upstream needs HTTP/1.1 and an empty Connection
|
||||||
|
# header (the default would forward "close").
|
||||||
proxy_http_version 1.1;
|
proxy_http_version 1.1;
|
||||||
|
proxy_set_header Connection "";
|
||||||
proxy_set_header Host $host;
|
proxy_set_header Host $host;
|
||||||
# SET, not append. The login throttle keys on the first X-Forwarded-For
|
# SET, not append. The login throttle keys on the first X-Forwarded-For
|
||||||
# entry, so a client-supplied header must never survive into the app.
|
# entry, so a client-supplied header must never survive into the app.
|
||||||
# $remote_addr is the real visitor because of the real_ip snippet above.
|
# $remote_addr is the connection's peer, which is the visitor itself
|
||||||
|
# now that no proxy sits in front of nginx.
|
||||||
proxy_set_header X-Forwarded-For $remote_addr;
|
proxy_set_header X-Forwarded-For $remote_addr;
|
||||||
proxy_set_header X-Forwarded-Proto $scheme;
|
proxy_set_header X-Forwarded-Proto $scheme;
|
||||||
|
# "1" while the request arrived as 0-RTT data (RFC 8470); the app
|
||||||
|
# rejects non-safe methods sent that way.
|
||||||
|
proxy_set_header Early-Data $ssl_early_data;
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -533,6 +564,13 @@ server {
|
|||||||
}
|
}
|
||||||
```
|
```
|
||||||
|
|
||||||
|
**Only while the record is proxied through Cloudflare:** the connection's peer
|
||||||
|
is then Cloudflare, so `real_ip` has to rewrite `$remote_addr` from
|
||||||
|
`CF-Connecting-IP` before the `X-Forwarded-For` line runs. Add
|
||||||
|
`include /etc/nginx/snippets/cloudflare-real-ip.conf;` to the server block,
|
||||||
|
above `location /`. Leave it out when the record is DNS-only: it would be inert
|
||||||
|
for ordinary visitors, but anything connecting *from* a Cloudflare address (a
|
||||||
|
Worker, say) could then name its own address and dodge the login throttle.
|
||||||
`/etc/nginx/snippets/cloudflare-real-ip.conf` is one `set_real_ip_from` line per
|
`/etc/nginx/snippets/cloudflare-real-ip.conf` is one `set_real_ip_from` line per
|
||||||
published Cloudflare range plus the header to read. Cloudflare adds ranges from
|
published Cloudflare range plus the header to read. Cloudflare adds ranges from
|
||||||
time to time, so **regenerate it from the source rather than copying this list**
|
time to time, so **regenerate it from the source rather than copying this list**
|
||||||
@@ -574,15 +612,21 @@ real_ip_header CF-Connecting-IP;
|
|||||||
```
|
```
|
||||||
|
|
||||||
Enable the site (`ln -s` into `sites-enabled`, `nginx -t`, `systemctl reload
|
Enable the site (`ln -s` into `sites-enabled`, `nginx -t`, `systemctl reload
|
||||||
nginx`), then `curl https://daily.hallada.net/healthz` should return `ok`. No
|
nginx`), then `curl https://daily.hallada.net/healthz` should return `ok`.
|
||||||
|
Every response carries `Server-Timing: app;dur=<ms>`, the time the app spent
|
||||||
|
on the request; the browser's DevTools network panel shows it next to the
|
||||||
|
network timings, and `curl -sI` prints it, so origin work and the network can
|
||||||
|
be told apart without touching the logs. No
|
||||||
auth is needed at the proxy layer: rating links are self-authenticating (HMAC
|
auth is needed at the proxy layer: rating links are self-authenticating (HMAC
|
||||||
tokens) and the OPDS/file routes use the app-level Basic auth from
|
tokens) and the OPDS/file routes use the app-level Basic auth from
|
||||||
`server.basic_auth_user`/`_pass` if you set them.
|
`server.basic_auth_user`/`_pass` if you set them.
|
||||||
|
|
||||||
#### HTTP caching
|
#### HTTP caching
|
||||||
|
|
||||||
The origin says what may be cached and for how long; the CDN is configured to
|
The origin says what may be cached and for how long. No shared cache sits in
|
||||||
respect it (runbook §2). The whole matrix:
|
front of it today (the Cloudflare proxy was retired on 2026-09-05), but every
|
||||||
|
response still carries an explicit policy so the proxy can come back with a DNS
|
||||||
|
toggle and nothing else. The whole matrix:
|
||||||
|
|
||||||
| route | `Cache-Control` |
|
| route | `Cache-Control` |
|
||||||
|---|---|
|
|---|---|
|
||||||
|
|||||||
@@ -1,5 +1,19 @@
|
|||||||
# Runbook — putting daily.hallada.net behind Cloudflare
|
# Runbook — putting daily.hallada.net behind Cloudflare
|
||||||
|
|
||||||
|
> **Status (2026-09-05): retired.** The `daily` record is **DNS only** again, one
|
||||||
|
> day after this rollout. Measured from Boston with a session cookie (so the edge
|
||||||
|
> bypassed its cache, as it does for every signed-in request): 70 ms after the
|
||||||
|
> TLS handshake through the proxy against 27 ms straight to the origin. The edge
|
||||||
|
> adds a proxy hop and its own overhead on every uncached request, and at this
|
||||||
|
> traffic the cache is cold for anonymous readers too, so the proxy cost the one
|
||||||
|
> signed-in reader more than it gave anyone. The zone stays on Cloudflare's
|
||||||
|
> nameservers; flipping the record back to Proxied re-enables everything below.
|
||||||
|
> When you do, also put the `cloudflare-real-ip.conf` include back into the nginx
|
||||||
|
> server block (README, *Reverse proxy*) — it was removed with the proxy because
|
||||||
|
> a direct connection from a Cloudflare address could otherwise name its own
|
||||||
|
> client IP. The origin's `Cache-Control` matrix (§0) is still in force and is
|
||||||
|
> what makes the toggle safe in either direction.
|
||||||
|
|
||||||
**Written:** 2026-09-04 for the production host. Steps 1–3 happen in the Cloudflare
|
**Written:** 2026-09-04 for the production host. Steps 1–3 happen in the Cloudflare
|
||||||
and registrar dashboards; steps 4–5 are on the server as an operator with `sudo`.
|
and registrar dashboards; steps 4–5 are on the server as an operator with `sudo`.
|
||||||
The origin-side changes (the `Cache-Control` matrix below) ship in the same
|
The origin-side changes (the `Cache-Control` matrix below) ship in the same
|
||||||
|
|||||||
@@ -5,7 +5,7 @@
|
|||||||
//! (implementation notes §2). Pipeline writes are idempotent upserts so that
|
//! (implementation notes §2). Pipeline writes are idempotent upserts so that
|
||||||
//! `generate --date X` can be re-run safely; feedback events are append-only.
|
//! `generate --date X` can be re-run safely; feedback events are append-only.
|
||||||
|
|
||||||
use std::collections::BTreeMap;
|
use std::collections::{BTreeMap, HashMap};
|
||||||
use std::path::Path;
|
use std::path::Path;
|
||||||
use std::str::FromStr;
|
use std::str::FromStr;
|
||||||
use std::time::Duration;
|
use std::time::Duration;
|
||||||
@@ -333,6 +333,46 @@ impl Db {
|
|||||||
Ok(Some(article))
|
Ok(Some(article))
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// Every article in `ids`, keyed by id, with its social refs attached:
|
||||||
|
/// one statement for the articles and one for the social rows, however
|
||||||
|
/// many ids there are. Ids without a row are simply absent. This is what
|
||||||
|
/// a page that shows a whole issue should call; `get_article` in a loop
|
||||||
|
/// costs two statements per pick, and the per-statement overhead, not the
|
||||||
|
/// SQLite work, was most of that page's origin time.
|
||||||
|
pub async fn get_articles(&self, ids: &[ArticleId]) -> Result<HashMap<ArticleId, Article>> {
|
||||||
|
let mut articles = HashMap::with_capacity(ids.len());
|
||||||
|
// SQLite's default bound-parameter ceiling is 32 766; stay well under.
|
||||||
|
for chunk in ids.chunks(500) {
|
||||||
|
// Only the placeholder count is interpolated; every value is bound,
|
||||||
|
// which is what `AssertSqlSafe` asserts.
|
||||||
|
let placeholders = vec!["?"; chunk.len()].join(", ");
|
||||||
|
let mut query = sqlx::query(sqlx::AssertSqlSafe(format!(
|
||||||
|
"{ARTICLE_SELECT_BY_IDS} ({placeholders})"
|
||||||
|
)));
|
||||||
|
for id in chunk {
|
||||||
|
query = query.bind(*id);
|
||||||
|
}
|
||||||
|
for row in query.fetch_all(&self.pool).await? {
|
||||||
|
let article = article_from_row(&row)?;
|
||||||
|
articles.insert(article.id, article);
|
||||||
|
}
|
||||||
|
let mut query = sqlx::query(sqlx::AssertSqlSafe(format!(
|
||||||
|
"SELECT article_id, source, item_id, score, num_comments, item_url, fetched_at
|
||||||
|
FROM social WHERE article_id IN ({placeholders}) ORDER BY article_id, source"
|
||||||
|
)));
|
||||||
|
for id in chunk {
|
||||||
|
query = query.bind(*id);
|
||||||
|
}
|
||||||
|
for row in query.fetch_all(&self.pool).await? {
|
||||||
|
let social = social_from_row(&row)?;
|
||||||
|
if let Some(article) = articles.get_mut(&social.article_id) {
|
||||||
|
article.social.push(social);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
Ok(articles)
|
||||||
|
}
|
||||||
|
|
||||||
pub async fn article_id_for_url(&self, canonical_url: &str) -> Result<Option<ArticleId>> {
|
pub async fn article_id_for_url(&self, canonical_url: &str) -> Result<Option<ArticleId>> {
|
||||||
let row = sqlx::query("SELECT id FROM articles WHERE canonical_url = ?")
|
let row = sqlx::query("SELECT id FROM articles WHERE canonical_url = ?")
|
||||||
.bind(canonical_url)
|
.bind(canonical_url)
|
||||||
@@ -785,8 +825,13 @@ impl Db {
|
|||||||
}
|
}
|
||||||
|
|
||||||
/// Joined projection used by [`Db::get_article`]; keep in sync with [`article_from_row`].
|
/// Joined projection used by [`Db::get_article`]; keep in sync with [`article_from_row`].
|
||||||
const ARTICLE_SELECT_BY_ID: &str = "\
|
/// The article projection `article_from_row` reads, with the `WHERE` clause
|
||||||
SELECT a.id AS id, a.canonical_url AS canonical_url, a.title AS title,
|
/// supplied by the caller so the single-id and the `IN (...)` lookups cannot
|
||||||
|
/// drift apart.
|
||||||
|
macro_rules! article_select {
|
||||||
|
($where:literal) => {
|
||||||
|
concat!(
|
||||||
|
"SELECT a.id AS id, a.canonical_url AS canonical_url, a.title AS title,
|
||||||
a.best_entry_id AS best_entry_id, a.content_html AS content_html,
|
a.best_entry_id AS best_entry_id, a.content_html AS content_html,
|
||||||
a.word_count AS word_count, a.excerpt_only AS excerpt_only,
|
a.word_count AS word_count, a.excerpt_only AS excerpt_only,
|
||||||
a.image_count AS image_count, a.sources_json AS sources_json,
|
a.image_count AS image_count, a.sources_json AS sources_json,
|
||||||
@@ -795,7 +840,15 @@ SELECT a.id AS id, a.canonical_url AS canonical_url, a.title AS title,
|
|||||||
e.feed_title AS feed_title, e.category AS category,
|
e.feed_title AS feed_title, e.category AS category,
|
||||||
e.published_at AS published_at, e.comments_url AS comments_url
|
e.published_at AS published_at, e.comments_url AS comments_url
|
||||||
FROM articles a LEFT JOIN entries e ON e.id = a.best_entry_id
|
FROM articles a LEFT JOIN entries e ON e.id = a.best_entry_id
|
||||||
WHERE a.id = ?";
|
",
|
||||||
|
$where
|
||||||
|
)
|
||||||
|
};
|
||||||
|
}
|
||||||
|
|
||||||
|
const ARTICLE_SELECT_BY_ID: &str = article_select!("WHERE a.id = ?");
|
||||||
|
/// Followed at runtime by a parenthesised placeholder list.
|
||||||
|
const ARTICLE_SELECT_BY_IDS: &str = article_select!("WHERE a.id IN");
|
||||||
|
|
||||||
// ---------------------------------------------------------------------------
|
// ---------------------------------------------------------------------------
|
||||||
// Row mapping helpers (implementation notes §1: manual mapping, no macros)
|
// Row mapping helpers (implementation notes §1: manual mapping, no macros)
|
||||||
@@ -1112,6 +1165,11 @@ mod tests {
|
|||||||
assert_eq!(loaded.social.len(), 1);
|
assert_eq!(loaded.social.len(), 1);
|
||||||
assert_eq!(loaded.social[0].score, 342);
|
assert_eq!(loaded.social[0].score, 342);
|
||||||
assert_eq!(loaded.feed_title, "Hacker News");
|
assert_eq!(loaded.feed_title, "Hacker News");
|
||||||
|
// The batched lookup agrees with the single one and skips unknown ids.
|
||||||
|
let batch = db.get_articles(&[id, 9_999]).await.unwrap();
|
||||||
|
assert_eq!(batch.len(), 1);
|
||||||
|
assert_eq!(batch[&id], loaded);
|
||||||
|
assert!(db.get_articles(&[]).await.unwrap().is_empty());
|
||||||
assert_eq!(
|
assert_eq!(
|
||||||
db.article_id_for_url("https://example.com/1")
|
db.article_id_for_url("https://example.com/1")
|
||||||
.await
|
.await
|
||||||
|
|||||||
+18
-4
@@ -511,13 +511,27 @@ fn read_password_hidden(prompt: &str) -> Result<String> {
|
|||||||
}
|
}
|
||||||
|
|
||||||
/// `RUST_LOG`-driven tracing, defaulting to `info` (crate table "logging").
|
/// `RUST_LOG`-driven tracing, defaulting to `info` (crate table "logging").
|
||||||
|
///
|
||||||
|
/// Two layers over one registry rather than a bare `fmt()`: the statement
|
||||||
|
/// timings behind the `db` metric of `Server-Timing` ride in on sqlx's own
|
||||||
|
/// `DEBUG` events, and [`daily_epub::web::timing`] needs those enabled without
|
||||||
|
/// any of them reaching the log. Each layer carries its own filter, so the
|
||||||
|
/// `RUST_LOG` above still says exactly what gets printed.
|
||||||
fn init_tracing() {
|
fn init_tracing() {
|
||||||
|
use tracing_subscriber::Layer as _;
|
||||||
|
use tracing_subscriber::layer::SubscriberExt as _;
|
||||||
|
use tracing_subscriber::util::SubscriberInitExt as _;
|
||||||
|
|
||||||
let filter = EnvFilter::try_from_default_env()
|
let filter = EnvFilter::try_from_default_env()
|
||||||
.unwrap_or_else(|_| EnvFilter::new("info,sqlx=warn,hyper=warn,reqwest=warn"));
|
.unwrap_or_else(|_| EnvFilter::new("info,sqlx=warn,hyper=warn,reqwest=warn"));
|
||||||
tracing_subscriber::fmt()
|
tracing_subscriber::registry()
|
||||||
.with_env_filter(filter)
|
.with(
|
||||||
.with_target(false)
|
tracing_subscriber::fmt::layer()
|
||||||
.with_writer(std::io::stderr)
|
.with_target(false)
|
||||||
|
.with_writer(std::io::stderr)
|
||||||
|
.with_filter(filter),
|
||||||
|
)
|
||||||
|
.with(daily_epub::web::timing::sqlx_timing_layer())
|
||||||
.init();
|
.init();
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|||||||
@@ -177,12 +177,17 @@ pub fn router(state: AppState) -> Router {
|
|||||||
.layer(PropagateRequestIdLayer::x_request_id())
|
.layer(PropagateRequestIdLayer::x_request_id())
|
||||||
.layer(TraceLayer::new_for_http())
|
.layer(TraceLayer::new_for_http())
|
||||||
.layer(SetRequestIdLayer::x_request_id(MakeRequestUuid))
|
.layer(SetRequestIdLayer::x_request_id(MakeRequestUuid))
|
||||||
|
// Immediately inside the auth layer, so what is left outside it is the
|
||||||
|
// session load and save that `server_timing` reports as `sess`.
|
||||||
|
.layer(from_fn(crate::web::route_boundary))
|
||||||
.layer(auth_layer)
|
.layer(auth_layer)
|
||||||
.layer(from_fn_with_state(
|
.layer(from_fn_with_state(
|
||||||
state.clone(),
|
state.clone(),
|
||||||
crate::web::session::require_same_origin,
|
crate::web::session::require_same_origin,
|
||||||
))
|
))
|
||||||
|
.layer(from_fn(crate::web::reject_early_data))
|
||||||
.layer(from_fn(crate::web::security_headers))
|
.layer(from_fn(crate::web::security_headers))
|
||||||
|
.layer(from_fn(crate::web::server_timing))
|
||||||
.with_state(state)
|
.with_state(state)
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|||||||
@@ -649,8 +649,11 @@ async fn build_current_rows(
|
|||||||
let mut rows = Vec::new();
|
let mut rows = Vec::new();
|
||||||
let mut feeds: BTreeMap<FeedId, String> = BTreeMap::new();
|
let mut feeds: BTreeMap<FeedId, String> = BTreeMap::new();
|
||||||
let mut rank = 0usize;
|
let mut rank = 0usize;
|
||||||
|
let ids: Vec<ArticleId> = ratings.iter().map(|rating| rating.article_id).collect();
|
||||||
|
let articles = db.get_articles(&ids).await?;
|
||||||
|
let sources = event_sources_for(db, &ids).await?;
|
||||||
for rating in ratings {
|
for rating in ratings {
|
||||||
let article = db.get_article(rating.article_id).await?;
|
let article = articles.get(&rating.article_id);
|
||||||
let this_rank = if rating.label == "cleared" {
|
let this_rank = if rating.label == "cleared" {
|
||||||
None
|
None
|
||||||
} else {
|
} else {
|
||||||
@@ -659,22 +662,12 @@ async fn build_current_rows(
|
|||||||
Some(current)
|
Some(current)
|
||||||
};
|
};
|
||||||
let has_embedding = embedded.contains(&rating.article_id);
|
let has_embedding = embedded.contains(&rating.article_id);
|
||||||
let contribution = contribution(
|
let contribution = contribution(rating, article, has_embedding, this_rank, now, config);
|
||||||
rating,
|
let direct = article.map(signals::direct_feeds).unwrap_or_default();
|
||||||
article.as_ref(),
|
|
||||||
has_embedding,
|
|
||||||
this_rank,
|
|
||||||
now,
|
|
||||||
config,
|
|
||||||
);
|
|
||||||
let direct = article
|
|
||||||
.as_ref()
|
|
||||||
.map(signals::direct_feeds)
|
|
||||||
.unwrap_or_default();
|
|
||||||
for feed_id in &direct {
|
for feed_id in &direct {
|
||||||
feeds
|
feeds
|
||||||
.entry(*feed_id)
|
.entry(*feed_id)
|
||||||
.or_insert_with(|| feed_title_for(article.as_ref(), *feed_id));
|
.or_insert_with(|| feed_title_for(article, *feed_id));
|
||||||
}
|
}
|
||||||
|
|
||||||
let (badge, _) = widget_label(&rating.label);
|
let (badge, _) = widget_label(&rating.label);
|
||||||
@@ -691,7 +684,7 @@ async fn build_current_rows(
|
|||||||
{
|
{
|
||||||
continue;
|
continue;
|
||||||
}
|
}
|
||||||
let source = event_source_for(db, rating).await?;
|
let source = sources.get(&rating.article_id).cloned().unwrap_or_default();
|
||||||
if filters
|
if filters
|
||||||
.source
|
.source
|
||||||
.as_deref()
|
.as_deref()
|
||||||
@@ -754,21 +747,43 @@ async fn build_current_rows(
|
|||||||
Ok((rows, feeds))
|
Ok((rows, feeds))
|
||||||
}
|
}
|
||||||
|
|
||||||
/// The `source` of the event behind a current verdict (`RatedArticle` does not
|
/// The `source` of the event behind each current verdict (`RatedArticle` does
|
||||||
/// carry it).
|
/// not carry it), for every article of the page in one statement per chunk.
|
||||||
async fn event_source_for(db: &Db, rating: &RatedArticle) -> Result<String, WebError> {
|
/// An article with no explicit event is absent from the map; the caller shows
|
||||||
let row = sqlx::query(
|
/// an empty source for it.
|
||||||
"SELECT source FROM rating_events
|
async fn event_sources_for(
|
||||||
WHERE article_id = ? AND kind = 'explicit'
|
db: &Db,
|
||||||
ORDER BY event_at DESC, id DESC LIMIT 1",
|
ids: &[ArticleId],
|
||||||
)
|
) -> Result<HashMap<ArticleId, String>, WebError> {
|
||||||
.bind(rating.article_id)
|
let mut sources = HashMap::with_capacity(ids.len());
|
||||||
.fetch_optional(db.pool())
|
// SQLite's default bound-parameter ceiling is 32 766; stay well under.
|
||||||
.await
|
for chunk in ids.chunks(500) {
|
||||||
.map_err(DbError::from)?;
|
// Only the placeholder count is interpolated; every value is bound,
|
||||||
Ok(row
|
// which is what `AssertSqlSafe` asserts.
|
||||||
.map(|row| row.get::<String, _>("source"))
|
let placeholders = vec!["?"; chunk.len()].join(", ");
|
||||||
.unwrap_or_default())
|
let mut query = sqlx::query(sqlx::AssertSqlSafe(format!(
|
||||||
|
"SELECT article_id, source FROM (
|
||||||
|
SELECT article_id, source,
|
||||||
|
ROW_NUMBER() OVER (
|
||||||
|
PARTITION BY article_id
|
||||||
|
ORDER BY event_at DESC, id DESC
|
||||||
|
) AS event_rank
|
||||||
|
FROM rating_events
|
||||||
|
WHERE kind = 'explicit' AND article_id IN ({placeholders})
|
||||||
|
)
|
||||||
|
WHERE event_rank = 1"
|
||||||
|
)));
|
||||||
|
for id in chunk {
|
||||||
|
query = query.bind(*id);
|
||||||
|
}
|
||||||
|
for row in query.fetch_all(db.pool()).await.map_err(DbError::from)? {
|
||||||
|
sources.insert(
|
||||||
|
row.get::<ArticleId, _>("article_id"),
|
||||||
|
row.get::<String, _>("source"),
|
||||||
|
);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
Ok(sources)
|
||||||
}
|
}
|
||||||
|
|
||||||
async fn load_events(
|
async fn load_events(
|
||||||
@@ -1292,6 +1307,12 @@ mod tests {
|
|||||||
assert!(body.contains("Postgres failover story"));
|
assert!(body.contains("Postgres failover story"));
|
||||||
assert!(!body.contains("A listicle"));
|
assert!(!body.contains("A listicle"));
|
||||||
|
|
||||||
|
let by_source_current =
|
||||||
|
get(&app, "/dashboard/ratings?source=dashboard", Some(&cookie)).await;
|
||||||
|
let body = text(by_source_current).await;
|
||||||
|
assert!(body.contains("Postgres failover story"));
|
||||||
|
assert!(!body.contains("A listicle"));
|
||||||
|
|
||||||
let events = get(&app, "/dashboard/ratings?tab=events", Some(&cookie)).await;
|
let events = get(&app, "/dashboard/ratings?tab=events", Some(&cookie)).await;
|
||||||
assert_eq!(events.status(), StatusCode::OK);
|
assert_eq!(events.status(), StatusCode::OK);
|
||||||
let body = text(events).await;
|
let body = text(events).await;
|
||||||
@@ -1326,6 +1347,40 @@ mod tests {
|
|||||||
assert!(!body.contains("A listicle"));
|
assert!(!body.contains("A listicle"));
|
||||||
}
|
}
|
||||||
|
|
||||||
|
#[tokio::test]
|
||||||
|
async fn event_sources_take_the_newest_explicit_event() {
|
||||||
|
let dir = tempfile::tempdir().unwrap();
|
||||||
|
let db = Db::open_and_migrate(&dir.path().join("db.sqlite"))
|
||||||
|
.await
|
||||||
|
.unwrap();
|
||||||
|
let rated = seed_article(&db, 1, 1001, "Rated twice").await;
|
||||||
|
let unrated = seed_article(&db, 2, 1002, "Never rated").await;
|
||||||
|
seed_event(
|
||||||
|
&db,
|
||||||
|
rated,
|
||||||
|
"good",
|
||||||
|
0.35,
|
||||||
|
"cli",
|
||||||
|
None,
|
||||||
|
"2026-08-01T00:00:00Z",
|
||||||
|
)
|
||||||
|
.await;
|
||||||
|
seed_event(
|
||||||
|
&db,
|
||||||
|
rated,
|
||||||
|
"loved",
|
||||||
|
1.0,
|
||||||
|
"dashboard",
|
||||||
|
None,
|
||||||
|
"2026-08-20T00:00:00Z",
|
||||||
|
)
|
||||||
|
.await;
|
||||||
|
let sources = event_sources_for(&db, &[rated, unrated]).await.unwrap();
|
||||||
|
assert_eq!(sources.get(&rated).map(String::as_str), Some("dashboard"));
|
||||||
|
assert_eq!(sources.get(&unrated), None);
|
||||||
|
assert!(event_sources_for(&db, &[]).await.unwrap().is_empty());
|
||||||
|
}
|
||||||
|
|
||||||
#[tokio::test]
|
#[tokio::test]
|
||||||
async fn ratings_page_is_admin_only() {
|
async fn ratings_page_is_admin_only() {
|
||||||
let dir = tempfile::tempdir().unwrap();
|
let dir = tempfile::tempdir().unwrap();
|
||||||
|
|||||||
+13
-2
@@ -89,8 +89,17 @@ pub async fn load(
|
|||||||
};
|
};
|
||||||
let (mut issue, from_json) = if let Some(raw) = row.issue_json.as_deref() {
|
let (mut issue, from_json) = if let Some(raw) = row.issue_json.as_deref() {
|
||||||
let mut issue: Issue = serde_json::from_str(raw).context("decoding issues.issue_json")?;
|
let mut issue: Issue = serde_json::from_str(raw).context("decoding issues.issue_json")?;
|
||||||
|
// The snapshot's articles are refreshed from the live rows (social
|
||||||
|
// scores move after publish) in one batched lookup.
|
||||||
|
let ids: Vec<ArticleId> = issue
|
||||||
|
.lineup
|
||||||
|
.picks
|
||||||
|
.iter()
|
||||||
|
.map(|pick| pick.article.id)
|
||||||
|
.collect();
|
||||||
|
let mut articles = db.get_articles(&ids).await?;
|
||||||
for pick in &mut issue.lineup.picks {
|
for pick in &mut issue.lineup.picks {
|
||||||
if let Some(article) = db.get_article(pick.article.id).await? {
|
if let Some(article) = articles.remove(&pick.article.id) {
|
||||||
pick.article = article;
|
pick.article = article;
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@@ -103,12 +112,14 @@ pub async fn load(
|
|||||||
.bind(date.to_string())
|
.bind(date.to_string())
|
||||||
.fetch_all(db.pool())
|
.fetch_all(db.pool())
|
||||||
.await?;
|
.await?;
|
||||||
|
let ids: Vec<ArticleId> = rows.iter().map(|row| row.get("article_id")).collect();
|
||||||
|
let mut articles = db.get_articles(&ids).await?;
|
||||||
let mut picks = Vec::with_capacity(rows.len());
|
let mut picks = Vec::with_capacity(rows.len());
|
||||||
let mut seen_sections = Vec::new();
|
let mut seen_sections = Vec::new();
|
||||||
let mut summaries = BTreeMap::new();
|
let mut summaries = BTreeMap::new();
|
||||||
for pick_row in rows {
|
for pick_row in rows {
|
||||||
let article_id: i64 = pick_row.get("article_id");
|
let article_id: i64 = pick_row.get("article_id");
|
||||||
let Some(article) = db.get_article(article_id).await? else {
|
let Some(article) = articles.remove(&article_id) else {
|
||||||
continue;
|
continue;
|
||||||
};
|
};
|
||||||
let section: String = pick_row.get("section");
|
let section: String = pick_row.get("section");
|
||||||
|
|||||||
+292
-5
@@ -3,6 +3,7 @@ pub mod issue;
|
|||||||
pub mod public;
|
pub mod public;
|
||||||
pub mod rate;
|
pub mod rate;
|
||||||
pub mod session;
|
pub mod session;
|
||||||
|
pub mod timing;
|
||||||
pub mod users;
|
pub mod users;
|
||||||
|
|
||||||
use std::fmt;
|
use std::fmt;
|
||||||
@@ -191,7 +192,7 @@ impl WebState {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
#[derive(Debug, Clone, Serialize, Deserialize)]
|
#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
|
||||||
pub struct Flash {
|
pub struct Flash {
|
||||||
pub kind: String,
|
pub kind: String,
|
||||||
pub text: String,
|
pub text: String,
|
||||||
@@ -329,18 +330,104 @@ impl Page {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// Consume the one-shot flash message for this page, if there is one.
|
||||||
|
///
|
||||||
|
/// Reads before removing: `Session::remove` marks the session modified even
|
||||||
|
/// when the key is absent, and a modified session is written back to SQLite
|
||||||
|
/// at the end of the request, so the naive version cost every signed-in page
|
||||||
|
/// a write. Because a session is only saved when modified, its inactivity
|
||||||
|
/// expiry only slides when something changes it; [`touch_session`] keeps the
|
||||||
|
/// `server.session_days` window sliding by writing at most once a day.
|
||||||
pub async fn take_flash(session: &Session) -> Result<Option<Flash>, WebError> {
|
pub async fn take_flash(session: &Session) -> Result<Option<Flash>, WebError> {
|
||||||
session
|
let flash = session
|
||||||
.remove("flash")
|
.get::<Flash>(FLASH_KEY)
|
||||||
.await
|
.await
|
||||||
.map_err(|error| WebError::Internal(error.into()))
|
.map_err(session_error)?;
|
||||||
|
if flash.is_some() {
|
||||||
|
session
|
||||||
|
.remove_value(FLASH_KEY)
|
||||||
|
.await
|
||||||
|
.map_err(session_error)?;
|
||||||
|
return Ok(flash);
|
||||||
|
}
|
||||||
|
touch_session(session).await?;
|
||||||
|
Ok(None)
|
||||||
|
}
|
||||||
|
|
||||||
|
const FLASH_KEY: &str = "flash";
|
||||||
|
/// Session key holding the unix time of the last expiry-extending write.
|
||||||
|
const TOUCHED_KEY: &str = "touched_at";
|
||||||
|
/// How often a signed-in session is written just to slide its expiry.
|
||||||
|
const TOUCH_INTERVAL_SECS: i64 = 24 * 60 * 60;
|
||||||
|
|
||||||
|
/// Slide a signed-in session's inactivity expiry, at most once a day.
|
||||||
|
///
|
||||||
|
/// Only a session that already carries a login is touched. An anonymous
|
||||||
|
/// request must never create a session: the cookie would follow that reader
|
||||||
|
/// to every public page and take them out of the shared cache.
|
||||||
|
async fn touch_session(session: &Session) -> Result<(), WebError> {
|
||||||
|
let signed_in = session
|
||||||
|
.get_value(session::AUTH_DATA_KEY)
|
||||||
|
.await
|
||||||
|
.map_err(session_error)?
|
||||||
|
.is_some();
|
||||||
|
if !signed_in {
|
||||||
|
return Ok(());
|
||||||
|
}
|
||||||
|
let now = Timestamp::now().as_second();
|
||||||
|
let last = session
|
||||||
|
.get::<i64>(TOUCHED_KEY)
|
||||||
|
.await
|
||||||
|
.map_err(session_error)?;
|
||||||
|
if last.is_none_or(|last| now - last >= TOUCH_INTERVAL_SECS) {
|
||||||
|
session
|
||||||
|
.insert(TOUCHED_KEY, now)
|
||||||
|
.await
|
||||||
|
.map_err(session_error)?;
|
||||||
|
}
|
||||||
|
Ok(())
|
||||||
|
}
|
||||||
|
|
||||||
|
fn session_error(error: axum_login::tower_sessions::session::Error) -> WebError {
|
||||||
|
WebError::Internal(error.into())
|
||||||
|
}
|
||||||
|
|
||||||
|
/// `Server-Timing` on every response, so the browser's DevTools (or
|
||||||
|
/// `curl -sI`) can split origin work from the network and then split the
|
||||||
|
/// origin work up again. See [`timing`] for the metrics and how they are
|
||||||
|
/// collected.
|
||||||
|
pub use self::timing::{route_boundary, server_timing};
|
||||||
|
|
||||||
|
/// Refuse TLS 1.3 0-RTT data for anything but a safe method (RFC 8470 §5.2).
|
||||||
|
///
|
||||||
|
/// With `ssl_early_data on`, nginx forwards `Early-Data: 1` for a request the
|
||||||
|
/// browser sent inside the handshake. A replayed early-data `GET` is
|
||||||
|
/// harmless; a replayed `POST` (a rating, a login attempt, a job start) is
|
||||||
|
/// not, so those get 425 and the browser resends after the handshake.
|
||||||
|
pub async fn reject_early_data(request: Request, next: Next) -> Response {
|
||||||
|
let early = request
|
||||||
|
.headers()
|
||||||
|
.get("early-data")
|
||||||
|
.is_some_and(|value| value == "1");
|
||||||
|
if early && !request.method().is_safe() {
|
||||||
|
return (
|
||||||
|
StatusCode::TOO_EARLY,
|
||||||
|
[(header::CACHE_CONTROL, "no-store")],
|
||||||
|
"retry after the TLS handshake completes",
|
||||||
|
)
|
||||||
|
.into_response();
|
||||||
|
}
|
||||||
|
next.run(request).await
|
||||||
}
|
}
|
||||||
|
|
||||||
pub struct Html<T: Template>(pub T);
|
pub struct Html<T: Template>(pub T);
|
||||||
|
|
||||||
impl<T: Template> IntoResponse for Html<T> {
|
impl<T: Template> IntoResponse for Html<T> {
|
||||||
fn into_response(self) -> Response {
|
fn into_response(self) -> Response {
|
||||||
match self.0.render() {
|
let started = std::time::Instant::now();
|
||||||
|
let rendered = self.0.render();
|
||||||
|
timing::record_render(started.elapsed());
|
||||||
|
match rendered {
|
||||||
Ok(body) => (
|
Ok(body) => (
|
||||||
StatusCode::OK,
|
StatusCode::OK,
|
||||||
[(header::CONTENT_TYPE, "text/html; charset=utf-8")],
|
[(header::CONTENT_TYPE, "text/html; charset=utf-8")],
|
||||||
@@ -701,6 +788,20 @@ mod tests {
|
|||||||
use crate::db::Db;
|
use crate::db::Db;
|
||||||
use crate::server::{AppState, router};
|
use crate::server::{AppState, router};
|
||||||
|
|
||||||
|
/// The `db` metric only fills in when [`timing::sqlx_timing_layer`] is
|
||||||
|
/// installed, and it has to be installed *globally*: sqlx times statements
|
||||||
|
/// on a worker thread, which sees no thread-local default. Global means
|
||||||
|
/// once per test binary, hence the `Once`; nothing is written anywhere, so
|
||||||
|
/// the tests that do not care never notice it.
|
||||||
|
fn install_timing_layer() {
|
||||||
|
use tracing_subscriber::layer::SubscriberExt as _;
|
||||||
|
static INSTALLED: std::sync::Once = std::sync::Once::new();
|
||||||
|
INSTALLED.call_once(|| {
|
||||||
|
let subscriber = tracing_subscriber::registry().with(timing::sqlx_timing_layer());
|
||||||
|
let _ = tracing::subscriber::set_global_default(subscriber);
|
||||||
|
});
|
||||||
|
}
|
||||||
|
|
||||||
async fn test_state(config: Config) -> (tempfile::TempDir, AppState) {
|
async fn test_state(config: Config) -> (tempfile::TempDir, AppState) {
|
||||||
let dir = tempfile::tempdir().unwrap();
|
let dir = tempfile::tempdir().unwrap();
|
||||||
let db = Db::open_and_migrate(&dir.path().join("db.sqlite"))
|
let db = Db::open_and_migrate(&dir.path().join("db.sqlite"))
|
||||||
@@ -753,6 +854,192 @@ mod tests {
|
|||||||
.unwrap()
|
.unwrap()
|
||||||
}
|
}
|
||||||
|
|
||||||
|
#[tokio::test]
|
||||||
|
async fn take_flash_reads_without_dirtying_an_empty_session() {
|
||||||
|
let (_dir, state) = test_state(Config::default()).await;
|
||||||
|
let store = std::sync::Arc::new(session::SqliteSessionStore::new(state.db.pool().clone()));
|
||||||
|
let session = Session::new(None, store, None);
|
||||||
|
assert_eq!(take_flash(&session).await.unwrap(), None);
|
||||||
|
assert!(!session.is_modified());
|
||||||
|
assert!(session.is_empty().await);
|
||||||
|
|
||||||
|
let flash = Flash {
|
||||||
|
kind: "ok".into(),
|
||||||
|
text: "saved".into(),
|
||||||
|
};
|
||||||
|
session.insert(FLASH_KEY, &flash).await.unwrap();
|
||||||
|
assert_eq!(take_flash(&session).await.unwrap(), Some(flash));
|
||||||
|
assert_eq!(take_flash(&session).await.unwrap(), None);
|
||||||
|
}
|
||||||
|
|
||||||
|
#[tokio::test]
|
||||||
|
async fn signed_in_pages_touch_the_session_once_a_day_not_every_request() {
|
||||||
|
let mut config = Config::default();
|
||||||
|
config.server.public_url = "https://daily.example".into();
|
||||||
|
let (_dir, state) = test_state(config).await;
|
||||||
|
// Only the dashboard and the signed-in issue pages consume flashes, so
|
||||||
|
// an admin exercises the path without an issue in the database.
|
||||||
|
users::add(&state.db, "admin", "correct horse battery", true)
|
||||||
|
.await
|
||||||
|
.unwrap();
|
||||||
|
let app = router(state.clone());
|
||||||
|
let cookie = login_cookie(&app, "admin", "correct horse battery").await;
|
||||||
|
let stamp = || async {
|
||||||
|
sqlx::query_scalar::<_, String>("SELECT updated_at || ' ' || data FROM sessions")
|
||||||
|
.fetch_one(state.db.pool())
|
||||||
|
.await
|
||||||
|
.unwrap()
|
||||||
|
};
|
||||||
|
let get = |uri: &str| {
|
||||||
|
Request::builder()
|
||||||
|
.uri(uri)
|
||||||
|
.header(header::COOKIE, cookie.clone())
|
||||||
|
.body(Body::empty())
|
||||||
|
.unwrap()
|
||||||
|
};
|
||||||
|
// The first page after login writes the daily touch stamp…
|
||||||
|
let response = app
|
||||||
|
.clone()
|
||||||
|
.oneshot(get("/dashboard/articles"))
|
||||||
|
.await
|
||||||
|
.unwrap();
|
||||||
|
assert_eq!(response.status(), StatusCode::OK);
|
||||||
|
let first = stamp().await;
|
||||||
|
assert!(first.contains(TOUCHED_KEY), "{first}");
|
||||||
|
// …and the pages after it leave the row alone.
|
||||||
|
for uri in [
|
||||||
|
"/dashboard/articles",
|
||||||
|
"/dashboard/ratings",
|
||||||
|
"/dashboard/stats",
|
||||||
|
"/",
|
||||||
|
"/account",
|
||||||
|
] {
|
||||||
|
let response = app.clone().oneshot(get(uri)).await.unwrap();
|
||||||
|
assert_eq!(response.status(), StatusCode::OK, "{uri}");
|
||||||
|
}
|
||||||
|
assert_eq!(stamp().await, first);
|
||||||
|
}
|
||||||
|
|
||||||
|
#[tokio::test]
|
||||||
|
async fn server_timing_header_and_early_data_guard() {
|
||||||
|
let (_dir, state) = test_state(Config::default()).await;
|
||||||
|
let app = router(state);
|
||||||
|
let response = app
|
||||||
|
.clone()
|
||||||
|
.oneshot(
|
||||||
|
Request::builder()
|
||||||
|
.uri("/healthz")
|
||||||
|
.body(Body::empty())
|
||||||
|
.unwrap(),
|
||||||
|
)
|
||||||
|
.await
|
||||||
|
.unwrap();
|
||||||
|
let timing = response
|
||||||
|
.headers()
|
||||||
|
.get("server-timing")
|
||||||
|
.unwrap()
|
||||||
|
.to_str()
|
||||||
|
.unwrap();
|
||||||
|
assert!(timing.starts_with("app;dur="), "{timing}");
|
||||||
|
// `/healthz` is routed but touches neither SQLite nor a template.
|
||||||
|
assert!(timing.contains("sess;dur="), "{timing}");
|
||||||
|
assert!(!timing.contains("db;dur="), "{timing}");
|
||||||
|
assert!(!timing.contains("tpl;dur="), "{timing}");
|
||||||
|
|
||||||
|
// A safe method may arrive as 0-RTT data; a POST may not.
|
||||||
|
let response = app
|
||||||
|
.clone()
|
||||||
|
.oneshot(
|
||||||
|
Request::builder()
|
||||||
|
.uri("/healthz")
|
||||||
|
.header("early-data", "1")
|
||||||
|
.body(Body::empty())
|
||||||
|
.unwrap(),
|
||||||
|
)
|
||||||
|
.await
|
||||||
|
.unwrap();
|
||||||
|
assert_eq!(response.status(), StatusCode::OK);
|
||||||
|
let mut request = post("/login", "username=a&password=b", "192.0.2.1");
|
||||||
|
request
|
||||||
|
.headers_mut()
|
||||||
|
.insert("early-data", HeaderValue::from_static("1"));
|
||||||
|
let response = app.oneshot(request).await.unwrap();
|
||||||
|
assert_eq!(response.status(), StatusCode::TOO_EARLY);
|
||||||
|
}
|
||||||
|
|
||||||
|
/// The `db` metric crosses a thread boundary to get here: sqlx runs the
|
||||||
|
/// statement on the connection's worker thread and only reports the
|
||||||
|
/// elapsed time there, inside the span this request handed it. This is the
|
||||||
|
/// test that the hand-off actually holds together.
|
||||||
|
#[tokio::test]
|
||||||
|
async fn server_timing_breaks_the_request_into_session_db_and_template() {
|
||||||
|
install_timing_layer();
|
||||||
|
let (_dir, state) = test_state(Config::default()).await;
|
||||||
|
users::add(&state.db, "admin", "correct horse battery", true)
|
||||||
|
.await
|
||||||
|
.unwrap();
|
||||||
|
let app = router(state);
|
||||||
|
let cookie = login_cookie(&app, "admin", "correct horse battery").await;
|
||||||
|
let response = app
|
||||||
|
.oneshot(
|
||||||
|
Request::builder()
|
||||||
|
.uri("/dashboard/articles")
|
||||||
|
.header(header::COOKIE, cookie)
|
||||||
|
.body(Body::empty())
|
||||||
|
.unwrap(),
|
||||||
|
)
|
||||||
|
.await
|
||||||
|
.unwrap();
|
||||||
|
assert_eq!(response.status(), StatusCode::OK);
|
||||||
|
let timing = response
|
||||||
|
.headers()
|
||||||
|
.get("server-timing")
|
||||||
|
.unwrap()
|
||||||
|
.to_str()
|
||||||
|
.unwrap()
|
||||||
|
.to_string();
|
||||||
|
|
||||||
|
// Every metric is present, and each is a number the spec allows.
|
||||||
|
assert!(timing.starts_with("app;dur="), "{timing}");
|
||||||
|
let mut durations = std::collections::HashMap::new();
|
||||||
|
for metric in timing.split(", ") {
|
||||||
|
let (name, rest) = metric.split_once(";dur=").expect(&timing);
|
||||||
|
let number = rest.split(';').next().unwrap();
|
||||||
|
durations.insert(name, number.parse::<f64>().expect(&timing));
|
||||||
|
}
|
||||||
|
for name in ["app", "sess", "db", "tpl"] {
|
||||||
|
assert!(durations.contains_key(name), "{name} missing from {timing}");
|
||||||
|
}
|
||||||
|
|
||||||
|
// A dashboard page loads the session and renders, so each of those is
|
||||||
|
// inside the whole rather than beside it. `db` is left out: it is a
|
||||||
|
// sum of statement times, which a handler running queries concurrently
|
||||||
|
// could legitimately push past the wall clock.
|
||||||
|
let app_dur = durations["app"];
|
||||||
|
for name in ["sess", "tpl"] {
|
||||||
|
assert!(durations[name] <= app_dur, "{name} exceeds app in {timing}");
|
||||||
|
}
|
||||||
|
// `sess` is the session load and save; `db` includes those statements
|
||||||
|
// and the page's own, so neither is a subset of the other, but both
|
||||||
|
// had to have measured something.
|
||||||
|
assert!(durations["db"] > 0.0, "{timing}");
|
||||||
|
|
||||||
|
// The statement count rides along in `desc`, which is where DevTools
|
||||||
|
// shows it. A dashboard page runs several: session, user, articles.
|
||||||
|
let db = timing
|
||||||
|
.split(", ")
|
||||||
|
.find(|metric| metric.starts_with("db;"))
|
||||||
|
.expect(&timing);
|
||||||
|
let count: u32 = db
|
||||||
|
.split("desc=\"")
|
||||||
|
.nth(1)
|
||||||
|
.and_then(|desc| desc.split_whitespace().next())
|
||||||
|
.and_then(|count| count.parse().ok())
|
||||||
|
.unwrap_or_else(|| panic!("no statement count in {db}"));
|
||||||
|
assert!(count > 1, "{db}");
|
||||||
|
assert!(db.ends_with(" queries\""), "{db}");
|
||||||
|
}
|
||||||
|
|
||||||
#[tokio::test]
|
#[tokio::test]
|
||||||
async fn login_cookie_account_logout_and_anonymous_pages() {
|
async fn login_cookie_account_logout_and_anonymous_pages() {
|
||||||
let mut config = Config::default();
|
let mut config = Config::default();
|
||||||
|
|||||||
+6
-3
@@ -308,9 +308,12 @@ pub async fn feed(State(state): State<AppState>) -> Result<Response, WebError> {
|
|||||||
};
|
};
|
||||||
updated = updated.max(view.issue.meta.generated_at);
|
updated = updated.max(view.issue.meta.generated_at);
|
||||||
let issue = PublicIssue::from(&view.issue);
|
let issue = PublicIssue::from(&view.issue);
|
||||||
let content = FeedEntryTemplate { issue: &issue }
|
// Counted towards `tpl` by hand: the feed renders per entry rather
|
||||||
.render()
|
// than through `Html`, which is where every HTML page is measured.
|
||||||
.map_err(|error| WebError::Internal(error.into()))?;
|
let started = std::time::Instant::now();
|
||||||
|
let content = FeedEntryTemplate { issue: &issue }.render();
|
||||||
|
crate::web::timing::record_render(started.elapsed());
|
||||||
|
let content = content.map_err(|error| WebError::Internal(error.into()))?;
|
||||||
let href = format!(
|
let href = format!(
|
||||||
"{}/issues/{}",
|
"{}/issues/{}",
|
||||||
config.server.public_url.trim_end_matches('/'),
|
config.server.public_url.trim_end_matches('/'),
|
||||||
|
|||||||
@@ -20,6 +20,11 @@ use crate::server::AppState;
|
|||||||
use crate::web::users::{self, Role, User};
|
use crate::web::users::{self, Role, User};
|
||||||
use crate::web::{Html, Page, WebError};
|
use crate::web::{Html, Page, WebError};
|
||||||
|
|
||||||
|
/// The session key axum-login keeps the signed-in user under (its default
|
||||||
|
/// `data_key`); the presence of this key is what "signed in" means to
|
||||||
|
/// [`crate::web::take_flash`]'s once-a-day session touch.
|
||||||
|
pub const AUTH_DATA_KEY: &str = "axum-login.data";
|
||||||
|
|
||||||
const DUMMY_HASH: &str = "$argon2i$v=19$m=65536,t=1,p=1$c29tZXNhbHQAAAAAAAAAAA$+r0d29hqEB0yasKr55ZgICsQGSkl0v0kgwhd+U3wyRo";
|
const DUMMY_HASH: &str = "$argon2i$v=19$m=65536,t=1,p=1$c29tZXNhbHQAAAAAAAAAAA$+r0d29hqEB0yasKr55ZgICsQGSkl0v0kgwhd+U3wyRo";
|
||||||
|
|
||||||
#[derive(Clone, Debug)]
|
#[derive(Clone, Debug)]
|
||||||
|
|||||||
@@ -0,0 +1,343 @@
|
|||||||
|
//! Per-request `Server-Timing` metrics (§3.12).
|
||||||
|
//!
|
||||||
|
//! The header splits one request into the parts worth telling apart:
|
||||||
|
//!
|
||||||
|
//! | metric | what it covers |
|
||||||
|
//! |---|---|
|
||||||
|
//! | `app` | everything this process did, the outermost middleware inwards |
|
||||||
|
//! | `sess` | the session/auth layers: the cookie's `SELECT` on the way in, the save on the way out |
|
||||||
|
//! | `db` | SQLite statement time, with the statement count in `desc` |
|
||||||
|
//! | `tpl` | askama rendering |
|
||||||
|
//!
|
||||||
|
//! They overlap rather than partition: `sess` and `db` are both inside `app`,
|
||||||
|
//! and they share the session's own statements. Handler time is `app` − `sess`,
|
||||||
|
//! and `sess` − (the session's share of `db`) is what the auth layers cost
|
||||||
|
//! beyond SQLite — on a warm `/account` that gap has been most of the request,
|
||||||
|
//! which is the sort of thing these metrics exist to make visible.
|
||||||
|
//!
|
||||||
|
//! `db` is collected the only way that works for SQLite: sqlx runs statements
|
||||||
|
//! on a per-connection worker *thread*, so a task-local set by the middleware
|
||||||
|
//! is invisible there. What does cross over is the caller's [`tracing::Span`] —
|
||||||
|
//! `sqlx-sqlite` sends it alongside every command and enters it while the
|
||||||
|
//! statement runs — so the `sqlx::query` event it emits on finishing lands
|
||||||
|
//! inside this request's span. [`SqlxTimingLayer`] picks the elapsed time off
|
||||||
|
//! that event and adds it to the metrics hanging in the span's extensions.
|
||||||
|
//! Metrics recorded on the request task itself (`tpl`, the `sess` boundary)
|
||||||
|
//! take the shorter path through the task-local.
|
||||||
|
//!
|
||||||
|
//! Nothing here is load-bearing: without [`SqlxTimingLayer`] installed the `db`
|
||||||
|
//! metric is simply absent, and without a subscriber at all the span costs
|
||||||
|
//! nothing and `app` still reports.
|
||||||
|
//!
|
||||||
|
//! What installing it does cost is process-wide: the filter's `DEBUG` hint
|
||||||
|
//! lifts the global maximum level from `INFO`, so every `DEBUG` span in any
|
||||||
|
//! dependency (tower-http's per-request span, axum-login's instrumented user
|
||||||
|
//! loads) is now materialised in the registry, and sqlx builds a summary
|
||||||
|
//! string for each statement it reports. Microseconds per request, against
|
||||||
|
//! an origin measured in milliseconds; noted so it is not mistaken for free.
|
||||||
|
|
||||||
|
use std::fmt::Write as _;
|
||||||
|
use std::sync::Arc;
|
||||||
|
use std::sync::atomic::{AtomicU32, AtomicU64, Ordering};
|
||||||
|
use std::time::{Duration, Instant};
|
||||||
|
|
||||||
|
use axum::extract::Request;
|
||||||
|
use axum::http::{HeaderValue, header};
|
||||||
|
use axum::middleware::Next;
|
||||||
|
use axum::response::Response;
|
||||||
|
use tracing::Instrument as _;
|
||||||
|
use tracing_subscriber::layer::{Context, Layer};
|
||||||
|
use tracing_subscriber::registry::LookupSpan;
|
||||||
|
|
||||||
|
/// Target of the per-request span. It is how [`SqlxTimingLayer`] recognises
|
||||||
|
/// the one span to hang metrics on, and being off the crate's module path also
|
||||||
|
/// keeps the span out of the log under the default `RUST_LOG` (`info`).
|
||||||
|
const REQUEST_TARGET: &str = "daily_epub::request";
|
||||||
|
|
||||||
|
/// The target sqlx logs every finished statement to.
|
||||||
|
const SQLX_TARGET: &str = "sqlx::query";
|
||||||
|
|
||||||
|
/// Sentinel for a boundary mark that was never reached.
|
||||||
|
const UNSET: u64 = u64::MAX;
|
||||||
|
|
||||||
|
tokio::task_local! {
|
||||||
|
/// The metrics for the request running on this task. Set by
|
||||||
|
/// [`server_timing`], so it covers everything inside that middleware.
|
||||||
|
static CURRENT: Arc<RequestMetrics>;
|
||||||
|
}
|
||||||
|
|
||||||
|
/// One request's accumulated timings.
|
||||||
|
///
|
||||||
|
/// Written from two places at once — the request task and a sqlx worker
|
||||||
|
/// thread — so every counter is atomic. `Relaxed` is enough: nothing here
|
||||||
|
/// orders anything else, and the totals are only read after the response is
|
||||||
|
/// complete and both writers are done.
|
||||||
|
#[derive(Debug)]
|
||||||
|
pub struct RequestMetrics {
|
||||||
|
started: Instant,
|
||||||
|
db_nanos: AtomicU64,
|
||||||
|
db_statements: AtomicU32,
|
||||||
|
tpl_nanos: AtomicU64,
|
||||||
|
tpl_renders: AtomicU32,
|
||||||
|
/// Nanoseconds after `started` at which the routed part of the stack was
|
||||||
|
/// entered and left; [`UNSET`] until [`route_boundary`] marks them.
|
||||||
|
route_entered: AtomicU64,
|
||||||
|
route_left: AtomicU64,
|
||||||
|
}
|
||||||
|
|
||||||
|
impl RequestMetrics {
|
||||||
|
fn new() -> Self {
|
||||||
|
Self {
|
||||||
|
started: Instant::now(),
|
||||||
|
db_nanos: AtomicU64::new(0),
|
||||||
|
db_statements: AtomicU32::new(0),
|
||||||
|
tpl_nanos: AtomicU64::new(0),
|
||||||
|
tpl_renders: AtomicU32::new(0),
|
||||||
|
route_entered: AtomicU64::new(UNSET),
|
||||||
|
route_left: AtomicU64::new(UNSET),
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
fn add_db(&self, elapsed: Duration) {
|
||||||
|
self.db_nanos.fetch_add(nanos(elapsed), Ordering::Relaxed);
|
||||||
|
self.db_statements.fetch_add(1, Ordering::Relaxed);
|
||||||
|
}
|
||||||
|
|
||||||
|
fn add_render(&self, elapsed: Duration) {
|
||||||
|
self.tpl_nanos.fetch_add(nanos(elapsed), Ordering::Relaxed);
|
||||||
|
self.tpl_renders.fetch_add(1, Ordering::Relaxed);
|
||||||
|
}
|
||||||
|
|
||||||
|
/// The `sess` metric: everything outside the routed stack, which is the
|
||||||
|
/// session load on the way in plus the session save on the way out. Absent
|
||||||
|
/// until both boundaries have been marked — a request rejected before it
|
||||||
|
/// reaches the router (a 425, a cross-origin 403) never gets there.
|
||||||
|
fn session_nanos(&self) -> Option<u64> {
|
||||||
|
let entered = self.route_entered.load(Ordering::Relaxed);
|
||||||
|
let left = self.route_left.load(Ordering::Relaxed);
|
||||||
|
if entered == UNSET || left == UNSET {
|
||||||
|
return None;
|
||||||
|
}
|
||||||
|
Some(entered + nanos(self.started.elapsed()).saturating_sub(left))
|
||||||
|
}
|
||||||
|
|
||||||
|
/// The header value: `app` always, the rest only where they were measured.
|
||||||
|
fn header(&self) -> String {
|
||||||
|
let mut value = String::with_capacity(72);
|
||||||
|
write!(
|
||||||
|
value,
|
||||||
|
"app;dur={:.2}",
|
||||||
|
millis(nanos(self.started.elapsed()))
|
||||||
|
)
|
||||||
|
.expect("writing to a String cannot fail");
|
||||||
|
if let Some(session) = self.session_nanos() {
|
||||||
|
write!(value, ", sess;dur={:.2}", millis(session))
|
||||||
|
.expect("writing to a String cannot fail");
|
||||||
|
}
|
||||||
|
let statements = self.db_statements.load(Ordering::Relaxed);
|
||||||
|
if statements > 0 {
|
||||||
|
let unit = if statements == 1 { "query" } else { "queries" };
|
||||||
|
write!(
|
||||||
|
value,
|
||||||
|
", db;dur={:.2};desc=\"{statements} {unit}\"",
|
||||||
|
millis(self.db_nanos.load(Ordering::Relaxed))
|
||||||
|
)
|
||||||
|
.expect("writing to a String cannot fail");
|
||||||
|
}
|
||||||
|
if self.tpl_renders.load(Ordering::Relaxed) > 0 {
|
||||||
|
write!(
|
||||||
|
value,
|
||||||
|
", tpl;dur={:.2}",
|
||||||
|
millis(self.tpl_nanos.load(Ordering::Relaxed))
|
||||||
|
)
|
||||||
|
.expect("writing to a String cannot fail");
|
||||||
|
}
|
||||||
|
value
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Saturating, because a `Duration` holds more nanoseconds than a `u64` can.
|
||||||
|
fn nanos(elapsed: Duration) -> u64 {
|
||||||
|
u64::try_from(elapsed.as_nanos()).unwrap_or(u64::MAX)
|
||||||
|
}
|
||||||
|
|
||||||
|
fn millis(nanos: u64) -> f64 {
|
||||||
|
nanos as f64 / 1_000_000.0
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Run `f` against the metrics of the request on this task, if there is one.
|
||||||
|
fn with_metrics(f: impl FnOnce(&RequestMetrics)) {
|
||||||
|
let _ = CURRENT.try_with(|metrics| f(metrics));
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Add one template render to the `tpl` metric. Called by
|
||||||
|
/// [`crate::web::Html`], which is how every HTML page is rendered.
|
||||||
|
pub fn record_render(elapsed: Duration) {
|
||||||
|
with_metrics(|metrics| metrics.add_render(elapsed));
|
||||||
|
}
|
||||||
|
|
||||||
|
/// `Server-Timing` on every response: see the module docs for the metrics.
|
||||||
|
///
|
||||||
|
/// Outermost layer, so `app` covers the session load, auth and rendering. The
|
||||||
|
/// per-request span is opened *inside* the task-local scope so that
|
||||||
|
/// [`SqlxTimingLayer::on_new_span`] can hang these same metrics on it.
|
||||||
|
pub async fn server_timing(request: Request, next: Next) -> Response {
|
||||||
|
let metrics = Arc::new(RequestMetrics::new());
|
||||||
|
let mut response = CURRENT
|
||||||
|
.scope(metrics.clone(), async move {
|
||||||
|
let span = tracing::debug_span!(target: REQUEST_TARGET, "http_request");
|
||||||
|
next.run(request).instrument(span).await
|
||||||
|
})
|
||||||
|
.await;
|
||||||
|
if let Ok(value) = HeaderValue::from_str(&metrics.header()) {
|
||||||
|
response
|
||||||
|
.headers_mut()
|
||||||
|
.insert(header::HeaderName::from_static("server-timing"), value);
|
||||||
|
}
|
||||||
|
response
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Marks where the routed part of the stack begins, so the time spent in the
|
||||||
|
/// session and auth layers wrapped around it can be reported as `sess`.
|
||||||
|
/// Belongs immediately inside the auth layer; anywhere else and the metric
|
||||||
|
/// quietly measures something other than its name.
|
||||||
|
pub async fn route_boundary(request: Request, next: Next) -> Response {
|
||||||
|
with_metrics(|metrics| {
|
||||||
|
metrics
|
||||||
|
.route_entered
|
||||||
|
.store(nanos(metrics.started.elapsed()), Ordering::Relaxed);
|
||||||
|
});
|
||||||
|
let response = next.run(request).await;
|
||||||
|
with_metrics(|metrics| {
|
||||||
|
metrics
|
||||||
|
.route_left
|
||||||
|
.store(nanos(metrics.started.elapsed()), Ordering::Relaxed);
|
||||||
|
});
|
||||||
|
response
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Adds every `sqlx::query` event's elapsed time to the request it ran for.
|
||||||
|
///
|
||||||
|
/// Install it with [`sqlx_timing_layer`], which filters it down to the two
|
||||||
|
/// targets it needs; on its own it would be asked about every event in the
|
||||||
|
/// process.
|
||||||
|
pub struct SqlxTimingLayer;
|
||||||
|
|
||||||
|
/// [`SqlxTimingLayer`] under the filter it needs. This is the form to install.
|
||||||
|
pub fn sqlx_timing_layer<S>() -> impl Layer<S>
|
||||||
|
where
|
||||||
|
S: tracing::Subscriber + for<'a> LookupSpan<'a>,
|
||||||
|
{
|
||||||
|
SqlxTimingLayer.with_filter(SqlxTimingFilter)
|
||||||
|
}
|
||||||
|
|
||||||
|
/// What [`SqlxTimingLayer`] is shown: the `sqlx::query` event, and every span.
|
||||||
|
///
|
||||||
|
/// Asking for the event at `DEBUG` is also what makes sqlx emit it — it only
|
||||||
|
/// fires when some subscriber wants it — so this filter is what turns
|
||||||
|
/// statement timing on, whatever `RUST_LOG` says.
|
||||||
|
///
|
||||||
|
/// Every *span*, though, is not over-reach; it is the whole thing working.
|
||||||
|
/// The event surfaces on a sqlx worker thread whose span stack holds exactly
|
||||||
|
/// one entry: the innermost span the calling task was inside, which in this
|
||||||
|
/// stack is `axum_login`'s `call`, not the request span two levels up.
|
||||||
|
/// `Context::lookup_current` will not hand back a span its own layer's filter
|
||||||
|
/// rejects, and its fallback re-walks that same one-entry thread stack rather
|
||||||
|
/// than the parent chain — so a single unseen span between the request span
|
||||||
|
/// and the query hides the request span completely, and the only symptom is a
|
||||||
|
/// `db` metric that quietly never appears. Naming the targets to expect would
|
||||||
|
/// mean re-learning that the next time a middleware is added.
|
||||||
|
///
|
||||||
|
/// Being shown a span costs a target comparison, and changes nothing about
|
||||||
|
/// the log: the `fmt` layer still applies `RUST_LOG` to what it prints.
|
||||||
|
struct SqlxTimingFilter;
|
||||||
|
|
||||||
|
impl<S> tracing_subscriber::layer::Filter<S> for SqlxTimingFilter {
|
||||||
|
/// Whether a callsite is a span, and what target it has, are both fixed at
|
||||||
|
/// compile time, so this is exact and the interest cache still applies.
|
||||||
|
fn callsite_enabled(
|
||||||
|
&self,
|
||||||
|
meta: &'static tracing::Metadata<'static>,
|
||||||
|
) -> tracing::subscriber::Interest {
|
||||||
|
if Self::wanted(meta) {
|
||||||
|
tracing::subscriber::Interest::always()
|
||||||
|
} else {
|
||||||
|
tracing::subscriber::Interest::never()
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
fn enabled(&self, meta: &tracing::Metadata<'_>, _: &Context<'_, S>) -> bool {
|
||||||
|
Self::wanted(meta)
|
||||||
|
}
|
||||||
|
|
||||||
|
/// `DEBUG` is what this layer *needs*, not a ceiling on what it accepts:
|
||||||
|
/// no span above the process-wide maximum is ever created, so capping the
|
||||||
|
/// hint here keeps that maximum where sqlx's own event already puts it
|
||||||
|
/// rather than dragging it to `TRACE`. A `RUST_LOG` that asks for `TRACE`
|
||||||
|
/// raises the maximum itself, and those spans are then let through too.
|
||||||
|
fn max_level_hint(&self) -> Option<tracing_subscriber::filter::LevelFilter> {
|
||||||
|
Some(tracing_subscriber::filter::LevelFilter::DEBUG)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
impl SqlxTimingFilter {
|
||||||
|
fn wanted(meta: &tracing::Metadata<'_>) -> bool {
|
||||||
|
meta.is_span() || meta.target() == SQLX_TARGET
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
impl<S> Layer<S> for SqlxTimingLayer
|
||||||
|
where
|
||||||
|
S: tracing::Subscriber + for<'a> LookupSpan<'a>,
|
||||||
|
{
|
||||||
|
/// Hang the task's metrics on the request span as it opens. This runs
|
||||||
|
/// synchronously inside [`server_timing`]'s task-local scope, which is the
|
||||||
|
/// whole trick: from here on the metrics are reachable from any thread
|
||||||
|
/// that enters the span.
|
||||||
|
fn on_new_span(
|
||||||
|
&self,
|
||||||
|
_attrs: &tracing::span::Attributes<'_>,
|
||||||
|
id: &tracing::Id,
|
||||||
|
ctx: Context<'_, S>,
|
||||||
|
) {
|
||||||
|
let Some(span) = ctx.span(id) else { return };
|
||||||
|
if span.metadata().target() != REQUEST_TARGET {
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
let _ = CURRENT.try_with(|metrics| {
|
||||||
|
span.extensions_mut().insert(metrics.clone());
|
||||||
|
});
|
||||||
|
}
|
||||||
|
|
||||||
|
fn on_event(&self, event: &tracing::Event<'_>, ctx: Context<'_, S>) {
|
||||||
|
if event.metadata().target() != SQLX_TARGET {
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
let mut elapsed = ElapsedSecs(None);
|
||||||
|
event.record(&mut elapsed);
|
||||||
|
let Some(elapsed) = elapsed.0 else { return };
|
||||||
|
let Some(scope) = ctx.event_scope(event) else {
|
||||||
|
return;
|
||||||
|
};
|
||||||
|
for span in scope {
|
||||||
|
if let Some(metrics) = span.extensions().get::<Arc<RequestMetrics>>() {
|
||||||
|
metrics.add_db(Duration::from_secs_f64(elapsed));
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Pulls `elapsed_secs` off a `sqlx::query` event — the numeric field sqlx
|
||||||
|
/// emits next to the human-readable `elapsed`.
|
||||||
|
struct ElapsedSecs(Option<f64>);
|
||||||
|
|
||||||
|
impl tracing::field::Visit for ElapsedSecs {
|
||||||
|
fn record_f64(&mut self, field: &tracing::field::Field, value: f64) {
|
||||||
|
if field.name() == "elapsed_secs" {
|
||||||
|
self.0 = Some(value);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
fn record_debug(&mut self, _: &tracing::field::Field, _: &dyn std::fmt::Debug) {}
|
||||||
|
}
|
||||||
Reference in new issue
Block a user