Files
conti-backend/docs/08-observability.md
T
2026-08-17 15:31:27 +08:00

20 KiB
Raw Blame History

08. 可观测性

决策

统一 Trace ID + 结构化(JSON)日志 + Micrometer 指标,对应架构图 Cross-Cutting 里的 Observability 要求;关键行为单独走审计日志通道,对应 Audit / Security

traceId 用 Spring Boot 自带的 Micrometer Tracing 生成和传播,不自己写 TraceIdFilter——理由见下一节。

结构约定

platform-observability/
  ClientTraceIdBridgeFilter      # 把客户端的 X-Trace-Id 接进 Micrometer 的 trace 上下文
  TraceResponseFilter             # 把最终生效的 traceId 写回响应头
  logback-spring.xml               # 结构化日志格式 + 脱敏配置
  MetricsConfig                     # Micrometer 基础配置,暴露 /actuator/prometheus
  AuditLogAspect                     # AOP 切面,标注 @Audited 的方法自动记录审计日志

traceId:用 Micrometer Tracing

// build.gradle
implementation 'org.springframework.boot:spring-boot-starter-actuator'
implementation 'io.micrometer:micrometer-registry-prometheus'
implementation 'io.micrometer:micrometer-tracing-bridge-otel'   // 版本由 Boot BOM 管
management:
  tracing:
    enabled: true              # 开着:这是 traceId 进 MDC 的前提,关掉连日志里的 traceId 都没有了
    export:
      enabled: false           # 但不往任何后端上报 span —— 我们现在只要日志关联,不建全链路追踪系统
    sampling:
      probability: 1.0         # 不上报就没有采样成本,全采即可,避免部分请求日志里没有 traceId

加上依赖之后,Spring Boot 会自动:

  • 为每个进来的 HTTP 请求创建一个 span,把 traceId / spanId 自动放进 MDC
  • 出站的 RestClient 调用自动带上 W3C 标准的 traceparent 头(前提是用注入的 RestClient.Builder 构建,见 05-integration-layer.md);
  • 线程池、@Async@Scheduled 等场景由 Micrometer 的上下文传播机制接管,不需要自己搬运 MDC。

为什么不自己写 TraceIdFilter:自己写的版本只覆盖"HTTP 入口 + 手工加请求头"这两个点,一旦出现线程切换(并行聚合、异步任务)或者需要跟别的系统按标准协议对接,就要自己一点点补;而这些正是最容易漏、漏了又最难查的地方(日志断链时你只会觉得"这个请求怎么没日志")。Micrometer Tracing 是 Boot 的一等公民,这些点框架都已经处理好,而且将来真要接 APMJaeger/Zipkin/Application Insights)时,只需要加一个 exporter 依赖、把 export.enabled 打开,代码一行不用改。

与客户端 X-Trace-Id 的对接契约

客户端每个请求都会带一个自己生成的 X-Trace-Id(见 ../05-networking.md),要求"后端复用它",这样一次用户操作在 APP 日志和服务端日志里是同一个 ID。但 Micrometer 认的是 W3C 的 traceparent 头,所以中间需要一层桥接:

契约(同时解决客户端文档里挂着的那条待确认项)

  1. 客户端生成的 X-Trace-Id 必须是 32 位小写十六进制字符(UUID 去掉四个横线正好 32 位 hex,直接用即可),且不能全为 0
  2. 后端校验通过则用它作为本次请求的 traceId校验不通过就忽略它,自行生成——绝不把一个未经校验的请求头值直接当 ID 用。
  3. 后端在响应头里回写最终生效的 X-Trace-Id,客户端以响应头为准(这样客户端能发现自己的值被丢弃了)。
  4. ApiResult.traceId 返回的也是这个最终生效的值。
// platform-observability/.../ClientTraceIdBridgeFilter.kt
@Component
@Order(Ordered.HIGHEST_PRECEDENCE)     // 必须排在 Micrometer 的 observation filter 之前
class ClientTraceIdBridgeFilter : OncePerRequestFilter() {

    companion object {
        // 只接受 W3C trace-id 格式。这条正则同时也是安全边界:
        // 请求头的值会进日志,不校验就等于允许任何人往日志里注入内容(换行伪造日志行、
        // 塞进超长字符串撑爆日志存储、塞进控制字符干扰下游日志解析)。
        private val TRACE_ID = Regex("^[0-9a-f]{32}$")
        private const val INVALID = "00000000000000000000000000000000"
    }

