PST-004: The JSON log records the full request line, so query strings and URL-path tokens reach the log file, the Logs page and the log collector #733

New issue

Closed

opened 2026-10-10 10:55:44 +00:00 by tiagoagueda · 0 comments

tiagoagueda commented

2026-10-10 10:55:44 +00:00

Owner

Found in the security audit of 2026-10-10 (SECURITY-AUDIT-2026-10-10.md), run against main at c30851b from 8 to 10 October 2026, as PST-004. Severity: Medium.

The text below is the audit's entry, unchanged apart from links to the other issues it names. The finding was produced by automated review and checked by a second automated pass; re-check it before acting on it.

Severity: Medium
Category: logging-of-personal-data / log-injection
Location: src/postulo/core/logs.py (155-181)
Found by: administrator surface and plugins, information disclosure
Related: PST-025 (#754), PST-068 (#797)

Who can do it, and what they need. (a) Any administrator reading Server settings → Logs, or any party holding POSTULO_LOGS_TOKEN (a remote log collector), learns what members typed into GET parameters of requests that ended in a 4xx. (b) An unauthenticated stranger who can reach the instance can write arbitrary text into the administrator-facing log and evict real records. Precondition for (a): POSTULO_LOG_DIR set (the default), which is also what the Logs page and /logs need; for (b): nothing.

How it works.

Django's log_response() logs every response with status >= 400 to the django.request logger with extra={"status_code": ..., "request": request}. JSONFormatter.format iterates record.__dict__, skips only the STANDARD names, and for a value json.dumps cannot encode falls back to repr(value); HttpRequest.__repr__ is <WSGIRequest: GET '/path?query'>, i.e. get_full_path() with the query string. Verified with a scratch test: GET /no-such-page/?note=QS-MARKER&q=trade+union produced the JSON record {"logger": "django.request", "message": "Not Found: /no-such-page/", "request": "<WSGIRequest: GET '/no-such-page/?note=QS-MARKER-7f3a9c&q=trade+union'>", "status_code": 404}; GET /api/v1/search?q=API-QS-MARKER without a token (401) logged the search term; GET /career/skills/suggestions/?name=shop-steward-xyz after the suggestion rate was spent (429) logged what the member was typing in the skill box. LogsView renders record.extras under “More” on the admin page, and collect() in views_logs.py spreads **record.extras into every NDJSON line handed to the collector. Real cases: an API client whose token was revoked or expired keeps sending GET /api/v1/search?q=… and GET /api/v1/listings?… (401 each time, every query logged); a member hits the skill-suggestion limit (what they typed is logged); any bookmarked table/filter URL that 404s. For (b) a stranger requests /x?msg=<anything> thousands of times: each is a WARNING on the admin page, and with 5 MB × 3 rotations the genuine records are rotated away.

Impact. Text members typed (search terms, skill names, filter values) and API search queries reach the instance log, the administrator's Logs page and any external collector — exactly the class of leak the project removed for httpx (#548) and promises never happens for special-category data ("never in a log"). The same channel lets an unauthenticated party inject noise into the administrator's view and push real records out of the rotation.

Evidence.

src/postulo/core/logs.py:169-180: `for key, value in record.__dict__.items(): if key in STANDARD or key.startswith("_"): continue ... try: json.dumps(value) except (TypeError, ValueError): value = repr(value); payload[key] = value`. src/postulo/core/views_logs.py:166-173: `json.dumps({"time": record.time, ..., **record.extras}, ...)`. src/postulo/templates/server/logs.html:113-115: `{% for key, value in record.extras.items %} ... <dd class="break-all"><code>{{ value }}</code></dd>`. Scratch test output: `EXTRAS: {'request': "<WSGIRequest: GET '/no-such-page/?note=QS-MARKER-7f3a9c&q=trade+union'>", 'status_code': 404}`; `('django.request', 'Unauthorized: /api/v1/search', {'request': "<WSGIRequest: GET '/api/v1/search?q=API-QS-MARKER-11aa'>", ...})`; `('django.request', 'Too Many Requests: /career/skills/suggestions/', {'request': "<WSGIRequest: GET '/career/skills/suggestions/?name=shop-steward-xyz'>", ...})`.

Verification (verdict: confirmed; severity after verification: Medium).

End-to-end reproduction against the real file handler the test settings configure (same SharedRotatingFileHandler + JSONFormatter as production). Django's log_response (django/utils/log.py, 6.1.1) logs every response >= 400 to django.request with extra={'status_code', 'request'}; Postulo's LOGGING (config/settings/base.py:798-858) defines no 'django' or 'django.request' logger and no filter, so the record propagates to root and to the 'file' handler; JSONFormatter.format (core/logs.py:169-180) keeps every non-STANDARD attribute and falls back to repr() for anything json.dumps refuses, and HttpRequest.repr is '<WSGIRequest: GET %r>' % get_full_path(), query string included. A 404 from an anonymous visitor, a 401 on /api/v1/search with a stale token, and a 429 on /career/skills/suggestions/ each wrote the full query string to postulo.log; LogsView renders record.extras under 'More' and the /logs collector spreads **record.extras into every NDJSON line. No mitigation exists: the console line (docker logs) does not carry extras, which is why nobody noticed, but the file, the admin page and the collector do. The project's own standard treats this class as security (CHANGELOG #548 removed httpx URL lines because 'staff and a log collector could read other people's ... addresses'), and the suggestions view's docstring (resume/views.py:163-164) promises what was typed 'never goes anywhere but the search', which the 429 line breaks. Readers are the operator's administrators and the collector, which bounds the scope: the threat model trusts administrators with the instance but draws the line at members' content ('never anyone's applications or documents'). I found no query parameter that carries a secret (OAuth callbacks redirect on every outcome; API tokens travel in headers), so this is typed text and filter values, not credentials. The log-injection/eviction half (b) is real but is noise a stranger can write into any Django log via 4xx lines; the threat model puts DoS out of scope, and json.dumps plus get_full_path's escaping mean no line splitting or HTML injection (the template autoescapes {{ value }}).

