可观测性
pkg/core/obs 一次给齐三件事:结构化日志、Prometheus 指标、
OpenTelemetry 链路。日志默认开,指标随 /metrics 暴露,链路是 opt-in
且关掉时全部为 no-op。
日志:slog JSON 加一个相关 id
verticle.Run 启动时调用 obs.Init(name, level):JSON 写到
stdout,每条都带 "service" 字段。业务代码一律用带 ctx 的包级函数,
相关 id 会自动挂上,不需要传 logger:
func Init(service string, level string) error {
var lv slog.Level
if err := lv.UnmarshalText([]byte(level)); err != nil {
lv = slog.LevelInfo
}
h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: lv})
slog.SetDefault(slog.New(h).With("service", service))
return nil
}
func Debug(ctx context.Context, msg string, args ...any) { Log(ctx).Debug(msg, args...) }
func Info(ctx context.Context, msg string, args ...any) { Log(ctx).Info(msg, args...) }
func Warn(ctx context.Context, msg string, args ...any) { Log(ctx).Warn(msg, args...) }
func Error(ctx context.Context, msg string, args ...any) { Log(ctx).Error(msg, args...) }
obs.Info(ctx, "user created", "user_id", 123, "dur_ms", 12)
// {"time":"…","level":"INFO","msg":"user created","service":"demo","trace_id":"a1b2c3d4","user_id":123,"dur_ms":12}
obs.Log(ctx) 是"已经带上 trace_id 的 logger",要传给别的库时用它。
不要 fmt.Println 打日志,也不要自己 new logger。
obs.TraceID(ctx) 先问当前 span:开了 tracing 就是 span 的 trace id
(32 位 hex,能直接拿去追踪后端查);没有 span 就取 WithTraceID 塞进
ctx 的请求级 id。所以把 tracing 打开的那一刻,日志里的相关 id 自动升级为
trace id,调用点一行都不用改。
相关 id 的来源与优先级
httpx 的封套层按顺序取第一个可用的值,然后回写响应头
X-Request-ID:
| 顺序 | 来源 | 说明 |
|---|---|---|
| 1 | 入站 X-Request-ID |
调用方自己带的关联 id,原样透传(便于跨系统对齐);超过 128 字节截断 |
| 2 | 当前 span 的 trace id | 仅当 tracing 开启且入站未带 id |
| 3 | 新生成的 8 字节 hex | 两者都没有时兜底,保证日志一定可关联 |
// pkg/core/httpx/server.go
traceID := r.Header.Get("X-Request-ID")
if len(traceID) > maxTraceIDLen {
// An oversized id would ride along in every log line.
traceID = traceID[:maxTraceIDLen] // = 128
}
if traceID == "" {
traceID = obs.TraceID(spanCtx)
}
if traceID == "" {
traceID = newTraceID()
}
w.Header().Set("X-Request-ID", traceID)
X-Request-ID 会跟着这个请求产生的
每一条日志、每一个 span 属性走,把存储和带宽吃掉。W3C trace id 只有 32 个 hex 字符,
超过 128 字节的已经不是关联 id 了,直接截断。
请求的 ctx 与连接解耦,相关 id 在这一步注入。所以客户端断连不会污染 id,handler 也还能把副作用写完(记 499,详见 HTTP 与路由):
ctx, cancel := context.WithTimeout(
context.WithoutCancel(obs.WithTraceID(spanCtx, traceID)), s.cfg.Timeout)
defer cancel()
Prometheus 指标
obs.NewMetrics() 建一个独立 registry,装 Go runtime / process 收集器
与两个框架指标,GET /metrics 用的就是这个 registry:
| 指标 | 类型 | 标签 |
|---|---|---|
http_server_requests_total |
counter | route method code |
http_server_request_duration_seconds |
histogram | route method code |
go_* / process_* |
runtime / 进程 | — |
route 取的是 http.Request.Pattern,即路由模板
(GET /api/v1/hello/{name})而不是原始路径——否则每个用户 id 都会
变成一个独立时间序列。code 来自封套层记录的状态码,客户端断开记 499。
自定义指标在 Setup 里注册。env.Metrics 在 Setup
之前就已就绪,且与 /metrics 共用同一个 registry:
func (s *obsService) Setup(ctx context.Context, env *verticle.Env) error {
s.work = env.Metrics.Counter("observe_work_total", "processed calls", "name")
s.value = env.Metrics.Gauge("observe_last_value", "last computed value", "name")
return nil
}
// handler 里
s.work.WithLabelValues(name).Inc()
s.value.WithLabelValues(name).Set(float64(value))
Counter / Gauge / Histogram 三个方法签名与
prometheus 一致,Histogram 传空 buckets 表示用 prometheus.DefBuckets。
同名重复声明返回第一次的句柄(库与服务各自声明同一指标不会互相炸),
但同名声明成不同类型会 panic —— 这属于真 bug,应该启动就发现。
OpenTelemetry 链路
默认关闭。开关只有配置,代码不写分支:
trace:
enabled: false
# endpoint: "localhost:4317" # OTLP/gRPC collector;留空则只生成 span 不外发
# sample_ratio: 1.0 # 采样比例 0~1(0 = 全丢,1 = 全采)
# export_timeout: 10s
| 配置键 | tag 默认值 | 作用 |
|---|---|---|
trace.enabled |
false |
总开关。关着时 InitTracing 清空 provider 与传播器,回到纯 X-Request-ID 行为 |
trace.endpoint |
空(optional) | OTLP/gRPC collector 地址,如 localhost:4317;留空则 span 只带 trace id 不上报 |
trace.insecure |
空(optional) | OTLP/gRPC 以明文拨号(集群内常见形态,TLS 交给 mesh) |
trace.sample_ratio |
1.0 |
头部采样比例;≥1 全采,≤0 全丢,中间值按 trace id 比例采 |
trace.export_timeout |
10s |
单批导出的上限;≤0 时在 InitTracing 里回填 10s |
sampler 一律包一层 ParentBased:上游已经决定采样的链路始终保留,
否则追踪后端只会看到半条链——比没有更难用。开启后 Run 拿到一个
shutdown 函数,在优雅退出的排空阶段 flush 最后一批 span。
// 业务代码加子 span:关着的时候是 no-op span,不用写 if tracing 分支
ctx, span := obs.StartSpan(ctx, "compute")
defer span.End()
// 出站调用时把链路带出去(HTTP)
h := http.Header{}
obs.InjectHTTP(ctx, h) // 写入 traceparent,下游服务续接同一条链路
HTTP 侧由封套层自动完成:obs.StartHTTPSpan 从请求头 extract 出
traceparent 续接调用方的链路,开一个 SpanKindServer 的 span,
span 名与 http.route 都取路由模板(低基数),响应时
obs.EndHTTPSpan 记上 http.response.status_code 并结束。
StartHTTPSpan 直接返回原 ctx 与 no-op span,不读
入站的 traceparent:读进来会往 ctx 里塞一个活的 SpanContext,把相关 id 劫持成对方的
trace id——而本进程根本没记录任何 span。这是"关掉 tracing 后行为与接入前完全一致"
的实现细节。
跨进程传播:三条通道都是自动的
| 通道 | 载体 | 接入方式 | 关闭时 |
|---|---|---|---|
| HTTP | 请求头(traceparent) |
httpx 封套层,业务零代码 |
no-op span,相关 id 回落 X-Request-ID |
| gRPC | gRPC metadata 的 traceparent |
服务端 unary / stream 拦截器 + 客户端 unary / stream 拦截器,New/Dial 时无条件装上 |
no-op tracer + no-op propagator |
| rpcx | 请求 metadata(share.ReqMetaDataKey) |
服务端 plugin(PreHandleRequest + PostCall)+ 客户端 XClient 包装 |
同上 |
obs.Extract / obs.Inject 接受任意
propagation.TextMapCarrier,gRPC 与 rpcx 各自用一个薄适配层把 metadata
包成 carrier,因此走的是同一套 W3C 传播器。rpcx 的 Failtry 重试会在同一个
client span 下重发,一次逻辑调用一个 span。
一个请求经过两个服务
sequenceDiagram
autonumber
participant C as 客户端
participant A as 服务 A(http + 日志 + 指标)
participant B as 服务 B
participant O as OTLP collector
C->>A: GET /api/v1/hello/world
traceparent / X-Request-ID
A->>A: StartHTTPSpan:extract 出 trace id
开 server span(名=路由模板)
A->>A: ctx 注入 trace id → 每条日志带 trace_id
A->>A: obs.StartSpan("compute") 子 span
A->>B: gRPC/rpcx:Inject 写 traceparent 到 metadata
B->>B: 拦截器/plugin:Extract → 续接同一条链路
B-->>A: 返回(span 结束,状态码作属性)
A->>A: EndHTTPSpan + 记 http_server_* 指标
A-->>C: 响应封套 + X-Request-ID 回写
A-->>O: 批量导出 span(bounded by export_timeout)
B-->>O: 批量导出 span
traceparent,进程内靠 ctx。
日志、指标、链路三者在服务 A 内是同一份请求上下文——所以日志里的
trace_id 能直接跳到追踪后端,指标里的 route
又能定位是哪条路由在变慢。
排障顺序
-
先看指标定位面:
http_server_requests_total按route+code找出是哪条路由的哪类状态码在涨。 -
再用相关 id 收窄:从客户端手上的响应头
X-Request-ID或日志里的trace_id,把这一个请求在所有服务的日志串起来。 - 最后用链路看因果:开了 tracing 时用 trace id 打开完整 span 树, 看时间花在哪一跳、哪一步。
相关示例
- examples/observability:日志带 trace_id、自定义指标、
trace.enabled开箱对比。 - examples/grpc:gRPC 通道的自动跨进程传播。
- examples/rpcx:rpcx plugin + 客户端包装的传播。