Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 12 additions & 5 deletions docs/agents.md
Original file line number Diff line number Diff line change
Expand Up @@ -156,7 +156,7 @@ from the submodule named beside it further down.
| Base ORM | `Base`, `BaseTable`, `DatetimeColumnsMixin`, `DB_NAMING_CONVENTION`, `PydanticJSONB`, `GenericJSONDict`, `UnConstrainedEnum`, `load_orm_metadata` |
| Engine utilities | `build_engine_kwargs`, `resolve_pool_class`, `register_pool_class`, `PoolRegistry`, `PoolClassStr`, `configure_orjson_serialization` |
| Config protocols | `PostgresSettingsProtocol`, `ConnectionSettingsProtocol`, `PoolSettingsProtocol`, `QuerySettingsProtocol` |
| Metrics protocols | `PostgresMetricsProtocol`, `PoolStatsRecorder`, `CheckoutRecorder`, `CheckoutWaitRecorder`, `ErrorRecorder` |
| Metrics protocols | `PostgresMetricsProtocol`, `PoolStatsRecorder`, `PoolStatsFunctionRecorder`, `CheckoutRecorder`, `CheckoutWaitRecorder`, `ErrorRecorder` |
| Version | `__version__` |

### `AsyncSessionManager`
Expand Down Expand Up @@ -202,7 +202,13 @@ are startup parameters, so read rule 16 before adding one.
`sqlalchemy_foundation_kit.session.manager`, not re-exported — wire the pool listeners,
respectively the per-transaction `search_path`, onto an engine you built yourself. The
manager calls them when `metrics` / `search_path` is passed. A raising metrics callback is
logged and swallowed, never propagated.
logged and swallowed, never propagated. The pool gauges are read when the registry is
collected if `metrics` implements `PoolStatsFunctionRecorder`
(`set_pool_stats_functions(pool_size, pool_checked_out, pool_overflow)`, each a
zero-argument callable over the engine's current pool), as `PostgresMetrics` does;
otherwise `record_pool_stats` is called from the `checkout` / `checkin` events and lags one
return behind, so an idle pool keeps its last burst. One `PostgresMetrics` reports one
engine.

`instrument_pool_class(pool_class, metrics)` lives beside them and is the other half of the
metrics wiring: it returns a subclass of `pool_class` that times `Pool.connect()`, which is
Expand Down Expand Up @@ -336,9 +342,9 @@ variables only through the parent `BaseSettings` that holds it. Under

| Series | Type | What it measures |
|---|---|---|
| `postgres_db_pool_size` | gauge | connections the pool holds |
| `postgres_db_pool_size` | gauge | the configured `pool_size`; 0 for `null` / `static` |
| `postgres_db_pool_checked_out` | gauge | connections currently in use |
| `postgres_db_pool_overflow` | gauge | connections over `pool_size`, within `max_overflow` |
| `postgres_db_pool_overflow` | gauge | open connections over `pool_size`, within `max_overflow`; never negative |
| `postgres_db_connection_checkout_wait_seconds` | histogram | how long a caller **waited** for a connection — the queue wait, plus the pre-ping and the connect handshake when the pool had to grow. Buckets run to 30 s, the default `pool_timeout` |
| `postgres_db_connection_held_duration_seconds` | histogram | how long a caller **held** one, checkout to checkin — the query time seen from the pool |
| `postgres_db_connection_checkout_duration_seconds` | histogram | **deprecated**, and never measured what its name says: it is the held duration under its old name. Kept for one more minor release, then dropped. Move dashboards to `…_held_duration_seconds`, or to `…_checkout_wait_seconds` if what you wanted was the wait |
Expand Down Expand Up @@ -446,7 +452,7 @@ decorator.
### Fixed since 0.2.0

Three published entry points raise before they reach the database on 0.2.0; on 0.2.1 the
PgBouncer-safe defaults cannot connect through PgBouncer; and up to 0.3.0 the pool metrics
PgBouncer-safe defaults cannot connect through PgBouncer; and up to 0.4.0 the pool metrics
do not say what their names say. All are right on current versions; the workaround column
is what to do on the version the row names.

Expand All @@ -457,6 +463,7 @@ is what to do on the version the row names.
| `import sqlalchemy_foundation_kit.contrib.di` (or `.contrib.dependency_injector`) without its extra (0.2.0) | `AttributeError: 'NoneType' object has no attribute 'APP'` (resp. `'DeclarativeContainer'`) instead of the intended `ImportError` | install the extra; the message is not the one the code meant to give you |
| `create_async_session_manager(config)` through PgBouncer in transaction mode (0.2.1 and earlier) | `jit="off"` was the default and `db_schema` went as `search_path`, both as startup parameters: a default PgBouncer refuses every connection with `ProtocolViolationError: unsupported startup parameter: jit`; with `ignore_startup_parameters=jit,search_path` it connects and silently drops both, so every query lands in `public` | `jit=None`, `db_schema=None`, and `ALTER ROLE … SET search_path` on the server |
| `postgres_db_connection_timeouts_total` (0.3.0 and earlier) | stayed at zero through every pool checkout timeout. The counter was fed only from the engine's `handle_error` listener, and a pool `TimeoutError` is raised by `pool.connect()` before any DBAPI call, so it never reaches that listener — the one timeout a pool actually produces under load was the one the counter did not count | count `sqlalchemy.exc.TimeoutError` around your own session calls |
| `postgres_db_pool_overflow`, `postgres_db_pool_checked_out` (0.4.0 and earlier) | sampled from the `checkout` / `checkin` events: `overflow` exported `QueuePool.overflow()`, which starts at `-pool_size` (`-9` with one connection open of 10), and since `checkin` fires before the connection is back, an idle pool kept reporting its last burst as checked out | read `pool.checkedout()` and `max(pool.overflow(), 0)` yourself |
| `postgres_db_connection_checkout_duration_seconds` (0.3.0 and earlier) | the only checkout histogram there was, and it measures the time between the `checkout` and `checkin` events — how long a connection was *held*, which is query duration seen from the pool. The time a caller waited for a connection, which is what the name suggests and what predicts a pool outage, was not exposed at all | none; the wait was not measurable from outside the pool |

`IsolationLevel` itself was always fine — `READ_UNCOMMITTED`, `READ_COMMITTED`,
Expand Down
13 changes: 10 additions & 3 deletions docs/guide/advanced.md
Original file line number Diff line number Diff line change
Expand Up @@ -268,9 +268,9 @@ session_manager = create_async_session_manager(

| Metric | Type | Description |
|--------|------|-------------|
| `myapp_postgres_db_pool_size` | Gauge | Current pool size |
| `myapp_postgres_db_pool_size` | Gauge | Configured `pool_size` (0 for a pool without a queue) |
| `myapp_postgres_db_pool_checked_out` | Gauge | Connections currently in use |
| `myapp_postgres_db_pool_overflow` | Gauge | Overflow connections created |
| `myapp_postgres_db_pool_overflow` | Gauge | Open connections over `pool_size`, within `max_overflow` |
| `myapp_postgres_db_connection_checkout_wait_seconds` | Histogram | Time a caller **waited** for a connection |
| `myapp_postgres_db_connection_held_duration_seconds` | Histogram | Time a caller **held** a connection, checkout to checkin |
| `myapp_postgres_db_connection_checkout_duration_seconds` | Histogram | Deprecated alias of the held duration — see below |
Expand All @@ -279,6 +279,12 @@ session_manager = create_async_session_manager(

Without a `prefix` the names are `postgres_db_pool_size` and so on.

The three gauges are read from the pool when Prometheus scrapes, not sampled from pool
events, so an idle pool reports `checked_out` 0 instead of whatever its last burst left
behind. A custom metrics object gets the same by implementing `PoolStatsFunctionRecorder`;
one that only implements `record_pool_stats` is sampled on checkout and checkin, and lags
one return behind.

**Wait or held — they are not the same number.** The wait is the time spent inside
`pool.connect()` before a connection is handed out: the queue wait, plus the pre-ping and
the connect handshake when the pool has to grow. It is the metric that predicts a pool
Expand Down Expand Up @@ -333,7 +339,8 @@ async def metrics_endpoint():
**Grafana Dashboard Example:**

```promql
# Pool utilization
# Pool utilization against pool_size -- above 100 while overflow connections are in use;
# the hard ceiling is pool_size + max_overflow
(myapp_postgres_db_pool_checked_out / myapp_postgres_db_pool_size) * 100

# P95 wait for a connection -- the one to alert on
Expand Down
2 changes: 2 additions & 0 deletions sqlalchemy_foundation_kit/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -33,6 +33,7 @@
CheckoutRecorder,
CheckoutWaitRecorder,
ErrorRecorder,
PoolStatsFunctionRecorder,
PoolStatsRecorder,
PostgresMetricsProtocol,
)
Expand Down Expand Up @@ -92,6 +93,7 @@
"CheckoutRecorder",
"CheckoutWaitRecorder",
"ErrorRecorder",
"PoolStatsFunctionRecorder",
"PoolStatsRecorder",
"PostgresMetricsProtocol",
# Session Management
Expand Down
24 changes: 20 additions & 4 deletions sqlalchemy_foundation_kit/contrib/metrics/postgres.py
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@
from __future__ import annotations

import re
from collections.abc import Callable

try:
from prometheus_client import Counter, Gauge, Histogram
Expand Down Expand Up @@ -59,9 +60,9 @@ class PostgresMetrics:
"""Postgres connection pool metrics.

Metrics:
- postgres_db_pool_size: Current database connection pool size.
- postgres_db_pool_size: Configured pool_size of the connection pool.
- postgres_db_pool_checked_out: Number of connections currently checked out.
- postgres_db_pool_overflow: Number of connections over pool_size (within max_overflow).
- postgres_db_pool_overflow: Number of open connections over pool_size (within max_overflow).
- postgres_db_connection_checkout_wait_seconds: Time a caller waited for a connection.
- postgres_db_connection_held_duration_seconds: Time a connection was held by its caller.
- postgres_db_connection_checkout_duration_seconds: Deprecated alias of the held duration,
Expand All @@ -72,6 +73,10 @@ class PostgresMetrics:
Labels:
- error_type: Type of connection error (for errors_total).

The three pool gauges are read from the pool when the registry is collected, not
sampled from pool events, so an idle pool reports what it holds. One instance reports
one engine: attached to a second engine, the gauges follow the second.

The wait histogram and the timeout counter are fed by the instrumented pool class the
session manager builds, so they only move on an engine created by
``AsyncSessionManager`` (or one whose pool went through ``instrument_pool_class``).
Expand All @@ -90,15 +95,15 @@ def __init__(self, prefix: str | None = None) -> None:

self.pool_size = Gauge(
_make_metric_name("postgres_db_pool_size", prefix),
"Current database connection pool size",
"Configured pool_size of the database connection pool",
)
self.pool_checked_out = Gauge(
_make_metric_name("postgres_db_pool_checked_out", prefix),
"Number of database connections currently checked out",
)
self.pool_overflow = Gauge(
_make_metric_name("postgres_db_pool_overflow", prefix),
"Number of connections over pool_size (within max_overflow)",
"Number of open connections over pool_size (within max_overflow)",
)
self.connection_checkout_wait = Histogram(
_make_metric_name("postgres_db_connection_checkout_wait_seconds", prefix),
Expand Down Expand Up @@ -136,6 +141,17 @@ def record_pool_stats(
self.pool_checked_out.set(float(pool_checked_out))
self.pool_overflow.set(float(pool_overflow))

def set_pool_stats_functions(
self,
pool_size: Callable[[], float],
pool_checked_out: Callable[[], float],
pool_overflow: Callable[[], float],
) -> None:
"""Read the pool gauges from these functions whenever the registry is collected."""
self.pool_size.set_function(pool_size)
self.pool_checked_out.set_function(pool_checked_out)
self.pool_overflow.set_function(pool_overflow)

def record_checkout(
self,
duration: float,
Expand Down
2 changes: 2 additions & 0 deletions sqlalchemy_foundation_kit/protocols/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@
CheckoutRecorder,
CheckoutWaitRecorder,
ErrorRecorder,
PoolStatsFunctionRecorder,
PoolStatsRecorder,
PostgresMetricsProtocol,
)
Expand All @@ -18,6 +19,7 @@
"CheckoutRecorder",
"CheckoutWaitRecorder",
"ErrorRecorder",
"PoolStatsFunctionRecorder",
"PoolStatsRecorder",
"PostgresMetricsProtocol",
]
47 changes: 45 additions & 2 deletions sqlalchemy_foundation_kit/protocols/metrics.py
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@

from __future__ import annotations

from collections.abc import Callable
from typing import Protocol, runtime_checkable


Expand All @@ -21,10 +22,51 @@ def record_pool_stats(
) -> None:
"""Record database connection pool statistics.

Called from the pool's ``checkout`` and ``checkin`` events, so each call describes
the pool as that event saw it -- and ``checkin`` fires before the connection is
back, so the last call of a burst still counts it as checked out. A recorder that
also implements :class:`PoolStatsFunctionRecorder` reads the pool when it is
collected instead, and this method is then not called.

Args:
pool_size: Current total number of connections in the pool.
pool_size: The configured ``pool_size`` of a queue pool, 0 for any other pool.
pool_checked_out: Number of connections currently in use.
pool_overflow: Number of connections over the configured pool_size.
pool_overflow: Number of open connections over ``pool_size``, within
``max_overflow``; never negative.
"""
...


@runtime_checkable
class PoolStatsFunctionRecorder(Protocol):
"""Capability protocol for reading pool statistics when the metrics are collected.

A gauge sampled from pool events goes stale: the ``checkin`` event fires before the
connection is returned, and nothing fires once the pool is idle, so an idle pool keeps
reporting the last burst. A recorder that implements this protocol is handed
functions that read the pool on demand -- ``prometheus_client``'s
``Gauge.set_function`` -- and :class:`PoolStatsRecorder` is then not used for it.

Not part of :class:`PostgresMetricsProtocol`, so implementations written without it
stay valid; the session manager tests for it with ``isinstance``.
"""

def set_pool_stats_functions(
self,
pool_size: Callable[[], float],
pool_checked_out: Callable[[], float],
pool_overflow: Callable[[], float],
) -> None:
"""Read the pool statistics from these functions whenever they are collected.

Each function reads the engine's current pool, so the pool that ``dispose()``
creates is the one reported. Values mean the same as in
:meth:`PoolStatsRecorder.record_pool_stats`.

Args:
pool_size: Returns the configured ``pool_size``.
pool_checked_out: Returns the number of connections currently in use.
pool_overflow: Returns the number of open connections over ``pool_size``.
"""
...

Expand Down Expand Up @@ -104,6 +146,7 @@ class PostgresMetricsProtocol(PoolStatsRecorder, CheckoutRecorder, ErrorRecorder
"CheckoutRecorder",
"CheckoutWaitRecorder",
"ErrorRecorder",
"PoolStatsFunctionRecorder",
"PoolStatsRecorder",
"PostgresMetricsProtocol",
]
46 changes: 42 additions & 4 deletions sqlalchemy_foundation_kit/session/manager.py
Original file line number Diff line number Diff line change
Expand Up @@ -21,10 +21,11 @@

from .._typing import SessionT
from ..base import build_engine_kwargs, resolve_pool_class
from ..protocols import CheckoutWaitRecorder
from ..protocols import CheckoutWaitRecorder, PoolStatsFunctionRecorder

if TYPE_CHECKING:
from sqlalchemy.engine import Connection
from sqlalchemy.pool import Pool

from ..config import PoolSettingsProtocol
from ..protocols import PostgresMetricsProtocol
Expand Down Expand Up @@ -54,6 +55,25 @@ def _safe_metric_call(func: Callable[[], None], error_msg: str) -> None:
logger.exception(error_msg)


def _pool_size(pool: Pool) -> int:
"""The configured ``pool_size`` of a queue pool, 0 for a pool without one."""
return int(pool.size()) if hasattr(pool, "size") else 0


def _pool_checked_out(pool: Pool) -> int:
"""Connections currently in use."""
return int(pool.checkedout()) if hasattr(pool, "checkedout") else 0


def _pool_overflow(pool: Pool) -> int:
"""Open connections over ``pool_size``.

``QueuePool.overflow()`` starts at ``-pool_size`` and counts every connection the pool
opens, so it is negative until the pool has grown past ``pool_size``.
"""
return max(int(pool.overflow()), 0) if hasattr(pool, "overflow") else 0


def instrument_pool_class(pool_class: type, metrics: CheckoutWaitRecorder) -> type:
"""Build a pool class that times the wait for a connection and counts pool timeouts.

Expand Down Expand Up @@ -121,6 +141,12 @@ def attach_metrics(engine: AsyncEngine, metrics: PostgresMetricsProtocol) -> Non
Registers event handlers for connection checkout, checkin, and error events
to collect pool statistics and connection metrics.

The pool gauges come from the pool itself: a ``metrics`` that implements
``PoolStatsFunctionRecorder`` is handed functions that read ``engine.pool`` whenever
the metrics are collected, so an idle pool reports what it holds rather than its last
burst, and a pool recreated by ``dispose()`` is the one read. One that only implements
``record_pool_stats`` is sampled from the ``checkout`` and ``checkin`` events instead.

The checkout wait and the pool checkout timeout are **not** listeners — no pool event
fires for either — and come from the pool class :func:`instrument_pool_class` builds.
If ``metrics`` records the wait but the engine's pool was built without it, that is
Expand All @@ -142,12 +168,24 @@ def attach_metrics(engine: AsyncEngine, metrics: PostgresMetricsProtocol) -> Non
type(pool).__name__,
)

reads_pool_on_collect = False
if isinstance(metrics, PoolStatsFunctionRecorder):
reads_pool_on_collect = True
# engine.pool is looked up on every read: dispose() replaces the pool object.
metrics.set_pool_stats_functions(
pool_size=lambda: _pool_size(engine.pool),
pool_checked_out=lambda: _pool_checked_out(engine.pool),
pool_overflow=lambda: _pool_overflow(engine.pool),
)

def record_pool_stats() -> None:
if reads_pool_on_collect:
return
_safe_metric_call(
lambda: metrics.record_pool_stats(
pool_size=pool.size() if hasattr(pool, "size") else 0,
pool_checked_out=(pool.checkedout() if hasattr(pool, "checkedout") else 0),
pool_overflow=pool.overflow() if hasattr(pool, "overflow") else 0,
pool_size=_pool_size(pool),
pool_checked_out=_pool_checked_out(pool),
pool_overflow=_pool_overflow(pool),
),
"Failed to record database pool stats",
)
Expand Down
Loading
Loading