mirror of
https://github.com/taylanbakircioglu/haproxy-openmanager.git
synced 2026-09-16 15:45:11 +00:00
fix(requestlog): stop the table size from scaling with fleet size
The row rate of `request_logs` was a function of how many nodes are installed,
not of what anyone did. Counted from the agent loop in linux_install.sh, each
agent's 30s cycle issues three logged calls - config, pending-requests,
upgrade-status (the heartbeat is already on the default exclude list) - plus
keepalived-config and keepalived-status every fifth cycle. That is ~9 800
rows/day per agent, essentially all of them 200s meaning "nothing changed".
Measured on PostgreSQL 15 against the real DDL and all nine indexes, at 2 424
bytes/row:
20 agents ~196k rows/day 453 MB/day row cap reached in 2.5 days
200 agents ~2.0M rows/day 4.4 GB/day row cap reached in 6 hours
500 agents ~4.9M rows/day 11 GB/day row cap reached in 2 hours
The cap holds, so nothing runs away - but it holds by deleting, and what it
deletes is everything else. The shipped policy says 7 days of successes and 30
days of failures; on a 200-node fleet it delivers about six HOURS of both. The
forensic record the feature exists for is evicted by polling noise, and the
larger the installation the less history it keeps.
`requestlog.capture_agent_success`, default FALSE: a SUCCESSFUL inbound call
from an agent is not recorded. Failures always are, whatever the flag says -
they are what an operator needs and they are rare, so they cost nothing. With
this the table's size follows operator activity, and adding nodes does not
shorten anyone's retention.
Agent traffic is identified by header only, no database round-trip on the hot
path: the installed agent sends `X-API-Key` and never `Authorization`, the UI
sends a JWT and never an agent key. `generate-install-script`, the one endpoint
that accepts either, classifies correctly under the same rule - an operator
generating a script sends Authorization, a self-upgrading agent sends only the
key. The result is stored in the existing `target` column, which already means
"who was on the other end" for outbound rows and now means the same for inbound
ones, so no schema change and the existing target index applies.
Second half, and the reason this is one commit: `operator` holds
`requestlog.read` because, per the migration that grants it, "operators debug
failing applies and ACME orders". They could not. An apply fails on the NODE,
and the node reports that over its own API key, so the row carrying the
diagnosis has `user_id IS NULL` - and own-rows-only scoping hid it from exactly
the role the grant was written for. Scoping now admits agent rows alongside the
caller's own. Deliberately keyed on `target = 'agent'` rather than `user_id IS
NULL`: anonymous traffic is not agent traffic, so failed logins and their
usernames, and unauthenticated probes, stay admin-only.
Verified end to end through the real middleware: a successful agent poll is
dropped, a 422 from config-validation-failed is kept, operator and anonymous
calls are unaffected, and flipping the setting on restores the old behaviour.
This commit is contained in:
@@ -2154,6 +2154,7 @@ async def ensure_request_log_settings():
|
||||
('requestlog.capture_outbound', 'true', 'requestlog', 'Log outbound HTTP calls made by the backend'),
|
||||
('requestlog.capture_bodies', 'true', 'requestlog', 'Capture redacted, size-capped request/response bodies'),
|
||||
('requestlog.capture_get', 'true', 'requestlog', 'Log inbound GET requests'),
|
||||
('requestlog.capture_agent_success', 'false', 'requestlog', 'Log SUCCESSFUL agent polls too (failures are always logged); off by default because the row rate scales with fleet size, not operator activity'),
|
||||
('requestlog.max_body_bytes', '8192', 'requestlog', 'Per-body capture cap in bytes'),
|
||||
('requestlog.sample_rate', '1.0', 'requestlog', 'Sampling rate for successful inbound requests (errors always 1.0)'),
|
||||
('requestlog.exclude_paths', '["/api/request-logs","/api/health","/api/docs","/api/redoc","/api/openapi.json","/.well-known/acme-challenge","/api/agents/heartbeat","/static","/favicon.ico"]', 'requestlog', 'Path prefixes that are never logged'),
|
||||
|
||||
@@ -32,7 +32,12 @@ from starlette.types import ASGIApp, Receive, Scope, Send
|
||||
from utils.logging_config import correlation_id_context
|
||||
from utils.request_log_redaction import is_capturable_content_type, scrub_query_string
|
||||
from utils.request_log_settings import get_config
|
||||
from utils.request_log_sink import RequestLogRow, request_id_context, request_log_sink
|
||||
from utils.request_log_sink import (
|
||||
TARGET_INBOUND_AGENT,
|
||||
RequestLogRow,
|
||||
request_id_context,
|
||||
request_log_sink,
|
||||
)
|
||||
|
||||
logger = logging.getLogger("haproxy_openmanager.request_log")
|
||||
|
||||
@@ -88,6 +93,25 @@ def _identify(scope: Scope) -> Tuple[Optional[int], Optional[str]]:
|
||||
return user_id, (str(username) if username else None)
|
||||
|
||||
|
||||
def _is_agent_call(scope: Scope) -> bool:
|
||||
"""True when the caller authenticated as an AGENT rather than as a user.
|
||||
|
||||
Every call the installed agent makes carries `X-API-Key` and never an
|
||||
`Authorization` header (linux_install.sh / macos_install.sh: heartbeat,
|
||||
config, pending-requests, upgrade-status, keepalived-*, config-response are
|
||||
all `-H "X-API-Key: $AGENT_TOKEN"`), while the UI carries a JWT and never an
|
||||
agent key. The one endpoint that accepts either -
|
||||
`POST /api/agents/generate-install-script`, used by agent self-upgrade -
|
||||
is correctly classified by the same rule: an operator generating a script
|
||||
sends Authorization, the self-upgrading agent sends only the key.
|
||||
|
||||
Header-only, so it costs two scope reads and no database round-trip.
|
||||
"""
|
||||
if _header(scope, b"authorization"):
|
||||
return False
|
||||
return bool(_header(scope, b"x-api-key"))
|
||||
|
||||
|
||||
def _client_ip(scope: Scope) -> Optional[str]:
|
||||
"""The peer address only.
|
||||
|
||||
@@ -269,6 +293,10 @@ class RequestResponseLogMiddleware:
|
||||
RequestLogRow(
|
||||
request_id=request_id,
|
||||
direction="inbound",
|
||||
# Who was on the other end. `offer()` uses this to drop
|
||||
# SUCCESSFUL agent polls, which are ~9 800 rows/day per node and
|
||||
# would otherwise make the table's size a function of fleet size.
|
||||
target=TARGET_INBOUND_AGENT if _is_agent_call(scope) else None,
|
||||
method=method,
|
||||
url=path + (("?" + scrubbed_query) if scrubbed_query else ""),
|
||||
path=path,
|
||||
|
||||
@@ -43,7 +43,7 @@ from utils.request_log_settings import (
|
||||
refresh_config,
|
||||
set_config,
|
||||
)
|
||||
from utils.request_log_sink import request_log_sink
|
||||
from utils.request_log_sink import TARGET_INBOUND_AGENT, request_log_sink
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
@@ -69,6 +69,7 @@ class RequestLogSettings(BaseModel):
|
||||
capture_outbound: bool = True
|
||||
capture_bodies: bool = True
|
||||
capture_get: bool = True
|
||||
capture_agent_success: bool = False
|
||||
max_body_bytes: int = Field(8192, ge=0, le=262144)
|
||||
sample_rate: float = Field(1.0, ge=0.0, le=1.0)
|
||||
exclude_paths: List[str] = Field(
|
||||
@@ -396,11 +397,25 @@ async def list_request_logs(
|
||||
|
||||
# Self-scoping. Captured bodies are a broader disclosure surface than the
|
||||
# existing activity log, so a caller holding only `requestlog.read` sees
|
||||
# their OWN inbound requests and nothing else. `requestlog.manage` (and the
|
||||
# their OWN inbound requests, plus the fleet's. `requestlog.manage` (and the
|
||||
# is_admin bypass inside it) lifts the restriction.
|
||||
#
|
||||
# The agent clause is not a widening for its own sake, it is what makes the
|
||||
# `operator` grant do what the migration says it is for: "operators debug
|
||||
# failing applies and ACME orders, so they get read access to the request
|
||||
# log". An apply fails on the NODE, and the node reports that back over its
|
||||
# own API key - so the row carrying the diagnosis is an agent row with
|
||||
# `user_id IS NULL`, which own-rows-only scoping hid from exactly the role
|
||||
# the grant was written for. Scoped on `target`, not on `user_id IS NULL`:
|
||||
# anonymous inbound traffic (failed logins and their usernames, unauthorised
|
||||
# probes) is NOT agent traffic and stays admin-only.
|
||||
if not can_manage:
|
||||
params.append(current_user["id"])
|
||||
where.append(f"(direction = 'inbound' AND user_id = ${len(params)})")
|
||||
own = f"user_id = ${len(params)}"
|
||||
params.append(TARGET_INBOUND_AGENT)
|
||||
where.append(
|
||||
f"(direction = 'inbound' AND ({own} OR target = ${len(params)}))"
|
||||
)
|
||||
|
||||
where_sql = (" WHERE " + " AND ".join(where)) if where else ""
|
||||
|
||||
@@ -466,7 +481,11 @@ async def get_request_log(log_id: int, authorization: Optional[str] = Header(Non
|
||||
record["client_ip"] = record.pop("client_ip_text", None)
|
||||
|
||||
if not can_manage and not (
|
||||
record.get("direction") == "inbound" and record.get("user_id") == current_user["id"]
|
||||
record.get("direction") == "inbound"
|
||||
and (
|
||||
record.get("user_id") == current_user["id"]
|
||||
or record.get("target") == TARGET_INBOUND_AGENT
|
||||
)
|
||||
):
|
||||
# Same self-scoping rule as the list endpoint. 404 rather than 403
|
||||
# so the endpoint does not confirm that a given id exists.
|
||||
|
||||
@@ -49,6 +49,17 @@ class RequestLogConfig:
|
||||
capture_outbound: bool = True
|
||||
capture_bodies: bool = True
|
||||
capture_get: bool = True
|
||||
# SUCCESSFUL agent polls only. Off by default because the row rate of this
|
||||
# table is otherwise a linear function of fleet size, not of operator
|
||||
# activity: each agent runs a 30s cycle that issues three logged calls
|
||||
# (config, pending-requests, upgrade-status; the heartbeat is already
|
||||
# excluded) plus two more every fifth cycle. Measured, that is ~9 800 rows
|
||||
# per day PER AGENT, so a 200-node fleet writes ~2M rows/day and reaches the
|
||||
# 500 000 max_rows cap in about six hours - at which point the shipped
|
||||
# "7 days of successes, 30 days of failures" is not 7 and 30, it is 0.25.
|
||||
# FAILED agent calls are always kept regardless of this flag: they are the
|
||||
# half an operator actually needs, and they are rare.
|
||||
capture_agent_success: bool = False
|
||||
max_body_bytes: int = 8192
|
||||
sample_rate: float = 1.0
|
||||
exclude_paths: Tuple[str, ...] = DEFAULT_EXCLUDE_PATHS
|
||||
@@ -64,6 +75,7 @@ class RequestLogConfig:
|
||||
"capture_outbound": self.capture_outbound,
|
||||
"capture_bodies": self.capture_bodies,
|
||||
"capture_get": self.capture_get,
|
||||
"capture_agent_success": self.capture_agent_success,
|
||||
"max_body_bytes": self.max_body_bytes,
|
||||
"sample_rate": self.sample_rate,
|
||||
"exclude_paths": list(self.exclude_paths),
|
||||
@@ -171,6 +183,10 @@ def config_from_mapping(values: Dict[str, Any], base: Optional[RequestLogConfig]
|
||||
capture_outbound=_as_bool(values.get("capture_outbound", base.capture_outbound), base.capture_outbound),
|
||||
capture_bodies=_as_bool(values.get("capture_bodies", base.capture_bodies), base.capture_bodies),
|
||||
capture_get=_as_bool(values.get("capture_get", base.capture_get), base.capture_get),
|
||||
capture_agent_success=_as_bool(
|
||||
values.get("capture_agent_success", base.capture_agent_success),
|
||||
base.capture_agent_success,
|
||||
),
|
||||
max_body_bytes=_clamp_int(values.get("max_body_bytes", base.max_body_bytes), "max_body_bytes", base.max_body_bytes),
|
||||
sample_rate=_clamp_float(values.get("sample_rate", base.sample_rate), base.sample_rate, 0.0, 1.0),
|
||||
exclude_paths=normalize_exclude_paths(values.get("exclude_paths"), base.exclude_paths),
|
||||
|
||||
@@ -40,6 +40,15 @@ request_id_context: ContextVar[Optional[str]] = ContextVar(
|
||||
"request_log_request_id", default=None
|
||||
)
|
||||
|
||||
# `target` on an INBOUND row means the same thing it means on an outbound one:
|
||||
# who was on the other end. Set by the middleware when the caller authenticated
|
||||
# with an agent API key rather than a user JWT, which is how agent traffic is
|
||||
# told apart from operator traffic without a database lookup on the hot path.
|
||||
# Deliberately the same literal as http_instrumentation.TARGET_AGENT, so
|
||||
# `target = 'agent'` selects the whole conversation with the fleet in both
|
||||
# directions; `direction` separates them when that matters.
|
||||
TARGET_INBOUND_AGENT = "agent"
|
||||
|
||||
_INSERT_SQL = """
|
||||
INSERT INTO request_logs (
|
||||
request_id, direction, target, method, url, path, query_params,
|
||||
@@ -203,6 +212,21 @@ class RequestLogSink:
|
||||
return
|
||||
if row.direction == "outbound" and not cfg.capture_outbound:
|
||||
return
|
||||
# Fleet-scale gate, and the reason this table's size is a function of
|
||||
# operator activity rather than of node count. An agent's 30s cycle
|
||||
# issues three logged calls, plus two more every fifth cycle: ~9 800
|
||||
# rows/day PER AGENT, all of them 200s saying "nothing changed". At a
|
||||
# few hundred nodes that is millions of rows a day, and the row cap is
|
||||
# then reached in hours, which silently shortens the configured
|
||||
# retention for EVERYTHING else in the table - including the failures
|
||||
# the log exists for. Successes are dropped, failures never are.
|
||||
if (
|
||||
row.direction == "inbound"
|
||||
and row.target == TARGET_INBOUND_AGENT
|
||||
and not cfg.capture_agent_success
|
||||
and row.status_class in (1, 2, 3)
|
||||
):
|
||||
return
|
||||
if (
|
||||
row.direction == "inbound"
|
||||
and cfg.sample_rate < 1.0
|
||||
|
||||
@@ -493,6 +493,14 @@ const Settings = () => {
|
||||
>
|
||||
<Switch />
|
||||
</Form.Item>
|
||||
<Form.Item
|
||||
name="capture_agent_success"
|
||||
label="Include successful agent polls"
|
||||
valuePropName="checked"
|
||||
tooltip="Each agent writes about 9,800 rows a day just saying nothing changed, so on a large fleet this fills the row cap in hours and shortens retention for everything else. FAILED agent calls are always logged regardless. Turn this on only while debugging a specific node, and turn it back off."
|
||||
>
|
||||
<Switch />
|
||||
</Form.Item>
|
||||
<Form.Item
|
||||
name="capture_bodies"
|
||||
label="Capture bodies (redacted)"
|
||||
|
||||
Reference in New Issue
Block a user