#![cfg_attr(
not(test),
deny(
clippy::unwrap_used,
clippy::expect_used,
clippy::panic,
clippy::unreachable,
clippy::todo,
clippy::unimplemented,
clippy::indexing_slicing,
clippy::string_slice,
clippy::arithmetic_side_effects,
)
)]
use std::collections::{HashMap, VecDeque};
use std::future::Future;
use std::io::IoSlice;
use std::pin::Pin;
use std::sync::atomic::{AtomicU64, Ordering};
use std::sync::{Arc, Weak};
use std::task::{Context, Poll};
use std::time::Duration;
use deadpool::managed::{Hook, HookError};
use diesel::{ConnectionError, ConnectionResult};
use diesel_async::AsyncPgConnection;
use diesel_async::pooled_connection::deadpool::Pool;
use diesel_async::pooled_connection::{
AsyncDieselConnectionManager, ManagerConfig, RecyclingMethod,
};
use futures::FutureExt as _;
use tokio::io::{AsyncRead, AsyncWrite, ReadBuf};
use tokio::net::TcpStream;
use crate::capsule::capture::{CaptureScope, scope_by_id};
use crate::capsule::schema::{BindValue, ConnectionTape, Exchange, ExchangeProtocol};
use crate::capsule::wire::{
self, FrameSplitter, FrontendMessage, MarkerId, is_session_housekeeping,
};
use crate::config::{AutumnConfig, DatabaseConfig};
use crate::db::{DatabaseTopology, PoolError};
const MAX_MEMO_ENTRIES: usize = 256;
const MAX_MEMO_BYTES: usize = 1024 * 1024;
const MEMO_BUDGET_SHARE: usize = 4;
const MAX_STATEMENT_NAMES: usize = 1024;
const CLEAR_MARKER_SQL: &str = "SET autumn.capsule_request = ''";
const MAX_IN_FLIGHT: usize = 64;
const DEFAULT_PG_PORT: u16 = 5432;
const EXCHANGE_OVERHEAD_BYTES: usize = 64;
#[must_use]
pub fn capture_unavailable_reason(url: &str) -> Option<String> {
if !matches!(
crate::db::tls::TlsPosture::from_database_url(url),
crate::db::tls::TlsPosture::Off
) {
return Some(
"the database URL asks for TLS (sslmode), and capture cannot frame an \
encrypted connection"
.to_owned(),
);
}
let Ok(config) = url.parse::<tokio_postgres::Config>() else {
return Some("the database URL is not a PostgreSQL connection string".to_owned());
};
if tcp_endpoints(&config).is_empty() {
return Some(
"the database URL names no TCP host (a Unix-socket connection cannot be teed)"
.to_owned(),
);
}
None
}
fn warn_db_capture_unavailable(reason: &str) {
tracing::warn!(
reason,
"failure-capsule database capture is disabled; capsules will record the request, \
clock and outcome but no database traffic"
);
}
pub fn note_db_capture_unavailable(scope: &CaptureScope, reason: &str) {
scope.note(format!("db capture unavailable: {reason}"));
scope.mark_truncated();
}
pub const SHARD_CAPTURE_NOTE: &str = "shard database traffic is not captured in this slice: this request checked out a \
`[[database.shards]]` connection, and its queries are absent from the tape";
pub fn note_shard_capture_gap() {
if let Some(scope) = crate::capsule::current_scope() {
scope.note(SHARD_CAPTURE_NOTE);
scope.mark_truncated();
}
}
pub type CapturePoolProvider = Box<
dyn FnOnce(
DatabaseConfig,
)
-> Pin<Box<dyn Future<Output = Result<Option<DatabaseTopology>, PoolError>> + Send>>
+ Send,
>;
pub fn build_recording_pool(
url: &str,
max_size: usize,
connect_timeout: Duration,
role: &'static str,
) -> Result<Pool<AsyncPgConnection>, PoolError> {
if let Some(reason) = capture_unavailable_reason(url) {
return Err(PoolError::UnsupportedBackend(format!(
"a failure-capsule recording pool cannot be built for this database URL: {reason}"
)));
}
let mut manager_config = ManagerConfig::<AsyncPgConnection>::default();
manager_config.recycling_method = RecyclingMethod::Fast;
manager_config.custom_setup = Box::new(move |url: &str| {
let url = url.to_owned();
async move { establish_recording(&url, role).await }.boxed()
});
let manager =
AsyncDieselConnectionManager::<AsyncPgConnection>::new_with_config(url, manager_config);
Ok(Pool::builder(manager)
.max_size(max_size.max(1))
.wait_timeout(Some(connect_timeout))
.create_timeout(Some(connect_timeout))
.post_create(attribution_hook())
.pre_recycle(attribution_hook())
.runtime(deadpool::Runtime::Tokio1)
.build()?)
}
fn attribution_hook() -> Hook<AsyncDieselConnectionManager<AsyncPgConnection>> {
Hook::async_fn(|conn: &mut AsyncPgConnection, _metrics| {
Box::pin(async move {
use diesel_async::SimpleAsyncConnection as _;
let marker = crate::capsule::current_scope()
.map(|scope| scope.id().to_owned())
.filter(|id| crate::capsule::is_valid_scope_id(id))
.and_then(|id| wire::marker_set_sql(&id))
.unwrap_or_else(|| CLEAR_MARKER_SQL.to_owned());
conn.batch_execute(&marker).await.map_err(|error| {
tracing::debug!(
%error,
"a recorded connection's capsule binding could not be set; it will be \
discarded rather than handed out misattributed"
);
HookError::message(format!(
"the failure-capsule recording pool could not set a connection's capsule \
binding: {error}"
))
})
})
})
}
async fn establish_recording(url: &str, role: &'static str) -> ConnectionResult<AsyncPgConnection> {
let config = url
.parse::<tokio_postgres::Config>()
.map_err(|error| ConnectionError::InvalidConnectionUrl(error.to_string()))?;
let endpoints = tcp_endpoints(&config);
if endpoints.is_empty() {
return Err(ConnectionError::InvalidConnectionUrl(
"the recording pool needs a TCP host in the database URL".to_owned(),
));
}
let mut failures: Vec<String> = Vec::new();
for (host, port) in &endpoints {
match establish_recording_at(&config, host, *port, role).await {
Ok(connection) => return Ok(connection),
Err(reason) => failures.push(format!("{host}:{port}: {reason}")),
}
}
Err(ConnectionError::BadConnection(format!(
"failed to establish a recorded connection to every configured host ({})",
failures.join("; ")
)))
}
async fn establish_recording_at(
config: &tokio_postgres::Config,
host: &str,
port: u16,
role: &'static str,
) -> Result<AsyncPgConnection, String> {
let stream = TcpStream::connect((host, port))
.await
.map_err(|error| error.to_string())?;
let _ = stream.set_nodelay(true);
let (client, connection) = config
.connect_raw(
RecordingStream::with_role(stream, role),
tokio_postgres::NoTls,
)
.await
.map_err(|error| error.to_string())?;
tokio::spawn(async move {
if let Err(error) = connection.await {
tracing::debug!(%error, "recorded database connection ended");
}
});
if matches!(
config.get_target_session_attrs(),
tokio_postgres::config::TargetSessionAttrs::ReadWrite
) {
let rows = client
.simple_query("SHOW transaction_read_only")
.await
.map_err(|error| error.to_string())?;
let read_only = rows.iter().any(|message| {
matches!(
message,
tokio_postgres::SimpleQueryMessage::Row(row) if row.get(0) == Some("on")
)
});
if read_only {
return Err(
"the session is read-only, and the URL asks for target_session_attrs=read-write"
.to_owned(),
);
}
}
AsyncPgConnection::try_from(client)
.await
.map_err(|error| error.to_string())
}
fn tcp_endpoints(config: &tokio_postgres::Config) -> Vec<(String, u16)> {
let ports = config.get_ports();
config
.get_hosts()
.iter()
.enumerate()
.filter_map(|(index, host)| match host {
tokio_postgres::config::Host::Tcp(name) => Some((
name.clone(),
ports
.get(index)
.or_else(|| ports.first())
.copied()
.unwrap_or(DEFAULT_PG_PORT),
)),
#[cfg(unix)]
tokio_postgres::config::Host::Unix(_) => None,
})
.collect()
}
#[must_use]
pub fn maybe_capture_pool_provider(
existing: Option<CapturePoolProvider>,
config: &AutumnConfig,
) -> Option<CapturePoolProvider> {
if !config.failure_capture.enabled {
return existing;
}
if !config.database.shards.is_empty() {
tracing::warn!(
shard_count = config.database.shards.len(),
"failure-capsule capture does not record `[[database.shards]]` traffic; a request \
that checks out a shard connection will have its capsule marked truncated, and \
`autumn replay` will refuse it"
);
}
if let Some(inner) = existing {
const REASON: &str =
"the application installed a custom DatabasePoolProvider, which Autumn does not wrap";
warn_db_capture_unavailable(REASON);
return Some(Box::new(move |database: DatabaseConfig| {
Box::pin(async move {
inner(database)
.await
.map(|topology| topology.map(|t| t.with_capture_gap(Some(REASON.to_owned()))))
})
}));
}
Some(Box::new(|database: DatabaseConfig| {
Box::pin(async move { recording_topology(&database) })
}))
}
fn recording_topology(config: &DatabaseConfig) -> Result<Option<DatabaseTopology>, PoolError> {
let Some(primary_url) = config.effective_primary_url() else {
return Ok(None);
};
let blocked = capture_unavailable_reason(primary_url).or_else(|| {
config
.replica_url
.as_deref()
.and_then(capture_unavailable_reason)
});
if let Some(reason) = blocked {
warn_db_capture_unavailable(&reason);
return crate::db::create_topology(config)
.map(|topology| topology.map(|t| t.with_capture_gap(Some(reason))));
}
let timeout = Duration::from_secs(config.connect_timeout_secs);
let primary = build_recording_pool(
primary_url,
config.effective_primary_pool_size(),
timeout,
crate::capsule::schema::TAPE_ROLE_PRIMARY,
)?;
let replica = config
.replica_url
.as_deref()
.map(|url| {
build_recording_pool(
url,
config.effective_replica_pool_size(),
timeout,
crate::capsule::schema::TAPE_ROLE_REPLICA,
)
})
.transpose()?;
Ok(Some(DatabaseTopology::from_pools(primary, replica)))
}
static NEXT_CONNECTION_ID: AtomicU64 = AtomicU64::new(1);
#[derive(Debug)]
pub struct RecordingStream<S> {
inner: S,
recorder: ConnectionRecorder,
}
impl<S> RecordingStream<S> {
#[cfg(test)]
#[must_use]
pub fn new(inner: S) -> Self {
Self::with_role(inner, crate::capsule::schema::TAPE_ROLE_PRIMARY)
}
#[must_use]
pub fn with_role(inner: S, role: &'static str) -> Self {
Self {
inner,
recorder: ConnectionRecorder::new(
NEXT_CONNECTION_ID.fetch_add(1, Ordering::Relaxed),
role,
),
}
}
}
impl<S: AsyncRead + Unpin> AsyncRead for RecordingStream<S> {
fn poll_read(
self: Pin<&mut Self>,
cx: &mut Context<'_>,
buf: &mut ReadBuf<'_>,
) -> Poll<std::io::Result<()>> {
let this = self.get_mut();
let before = buf.filled().len();
let polled = Pin::new(&mut this.inner).poll_read(cx, buf);
if matches!(polled, Poll::Ready(Ok(()))) {
let fresh = buf.filled().get(before..).unwrap_or_default();
if !fresh.is_empty() {
this.recorder.on_backend(fresh);
}
}
polled
}
}
impl<S: AsyncWrite + Unpin> AsyncWrite for RecordingStream<S> {
fn poll_write(
self: Pin<&mut Self>,
cx: &mut Context<'_>,
buf: &[u8],
) -> Poll<std::io::Result<usize>> {
let this = self.get_mut();
let polled = Pin::new(&mut this.inner).poll_write(cx, buf);
if let Poll::Ready(Ok(written)) = &polled {
let written = *written;
if let Some(chunk) = buf.get(..written) {
this.recorder.on_frontend(chunk);
}
}
polled
}
fn poll_write_vectored(
self: Pin<&mut Self>,
cx: &mut Context<'_>,
bufs: &[IoSlice<'_>],
) -> Poll<std::io::Result<usize>> {
let this = self.get_mut();
let polled = Pin::new(&mut this.inner).poll_write_vectored(cx, bufs);
if let Poll::Ready(Ok(written)) = &polled {
let mut remaining = *written;
for slice in bufs {
if remaining == 0 {
break;
}
let take = remaining.min(slice.len());
if let Some(chunk) = slice.get(..take) {
this.recorder.on_frontend(chunk);
}
remaining = remaining.saturating_sub(take);
}
}
polled
}
fn is_write_vectored(&self) -> bool {
false
}
fn poll_flush(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<std::io::Result<()>> {
let this = self.get_mut();
Pin::new(&mut this.inner).poll_flush(cx)
}
fn poll_shutdown(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<std::io::Result<()>> {
let this = self.get_mut();
Pin::new(&mut this.inner).poll_shutdown(cx)
}
}
const POISONED_CONNECTION_NOTE: &str = "db capture stopped earlier on the connection this request borrowed, so its queries are \
absent from the tape";
const MEMO_SHARE_NOTE: &str = "db capture: the connection's remembered history did not fit this capsule's budget share, so \
some of its prepared-statement metadata was left out; replay may report an unknown statement";
#[derive(Clone, Copy, Debug, PartialEq, Eq)]
enum MemoCopy {
Copied,
Partial,
OverBudget,
}
#[derive(Clone, Copy, Debug, PartialEq, Eq)]
enum Bucket {
Prologue,
Statements,
Catalog,
Request,
}
#[derive(Debug)]
struct Pending {
protocol: ExchangeProtocol,
sql: String,
binds: Vec<BindValue>,
has_parse: bool,
has_bind: bool,
housekeeping: bool,
response: Vec<u8>,
row_count: usize,
error: Option<String>,
}
impl Pending {
const fn extended() -> Self {
Self {
protocol: ExchangeProtocol::Extended,
sql: String::new(),
binds: Vec::new(),
has_parse: false,
has_bind: false,
housekeeping: false,
response: Vec::new(),
row_count: 0,
error: None,
}
}
fn simple(sql: String) -> Self {
Self {
protocol: ExchangeProtocol::Simple,
sql,
..Self::extended()
}
}
fn into_exchange(self) -> Exchange {
Exchange {
protocol: self.protocol,
sql: self.sql,
binds: self.binds,
response: self.response,
row_count: self.row_count,
error: self.error,
}
}
}
#[derive(Debug, Default)]
pub struct ConnectionMemo {
prologue: Vec<Exchange>,
statements: Vec<Exchange>,
catalog: Vec<Exchange>,
bytes: usize,
}
impl ConnectionMemo {
fn remember(&mut self, bucket: Bucket, exchange: &Exchange) {
let cost = exchange_bytes(exchange);
let entries = match bucket {
Bucket::Prologue => &mut self.prologue,
Bucket::Statements => &mut self.statements,
Bucket::Catalog => &mut self.catalog,
Bucket::Request => return,
};
if let Some(existing) = entries
.iter_mut()
.find(|entry| entry.sql == exchange.sql && entry.binds == exchange.binds)
{
self.bytes = self
.bytes
.saturating_sub(exchange_bytes(existing))
.saturating_add(cost);
*existing = exchange.clone();
return;
}
if entries.len() >= MAX_MEMO_ENTRIES || self.bytes.saturating_add(cost) > MAX_MEMO_BYTES {
return;
}
entries.push(exchange.clone());
self.bytes = self.bytes.saturating_add(cost);
}
}
#[derive(Debug)]
#[allow(
clippy::struct_excessive_bools,
reason = "the flags (first-marker window, disabled, poisoned) are independent \
lifecycle facts about one connection, not an encodable state machine"
)]
pub struct ConnectionRecorder {
id: u64,
role: &'static str,
frontend: FrameSplitter,
backend: FrameSplitter,
statement_sql: HashMap<String, String>,
building: Option<Pending>,
in_flight: VecDeque<Pending>,
memo: ConnectionMemo,
bound: Option<Weak<CaptureScope>>,
before_first_marker: bool,
stopped: bool,
poisoned: bool,
frontend_lost: bool,
}
impl ConnectionRecorder {
fn new(id: u64, role: &'static str) -> Self {
Self {
id,
role,
frontend: FrameSplitter::new_frontend(),
backend: FrameSplitter::new_backend(),
statement_sql: HashMap::new(),
building: None,
in_flight: VecDeque::new(),
memo: ConnectionMemo::default(),
bound: None,
before_first_marker: true,
stopped: false,
poisoned: false,
frontend_lost: false,
}
}
fn scope(&self) -> Option<Arc<CaptureScope>> {
self.bound
.as_ref()
.and_then(Weak::upgrade)
.filter(|scope| !scope.is_closed())
}
fn on_frontend(&mut self, bytes: &[u8]) {
if self.frontend_lost {
return;
}
let frames = self.frontend.push(bytes);
if self.frontend.is_unrecordable() {
self.frontend_lost = true;
self.give_up("the client stream could not be framed");
return;
}
for frame in frames {
if self.poisoned {
Self::watch_marker_while_poisoned(&frame);
} else {
self.on_frontend_frame(&frame);
}
}
}
fn on_backend(&mut self, bytes: &[u8]) {
if self.poisoned {
return;
}
let frames = self.backend.push(bytes);
if self.backend.is_unrecordable() {
self.give_up("the server stream could not be framed");
return;
}
for frame in frames {
self.on_backend_frame(&frame);
}
}
fn watch_marker_while_poisoned(frame: &wire::Frame) {
let FrontendMessage::Query(sql) = wire::parse_frontend(frame) else {
return;
};
let Some(MarkerId::Set(id)) = wire::marker_request_id(&sql) else {
return;
};
let Some(scope) = scope_by_id(&id) else {
return;
};
scope.note(POISONED_CONNECTION_NOTE);
scope.mark_truncated();
}
fn on_frontend_frame(&mut self, frame: &wire::Frame) {
match wire::parse_frontend(frame) {
FrontendMessage::Parse { name, sql, .. } => {
if self.statement_sql.len() >= MAX_STATEMENT_NAMES
&& !self.statement_sql.contains_key(&name)
{
self.give_up(
"this connection holds more live prepared statements than \
capture tracks",
);
return;
}
self.statement_sql.insert(name, sql.clone());
let pending = self.building.get_or_insert_with(Pending::extended);
if pending.sql.is_empty() {
pending.sql = sql;
}
pending.has_parse = true;
}
FrontendMessage::Bind {
statement, params, ..
} => {
let named = self.statement_sql.get(&statement).cloned();
let pending = self.building.get_or_insert_with(Pending::extended);
if pending.sql.is_empty()
&& let Some(sql) = named
{
pending.sql = sql;
}
pending.has_bind = true;
pending.binds = params
.into_iter()
.map(|param| param.map_or(BindValue::Null, BindValue::Value))
.collect();
}
FrontendMessage::Describe { .. } | FrontendMessage::Execute => {
let _ = self.building.get_or_insert_with(Pending::extended);
}
FrontendMessage::Close { kind, name } => {
if kind == b'S' {
self.statement_sql.remove(&name);
}
self.building
.get_or_insert_with(Pending::extended)
.housekeeping = true;
}
FrontendMessage::Sync => self.close_unit(),
FrontendMessage::Query(sql) => {
self.close_unit();
let marker = wire::marker_request_id(&sql);
let mut pending = Pending::simple(sql);
if let Some(marker) = marker {
pending.housekeeping = true;
self.apply_marker(marker);
}
self.push_unit(pending);
}
_ => {}
}
}
fn on_backend_frame(&mut self, frame: &wire::Frame) {
let from_queue = !self.in_flight.is_empty();
let Some(target) = (if from_queue {
self.in_flight.front_mut()
} else {
self.building.as_mut()
}) else {
return;
};
target.response.extend_from_slice(&frame.bytes);
if frame.tag == wire::TAG_DATA_ROW {
target.row_count = target.row_count.saturating_add(1);
}
if frame.tag == wire::TAG_ERROR_RESPONSE
&& let Some((code, message)) = wire::error_response_fields(frame)
{
target.error = Some(format!("{code}: {message}"));
}
if wire::terminates_exchange(frame) {
let finished = if from_queue {
self.in_flight.pop_front()
} else {
self.building.take()
};
if let Some(finished) = finished {
self.finish(finished);
}
}
}
fn close_unit(&mut self) {
if let Some(pending) = self.building.take() {
self.push_unit(pending);
}
}
fn push_unit(&mut self, pending: Pending) {
if self.in_flight.len() >= MAX_IN_FLIGHT {
self.give_up("too many exchanges in flight on one connection");
return;
}
self.in_flight.push_back(pending);
}
fn finish(&mut self, pending: Pending) {
if pending.housekeeping {
return;
}
let bucket = if pending.has_parse && !pending.has_bind {
Bucket::Statements
} else if wire::is_catalog_sql(&pending.sql) {
Bucket::Catalog
} else if self.before_first_marker {
Bucket::Prologue
} else {
Bucket::Request
};
if bucket == Bucket::Request && is_session_housekeeping(&pending.sql) {
return;
}
if bucket != Bucket::Request && pending.sql.is_empty() {
return;
}
let exchange = pending.into_exchange();
self.memo.remember(bucket, &exchange);
self.append(bucket, exchange);
}
fn append(&mut self, bucket: Bucket, exchange: Exchange) {
if self.stopped {
return;
}
let Some(scope) = self.scope() else {
return;
};
let budget = scope.settings().max_capsule_bytes;
let id = self.id;
let role = self.role;
let cost = exchange_bytes(&exchange);
let recorded = scope
.with_db(|db| {
if scope.is_closed() {
return true;
}
let tape = db.tape_mut(id);
if tape.role != role {
role.clone_into(&mut tape.role);
}
let entries = tape_bucket(tape, bucket);
if bucket != Bucket::Request
&& entries
.iter()
.any(|entry| entry.sql == exchange.sql && entry.binds == exchange.binds)
{
return true;
}
if !db.charge(cost, budget) {
return false;
}
tape_bucket(db.tape_mut(id), bucket).push(exchange);
true
})
.unwrap_or(false);
if !recorded {
scope.mark_truncated();
self.stopped = true;
}
}
fn apply_marker(&mut self, marker: MarkerId) {
self.before_first_marker = false;
match marker {
MarkerId::Set(id) => match scope_by_id(&id) {
Some(scope) => {
self.bound = Some(Arc::downgrade(&scope));
self.stopped = false;
self.copy_memo();
}
None => self.bound = None,
},
MarkerId::Clear => self.bound = None,
MarkerId::Invalid => {
tracing::warn!(
connection = self.id,
"a capsule attribution marker carried an unusable request id; queries on \
this connection will not be recorded"
);
let previous = self.scope();
self.bound = None;
if let Some(scope) = previous {
scope.note(
"db capture: a connection marker carried an unusable capsule id, so \
later queries on that connection are unattributed",
);
}
}
}
}
fn copy_memo(&mut self) {
let Some(scope) = self.scope() else {
return;
};
let budget = scope.settings().max_capsule_bytes;
let allowance = budget / MEMO_BUDGET_SHARE;
let id = self.id;
let memo = &self.memo;
let outcome = scope
.with_db(|db| {
if scope.is_closed() {
return MemoCopy::Copied;
}
let tape = db.tape_mut(id);
let want_statements = tape.statements.is_empty() && !memo.statements.is_empty();
let want_catalog = tape.catalog.is_empty() && !memo.catalog.is_empty();
let want_prologue = tape.prologue.is_empty() && !memo.prologue.is_empty();
let mut spent = 0usize;
let mut skipped = false;
let mut fits = |wanted: bool, entries: &[Exchange]| {
if !wanted {
return false;
}
let cost = total_bytes(entries);
if spent.saturating_add(cost) > allowance {
skipped = true;
return false;
}
spent = spent.saturating_add(cost);
true
};
let take_statements = fits(want_statements, &memo.statements);
let take_catalog = fits(want_catalog, &memo.catalog);
let take_prologue = fits(want_prologue, &memo.prologue);
if spent > 0 {
if !db.charge(spent, budget) {
return MemoCopy::OverBudget;
}
let tape = db.tape_mut(id);
if take_statements {
tape.statements.clone_from(&memo.statements);
}
if take_catalog {
tape.catalog.clone_from(&memo.catalog);
}
if take_prologue {
tape.prologue.clone_from(&memo.prologue);
}
}
if skipped {
MemoCopy::Partial
} else {
MemoCopy::Copied
}
})
.unwrap_or(MemoCopy::OverBudget);
match outcome {
MemoCopy::Copied => {}
MemoCopy::Partial => scope.note(MEMO_SHARE_NOTE),
MemoCopy::OverBudget => {
scope.mark_truncated();
self.stopped = true;
}
}
}
fn give_up(&mut self, reason: &str) {
self.poisoned = true;
self.building = None;
self.in_flight.clear();
self.memo = ConnectionMemo::default();
tracing::debug!(
connection = self.id,
reason,
"failure-capsule database recording stopped for this connection"
);
if let Some(scope) = self.scope() {
self.bound = None;
let id = self.id;
let role = self.role.to_owned();
scope.with_db(|db| {
*db.tape_mut(id) = ConnectionTape {
id,
role,
..ConnectionTape::default()
};
});
scope.note(format!("db capture stopped: {reason}"));
scope.mark_truncated();
}
}
}
const fn tape_bucket(tape: &mut ConnectionTape, bucket: Bucket) -> &mut Vec<Exchange> {
match bucket {
Bucket::Prologue => &mut tape.prologue,
Bucket::Statements => &mut tape.statements,
Bucket::Catalog => &mut tape.catalog,
Bucket::Request => &mut tape.exchanges,
}
}
fn exchange_bytes(exchange: &Exchange) -> usize {
let binds: usize = exchange
.binds
.iter()
.map(|bind| match bind {
BindValue::Value(bytes) => bytes.len(),
BindValue::Null | BindValue::Masked => 0,
})
.sum();
exchange
.sql
.len()
.saturating_add(exchange.response.len())
.saturating_add(binds)
.saturating_add(EXCHANGE_OVERHEAD_BYTES)
}
fn total_bytes(exchanges: &[Exchange]) -> usize {
exchanges
.iter()
.map(exchange_bytes)
.fold(0usize, usize::saturating_add)
}
#[cfg(test)]
mod tests {
use super::*;
use tokio::io::AsyncWriteExt as _;
#[test]
fn tcp_endpoints_lists_every_configured_host_in_order() {
let config = "host=first.example,second.example port=5433,5434 user=app dbname=app"
.parse::<tokio_postgres::Config>()
.expect("multi-host config parses");
assert_eq!(
tcp_endpoints(&config),
vec![
("first.example".to_owned(), 5433),
("second.example".to_owned(), 5434),
],
"a failover list must be preserved in configured order, with ports \
paired the way tokio-postgres pairs them"
);
let single_port = "host=first.example,second.example port=6000 user=app"
.parse::<tokio_postgres::Config>()
.expect("single-port config parses");
assert_eq!(
tcp_endpoints(&single_port),
vec![
("first.example".to_owned(), 6000),
("second.example".to_owned(), 6000),
],
"one configured port applies to every host"
);
}
#[tokio::test]
async fn a_host_that_accepts_tcp_but_fails_the_handshake_is_not_selected() {
let listener = tokio::net::TcpListener::bind("127.0.0.1:0")
.await
.expect("bind");
let half_up = listener.local_addr().expect("addr").port();
tokio::spawn(async move {
while let Ok((socket, _)) = listener.accept().await {
drop(socket);
}
});
let error = establish_recording(
&format!("host=127.0.0.1,127.0.0.1 port={half_up},1 user=postgres dbname=postgres"),
crate::capsule::schema::TAPE_ROLE_PRIMARY,
)
.await
.err()
.expect("neither endpoint can finish a handshake");
let message = error.to_string();
assert!(
message.contains(&format!("127.0.0.1:{half_up}")) && message.contains("127.0.0.1:1"),
"the error must show the loop moved past the TCP-accepting host \
and tried the whole failover list, got {message}"
);
}
#[tokio::test]
async fn exhausting_every_host_names_each_failed_attempt() {
let error = establish_recording(
"host=127.0.0.1,127.0.0.1 port=1,2 user=postgres dbname=postgres",
crate::capsule::schema::TAPE_ROLE_PRIMARY,
)
.await
.err()
.expect("nothing listens on ports 1 or 2");
let message = error.to_string();
assert!(
message.contains("127.0.0.1:1") && message.contains("127.0.0.1:2"),
"the error must name every attempted endpoint so an operator can \
see the whole failover list was tried, got {message}"
);
}
fn tagged(tag: u8, payload: &[u8]) -> Vec<u8> {
let mut out = vec![tag];
let len = i32::try_from(payload.len() + 4).expect("small payload");
out.extend_from_slice(&len.to_be_bytes());
out.extend_from_slice(payload);
out
}
fn query(sql: &str) -> Vec<u8> {
let mut payload = sql.as_bytes().to_vec();
payload.push(0);
tagged(b'Q', &payload)
}
fn startup() -> Vec<u8> {
let mut payload = 196_608u32.to_be_bytes().to_vec();
payload.extend_from_slice(b"user\0postgres\0\0");
let mut out = i32::try_from(payload.len() + 4)
.expect("small payload")
.to_be_bytes()
.to_vec();
out.extend_from_slice(&payload);
out
}
#[tokio::test]
async fn vectored_writes_are_refused_and_still_teed() {
let (client, _server) = tokio::io::duplex(4096);
let mut stream = RecordingStream::new(client);
assert!(
!AsyncWrite::is_write_vectored(&stream),
"the tee must advertise itself as non-vectored so writers hand it one \
contiguous buffer"
);
let startup = startup();
let first = query("SELECT 1");
let second = query("SELECT 2");
let written = stream
.write_vectored(&[
IoSlice::new(&startup),
IoSlice::new(&first),
IoSlice::new(&second),
])
.await
.expect("duplex accepts the write");
assert_eq!(written, startup.len() + first.len() + second.len());
let seen: Vec<&str> = stream
.recorder
.in_flight
.iter()
.map(|pending| pending.sql.as_str())
.collect();
assert_eq!(
seen,
vec!["SELECT 1", "SELECT 2"],
"every slice of a vectored write must reach the recorder"
);
}
#[tokio::test]
async fn simple_query_round_trip_becomes_one_exchange() {
let (client, _server) = tokio::io::duplex(4096);
let mut stream = RecordingStream::new(client);
stream.write_all(&startup()).await.expect("write startup");
stream
.write_all(&query("SELECT 1"))
.await
.expect("write query");
let mut response = tagged(b'C', b"SELECT 1\0");
response.extend_from_slice(&tagged(b'Z', b"I"));
stream.recorder.on_backend(&response);
assert!(
stream.recorder.in_flight.is_empty(),
"ReadyForQuery closes the exchange"
);
assert_eq!(
stream.recorder.memo.prologue.len(),
1,
"traffic before the first marker is the connection's prologue"
);
}
#[tokio::test]
async fn marker_statements_are_not_recorded_as_exchanges() {
let (client, _server) = tokio::io::duplex(4096);
let mut stream = RecordingStream::new(client);
stream.write_all(&startup()).await.expect("write startup");
stream
.write_all(&query(
"SET statement_timeout = 0; SET autumn.capsule_request = 'nobody'",
))
.await
.expect("write marker");
stream.recorder.on_backend(&tagged(b'Z', b"I"));
assert!(
stream.recorder.memo.prologue.is_empty(),
"the housekeeping marker must not be remembered as connection history"
);
assert!(
!stream.recorder.before_first_marker,
"the marker ends the prologue even when no scope claims it"
);
assert!(
stream.recorder.bound.is_none(),
"an unknown capsule id must leave the connection unattributed"
);
}
#[test]
fn clearing_marker_is_the_wire_marker() {
assert_eq!(
wire::marker_set_sql("").as_deref(),
Some(CLEAR_MARKER_SQL),
"the pool hooks must send exactly the clearing marker the recorder parses"
);
assert!(
is_session_housekeeping(CLEAR_MARKER_SQL),
"the unbind statement is Autumn's own bookkeeping and must never reach a tape"
);
assert_eq!(
wire::marker_request_id(CLEAR_MARKER_SQL),
Some(MarkerId::Clear)
);
}
#[tokio::test]
async fn a_poisoned_connection_tells_the_next_request_its_tape_is_missing() {
let scope = scope_for_test("later-request");
crate::capsule::capture::register(&scope);
let (client, _server) = tokio::io::duplex(1024 * 1024);
let mut stream = RecordingStream::new(client);
stream.write_all(&startup()).await.expect("write startup");
for index in 0..=MAX_IN_FLIGHT {
stream
.write_all(&query(&format!("SELECT {index}")))
.await
.expect("write query");
}
assert!(
stream.recorder.poisoned,
"an unbounded in-flight queue must stop recording"
);
stream
.write_all(&query("SET autumn.capsule_request = 'later-request'"))
.await
.expect("write marker");
assert!(
scope
.notes()
.iter()
.any(|note| note == POISONED_CONNECTION_NOTE),
"the later request's capsule must explain the missing tape, got {:?}",
scope.notes()
);
assert!(
scope.is_truncated(),
"a capsule with no tape because recording had already stopped must be refused \
by replay, not presented as a request that used no database"
);
}
#[tokio::test]
async fn closing_a_prepared_statement_forgets_its_sql() {
let (client, _server) = tokio::io::duplex(4096);
let mut stream = RecordingStream::new(client);
stream.write_all(&startup()).await.expect("write startup");
let mut parse = b"s1\0".to_vec();
parse.extend_from_slice(b"SELECT $1::text\0");
parse.extend_from_slice(&0i16.to_be_bytes());
stream
.write_all(&tagged(b'P', &parse))
.await
.expect("write parse");
assert_eq!(
stream.recorder.statement_sql.get("s1").map(String::as_str),
Some("SELECT $1::text")
);
stream
.write_all(&tagged(b'C', b"Ss1\0"))
.await
.expect("write close");
assert!(
stream.recorder.statement_sql.is_empty(),
"closing the statement must retire its name, got {:?}",
stream.recorder.statement_sql
);
}
#[tokio::test]
async fn a_warm_memo_cannot_eat_the_whole_capsule_budget() {
let settings = Arc::new(crate::capsule::CaptureSettings {
max_capsule_bytes: 4_000,
..crate::capsule::CaptureSettings::default()
});
let scope = Arc::new(CaptureScope::new(
"budget".to_owned(),
settings,
Arc::new(crate::log::filter::ParameterFilter::new(&[], &[])),
));
let mut recorder = ConnectionRecorder::new(7, crate::capsule::schema::TAPE_ROLE_PRIMARY);
recorder.bound = Some(Arc::downgrade(&scope));
for index in 0..20 {
recorder.memo.remember(
Bucket::Statements,
&Exchange {
protocol: ExchangeProtocol::Extended,
sql: format!("SELECT {index} FROM big"),
binds: Vec::new(),
response: vec![0u8; 500],
row_count: 0,
error: None,
},
);
}
recorder.copy_memo();
assert!(!recorder.stopped, "the memo must not stop recording");
assert!(
!scope.is_truncated(),
"a big memo must not refuse the capsule before the request has run"
);
let charged = scope.with_db(|db| db.charged_bytes()).expect("db lock");
assert!(
charged <= 1_000,
"the memo may claim at most a quarter of the 4000-byte budget, charged {charged}"
);
assert!(
scope.notes().iter().any(|note| note == MEMO_SHARE_NOTE),
"a capsule whose memo was trimmed must say so, got {:?}",
scope.notes()
);
recorder.append(
Bucket::Request,
Exchange {
protocol: ExchangeProtocol::Extended,
sql: "SELECT 1".to_owned(),
binds: Vec::new(),
response: vec![0u8; 100],
row_count: 1,
error: None,
},
);
assert!(
!scope.is_truncated(),
"the request's own exchange must fit the budget the memo did not take"
);
}
#[test]
fn catalog_probes_and_prepared_statements_land_in_their_own_buckets() {
let mut memo = ConnectionMemo::default();
let statement = Exchange {
protocol: ExchangeProtocol::Extended,
sql: "SELECT $1::text".to_owned(),
binds: Vec::new(),
response: vec![b'1', 0, 0, 0, 4],
row_count: 0,
error: None,
};
memo.remember(Bucket::Statements, &statement);
memo.remember(Bucket::Statements, &statement);
assert_eq!(
memo.statements.len(),
1,
"the same statement prepared twice is remembered once"
);
memo.remember(Bucket::Request, &statement);
assert!(
memo.prologue.is_empty() && memo.catalog.is_empty(),
"a request's own exchange is never connection history"
);
}
#[test]
fn session_settings_are_housekeeping_but_real_work_is_not() {
assert!(is_session_housekeeping("SET TIME ZONE 'UTC'"));
assert!(is_session_housekeeping("set client_encoding TO 'UTF8'"));
assert!(is_session_housekeeping(
"SET statement_timeout = 5000; SET autumn.capsule_request = 'abc'"
));
assert!(is_session_housekeeping(" SET TIME ZONE 'UTC'; "));
assert!(
!is_session_housekeeping("SET statement_timeout = 5000; SELECT 1"),
"a batch that also does real work is the request's, not housekeeping"
);
assert!(!is_session_housekeeping("SELECT $1::text"));
assert!(!is_session_housekeeping("SET LOCAL search_path TO app"));
assert!(
!is_session_housekeeping("SET LOCAL statement_timeout = 5000"),
"an application's transaction-scoped timeout must not be synthesized away"
);
assert!(!is_session_housekeeping("set local TIME ZONE 'UTC'"));
assert!(!is_session_housekeeping(""));
}
#[test]
fn tls_and_socket_urls_are_not_recordable() {
assert!(
capture_unavailable_reason("postgres://u:p@host:5432/db").is_none(),
"a plaintext TCP URL is recordable"
);
assert!(
capture_unavailable_reason("postgres://u:p@host:5432/db?sslmode=require")
.is_some_and(|reason| reason.contains("TLS")),
"a TLS URL must be refused with a reason naming TLS"
);
#[cfg(unix)]
assert!(
capture_unavailable_reason("postgres:///db?host=/var/run/postgresql").is_some(),
"a Unix-socket URL has no stream to tee"
);
}
fn scope_for_test(id: &str) -> Arc<CaptureScope> {
Arc::new(CaptureScope::new(
id.to_owned(),
Arc::new(crate::capsule::CaptureSettings::default()),
Arc::new(crate::log::filter::ParameterFilter::new(&[], &[])),
))
}
#[tokio::test]
async fn a_shard_checkout_notes_and_truncates_the_in_flight_capsule() {
let scope = scope_for_test("shard-gap");
crate::capsule::capture::CAPSULE_SCOPE
.scope(Arc::clone(&scope), async {
note_shard_capture_gap();
})
.await;
assert!(
scope.notes().iter().any(|note| note == SHARD_CAPTURE_NOTE),
"the capsule must say the shard traffic is missing, got {:?}",
scope.notes()
);
assert!(
scope.is_truncated(),
"a capsule missing its shard effects must be refused by replay, not \
presented as complete"
);
}
#[tokio::test]
async fn a_shard_checkout_outside_a_capture_scope_is_a_no_op() {
note_shard_capture_gap();
let scope = scope_for_test("no-shard");
assert!(scope.notes().is_empty());
assert!(!scope.is_truncated());
}
}