Corrections from verification. Bottom of medium: deterministic disclosure on every 4xx, but only to the instance's own administrators (the Logs page) and the operator-configured collector, and nothing I found puts a credential in a query string. Precondition for the file/page: POSTULO_LOG_DIR set (the default); for the collector: POSTULO_LOGS_ENDPOINT_ENABLED with a token. Precise consumers: core/logs.py JSONFormatter (the ConsoleFormatter line is unaffected), server_views.py LogsView (lines 506-544), views_logs.py collect (165-176). Remediation: have JSONFormatter drop or reduce the 'request' extra (log request.path, never get_full_path(), and never repr() an HttpRequest), or attach a logging filter to the file handler that strips 'request' from django.request records; add a test in tests/security that a 4xx with a query string leaves no query string in postulo.log, and a changelog note that existing postulo.log* files hold these lines until rotated, as #548 did. The injection/eviction half is informational (out of scope as DoS; a reverse proxy's rate limit is the stated answer).

Verification evidence.

Scratch output: '404 RECORDS: [{"message": "Not Found: /no-such-page/", "level": "WARNING", "request": "<WSGIRequest: GET \'/no-such-page/?note=QS-MARKER-7f3a9c&q=trade+union\'>", "status_code": 404}]' read back with logs.read() from the real postulo.log; '401 RECORDS: [... "request": "<WSGIRequest: GET \'/api/v1/search?q=API-QS-MARKER-11aa\'>" ...]'; '429 RECORDS: [... "message": "Too Many Requests: /career/skills/suggestions/", "request": "<WSGIRequest: GET \'/career/skills/suggestions/?name=shop-steward-xyz\'>" ...]' (POSTULO_SUGGESTION_RATE=1/h, second request by a signed-in member); admin GET /server/logs/?logger=django.request contained PAGE-MARKER-42; 'COLLECTOR LINE: [{"time": ..., "logger": "django.request", "message": "Not Found: /no-such-page/", "request": "<WSGIRequest: GET \'/no-such-page/?note=PAGE-MARKER-42\'>", "status_code": 404}]' from GET /logs with the bearer token. Code: core/logs.py:169-180 `for key, value in record.__dict__.items(): if key in STANDARD or key.startswith("_"): continue ... except (TypeError, ValueError): value = repr(value); payload[key] = value`; django/http/request.py HttpRequest.__repr__ `return "<%s: %s %r>" % (self.__class__.__name__, self.method, self.get_full_path())`; views_logs.py:166-173 `**record.extras`; templates/server/logs.html:113-115 `{% for key, value in record.extras.items %} ... <code>{{ value }}</code>`; resume/views.py:163-164 'What was typed is cut to the length a name may have and never goes anywhere but the search.'; grep for 'django.request' in src/ finds no logger config or filter. POSTULO_LOG_DIR defaults on (base.py:779).