    override fun doFilterInternal(request: HttpServletRequest, response: HttpServletResponse, chain: FilterChain) {
        val clientTraceId = request.getHeader("X-Trace-Id")
        if (clientTraceId == null || !TRACE_ID.matches(clientTraceId) || clientTraceId == INVALID) {
            chain.doFilter(request, response)     // 不合法就当没传,让 Micrometer 自己生成
            return
        }

        // 合成一个 W3C traceparent,让 Micrometer 把它当作父上下文接上,
        // 于是服务端这次请求的 traceId 就等于客户端传来的值。
        val traceparent = "00-$clientTraceId-${randomSpanId()}-01"
        chain.doFilter(TraceparentRequestWrapper(request, traceparent), response)
    }
}

// platform-observability/.../TraceResponseFilter.kt —— 排在 observation filter 之后,此时 MDC 已有 traceId
@Component
class TraceResponseFilter : OncePerRequestFilter() {
    override fun doFilterInternal(request: HttpServletRequest, response: HttpServletResponse, chain: FilterChain) {
        MDC.get("traceId")?.let { response.setHeader("X-Trace-Id", it) }
        chain.doFilter(request, response)
    }
}
// platform-web/.../TraceIdSupport.kt —— 06-api-design.md 里 ApiResult 用的就是它
fun currentTraceId(): String = MDC.get("traceId") ?: "unknown"

出站调用侧,除了 Micrometer 自动加的 traceparent,还会额外发一个 X-Trace-Id 给 F6 这类只认自定义头的外部系统,见 05-integration-layer.mdTracePropagationInterceptor

结构化日志

<!-- logback-spring.xml -->
<configuration>
    <appender name="JSON" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
            <includeMdcKeyName>traceId</includeMdcKeyName>
            <includeMdcKeyName>spanId</includeMdcKeyName>
            <customFields>{"app":"conti-backend","env":"${SPRING_PROFILES_ACTIVE:-local}"}</customFields>

            <!-- 兜底脱敏:即使有人不小心把整个对象打进日志,这些字段的值也会被替换掉。
                 它是最后一道防线,不是免死金牌 —— 主要靠下面"日志规范"里的规则。 -->
            <jsonGeneratorDecorator class="net.logstash.logback.mask.MaskingJsonGeneratorDecorator">
                <path>password</path>
                <path>accessToken</path>
                <path>refreshToken</path>
                <path>authorization</path>
            </jsonGeneratorDecorator>
        </encoder>
    </appender>
    <root level="INFO">
        <appender-ref ref="JSON" />
    </root>
</configuration>
// build.gradle
implementation 'net.logstash.logback:logstash-logback-encoder:9.0'   // 9.0 起用 Jackson 3,匹配 Boot 4

输出的每条日志会带上 traceId 字段,直接对接现有 ELK 方案(见 Architecture-Diagram/ODP ELK Logging Solution Project - Overview.pdf)时可以按 traceId 过滤出一次请求的完整链路日志。

日志级别规范

统一标准,避免"所有人都打 INFO"导致真正重要的信息被淹没:

级别 用在什么地方 是否告警
ERROR 需要人介入处理的问题:未预期异常、数据不一致、下游持续不可用
WARN 系统自己处理掉了但值得关注:降级返回、重试成功、乐观锁冲突、参数校验失败率异常 聚合后看趋势
INFO 关键业务节点:登录、切店、换票、外部系统调用的结果
DEBUG 排查用的中间状态 生产环境默认关闭
TRACE 不在生产环境使用
  • 用户输入错误不是 ERROR。参数校验失败、token 过期、无权限属于正常业务流,打 WARNINFO,打成 ERROR 会让告警彻底失去意义。
  • catch 住并处理掉的异常不打 ERROR,打 WARN 并说明降级动作。
  • 异常要把 Throwable 作为最后一个参数传进去log.error("xxx 失败", ex)),不要 log.error("xxx 失败: " + ex.message)——后者丢掉堆栈,等于放弃了排查的主要线索。
  • 生产环境日志级别可以通过 /actuator/loggers 端点临时调整(该端点仅内网可达),排查完记得调回来。

敏感信息脱敏

绝不进日志:密码、Authorization 头及其中的 token、refresh token、JWT 签名密钥、数据库密码、F6 API key。

需要脱敏后才能进日志:手机号(138****8000)、姓名、身份证号、车牌号、VIN、详细地址、银行卡号。这套系统涉及车主和车辆信息,车牌和 VIN 是能定位到具体个人的,按 PII 对待。

