From 4e2d936c274cfd8ee56cc008a60da494f4d920c2 Mon Sep 17 00:00:00 2001 From: taylanbakircioglu Date: Sat, 15 Aug 2026 11:04:30 +0300 Subject: [PATCH] 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. --- backend/database/migrations.py | 1 + backend/middleware/request_logger.py | 30 ++++++++++++++++++++++++++- backend/routers/request_logs.py | 27 ++++++++++++++++++++---- backend/utils/request_log_settings.py | 16 ++++++++++++++ backend/utils/request_log_sink.py | 24 +++++++++++++++++++++ frontend/src/components/Settings.js | 8 +++++++ 6 files changed, 101 insertions(+), 5 deletions(-) diff --git a/backend/database/migrations.py b/backend/database/migrations.py index bdd7944..c235975 100644 --- a/backend/database/migrations.py +++ b/backend/database/migrations.py @@ -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'), diff --git a/backend/middleware/request_logger.py b/backend/middleware/request_logger.py index 7cfc6ce..1e54494 100644 --- a/backend/middleware/request_logger.py +++ b/backend/middleware/request_logger.py @@ -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, diff --git a/backend/routers/request_logs.py b/backend/routers/request_logs.py index 7ba6a35..6f23c6c 100644 --- a/backend/routers/request_logs.py +++ b/backend/routers/request_logs.py @@ -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. diff --git a/backend/utils/request_log_settings.py b/backend/utils/request_log_settings.py index 6c351bf..dc05e82 100644 --- a/backend/utils/request_log_settings.py +++ b/backend/utils/request_log_settings.py @@ -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), diff --git a/backend/utils/request_log_sink.py b/backend/utils/request_log_sink.py index 9d27e04..64e8bc1 100644 --- a/backend/utils/request_log_sink.py +++ b/backend/utils/request_log_sink.py @@ -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 diff --git a/frontend/src/components/Settings.js b/frontend/src/components/Settings.js index 523e282..e5e6b1b 100644 --- a/frontend/src/components/Settings.js +++ b/frontend/src/components/Settings.js @@ -493,6 +493,14 @@ const Settings = () => { > + + +