Suggested remediation. In JSONFormatter, drop or reduce the request extra (and anything that is not JSON-serialisable) instead of falling back to repr(): e.g. skip keys whose value is an HttpRequest, or replace it with the path only (request.path) and the request id. Consider also setting django.request/django.security to not carry the request object into the file handler (a logging.Filter that pops record.request). Optionally cap how many 4xx lines per address per minute are written, so a stranger cannot churn the rotation.

Also covered by this issue.

The JSON log file records repr(request) for django.request errors, which embeds the full request path — including a recovery-link or invitation token when a 500 occurs on those routes — and the Logs page shows every extra to all administrators (src/postulo/core/logs.py (155-181); Low). A single-use account-recovery token or invitation token can leak to other administrators and log collectors. Narrow: requires a 500 on exactly those routes while the token is live (one hour / until accepted).

Found in the security audit of 2026-10-10 (`SECURITY-AUDIT-2026-10-10.md`), run against `main` at `c30851b` from 8 to 10 October 2026, as **PST-004**. Severity: **Medium**. The text below is the audit's entry, unchanged apart from links to the other issues it names. The finding was produced by automated review and checked by a second automated pass; re-check it before acting on it. --- - **Severity:** Medium - **Category:** logging-of-personal-data / log-injection - **Location:** `src/postulo/core/logs.py` (155-181) - **Found by:** administrator surface and plugins, information disclosure - **Related:** PST-025 (#754), PST-068 (#797) **Who can do it, and what they need.** (a) Any administrator reading Server settings → Logs, or any party holding POSTULO_LOGS_TOKEN (a remote log collector), learns what members typed into GET parameters of requests that ended in a 4xx. (b) An unauthenticated stranger who can reach the instance can write arbitrary text into the administrator-facing log and evict real records. Precondition for (a): POSTULO_LOG_DIR set (the default), which is also what the Logs page and /logs need; for (b): nothing. **How it works.** Django's `log_response()` logs every response with status >= 400 to the `django.request` logger with `extra={"status_code": ..., "request": request}`. `JSONFormatter.format` iterates `record.__dict__`, skips only the STANDARD names, and for a value `json.dumps` cannot encode falls back to `repr(value)`; `HttpRequest.__repr__` is `<WSGIRequest: GET '/path?query'>`, i.e. `get_full_path()` with the query string. Verified with a scratch test: GET `/no-such-page/?note=QS-MARKER&q=trade+union` produced the JSON record `{"logger": "django.request", "message": "Not Found: /no-such-page/", "request": "<WSGIRequest: GET '/no-such-page/?note=QS-MARKER-7f3a9c&q=trade+union'>", "status_code": 404}`; GET `/api/v1/search?q=API-QS-MARKER` without a token (401) logged the search term; GET `/career/skills/suggestions/?name=shop-steward-xyz` after the suggestion rate was spent (429) logged what the member was typing in the skill box. `LogsView` renders `record.extras` under “More” on the admin page, and `collect()` in views_logs.py spreads `**record.extras` into every NDJSON line handed to the collector. Real cases: an API client whose token was revoked or expired keeps sending `GET /api/v1/search?q=…` and `GET /api/v1/listings?…` (401 each time, every query logged); a member hits the skill-suggestion limit (what they typed is logged); any bookmarked table/filter URL that 404s. For (b) a stranger requests `/x?msg=<anything>` thousands of times: each is a WARNING on the admin page, and with 5 MB × 3 rotations the genuine records are rotated away. **Impact.** Text members typed (search terms, skill names, filter values) and API search queries reach the instance log, the administrator's Logs page and any external collector — exactly the class of leak the project removed for httpx (#548) and promises never happens for special-category data ("never in a log"). The same channel lets an unauthenticated party inject noise into the administrator's view and push real records out of the rotation. **Evidence.** ```text src/postulo/core/logs.py:169-180: `for key, value in record.__dict__.items(): if key in STANDARD or key.startswith("_"): continue ... try: json.dumps(value) except (TypeError, ValueError): value = repr(value); payload[key] = value`. src/postulo/core/views_logs.py:166-173: `json.dumps({"time": record.time, ..., **record.extras}, ...)`. src/postulo/templates/server/logs.html:113-115: `{% for key, value in record.extras.items %} ... <dd class="break-all"><code>{{ value }}</code></dd>`. Scratch test output: `EXTRAS: {'request': "<WSGIRequest: GET '/no-such-page/?note=QS-MARKER-7f3a9c&q=trade+union'>", 'status_code': 404}`; `('django.request', 'Unauthorized: /api/v1/search', {'request': "<WSGIRequest: GET '/api/v1/search?q=API-QS-MARKER-11aa'>", ...})`; `('django.request', 'Too Many Requests: /career/skills/suggestions/', {'request': "<WSGIRequest: GET '/career/skills/suggestions/?name=shop-steward-xyz'>", ...})`. ``` **Verification** (verdict: confirmed; severity after verification: Medium). End-to-end reproduction against the real file handler the test settings configure (same SharedRotatingFileHandler + JSONFormatter as production). Django's log_response (django/utils/log.py, 6.1.1) logs every response >= 400 to django.request with extra={'status_code', 'request'}; Postulo's LOGGING (config/settings/base.py:798-858) defines no 'django' or 'django.request' logger and no filter, so the record propagates to root and to the 'file' handler; JSONFormatter.format (core/logs.py:169-180) keeps every non-STANDARD attribute and falls back to repr() for anything json.dumps refuses, and HttpRequest.__repr__ is '<WSGIRequest: GET %r>' % get_full_path(), query string included. A 404 from an anonymous visitor, a 401 on /api/v1/search with a stale token, and a 429 on /career/skills/suggestions/ each wrote the full query string to postulo.log; LogsView renders record.extras under 'More' and the /logs collector spreads **record.extras into every NDJSON line. No mitigation exists: the console line (docker logs) does not carry extras, which is why nobody noticed, but the file, the admin page and the collector do. The project's own standard treats this class as security (CHANGELOG #548 removed httpx URL lines because 'staff and a log collector could read other people's ... addresses'), and the suggestions view's docstring (resume/views.py:163-164) promises what was typed 'never goes anywhere but the search', which the 429 line breaks. Readers are the operator's administrators and the collector, which bounds the scope: the threat model trusts administrators with the instance but draws the line at members' content ('never anyone's applications or documents'). I found no query parameter that carries a secret (OAuth callbacks redirect on every outcome; API tokens travel in headers), so this is typed text and filter values, not credentials. The log-injection/eviction half (b) is real but is noise a stranger can write into any Django log via 4xx lines; the threat model puts DoS out of scope, and json.dumps plus get_full_path's escaping mean no line splitting or HTML injection (the template autoescapes {{ value }}). **Corrections from verification.** Bottom of medium: deterministic disclosure on every 4xx, but only to the instance's own administrators (the Logs page) and the operator-configured collector, and nothing I found puts a credential in a query string. Precondition for the file/page: POSTULO_LOG_DIR set (the default); for the collector: POSTULO_LOGS_ENDPOINT_ENABLED with a token. Precise consumers: core/logs.py JSONFormatter (the ConsoleFormatter line is unaffected), server_views.py LogsView (lines 506-544), views_logs.py collect (165-176). Remediation: have JSONFormatter drop or reduce the 'request' extra (log request.path, never get_full_path(), and never repr() an HttpRequest), or attach a logging filter to the file handler that strips 'request' from django.request records; add a test in tests/security that a 4xx with a query string leaves no query string in postulo.log, and a changelog note that existing postulo.log* files hold these lines until rotated, as #548 did. The injection/eviction half is informational (out of scope as DoS; a reverse proxy's rate limit is the stated answer). **Verification evidence.** ```text Scratch output: '404 RECORDS: [{"message": "Not Found: /no-such-page/", "level": "WARNING", "request": "<WSGIRequest: GET \'/no-such-page/?note=QS-MARKER-7f3a9c&q=trade+union\'>", "status_code": 404}]' read back with logs.read() from the real postulo.log; '401 RECORDS: [... "request": "<WSGIRequest: GET \'/api/v1/search?q=API-QS-MARKER-11aa\'>" ...]'; '429 RECORDS: [... "message": "Too Many Requests: /career/skills/suggestions/", "request": "<WSGIRequest: GET \'/career/skills/suggestions/?name=shop-steward-xyz\'>" ...]' (POSTULO_SUGGESTION_RATE=1/h, second request by a signed-in member); admin GET /server/logs/?logger=django.request contained PAGE-MARKER-42; 'COLLECTOR LINE: [{"time": ..., "logger": "django.request", "message": "Not Found: /no-such-page/", "request": "<WSGIRequest: GET \'/no-such-page/?note=PAGE-MARKER-42\'>", "status_code": 404}]' from GET /logs with the bearer token. Code: core/logs.py:169-180 `for key, value in record.__dict__.items(): if key in STANDARD or key.startswith("_"): continue ... except (TypeError, ValueError): value = repr(value); payload[key] = value`; django/http/request.py HttpRequest.__repr__ `return "<%s: %s %r>" % (self.__class__.__name__, self.method, self.get_full_path())`; views_logs.py:166-173 `**record.extras`; templates/server/logs.html:113-115 `{% for key, value in record.extras.items %} ... <code>{{ value }}</code>`; resume/views.py:163-164 'What was typed is cut to the length a name may have and never goes anywhere but the search.'; grep for 'django.request' in src/ finds no logger config or filter. POSTULO_LOG_DIR defaults on (base.py:779). ``` **Suggested remediation.** In JSONFormatter, drop or reduce the `request` extra (and anything that is not JSON-serialisable) instead of falling back to `repr()`: e.g. skip keys whose value is an HttpRequest, or replace it with the path only (`request.path`) and the request id. Consider also setting `django.request`/`django.security` to not carry the `request` object into the file handler (a logging.Filter that pops `record.request`). Optionally cap how many 4xx lines per address per minute are written, so a stranger cannot churn the rotation. **Also covered by this issue.** - **The JSON log file records repr(request) for django.request errors, which embeds the full request path — including a recovery-link or invitation token when a 500 occurs on those routes — and the Logs page shows every extra to all administrators** (`src/postulo/core/logs.py` (155-181); Low). A single-use account-recovery token or invitation token can leak to other administrators and log collectors. Narrow: requires a 500 on exactly those routes while the token is live (one hour / until accepted).

tiagoagueda added the

bug

observability

security

labels

2026-10-10 10:55:44 +00:00

tiagoagueda added this to the 0.5.0 milestone

2026-10-10 10:57:19 +00:00

tiagoagueda referenced this issue

2026-10-10 10:57:33 +00:00

PST-025: The shipped gunicorn access log writes one-time bearer tokens that travel in URL paths #754

tiagoagueda referenced this issue