HEL-543: add data hub observability side-channel (provider status, source catalog, lineage)
- New provider_call_log/provider_health tables (additive-only schema), wired via a fail-open observability.observe()/record_call() helper. - Tushare pipeline keeps its existing src_calls record unchanged and now also feeds the unified provider_health/provider_call_log side channel. - Eastmoney/Tencent realtime_serve.py call sites and the iFinD steward call site are wrapped with observability.observe() at the call site only; no adapter internals, routing, fallback order, or return values are touched. - New read-only admin API endpoints: /admin/api/providers/status, /admin/api/source-catalog, /admin/api/lineage, /admin/api/lineage/affected. - New static, read-only source_catalog.py and lineage.py registries documenting existing providers/interfaces/datasets and known main-site consumers (cited against backend/features/screener and backend/features/heaven call sites). - provider_call_log is purged by the existing pipeline.cleanup() job alongside src_calls/job_runs. - 47 new unit/integration tests covering classification, fail-open behavior under DB/log failures, unchanged payloads/exceptions on success and failure paths, and the new HTTP endpoints. Full suite: 173 tests, all green. Co-authored-by: Cursor <cursoragent@cursor.com> Co-authored-by: multica-agent <github@multica.ai>
This commit is contained in:
co-authored by
Cursor
multica-agent
parent
4a90c32fcc
commit
f014eb11bd
@@ -0,0 +1,300 @@
|
||||
"""Side-channel provider-call observability (HEL-543).
|
||||
|
||||
This module is additive-only and must never change what any existing call
|
||||
returns or raises. It exists purely to answer, after the fact and without
|
||||
touching routing: which provider/interface was called, whether it
|
||||
succeeded, how stale/complete the payload looked, and why a fallback fired.
|
||||
|
||||
Hard rules enforced here:
|
||||
|
||||
- Every public entry point (`observe`, `record_call`) is wrapped so that a
|
||||
database failure, a classifier bug, or any other internal error is
|
||||
swallowed and logged at DEBUG level. It never raises into the caller and
|
||||
never delays/blocks the caller's real data path beyond a best-effort
|
||||
timing measurement.
|
||||
- `observe()` always returns exactly what `fn()` returned, and re-raises
|
||||
exactly what `fn()` raised (same exception object, unmodified). It does
|
||||
not retry, does not change ordering, and does not add new failure modes.
|
||||
- No mock data is ever produced or returned by this module.
|
||||
"""
|
||||
|
||||
from __future__ import annotations
|
||||
|
||||
import re
|
||||
import time
|
||||
from typing import Any, Callable, TypeVar
|
||||
|
||||
from datahub.timeutil import isoformat, now_shanghai
|
||||
|
||||
_T = TypeVar("_T")
|
||||
|
||||
# Additive-only schema: two new tables, no changes to any existing table.
|
||||
# Merged into datahub.db.SCHEMA the same way EXTENDED_SCHEMA is.
|
||||
OBS_SCHEMA = """
|
||||
CREATE TABLE IF NOT EXISTS provider_call_log (
|
||||
id INTEGER PRIMARY KEY AUTOINCREMENT,
|
||||
provider TEXT NOT NULL,
|
||||
interface TEXT NOT NULL,
|
||||
fetched_at TEXT NOT NULL,
|
||||
latency_ms INTEGER,
|
||||
status TEXT NOT NULL,
|
||||
error TEXT,
|
||||
fallback_reason TEXT,
|
||||
data_age_seconds INTEGER,
|
||||
created_at TEXT NOT NULL
|
||||
);
|
||||
|
||||
CREATE TABLE IF NOT EXISTS provider_health (
|
||||
provider TEXT NOT NULL,
|
||||
interface TEXT NOT NULL,
|
||||
state TEXT NOT NULL,
|
||||
last_ok_at TEXT,
|
||||
last_error TEXT,
|
||||
last_fallback_reason TEXT,
|
||||
consec_failures INTEGER NOT NULL DEFAULT 0,
|
||||
last_latency_ms INTEGER,
|
||||
last_data_age_seconds INTEGER,
|
||||
updated_at TEXT NOT NULL,
|
||||
PRIMARY KEY (provider, interface)
|
||||
);
|
||||
|
||||
CREATE INDEX IF NOT EXISTS idx_provider_call_log_created ON provider_call_log(created_at);
|
||||
CREATE INDEX IF NOT EXISTS idx_provider_call_log_provider ON provider_call_log(provider, interface, created_at);
|
||||
"""
|
||||
|
||||
DEFAULT_STALE_SECONDS = 300
|
||||
|
||||
_BLOCKED_MARKERS = (
|
||||
"<!doctype", "<html", "expecting value", "verify you are human",
|
||||
"unusual traffic", "captcha", "安全验证", "访问异常", "请完成验证",
|
||||
"拦截", "禁止访问", "forbidden",
|
||||
)
|
||||
|
||||
# Matches provider messages like "Eastmoney returned 0/3 indices" or
|
||||
# "Tencent returned 2/3 indices" (see adapters/eastmoney.py, adapters/tencent.py).
|
||||
_COUNT_MISMATCH_RE = re.compile(r"returned (\d+)\s*/\s*(\d+)")
|
||||
|
||||
|
||||
def _logger():
|
||||
from datahub.logutil import get_logger
|
||||
|
||||
return get_logger()
|
||||
|
||||
|
||||
def classify_error(message: str) -> tuple[str, str]:
|
||||
"""Best-effort, side-reading classification of an exception message.
|
||||
|
||||
Never raises. Unknown shapes fall back to a generic ``error`` status so a
|
||||
classifier miss can never be mistaken for a healthy call.
|
||||
"""
|
||||
try:
|
||||
lower = (message or "").lower()
|
||||
if any(marker in lower for marker in _BLOCKED_MARKERS):
|
||||
return "blocked", "response_looks_like_intercept_page"
|
||||
if "timeout" in lower or "timed out" in lower:
|
||||
return "timeout", "request_timeout"
|
||||
mismatch = _COUNT_MISMATCH_RE.search(lower)
|
||||
if mismatch and int(mismatch.group(1)) == 0:
|
||||
return "empty", "empty_or_incomplete_response"
|
||||
if mismatch:
|
||||
return "degraded", "partial_or_mismatched_response"
|
||||
if "empty" in lower or "no intraday chart data" in lower or "missing" in lower:
|
||||
return "empty", "empty_or_incomplete_response"
|
||||
if "too small" in lower or "incomplete" in lower or "mismatch" in lower:
|
||||
return "degraded", "partial_or_mismatched_response"
|
||||
return "error", ""
|
||||
except Exception: # pragma: no cover - defensive, must never raise
|
||||
return "error", ""
|
||||
|
||||
|
||||
def classify_rows(
|
||||
rows: Any,
|
||||
*,
|
||||
required_fields: tuple[str, ...] | None = None,
|
||||
freshness_field: str | None = "quote_time_epoch",
|
||||
max_age_seconds: int = DEFAULT_STALE_SECONDS,
|
||||
) -> tuple[str, str, int | None]:
|
||||
"""Read-only classification of an already-successful payload.
|
||||
|
||||
Only ever called on a value a caller is about to use as-is; this never
|
||||
mutates ``rows`` and a classifier bug always degrades to ``("ok", "",
|
||||
None)`` rather than mislabeling a real success as a failure.
|
||||
"""
|
||||
try:
|
||||
if isinstance(rows, dict):
|
||||
items = [rows] if rows else []
|
||||
elif isinstance(rows, (list, tuple)):
|
||||
items = [item for item in rows if isinstance(item, dict)]
|
||||
else:
|
||||
items = []
|
||||
if not items:
|
||||
return "empty", "no_rows_returned", None
|
||||
if required_fields:
|
||||
missing: set[str] = set()
|
||||
for item in items:
|
||||
for field in required_fields:
|
||||
if item.get(field) in (None, ""):
|
||||
missing.add(field)
|
||||
if missing:
|
||||
return "missing_fields", "missing:" + ",".join(sorted(missing)), None
|
||||
data_age: int | None = None
|
||||
if freshness_field:
|
||||
now_epoch = time.time()
|
||||
ages: list[int] = []
|
||||
for item in items:
|
||||
raw = item.get(freshness_field)
|
||||
try:
|
||||
epoch = int(raw or 0)
|
||||
except (TypeError, ValueError):
|
||||
epoch = 0
|
||||
if epoch > 0:
|
||||
ages.append(max(0, int(now_epoch - epoch)))
|
||||
if ages:
|
||||
data_age = max(ages)
|
||||
if data_age > max_age_seconds:
|
||||
return "stale", "data_age_exceeds_threshold", data_age
|
||||
return "ok", "", data_age
|
||||
except Exception: # pragma: no cover - defensive, must never raise
|
||||
return "ok", "", None
|
||||
|
||||
|
||||
def record_call(
|
||||
db: Any,
|
||||
provider: str,
|
||||
interface: str,
|
||||
*,
|
||||
status: str,
|
||||
latency_ms: int | None = None,
|
||||
error: str = "",
|
||||
fallback_reason: str = "",
|
||||
data_age_seconds: int | None = None,
|
||||
) -> None:
|
||||
"""Fail-open recorder. Never raises; a write failure here must never be
|
||||
able to take down a real, otherwise-successful data path."""
|
||||
if db is None:
|
||||
return
|
||||
try:
|
||||
now = isoformat(now_shanghai())
|
||||
ok = status == "ok"
|
||||
error_text = (error or "")[:500]
|
||||
reason_text = (fallback_reason or "")[:200]
|
||||
with db.write() as connection:
|
||||
connection.execute(
|
||||
"INSERT INTO provider_call_log("
|
||||
"provider, interface, fetched_at, latency_ms, status, error, "
|
||||
"fallback_reason, data_age_seconds, created_at) "
|
||||
"VALUES (?,?,?,?,?,?,?,?,?)",
|
||||
(provider, interface, now, latency_ms, status, error_text, reason_text, data_age_seconds, now),
|
||||
)
|
||||
connection.execute(
|
||||
"""
|
||||
INSERT INTO provider_health(
|
||||
provider, interface, state, last_ok_at, last_error, last_fallback_reason,
|
||||
consec_failures, last_latency_ms, last_data_age_seconds, updated_at)
|
||||
VALUES (?,?,?,?,?,?,?,?,?,?)
|
||||
ON CONFLICT(provider, interface) DO UPDATE SET
|
||||
state = excluded.state,
|
||||
last_ok_at = CASE WHEN excluded.state = 'ok' THEN excluded.last_ok_at ELSE provider_health.last_ok_at END,
|
||||
last_error = CASE WHEN excluded.state = 'ok' THEN '' ELSE excluded.last_error END,
|
||||
last_fallback_reason = excluded.last_fallback_reason,
|
||||
consec_failures = CASE WHEN excluded.state = 'ok' THEN 0 ELSE provider_health.consec_failures + 1 END,
|
||||
last_latency_ms = excluded.last_latency_ms,
|
||||
last_data_age_seconds = excluded.last_data_age_seconds,
|
||||
updated_at = excluded.updated_at
|
||||
""",
|
||||
(
|
||||
provider,
|
||||
interface,
|
||||
status,
|
||||
now if ok else None,
|
||||
"" if ok else (error_text or reason_text or "unknown_error"),
|
||||
reason_text,
|
||||
0 if ok else 1,
|
||||
latency_ms,
|
||||
data_age_seconds,
|
||||
now,
|
||||
),
|
||||
)
|
||||
except Exception: # pragma: no cover - defensive, must never raise
|
||||
try:
|
||||
_logger().debug(
|
||||
"observability record_call failed (fail-open)",
|
||||
extra={"hub": {"provider": provider, "interface": interface}},
|
||||
exc_info=True,
|
||||
)
|
||||
except Exception:
|
||||
pass
|
||||
|
||||
|
||||
def _safe_record_failure(db: Any, provider: str, interface: str, latency_ms: int, exc: BaseException) -> None:
|
||||
if db is None:
|
||||
return
|
||||
try:
|
||||
message = str(exc)
|
||||
status, reason = classify_error(message)
|
||||
record_call(
|
||||
db, provider, interface,
|
||||
status=status, latency_ms=latency_ms, error=message, fallback_reason=reason,
|
||||
)
|
||||
except Exception: # pragma: no cover - defensive, must never raise
|
||||
pass
|
||||
|
||||
|
||||
def _safe_record_success(
|
||||
db: Any,
|
||||
provider: str,
|
||||
interface: str,
|
||||
latency_ms: int,
|
||||
result: Any,
|
||||
classify: Callable[[Any], tuple[str, str, int | None] | None] | None,
|
||||
) -> None:
|
||||
if db is None:
|
||||
return
|
||||
status, reason, data_age = "ok", "", None
|
||||
if classify is not None:
|
||||
try:
|
||||
classified = classify(result)
|
||||
if classified:
|
||||
status, reason, data_age = classified
|
||||
except Exception: # pragma: no cover - defensive, must never raise
|
||||
# A classifier bug must never mislabel (or hide) a real success;
|
||||
# degrade to a plain "ok" call rather than skipping the log.
|
||||
status, reason, data_age = "ok", "", None
|
||||
try:
|
||||
record_call(
|
||||
db, provider, interface,
|
||||
status=status, latency_ms=latency_ms, fallback_reason=reason, data_age_seconds=data_age,
|
||||
)
|
||||
except Exception: # pragma: no cover - defensive, must never raise
|
||||
pass
|
||||
|
||||
|
||||
def observe(
|
||||
db: Any,
|
||||
provider: str,
|
||||
interface: str,
|
||||
fn: Callable[[], _T],
|
||||
*,
|
||||
classify: Callable[[Any], tuple[str, str, int | None] | None] | None = None,
|
||||
) -> _T:
|
||||
"""Call ``fn()`` and record a side-channel status row.
|
||||
|
||||
Returns exactly what ``fn()`` returns and re-raises exactly what
|
||||
``fn()`` raises. ``db`` may be ``None`` (e.g. in call sites that are not
|
||||
wired to a database yet); in that case this is a transparent passthrough
|
||||
with no recording at all.
|
||||
"""
|
||||
started = time.perf_counter()
|
||||
try:
|
||||
result = fn()
|
||||
except Exception:
|
||||
latency_ms = round((time.perf_counter() - started) * 1000)
|
||||
import sys
|
||||
|
||||
exc = sys.exc_info()[1]
|
||||
if exc is not None:
|
||||
_safe_record_failure(db, provider, interface, latency_ms, exc)
|
||||
raise
|
||||
latency_ms = round((time.perf_counter() - started) * 1000)
|
||||
_safe_record_success(db, provider, interface, latency_ms, result, classify)
|
||||
return result
|
||||
Reference in New Issue
Block a user