q792602257andClaude Opus 5
8381896eeb
失败此前在 trace 里近乎不可见：异常处理器把异常吃掉换成信封响应，自动 instrumentation 只看到一个 HTTP 状态码，而 AppError 默认 400、信封里 success=false，跟正常返回分不出来。 - api.py：四个异常处理器（对外失败的唯一出口）各记一次 span；兜底处理器额外 record_error——对外只回一句无信息量的错误文案，异常类型与栈只在本地日志里 - telemetry.py：新增 record_envelope / record_parse_failure / span_unless_suppressed；record_error 补 error.message / retryable / status_code；snapshot 支持 extra 带上「这份 HTML 是哪来的」 - worker/client.py：_request 自建 span，活到解信封之后。httpx 那个 CLIENT span 在 request() 返回时就结束，此时信封还没解——success=false code=6002（租约 无效）在它看来是完成的 200 请求 - span_unless_suppressed：suppress_instrumentation 只被 instrumentation 库尊重， 手工 span 不看它，lease 空转长轮询会从这个口子把孤立 trace 放回来 - 两个 scraping client 的解析失败分支收拢到 record_parse_failure；shop_items 显式标 stage=delegate 且不落快照（它自己不抓页面，按 html 推断只会得出 「fetch 失败」的错误结论） Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
390 lines
16 KiB
Python
390 lines
16 KiB
Python
"""OpenTelemetry traces 接入：仅在 otel_enabled=true 时初始化，否则全 noop
|
|
|
|
抓取与交易两个进程在 lifespan 启动时各自调用 `setup_telemetry(settings,
|
|
service_name=...)`：注册 TracerProvider + OTLP/HTTP exporter + 自动
|
|
instrumentation（FastAPI、httpx）。失败时（如 endpoint 不可达）不阻断主流程，
|
|
仅打日志；traces 是辅助观测，不应让进程起不来。
|
|
|
|
`shutdown_telemetry` 在 lifespan 关闭时 force_flush 后再 shutdown，确保缓冲区
|
|
里的 span 都已上报。
|
|
|
|
OTel SDK 默认的 ProxyTracerProvider 在 setup 之前就能用（noop span），所以
|
|
其它代码里直接 `trace.get_tracer(__name__)` + `start_as_current_span` 即可，
|
|
不必关心 telemetry 是否启用——禁用时 span 不会真正产生与上报。
|
|
|
|
自动 instrumentation（FastAPI + httpx）只覆盖「进程收到 HTTP 请求」与「进程发出
|
|
httpx 请求」两类边界。交易侧的实际工作两者都不是：站点交互走 Playwright（不经
|
|
httpx），worker 主循环是后台 asyncio 任务（没有 HTTP 入口）。所以那一侧必须手工
|
|
埋点，否则 trace 里只剩 worker 与网关之间的往返记录，看不到任何业务链路。本模块
|
|
为此提供三件东西：
|
|
|
|
- `traced`：给 async 方法套一层 span，异常自动记录（站点交互各步骤在用）
|
|
- `set_attributes` / `record_error`：批量写属性、统一记异常
|
|
- `suppressed`：屏蔽空转长轮询产生的孤立 trace
|
|
"""
|
|
from __future__ import annotations
|
|
|
|
import functools
|
|
import logging
|
|
from collections.abc import Awaitable, Callable, Iterator, Mapping
|
|
from contextlib import contextmanager
|
|
from typing import TYPE_CHECKING, ParamSpec, TypeVar
|
|
|
|
from opentelemetry import trace
|
|
from opentelemetry.exporter.otlp.proto.http.trace_exporter import OTLPSpanExporter
|
|
from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor
|
|
from opentelemetry.instrumentation.httpx import HTTPXClientInstrumentor
|
|
from opentelemetry.instrumentation.utils import (
|
|
is_instrumentation_enabled,
|
|
suppress_instrumentation,
|
|
)
|
|
from opentelemetry.sdk.resources import SERVICE_NAME, Resource
|
|
from opentelemetry.sdk.trace import TracerProvider
|
|
from opentelemetry.sdk.trace.export import BatchSpanProcessor
|
|
from opentelemetry.sdk.trace.sampling import ALWAYS_ON
|
|
from opentelemetry.trace import Span, SpanKind, Status, StatusCode
|
|
from opentelemetry.util.types import AttributeValue
|
|
|
|
from app.shared.config import Settings, get_settings
|
|
|
|
if TYPE_CHECKING:
|
|
from fastapi import FastAPI
|
|
|
|
P = ParamSpec("P")
|
|
R = TypeVar("R")
|
|
|
|
logger = logging.getLogger(__name__)
|
|
|
|
# 错误信息类属性的截断长度。站点错误页抽出来的 msg 可能很长（_extract_error_message
|
|
# 拼两条提示），而属性值过长会把 OTLP 请求撑大；排查看的是前半句，够了。
|
|
_MSG_MAX_CHARS = 512
|
|
|
|
# 全局 provider 引用，用于 instrument_app / shutdown 时判断当前是否已初始化。
|
|
# 显式持有比依赖 trace.get_tracer_provider() 的类型判断更稳——后者在测试场景
|
|
# 下可能被其它用例改动全局状态。
|
|
_provider: TracerProvider | None = None
|
|
|
|
|
|
def setup_telemetry(settings: Settings, *, service_name: str) -> None:
|
|
"""初始化 OTel：TracerProvider + OTLP exporter + httpx 自动 instrumentation。
|
|
|
|
- `otel_enabled=False` 或 endpoint 未配时仅打日志，不做任何事。
|
|
- 必须在创建任何 httpx.AsyncClient 之前调用，否则 httpx 不会被打桩。
|
|
两侧 main.py 的 lifespan 已把 setup 放在 site_session.start() 之前。
|
|
- 重复调用安全（_provider 已设时直接返回）。
|
|
"""
|
|
global _provider
|
|
if _provider is not None:
|
|
return
|
|
if not settings.otel_enabled or not settings.otel_endpoint:
|
|
logger.info("OpenTelemetry 未启用（endpoint 或 otel_enabled 未配置）")
|
|
return
|
|
|
|
resource = Resource.create({SERVICE_NAME: service_name})
|
|
provider = TracerProvider(resource=resource, sampler=ALWAYS_ON)
|
|
|
|
exporter = OTLPSpanExporter(
|
|
endpoint=settings.otel_endpoint,
|
|
headers=_parse_headers(settings.otel_headers),
|
|
timeout=10,
|
|
)
|
|
provider.add_span_processor(
|
|
BatchSpanProcessor(
|
|
exporter,
|
|
schedule_delay_millis=settings.otel_export_interval_ms,
|
|
)
|
|
)
|
|
trace.set_tracer_provider(provider)
|
|
_provider = provider
|
|
|
|
# httpx 是抓取/交易两侧唯一的外部 HTTP 客户端，打桩后所有 AsyncClient 请求
|
|
# 自动产生 CLIENT span。失败不影响主链路：进程仍可运行，只是看不到 span。
|
|
try:
|
|
HTTPXClientInstrumentor().instrument()
|
|
except Exception:
|
|
logger.warning("httpx 自动 instrumentation 失败", exc_info=True)
|
|
|
|
logger.info(
|
|
"OpenTelemetry 已启用：endpoint=%s service=%s",
|
|
settings.otel_endpoint,
|
|
service_name,
|
|
)
|
|
|
|
|
|
def instrument_app(app: "FastAPI") -> None:
|
|
"""FastAPI 应用打桩。必须在应用开始服务之前调用，与 setup_telemetry 的先后无关。
|
|
|
|
**不能用 `_provider is None` 做前置判断**：三个服务都在模块导入时执行
|
|
`app = create_app()`，而 `setup_telemetry` 要等 lifespan 启动才跑，那时
|
|
`_provider` 还是 None——照着判断就会直接 return，FastAPI 永远没被打桩，
|
|
观测后台里一条 server span 都不会有。
|
|
|
|
反过来「等 lifespan 里再打桩」也不行：instrument_app 是往应用上加中间件，
|
|
应用一旦开始服务，加进去的中间件不生效（实测 lifespan 内调用后 server span
|
|
为空）。所以只能在这里、在导入期就装上。
|
|
|
|
provider 尚未设置时拿到的是 ProxyTracer，它在 `set_tracer_provider` 之后会
|
|
自动委托到真实 provider（实测：导入期打桩 + lifespan 内设 provider，请求
|
|
照样产生 span），所以顺序不构成问题。
|
|
|
|
otel 关闭时跳过：省掉一层用不上的中间件。
|
|
|
|
`excluded_urls` 把健康检查挡在 server span 之外（默认 `/health$`）：容器
|
|
HEALTHCHECK 每 30 秒探一次、上游也在轮询，这些请求各自是一条孤立 trace，
|
|
量大且没有信息量。配置留空时传 None，让 OTel 回落到它自己的
|
|
`OTEL_PYTHON_FASTAPI_EXCLUDED_URLS` 环境变量。
|
|
"""
|
|
settings = get_settings()
|
|
if not settings.otel_enabled:
|
|
return
|
|
excluded = settings.otel_excluded_urls.strip() or None
|
|
FastAPIInstrumentor.instrument_app(app, excluded_urls=excluded)
|
|
|
|
|
|
def shutdown_telemetry() -> None:
|
|
"""flush + shutdown；幂等，未初始化时直接返回。"""
|
|
global _provider
|
|
if _provider is None:
|
|
return
|
|
try:
|
|
_provider.force_flush()
|
|
_provider.shutdown()
|
|
except Exception:
|
|
logger.debug("关闭 OpenTelemetry provider 失败", exc_info=True)
|
|
_provider = None
|
|
|
|
|
|
def snapshot(
|
|
span: Span,
|
|
name: str,
|
|
html: str | None,
|
|
max_bytes: int,
|
|
*,
|
|
extra: Mapping[str, AttributeValue | None] | None = None,
|
|
) -> None:
|
|
"""把 HTML 作为 span event 上报，超 max_bytes 截断并标注。
|
|
|
|
用于解析失败时复现页面：span 自身只放结构化指标（items 数、source 等），
|
|
完整 HTML 体量大、含商品/价格内容，仅在失败分支通过 event 携带。
|
|
|
|
`extra` 用来带上「这份 HTML 是哪来的」——落地 URL、页面标题、证据文件路径
|
|
之类。光有一坨 HTML 还得自己回头对是哪一步的产物，附在同一条 event 上省事。
|
|
"""
|
|
if html is None or not html:
|
|
return
|
|
original_bytes = len(html)
|
|
truncated = original_bytes > max_bytes
|
|
payload = html if not truncated else html[:max_bytes]
|
|
attributes: dict[str, AttributeValue] = {
|
|
"snapshot.html": payload,
|
|
"snapshot.original_bytes": original_bytes,
|
|
}
|
|
if truncated:
|
|
attributes["snapshot.truncated"] = True
|
|
for key, value in (extra or {}).items():
|
|
if value is not None:
|
|
attributes[key] = value
|
|
span.add_event(name, attributes=attributes)
|
|
|
|
|
|
@contextmanager
|
|
def suppressed() -> Iterator[None]:
|
|
"""在这个上下文里不产生任何自动 instrumentation span。
|
|
|
|
给「空转的长轮询」用：worker 每 30 秒问一次网关有没有活干，绝大多数时候
|
|
返回空。这些请求各自成为一条孤立 trace，量大且没有信息量——把观测后台刷满
|
|
的正是它们。领到任务后的每一次网关调用都在任务根 span 底下，不受影响。
|
|
|
|
**只挡自动 instrumentation**：OTel 那个上下文标记是给 instrumentation 库看的，
|
|
手工 `start_as_current_span` 不看它，照样会建 span。所以在这个上下文里手工埋点
|
|
要走 `span_unless_suppressed`，否则空转长轮询会从另一个口子把孤立 trace 放回来。
|
|
"""
|
|
with suppress_instrumentation():
|
|
yield
|
|
|
|
|
|
@contextmanager
|
|
def span_unless_suppressed(
|
|
tracer: trace.Tracer, name: str, *, kind: SpanKind = SpanKind.INTERNAL
|
|
) -> Iterator[Span]:
|
|
"""同 `start_as_current_span`，但在 `suppressed()` 里退化成 noop span。
|
|
|
|
手工埋点与 `suppressed()` 的配套件。`suppress_instrumentation` 只被
|
|
instrumentation 库尊重，手工建的 span 不受它影响——worker 的 `lease` /
|
|
`lease_query` 正是在 `suppressed()` 里调 `GatewayClient._request` 的，那里若
|
|
无条件建 span，空转的长轮询就会每 30 秒产出一条孤立 trace，等于绕开了
|
|
`suppressed()` 本来要解决的问题。
|
|
|
|
退化时给的是 `INVALID_SPAN`（NonRecordingSpan）：`set_attributes` /
|
|
`record_error` / `record_envelope` 作用在它上面全是 noop，调用方不必分支。
|
|
"""
|
|
if not is_instrumentation_enabled():
|
|
yield trace.INVALID_SPAN
|
|
return
|
|
with tracer.start_as_current_span(name, kind=kind) as span:
|
|
yield span
|
|
|
|
|
|
def record_error(span: Span, exc: BaseException) -> None:
|
|
"""把异常记到 span 上并置 ERROR 状态。
|
|
|
|
单独抽出来是因为 AppError 带的那几个字段（对外错误码 `err_code`、是否可重试
|
|
`retryable`、HTTP 状态码）正是排查时真正要看的东西：按码筛比按异常类名筛更
|
|
贴近上游看到的结果，而 `retryable` 直接决定这次失败该不该重来。异常消息也单独
|
|
落一个属性——`record_exception` 记的 event 在多数观测后台里要展开才看得到，
|
|
列表页按 `error.message` 筛不出来。
|
|
"""
|
|
span.record_exception(exc)
|
|
retryable = getattr(exc, "retryable", None)
|
|
set_attributes(
|
|
span,
|
|
{
|
|
"error.type": type(exc).__name__,
|
|
"error.message": str(exc)[:_MSG_MAX_CHARS],
|
|
"error.code": err_code if isinstance(err_code := getattr(exc, "err_code", None), int) else None,
|
|
"error.retryable": retryable if isinstance(retryable, bool) else None,
|
|
"error.status_code": sc if isinstance(sc := getattr(exc, "status_code", None), int) else None,
|
|
},
|
|
)
|
|
span.set_status(Status(StatusCode.ERROR, f"{type(exc).__name__}: {exc}"))
|
|
|
|
|
|
def record_envelope(
|
|
span: Span,
|
|
*,
|
|
success: bool,
|
|
err_code: int | None = None,
|
|
msg: str | None = None,
|
|
status_code: int | None = None,
|
|
) -> None:
|
|
"""把 `ApiResponse` 信封的结果记到 span 上。
|
|
|
|
自动 instrumentation 只看 HTTP 层，而本项目的失败**在信封里**：一次
|
|
`success=false, code=6002` 的回报，HTTP 层跟成功的调用长得一模一样（很多还
|
|
是 200）。于是 trace 里只剩「调用发生过」，「这次到底成没成、错在哪个码」
|
|
全在 body 里，不显式记就永远看不到——这正是「只知道调用了、不知道异常怎么
|
|
来的」的直接原因。
|
|
|
|
出入两侧都用它：服务端异常处理器往 server span 上记（见 `shared.api`），
|
|
worker 解信封时往 client span 上记（见 `trading.worker.client`），同一套
|
|
`api.*` 属性名，一条 trace 里两侧的结论可以直接对上。
|
|
"""
|
|
set_attributes(
|
|
span,
|
|
{
|
|
"api.success": success,
|
|
"api.code": err_code,
|
|
"api.status_code": status_code,
|
|
"api.msg": msg[:_MSG_MAX_CHARS] if msg else None,
|
|
},
|
|
)
|
|
if not success:
|
|
span.set_status(Status(StatusCode.ERROR, msg or f"api.code={err_code}"))
|
|
|
|
|
|
def add_event(
|
|
span: Span, name: str, attributes: Mapping[str, AttributeValue | None]
|
|
) -> None:
|
|
"""记一条 span event，跳过 None 值属性。
|
|
|
|
「过程」不能用属性表达：同名属性后写覆盖先写，三次抓取尝试写完只剩最后一次
|
|
的状态码，中间那两次为什么失败、升级到哪一级全被盖掉了。每次尝试各记一条
|
|
event，链路里才看得出升级路径。
|
|
"""
|
|
span.add_event(
|
|
name,
|
|
attributes={key: value for key, value in attributes.items() if value is not None},
|
|
)
|
|
|
|
|
|
def record_parse_failure(
|
|
span: Span,
|
|
exc: BaseException,
|
|
*,
|
|
html: str | None = None,
|
|
max_bytes: int = 0,
|
|
url: str | None = None,
|
|
stage: str | None = None,
|
|
) -> None:
|
|
"""页面类操作失败的统一记法：错误详情 + 失败阶段 + 失败页面快照。
|
|
|
|
抓取侧与 ラクマ 侧一共十个接口的失败分支原本各写一遍同样三步，且都漏了最关键
|
|
的一件事——**失败在哪一步**。`html` 是否已拿到恰好就是判据：还是空说明页面根本
|
|
没取回来（通道 / 反爬 / 上游 5xx），非空说明取回了但解析不出（多半站点改版）。
|
|
两者的排查方向完全相反，所以作为属性直接落下来，不让人对着一坨 HTML 猜。
|
|
|
|
`stage` 可显式覆盖：像 `shop_items` 那种「转调另外两个接口」的编排方法，失败
|
|
既不在自己的 fetch 也不在自己的 parse，据 html 推断只会给出错的结论。
|
|
"""
|
|
record_error(span, exc)
|
|
set_attributes(
|
|
span,
|
|
{
|
|
"parse.stage": stage or ("fetch" if not html else "parse"),
|
|
# 保留原有属性名（观测后台的既有筛选条件），但值改成真实异常类名——
|
|
# 原先无论什么失败都写死 "parse_error"，把反爬阻断也说成解析失败。
|
|
"parse.fail_reason": type(exc).__name__,
|
|
},
|
|
)
|
|
snapshot(span, "parse.failed_html", html, max_bytes, extra={"parse.url": url})
|
|
|
|
|
|
def traced(
|
|
name: str,
|
|
*,
|
|
kind: SpanKind = SpanKind.INTERNAL,
|
|
) -> Callable[[Callable[P, Awaitable[R]]], Callable[P, Awaitable[R]]]:
|
|
"""给 async 方法套一层 span，异常自动记录后原样抛出。
|
|
|
|
交易侧的实际工作是 Playwright 页面操作，httpx 自动 instrumentation 完全看不到
|
|
（浏览器请求不走 httpx），所以这些步骤必须手工埋点，否则 trace 里只剩 worker
|
|
与网关之间的 HTTP 往返。用装饰器而不是在每个方法里写 with 块，是因为这些方法
|
|
的函数体都已经很长，再加一层缩进不利于阅读。
|
|
|
|
未启用 telemetry 时 tracer 是 noop，装饰器只多一次函数调用，可以无条件套。
|
|
"""
|
|
|
|
def decorate(fn: Callable[P, Awaitable[R]]) -> Callable[P, Awaitable[R]]:
|
|
@functools.wraps(fn)
|
|
async def wrapper(*args: P.args, **kwargs: P.kwargs) -> R:
|
|
tracer = trace.get_tracer(fn.__module__)
|
|
with tracer.start_as_current_span(name, kind=kind) as span:
|
|
try:
|
|
return await fn(*args, **kwargs)
|
|
except Exception as exc:
|
|
record_error(span, exc)
|
|
raise
|
|
|
|
return wrapper
|
|
|
|
return decorate
|
|
|
|
|
|
def set_attributes(span: Span, attributes: Mapping[str, AttributeValue | None]) -> None:
|
|
"""批量设置属性，跳过 None 值。
|
|
|
|
站点交互里大量字段是可选的（site_order_id 要到提交后才有、payable_yen 只在
|
|
确认页解析后才有），逐个 if 判断会把埋点代码写得比业务逻辑还长。
|
|
"""
|
|
for key, value in attributes.items():
|
|
if value is not None:
|
|
span.set_attribute(key, value)
|
|
|
|
|
|
def _parse_headers(raw: str | None) -> list[tuple[str, str]] | None:
|
|
"""解析 "k1=v1,k2=v2" 形式的 header 配置；空输入返回 None。"""
|
|
if not raw or not raw.strip():
|
|
return None
|
|
pairs: list[tuple[str, str]] = []
|
|
for chunk in raw.split(","):
|
|
key, sep, value = chunk.partition("=")
|
|
if not sep or not key.strip():
|
|
continue
|
|
pairs.append((key.strip(), value.strip()))
|
|
return pairs or None
|
|
|
|
|
|
def is_initialized() -> bool:
|
|
"""供测试断言使用。"""
|
|
return _provider is not None
|