落地规则:

  1. 禁止把整个请求体/Entity 对象直接打进日志log.info("req={}", request))。今天这个对象里没有敏感字段,不代表明天加一个字段之后还没有——而加字段的人不会想起来去检查有哪些地方打过这个对象的日志。要打就显式列出需要的字段。
  2. 确实要打的敏感字段走统一的脱敏工具方法(Mask.phone(...)Mask.plateNo(...)),不各写各的。
  3. 上面 logback 里的 MaskingJsonGeneratorDecorator 是兜底,防的是"不小心写漏了",不是"有它就可以随便打"——它只按字段名匹配 JSON 结构,拼在字符串里的敏感值它一个都拦不住。
  4. 异常堆栈也可能带出敏感信息(比如 SQL 参数、请求 URL 上的查询串),所以 URL 上不放敏感参数——需要传就放请求体。

Micrometer / Actuator 配置

management:
  endpoints:
    web:
      exposure:
        include: health, prometheus, info
  endpoint:
    health:
      probes:
        enabled: true       # 暴露 /actuator/health/liveness、/readiness,供 K8s 探针使用
  metrics:
    tags:
      application: conti-backend

/actuator/prometheus/actuator/loggers 不对公网暴露:只在集群内可达(SecurityConfig 里只 permitAll 了 /actuator/health/**,见 04-security-auth.md),Prometheus 从集群内抓取。

K8s 探针配置(liveness / readiness

management.endpoint.health.probes.enabled=true 只是让 Spring Boot 暴露出 /actuator/health/liveness/actuator/health/readiness 两个分组端点,真正让 K8s 用起来还需要在 Deployment 里配置探针指向这两个端点:

# k8s/deployment-uat.yaml(节选,补充探针配置)
spec:
  containers:
    - name: conti-backend
      startupProbe:                       # 启动阶段专用,跑通之前 liveness/readiness 都不生效
        httpGet:
          path: /actuator/health/liveness
          port: 8080
        periodSeconds: 5
        failureThreshold: 30              # 最多给 150 秒完成 JVM 启动 + Flyway 迁移
      livenessProbe:
        httpGet:
          path: /actuator/health/liveness
          port: 8080
        periodSeconds: 10
      readinessProbe:
        httpGet:
          path: /actuator/health/readiness
          port: 8080
        periodSeconds: 5

startupProbe 而不是给 liveness 配一个很大的 initialDelaySeconds:后者是"所有情况下都固定等这么久",启动快的时候白等,启动慢的时候(比如某次迁移脚本比较大)仍然会被误杀;startupProbe 是"给足上限、就绪即结束",两头都照顾到。

两者失败后的处理完全不同,容易搞混:

  • livenessProbe 失败 → K8s 认为这个 Pod 已经"死掉"(比如死锁、内存泄漏导致完全无响应),直接重启这个 Pod。
  • readinessProbe 失败 → K8s 只是把这个 Pod 从 Service 的 Endpoints 里摘除(不再转发流量给它),不重启;等探针恢复健康后自动重新加回来——典型场景是数据库连接池暂时耗尽、正在处理慢请求,这种情况不需要重启,只需要暂时别把新流量导过去。

readiness group 默认会包含数据库连接(DataSourceHealthIndicator)等下游依赖检查,liveness group 默认只检查应用自身状态(不含外部依赖)——这个区分本身也是为了避免"F6 挂了导致 liveness 失败、Pod 被不断重启"这种误杀,外部依赖异常应该走 05-integration-layer.md 的熔断降级,而不是拖累 K8s 探针。

不要把 F6 之类的外部依赖加进 readiness,理由同上:F6 抖一下不应该让我们所有 Pod 同时被摘出负载均衡,那是自己把自己搞挂。

Resilience4j 指标接入 Micrometer

05-integration-layer.md 里给 F6/Mini 调用配置的熔断、重试、舱壁,本身的运行状态也应该能在监控里看到,不然只能等到线上报错才知道降级生效了:

implementation 'io.github.resilience4j:resilience4j-micrometer:2.4.0'

加上这个依赖后,各个 registry 会自动把状态注册成 Micrometer meter,不需要手写埋点,跟着现有的 /actuator/prometheus 一起暴露出去。

关键指标与告警

指标分三类看,缺一类都会有盲区:

① 系统健康

指标 告警起点
http_server_requests_seconds_count{status=~"5.."} 占比 5 分钟内 > 1%
http_server_requests_seconds P99 > 2s 持续 5 分钟
jvm_memory_used_bytes{area="heap"} / max > 85% 持续 10 分钟
hikaricp_connections_pending > 0 持续 1 分钟(有线程在排队等数据库连接,见 03-persistence.md 的池子容量算法)
Pod 重启次数 10 分钟内 ≥ 2 次

② 依赖健康

指标 告警起点
resilience4j_circuitbreaker_state{state="open"} 出现即告警——熔断器跳闸说明下游已经持续故障
resilience4j_bulkhead_available_concurrent_calls 降到 0 持续 1 分钟(并发名额被打满,正在丢请求)
resilience4j_retry_calls{kind="failed_with_retry"} 速率 明显抬升即关注

③ 业务健康(这一类最容易被忘,但恰恰是"系统全绿、用户用不了"时唯一能发现问题的指标)

指标 埋点方式 告警起点
登录成功率 Counterresult 打标签 5 分钟内 < 90%
切店失败数 同上 突增
WebView 换票失败率 同上 5 分钟内 > 5%
首页聚合降级 tile 数 Countertile 打标签 单个 tile 降级率 > 20%
// 业务埋点示例:不要自己维护计数器,用 MeterRegistry
@Service
class LoginService(private val meterRegistry: MeterRegistry) {
    fun login(...): LoginResult {
        val result = doLogin(...)
        meterRegistry.counter("business.login", "result", if (result.success) "success" else "failure").increment()
        return result
    }
}

告警阈值都是起点,不是最终值——上线后按实际曲线调整。阈值定得过敏感导致告警疲劳,比没有告警更糟糕,因为团队会开始习惯性忽略它。

审计日志

// platform-observability/.../Audited.kt
@Target(AnnotationTarget.FUNCTION)
@Retention(AnnotationRetention.RUNTIME)
annotation class Audited(val action: String)

// platform-observability/.../AuditLogAspect.kt
@Aspect
@Component
class AuditLogAspect(private val storeContextHolder: ObjectFactory<StoreContextHolder>) {
    private val auditLog = LoggerFactory.getLogger("AUDIT")

    @Around("@annotation(audited)")
    fun logAudit(joinPoint: ProceedingJoinPoint, audited: Audited): Any? {
        val result = runCatching { joinPoint.proceed() }
        val ctx = runCatching { storeContextHolder.`object` }.getOrNull()
        auditLog.info(
            "action={} userId={} storeId={} traceId={} success={}",
            audited.action, ctx?.userId, ctx?.storeId, currentTraceId(), result.isSuccess,
        )
        return result.getOrThrow()   // 审计失败不能影响业务;反过来业务异常也照常抛出
    }
}

// 使用方式
@Audited(action = "WEBVIEW_TICKET_ISSUE")
fun issueTicket(userId: Long, storeId: Long): WebviewTicket { ... }

审计日志走独立 loggerAUDIT),在 logback-spring.xml 里单独配置一个 appender 写到专门的审计索引,不和普通业务日志混在一起,方便设置更长的保留期和更严格的访问权限。

需要审计的行为:登录/登出、切换门店、WebView 换票、权限变更、任何写操作失败、外部系统调用失败。审计日志只记"谁在什么时候对什么做了什么、成功与否",不记业务数据内容——记内容就要面对上面那一整套脱敏问题。

关键规则

  • traceId 由 Micrometer Tracing 生成(或复用客户端合法的 X-Trace-Id),贯穿到 integration/* 调用外部系统,并随 ApiResult 返回给前端(见 06-api-design.md),方便排障(对应架构图 Flow 2 的"失败可支持排障"要求)。
  • 审计相关的关键行为走单独的审计日志通道。
  • 日志/指标最终对接现有 ELK 方案,具体接入方式(Filebeat 采集 stdout,还是直接推 Logstash)待确认;无论哪种,应用只往 stdout 打日志、不自己写文件——容器里写文件意味着要处理轮转、磁盘占用和 Pod 销毁后日志丢失。

附录:为什么 traceId 走 MDC,而不是每条日志手动传参

不用 MDC 的话,每个方法打日志都要显式传 traceId 参数:log.info("traceId={} 门店切换成功", traceId),深层调用链里每一层都要多加一个参数,代码侵入性很强,还容易漏传。MDCMapped Diagnostic Context)是日志框架提供的"线程内隐式上下文",设置一次,同一线程内后续所有日志调用(不管调用链多深)都会自动带上这个字段,日志格式配置里声明 includeMdcKeyName 即可。

代价和 04-security-auth.md 里提到的 ThreadLocal 类似:MDC 底层就是 ThreadLocal换了线程就丢。这一点在同步 Servlet 栈下大部分时候不用操心,但有一个真实的例外workbench 首页把多个下游并行拉起来时会用到自己的线程池,子线程里默认拿不到 traceId,那部分日志会断链。Micrometer Tracing 提供了 ContextPropagatingTaskDecorator(或 ContextSnapshot)来搬运上下文,配置线程池时必须带上——具体写法见 11-cross-domain-collaboration.md。这也是选 Micrometer 而不是手写 filter 的又一个理由:这套搬运机制是现成的。

待补充

  • 具体接入现有 ELK / APM 的方式和字段规范。
  • 审计日志的存储位置和保留期限(需要和安全/合规确认)。

参考链接