fix(ptica/observability): страховка скраба перестаёт утекать то, что защищает (#2753)
Три дыры в скрабе ПДн перед отправкой в мониторинг, и все три проверялись поиском подстроки в исходнике — гейтом, который зелен на сломанной проводке. 1. include_local_variables=False в обеих точках входа (main.py, celery_app.py). Дефолт SDK — True, Птица его нигде не переопределяла: при ЛЮБОМ исключении кадр стека нёс значения аргументов (телефон заявки, адрес, токен) под произвольными именами. Скраб сверяет ИМЕНА ключей — такое он не ловит по построению, то есть это не дополнительная мера, а условие его полноты. У МЕРЫ флаг стоит с #2737. 2. Сбой самого скраба больше не уходит в мониторинг: ignore_logger на модуль + логирование без трассировки и без str(exc). До этого logger.exception внутри before_send создавал НОВОЕ событие, в локальных переменных которого лежал неочищенный event целиком, и это событие снова падало в тот же обработчик. Проверено исполнением: рекурсия не завершается, 1000+ вложенных трассировок за минуту. Диагностика осталась в stdout — текст трассировки значений переменных не печатает. 3. Проводка проверяется ПОВЕДЕНИЕМ, а не текстом файла. tests/_sentry_wiring_ probe.py поднимает настоящий sentry_sdk.init() в подпроцессе, подменяет транспорт и смотрит, что до него доехало: тело запроса, транзакция, кадр стека, повторный вход при сбое скраба. Наружу не уходит ничего — DSN на несуществующий хост, capture_envelope подменён до первого события, маркеры случайные. Старый гейт зелен на разорванной проводке: удалить before_send=scrub_event и переформулировать соседний комментарий, назвав в нём тот же аргумент, — 2 passed. Новый на том же коде — 2 failed. На коде до этого коммита новые проверки красные (локальные переменные ушли в транспорт; сбой скраба вошёл в обработчик 4 раза).
This commit is contained in:
parent
de4b2a4ae5
commit
fb7e94ee65
5 changed files with 277 additions and 23 deletions
|
|
@ -87,6 +87,12 @@ if settings.glitchtip_dsn:
|
|||
traces_sample_rate=settings.glitchtip_traces_sample_rate,
|
||||
profiles_sample_rate=0.0,
|
||||
send_default_pii=False,
|
||||
# Локальные переменные кадров стека НЕ уходят в мониторинг (#2753).
|
||||
# Дефолт SDK — True: при любом исключении кадр несёт значения аргументов
|
||||
# (телефон заявки, адрес, токен) под ПРОИЗВОЛЬНЫМИ именами, а scrub_event
|
||||
# сверяет ИМЕНА ключей — такое он не ловит по построению. То есть это не
|
||||
# дополнительная мера, а условие, без которого скраб не полон.
|
||||
include_local_variables=False,
|
||||
before_send=scrub_event,
|
||||
before_send_transaction=scrub_event,
|
||||
integrations=[
|
||||
|
|
|
|||
|
|
@ -36,10 +36,19 @@ import logging
|
|||
import re
|
||||
from typing import Any
|
||||
|
||||
from sentry_sdk.integrations.logging import ignore_logger
|
||||
from sentry_sdk.types import Event
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
# Собственный сбой скраба НЕ должен становиться событием мониторинга (#2753).
|
||||
# LoggingIntegration (event_level=ERROR) превратила бы строку журнала об отказе
|
||||
# в новое событие, которое снова пойдёт через этот же обработчик; при
|
||||
# детерминированном сбое это рекурсия — защиты от неё в SDK нет (проверено:
|
||||
# 1000+ вложенных трассировок за минуту, процесс не завершается). Диагностика
|
||||
# остаётся в stdout контейнера: текст трассировки значений переменных не несёт.
|
||||
ignore_logger(__name__)
|
||||
|
||||
_REDACTED = "[REDACTED]"
|
||||
# Ключи consumer-PII (нижний регистр; сверка case-insensitive). Набор МЕРЫ
|
||||
# (client_name/client_phone/client_email/phone/email/name, #396) + company/
|
||||
|
|
@ -143,6 +152,13 @@ def scrub_event(event: Event, hint: dict[str, Any]) -> Event | None:
|
|||
try:
|
||||
scrub_pii_event(event, hint)
|
||||
scrub_sensitive_query(event, hint)
|
||||
except Exception:
|
||||
logger.exception("sentry_scrub.scrub_event: handler failed, sending event as-is")
|
||||
except Exception as exc:
|
||||
# Ни трассировки, ни str(exc): и то и другое способно нести значения из
|
||||
# ЕЩЁ НЕ ОЧИЩЕННОГО event — то есть страховка утекла бы ровно то, что
|
||||
# защищает (#2753). Имя класса исключения данных не несёт. Событием
|
||||
# мониторинга эта строка не станет — см. ignore_logger выше.
|
||||
logger.error(
|
||||
"sentry_scrub.scrub_event: handler failed (%s), sending event as-is",
|
||||
type(exc).__name__,
|
||||
)
|
||||
return event
|
||||
|
|
|
|||
|
|
@ -35,6 +35,10 @@ if settings.glitchtip_dsn:
|
|||
traces_sample_rate=settings.glitchtip_traces_sample_rate,
|
||||
profiles_sample_rate=0.0,
|
||||
send_default_pii=False,
|
||||
# Локальные переменные кадров стека НЕ уходят в мониторинг (#2753) — см.
|
||||
# app/main.py: скраб сверяет ИМЕНА ключей, а имя переменной произвольно.
|
||||
# В воркере вектор шире: задачи держат в кадрах сырые ответы источников.
|
||||
include_local_variables=False,
|
||||
before_send=scrub_event,
|
||||
before_send_transaction=scrub_event,
|
||||
integrations=[
|
||||
|
|
|
|||
146
backend/tests/_sentry_wiring_probe.py
Normal file
146
backend/tests/_sentry_wiring_probe.py
Normal file
|
|
@ -0,0 +1,146 @@
|
|||
"""Проба проводки GlitchTip: запускается ОТДЕЛЬНЫМ процессом из test_sentry_init.py.
|
||||
|
||||
Зачем подпроцесс. `app/main.py` и `app/workers/celery_app.py` зовут
|
||||
`sentry_sdk.init()` на импорте модуля и только при непустом `GLITCHTIP_DSN`. В
|
||||
процессе pytest этот путь недостижим (модуль уже в `sys.modules`, DSN пуст), а
|
||||
если бы и был достижим — глобальный клиент SDK остался бы живым для всех
|
||||
последующих тестов. Отдельный процесс даёт настоящую инициализацию и умирает
|
||||
вместе с ней.
|
||||
|
||||
Наружу не уходит ничего: `capture_envelope` подменяется ДО первого события, а
|
||||
DSN в тесте указывает на несуществующий хост. Значения-маркеры генерируются
|
||||
случайно на каждый запуск — кадр стека несёт не только переменные, но и строки
|
||||
исходника, поэтому литерал в коде пробы сделал бы проверку вечно красной.
|
||||
|
||||
stdout — одна строка JSON: counts / scrub_handler_entries / markers / payloads
|
||||
(тело каждого канала отдельно — см. `main`).
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import importlib
|
||||
import io
|
||||
import itertools
|
||||
import json
|
||||
import sys
|
||||
import uuid
|
||||
from typing import Any
|
||||
|
||||
import sentry_sdk
|
||||
|
||||
_FAILURE_CAP = 3
|
||||
|
||||
|
||||
def _fresh(prefix: str) -> str:
|
||||
return f"{prefix}-{uuid.uuid4().hex}"
|
||||
|
||||
|
||||
def _leaking_event(markers: dict[str, str]) -> dict[str, Any]:
|
||||
"""Событие с ПДн в трёх местах, которые закрывает scrub_event."""
|
||||
return {
|
||||
"message": "sentry-wiring-probe",
|
||||
"level": "error",
|
||||
"request": {
|
||||
"data": {"phone": markers["phone"], "message": markers["free_text"]},
|
||||
"url": f"https://example.invalid/probe?api_key={markers['url_secret']}",
|
||||
},
|
||||
}
|
||||
|
||||
|
||||
def main(module: str) -> int:
|
||||
importlib.import_module(module) # ← здесь отрабатывает sentry_sdk.init()
|
||||
|
||||
client = sentry_sdk.get_client()
|
||||
sent: list[str] = []
|
||||
|
||||
def _record(envelope: Any) -> None:
|
||||
buf = io.BytesIO()
|
||||
envelope.serialize_into(buf)
|
||||
sent.append(buf.getvalue().decode("utf-8", "replace"))
|
||||
|
||||
client.transport.capture_envelope = _record # type: ignore[union-attr,method-assign]
|
||||
|
||||
markers = {
|
||||
"phone": _fresh("probe-phone"),
|
||||
"free_text": _fresh("probe-free-text"),
|
||||
"url_secret": _fresh("probe-url-secret"),
|
||||
"local_var": _fresh("probe-local-var"),
|
||||
}
|
||||
|
||||
# 1. Канал ошибок (before_send).
|
||||
sentry_sdk.capture_event(_leaking_event(markers))
|
||||
after_error = len(sent)
|
||||
|
||||
# 2. Канал транзакций (before_send_transaction) — Starlette кладёт
|
||||
# request.data на transaction-scope так же, как на error-scope.
|
||||
transaction = _leaking_event(markers)
|
||||
transaction["type"] = "transaction"
|
||||
transaction["transaction"] = "sentry-wiring-probe-tx"
|
||||
transaction["contexts"] = {"trace": {"trace_id": "0" * 32, "span_id": "0" * 16}}
|
||||
transaction["start_timestamp"] = "2026-01-01T00:00:00.000000Z"
|
||||
transaction["timestamp"] = "2026-01-01T00:00:01.000000Z"
|
||||
transaction["spans"] = []
|
||||
sentry_sdk.capture_event(transaction)
|
||||
after_transaction = len(sent)
|
||||
|
||||
# 3. Локальные переменные кадра стека (include_local_variables). Имя
|
||||
# переменной произвольное — ключевой скраб такое не ловит по построению.
|
||||
def _raise_with_local() -> None:
|
||||
applicant_note = markers["local_var"] # noqa: F841 — ради кадра стека
|
||||
raise RuntimeError("sentry-wiring-probe boom")
|
||||
|
||||
try:
|
||||
_raise_with_local()
|
||||
except RuntimeError:
|
||||
sentry_sdk.capture_exception()
|
||||
after_exception = len(sent)
|
||||
|
||||
# 4. Сбой самого скраба не должен порождать ВТОРОЕ событие: иначе строка
|
||||
# журнала об отказе уходит в мониторинг через LoggingIntegration, снова
|
||||
# попадает в скраб, снова падает — рекурсия (#2753; на коде до фикса
|
||||
# проверено: не завершается, 1000+ вложенных трассировок за минуту).
|
||||
# Считаем ВХОДЫ в обработчик; после _FAILURE_CAP перестаём падать, иначе
|
||||
# проба на сломанном коде висела бы вместо того, чтобы честно покраснеть.
|
||||
from app.observability import sentry_scrub
|
||||
|
||||
original = sentry_scrub.scrub_pii_event
|
||||
entries: list[int] = []
|
||||
|
||||
def _boom(*_a: Any, **_kw: Any) -> Any:
|
||||
entries.append(1)
|
||||
if len(entries) > _FAILURE_CAP:
|
||||
return None
|
||||
raise RuntimeError("sentry-wiring-probe scrubber failure")
|
||||
|
||||
sentry_scrub.scrub_pii_event = _boom # type: ignore[assignment]
|
||||
try:
|
||||
# Без маркеров: это событие по замыслу уходит НЕОЧИЩЕННЫМ ("as-is").
|
||||
sentry_sdk.capture_event({"message": "sentry-wiring-probe-failure", "level": "error"})
|
||||
finally:
|
||||
sentry_scrub.scrub_pii_event = original # type: ignore[assignment]
|
||||
after_scrub_failure = len(sent)
|
||||
|
||||
# Тело каждого канала — отдельно: иначе утечка из одного (напр. локальные
|
||||
# переменные шага 3 несут те же маркеры, что тело запроса шага 1) красит
|
||||
# чужую проверку и мешает понять, что именно сломано.
|
||||
bounds = [0, after_error, after_transaction, after_exception, after_scrub_failure]
|
||||
names = ["error", "transaction", "exception", "scrub_failure"]
|
||||
spans = dict(zip(names, itertools.pairwise(bounds), strict=True))
|
||||
|
||||
print(
|
||||
json.dumps(
|
||||
{
|
||||
"counts": {name: end - start for name, (start, end) in spans.items()},
|
||||
"scrub_handler_entries": len(entries),
|
||||
"markers": markers,
|
||||
"payloads": {
|
||||
name: "\n".join(sent[start:end]) for name, (start, end) in spans.items()
|
||||
},
|
||||
}
|
||||
)
|
||||
)
|
||||
return 0
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
sys.exit(main(sys.argv[1]))
|
||||
|
|
@ -4,15 +4,21 @@
|
|||
только при непустом GLITCHTIP_DSN, что release-fallback работает корректно,
|
||||
что scrub_sensitive_query redact-ит api keys из URL spans, что scrub_pii_event
|
||||
redact-ит consumer-PII (client_name/client_phone/client_email/phone/email/name/
|
||||
company/message) из request.data/extra/contexts, и что composed-хендлер
|
||||
scrub_event реально повешен на ОБА канала (before_send И
|
||||
before_send_transaction) в main.py/celery_app.py (#2457-review).
|
||||
company/message) из request.data/extra/contexts (#2457-review), и — в конце
|
||||
файла — что до транспорта не доезжают ни ПДн тела запроса, ни значения
|
||||
локальных переменных кадра стека, ни второе событие о сбое самого скраба
|
||||
(#2753, поведение через подставной транспорт вместо поиска подстроки).
|
||||
"""
|
||||
|
||||
import json
|
||||
import os
|
||||
import pathlib
|
||||
import subprocess
|
||||
import sys
|
||||
from functools import lru_cache
|
||||
from unittest.mock import patch
|
||||
|
||||
import pytest
|
||||
import sentry_sdk
|
||||
|
||||
_BACKEND_ROOT = pathlib.Path(__file__).resolve().parents[1]
|
||||
|
|
@ -392,26 +398,102 @@ def test_scrub_event_survives_scrub_sensitive_query_exception() -> None:
|
|||
assert result is event
|
||||
|
||||
|
||||
# ── wiring: before_send/before_send_transaction реально используют scrub_event ──
|
||||
# ── wiring: ПДн не доходят до транспорта (поведение, а не текст исходника) ─────
|
||||
#
|
||||
# Source-grep вместо мока sentry_sdk.init: main.py/celery_app.py вызывают
|
||||
# sentry_sdk.init() на module-level import, поэтому мок пришлось бы ставить ДО
|
||||
# импорта app.main — фрагильно и не переиспользуемо между тестами (модуль уже
|
||||
# закэширован в sys.modules к моменту первого теста). Прямая проверка исходника
|
||||
# — детерминированный, дешёвый и точный регрессионный гейт на саму строку,
|
||||
# которую правил review (#2457).
|
||||
# До #2753 проводка проверялась поиском подстроки `before_send=scrub_event` в
|
||||
# файле. Такой гейт зелен и на разорванной проводке: обе точки входа несут
|
||||
# многострочные комментарии, где те же подстроки встречаются, — достаточно
|
||||
# удалить сам аргумент, оставив комментарий. Хуже того, подстрока ничего не
|
||||
# говорит о том, ДОШЛИ ли ПДн до транспорта: их можно выпустить и при живом
|
||||
# before_send (локальные переменные кадра стека уходят мимо ключевого скраба).
|
||||
#
|
||||
# Поэтому проверяем поведение: поднимаем настоящую инициализацию в подпроцессе
|
||||
# (`tests/_sentry_wiring_probe.py`), подменяем транспорт и смотрим, что до него
|
||||
# доехало. Наружу не уходит ничего — DSN указывает на несуществующий хост, а
|
||||
# `capture_envelope` подменён до первого события.
|
||||
|
||||
|
||||
def test_main_wires_scrub_event_to_both_channels() -> None:
|
||||
"""app/main.py: before_send И before_send_transaction ОБА на scrub_event."""
|
||||
text = (_BACKEND_ROOT / "app" / "main.py").read_text(encoding="utf-8")
|
||||
assert "before_send=scrub_event" in text
|
||||
assert "before_send_transaction=scrub_event" in text
|
||||
@lru_cache(maxsize=2)
|
||||
def _probe(module: str) -> str:
|
||||
"""Прогнать пробу проводки для точки входа `module`; вернуть JSON-строку."""
|
||||
env = {
|
||||
**os.environ,
|
||||
"TESTING": "1",
|
||||
# Синтаксически валидный DSN на несуществующий хост: init отработает,
|
||||
# сети не будет даже если транспорт когда-нибудь перестанут подменять.
|
||||
"GLITCHTIP_DSN": "https://probe@localhost.invalid/1",
|
||||
# Явно: у запуска скрипта в sys.path[0] попадает КАТАЛОГ СКРИПТА (tests/),
|
||||
# и без этого `import app` уехал бы в editable-установку пакета — то есть
|
||||
# проба мерила бы чужое дерево, а не то, что рядом с ней лежит.
|
||||
"PYTHONPATH": os.pathsep.join([str(_BACKEND_ROOT), os.environ.get("PYTHONPATH", "")]),
|
||||
}
|
||||
proc = subprocess.run(
|
||||
[sys.executable, str(_BACKEND_ROOT / "tests" / "_sentry_wiring_probe.py"), module],
|
||||
cwd=_BACKEND_ROOT,
|
||||
env=env,
|
||||
capture_output=True,
|
||||
text=True,
|
||||
timeout=300,
|
||||
check=False,
|
||||
)
|
||||
assert proc.returncode == 0, f"проба упала: {proc.stderr[-3000:]}"
|
||||
return proc.stdout.strip().splitlines()[-1]
|
||||
|
||||
|
||||
def test_celery_app_wires_scrub_event_to_both_channels() -> None:
|
||||
"""app/workers/celery_app.py: before_send И before_send_transaction ОБА на
|
||||
scrub_event (раньше before_send не было вообще)."""
|
||||
text = (_BACKEND_ROOT / "app" / "workers" / "celery_app.py").read_text(encoding="utf-8")
|
||||
assert "before_send=scrub_event" in text
|
||||
assert "before_send_transaction=scrub_event" in text
|
||||
@pytest.mark.parametrize("module", ["app.main", "app.workers.celery_app"])
|
||||
def test_pii_never_reaches_transport(module: str) -> None:
|
||||
"""Оба канала (error И transaction) отдают транспорту событие без ПДн.
|
||||
|
||||
Красный, если из `sentry_sdk.init()` убрать `before_send` ИЛИ
|
||||
`before_send_transaction` — комментарий с теми же словами не спасает.
|
||||
"""
|
||||
probe = json.loads(_probe(module))
|
||||
markers = probe["markers"]
|
||||
|
||||
for channel in ("error", "transaction"):
|
||||
payload = probe["payloads"][channel]
|
||||
# Контроль «событие вообще доехало»: без него проверка была бы зелёной
|
||||
# и на пробе, которая молча ничего не отправила.
|
||||
assert probe["counts"][channel] == 1, f"{module}/{channel}: событие не доехало"
|
||||
assert "[REDACTED]" in payload, f"{module}/{channel}: скраб не отработал"
|
||||
|
||||
leaked = [key for key in ("phone", "free_text", "url_secret") if markers[key] in payload]
|
||||
assert leaked == [], f"{module}/{channel}: до транспорта дошли ПДн — {leaked}"
|
||||
|
||||
|
||||
@pytest.mark.parametrize("module", ["app.main", "app.workers.celery_app"])
|
||||
def test_local_variables_never_reach_transport(module: str) -> None:
|
||||
"""`include_local_variables=False`: значения локальных переменных кадра стека
|
||||
не уходят в мониторинг (#2753).
|
||||
|
||||
Ключевой скраб такое не ловит по построению — имя переменной произвольно,
|
||||
а сверка идёт по именам. Красный, если флаг убрать из `sentry_sdk.init()`
|
||||
(в sentry-sdk он по умолчанию `True`).
|
||||
"""
|
||||
probe = json.loads(_probe(module))
|
||||
payload = probe["payloads"]["exception"]
|
||||
|
||||
assert probe["counts"]["exception"] == 1
|
||||
assert "sentry-wiring-probe boom" in payload, "событие с исключением не доехало"
|
||||
|
||||
assert (
|
||||
probe["markers"]["local_var"] not in payload
|
||||
), f"{module}: значение локальной переменной ушло в мониторинг"
|
||||
|
||||
|
||||
@pytest.mark.parametrize("module", ["app.main", "app.workers.celery_app"])
|
||||
def test_scrub_failure_does_not_spawn_second_event(module: str) -> None:
|
||||
"""Сбой самого скраба не порождает ВТОРОГО события (#2753).
|
||||
|
||||
`logger` этого модуля внесён в `ignore_logger`, иначе строка журнала об
|
||||
отказе ушла бы в мониторинг через LoggingIntegration (event_level=ERROR),
|
||||
снова попала бы в скраб, снова упала — рекурсия, защиты от которой в SDK
|
||||
нет (проверено на коде до фикса: не завершается). Красный, если
|
||||
`ignore_logger` убрать: обработчик войдёт повторно.
|
||||
"""
|
||||
probe = json.loads(_probe(module))
|
||||
|
||||
assert (
|
||||
probe["scrub_handler_entries"] == 1
|
||||
), "сбой скраба вернулся вторым событием: строка журнала уходит в мониторинг"
|
||||
assert probe["counts"]["scrub_failure"] == 1
|
||||
|
|
|
|||
Loading…
Add table
Reference in a new issue