All checks were successful
CI Trade-In / changes (pull_request) Successful in 9s
CI / changes (pull_request) Successful in 12s
CI Trade-In / browser-tests (pull_request) Has been skipped
CI Trade-In / frontend-checks (pull_request) Has been skipped
CI / backend-tests (pull_request) Has been skipped
CI / frontend-tests (pull_request) Has been skipped
CI / openapi-codegen-check (pull_request) Has been skipped
CI Trade-In / backend-tests (pull_request) Successful in 5m38s
Ревью-minor: якорь [?&] вплотную к имени пропускал client_secret=, refresh_token=, auth_token=, webhook_secret=. Разрешаем префикс [\w.-]* перед альтернацией — маскируем имена, ОКАНЧИВАЮЩИЕСЯ на чувствительное слово. Кейс not_a_secret_name заменён на честные отрицательные: ?secretary= и ?tokens_page= (не оканчиваются на secret/token) плюс /api/v1/token-info в пути. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
135 lines
5.2 KiB
Python
135 lines
5.2 KiB
Python
"""Секрет из query-строки не попадает в лог процесса (#3154).
|
||
|
||
Прод-факт: uvicorn access-log печатал полный путь вместе с `?secret=<64 hex>`
|
||
(секрет вебхука GlitchTip = `TRADEIN_INTERNAL_AUTH_SECRET`), лог уезжал в Loki и
|
||
лежал там открытым. Скруббер Alloy (#3115) ловит только форму `user:pass@host`.
|
||
|
||
Проверка ПО ЗНАЧЕНИЮ: строка гоняется через настоящий handler с фильтром, в
|
||
выводе должно быть `secret=***` и НЕ должно быть самого секрета.
|
||
"""
|
||
|
||
from __future__ import annotations
|
||
|
||
import os
|
||
|
||
os.environ.setdefault("DATABASE_URL", "postgresql+psycopg://test:test@localhost:5432/test")
|
||
|
||
import io
|
||
import logging
|
||
|
||
import pytest
|
||
|
||
from app.core.log_scrub import QuerySecretFilter, install_query_secret_filter, scrub_query_secrets
|
||
|
||
_SECRET = "5fc281ce5d1bcf612417dffcae51d82fe5c3db2d7c4b4eac9a1b2c3d4e5f60718"
|
||
|
||
# Настоящая форма access-строки uvicorn (msg + args, путь лежит в args).
|
||
_ACCESS_MSG = '%s - "%s %s HTTP/%s" %d'
|
||
|
||
|
||
def _emit(logger_name: str, msg: str, *args: object) -> str:
|
||
"""Прогоняет запись через настоящий handler и возвращает текст строки."""
|
||
stream = io.StringIO()
|
||
handler = logging.StreamHandler(stream)
|
||
handler.setFormatter(logging.Formatter("%(message)s"))
|
||
logger = logging.getLogger(logger_name)
|
||
logger.addHandler(handler)
|
||
logger.setLevel(logging.INFO)
|
||
previous_propagate = logger.propagate
|
||
logger.propagate = False
|
||
try:
|
||
logger.info(msg, *args)
|
||
finally:
|
||
logger.propagate = previous_propagate
|
||
logger.removeHandler(handler)
|
||
return stream.getvalue()
|
||
|
||
|
||
def test_uvicorn_access_line_masks_secret_query_param() -> None:
|
||
install_query_secret_filter("uvicorn.access")
|
||
line = _emit(
|
||
"uvicorn.access",
|
||
_ACCESS_MSG,
|
||
"172.18.0.3:60322",
|
||
"POST",
|
||
f"/api/v1/trade-in/ops/glitchtip-webhook?secret={_SECRET}",
|
||
"1.1",
|
||
200,
|
||
)
|
||
assert "secret=***" in line, line
|
||
assert _SECRET not in line, line
|
||
# Остальная строка цела — иначе access-лог перестал бы годиться для разбора.
|
||
assert "POST /api/v1/trade-in/ops/glitchtip-webhook?secret=*** HTTP/1.1" in line
|
||
assert "172.18.0.3:60322" in line and "200" in line
|
||
|
||
|
||
def test_app_logger_via_root_handler_masks_secret() -> None:
|
||
"""Фильтр стоит и на handler'ах корня — прикладные логгеры тоже закрыты."""
|
||
stream = io.StringIO()
|
||
handler = logging.StreamHandler(stream)
|
||
handler.setFormatter(logging.Formatter("%(message)s"))
|
||
handler.addFilter(QuerySecretFilter())
|
||
root = logging.getLogger()
|
||
root.addHandler(handler)
|
||
try:
|
||
logging.getLogger("app.some.module").warning(
|
||
"retry callback https://gendsgn.ru/hook?token=%s", _SECRET
|
||
)
|
||
finally:
|
||
root.removeHandler(handler)
|
||
out = stream.getvalue()
|
||
assert "token=***" in out, out
|
||
assert _SECRET not in out, out
|
||
|
||
|
||
@pytest.mark.parametrize(
|
||
"raw",
|
||
[
|
||
f"/hook?secret={_SECRET}",
|
||
f"/hook?SECRET={_SECRET}",
|
||
f"/hook?a=1&token={_SECRET}&b=2",
|
||
f"/hook?api_key={_SECRET}",
|
||
f"/hook?apiKey={_SECRET}",
|
||
f'"GET /hook?access_token={_SECRET} HTTP/1.1"',
|
||
# Имя с префиксом: чувствительное слово в КОНЦЕ имени параметра.
|
||
f"/hook?client_secret={_SECRET}",
|
||
f"/hook?webhook_secret={_SECRET}",
|
||
f"/hook?refresh_token={_SECRET}",
|
||
f"/hook?auth_token={_SECRET}",
|
||
],
|
||
)
|
||
def test_sensitive_param_names_are_masked(raw: str) -> None:
|
||
scrubbed = scrub_query_secrets(raw)
|
||
assert _SECRET not in scrubbed, scrubbed
|
||
assert "***" in scrubbed
|
||
|
||
|
||
@pytest.mark.parametrize(
|
||
"raw",
|
||
[
|
||
"GET /api/v1/trade-in/offers?limit=50&city=Екатеринбург",
|
||
"https://metrics.gendsgn.ru/ingest/loki/api/v1/push",
|
||
# Имя НЕ оканчивается на чувствительное слово — маскировать нечего.
|
||
"/hook?secretary=anna",
|
||
"/hook?tokens_page=2",
|
||
# `token-info` в ПУТИ, а не в query: значения там нет вовсе.
|
||
"GET /api/v1/token-info?limit=5",
|
||
],
|
||
)
|
||
def test_innocent_lines_untouched(raw: str) -> None:
|
||
assert scrub_query_secrets(raw) == raw
|
||
|
||
|
||
def test_filter_installed_by_app_main() -> None:
|
||
"""Проводка: импорт приложения ставит фильтр на access-лог uvicorn."""
|
||
import app.main # noqa: F401 (импорт ради побочного эффекта установки фильтра)
|
||
|
||
filters = logging.getLogger("uvicorn.access").filters
|
||
assert any(isinstance(f, QuerySecretFilter) for f in filters), filters
|
||
|
||
|
||
def test_install_is_idempotent() -> None:
|
||
install_query_secret_filter("uvicorn.access")
|
||
install_query_secret_filter("uvicorn.access")
|
||
filters = logging.getLogger("uvicorn.access").filters
|
||
assert sum(isinstance(f, QuerySecretFilter) for f in filters) == 1, filters
|