Skip to content

blackbull.server.cap_log

blackbull.server.cap_log

Cap-hit observability.

Every user-tunable resource cap in BlackBull (header sizes, the four timeouts, connection cap, WS frame cap, WS queue depth, H/2 stream caps, compression in-flight) is silent by default when it rejects traffic. Operators see the consequence — a 503, a CLOSE 1009, a dropped event — but no record naming the cap. Regressions like the 1 MiB WS frame default that shipped in v0.35.0 (caught by the Sprint 43 conformance lane in v0.39.0) can hide across releases.

This module emits one WARNING-level record per cap rejection on the blackbull.caps logger so a deployment that subscribes to that logger gets actionable visibility without grep-walking the framework code.

Surface:

  • :func:log_cap_hit — the single emission point. Call from any cap-rejection site with the cap name, requested value, and limit.
  • :class:CapHitCounter — per-connection state for the "first hit per cap logs in full; later hits silently counted; summary on :meth:~CapHitCounter.flush" rate-limit pattern.
  • :meth:CapHitCounter.bind — context manager that installs the counter on a :class:~contextvars.ContextVar. All :func:log_cap_hit calls inside the with block (including those in child tasks created via :class:asyncio.TaskGroup, which inherit context) automatically pick up the counter. Zero plumbing through actor constructors.

Every emitted record carries a connection_id so SIEM / log-aggregation pipelines can correlate first-hit, intermediate summary, and graceful-close summary records that all belong to the same connection — useful when peer is shared across many clients behind a NAT.

The counter also runs two dirty-flush triggers so a connection torn down by RST (or any abnormal path that skips graceful :meth:flush) still emits a summary for any suppressed hits:

  • Threshold trigger: after flush_threshold suppressed hits on any single cap, emit an intermediate summary and reset counts. Default 100; set to 0 to disable.
  • Interval trigger: an asyncio timer task started on the first suppressed hit emits an intermediate summary after flush_interval seconds if any cap still has suppressed hits. Default 60.0 s; set to 0 to disable.

Design recap in .claude/planning/candidates/cap-hit-logging.md.

CapHitCounter

Per-connection state for cap-hit rate limiting.

Construct one instance per connection (typically in :class:~blackbull.server.connection_actor.ConnectionActor), install it as the ambient counter for the duration of the connection via the :meth:bind context manager, and call :meth:flush once when the connection closes so a single summary record reports any suppressed hits.

Two dirty-flush triggers fire intermediate summaries even when :meth:flush is never called (e.g. RST close that skips the graceful path):

  • flush_threshold (default 100) — after this many suppressed hits on any single cap, emit and reset. Set to 0 to disable.
  • flush_interval (default 60.0 s) — an asyncio timer that emits and resets after this many seconds if any cap has suppressed hits. Set to 0 to disable.

connection_id property

Read-only access to the counter's connection id.

bind()

Context manager that installs self as the ambient counter.

Usage::

counter = CapHitCounter()
with counter.bind():
    ...                       # all log_cap_hit() in here uses *counter*
    # tasks created via asyncio.TaskGroup inherit it too

flush(*, peer=None, protocol=None, connection_id=None)

Emit one summary record per cap that had suppressed hits.

Caps with zero suppressed hits (fired exactly once, or already emitted via an intermediate summary) are omitted. Cancels the interval timer and clears all state — the counter is safe to reuse afterwards if the holder is pooled.

log_cap_hit(cap, requested, limit, *, counter=None, peer=None, scope_path=None, protocol=None, connection_id=None)

Emit one cap-hit record on blackbull.caps at WARN level.

The structured fields land in record.extra (cap, requested, limit, peer, scope_path, protocol, connection_id) so log handlers can route or aggregate without parsing the message string.

Resolution order for the rate-limit counter:

  1. The explicit counter keyword argument, if given.
  2. The active :class:CapHitCounter from the ambient :class:~contextvars.ContextVar (set via :meth:CapHitCounter.bind).
  3. None — every call emits, no rate limiting.

connection_id resolution mirrors the counter chain:

  1. The explicit connection_id keyword argument, if given.
  2. The active counter's :attr:CapHitCounter.connection_id.
  3. None — record carries connection_id=None.

The first call per (counter, cap) emits a full record; subsequent calls return silently and increment the counter's suppression tally. counter.flush() at connection close emits one summary per suppressed cap.