文档目录

4.6 配套代码：追踪、日志与基数控制

对应小节：4.6 应用可观测性三部分：① OpenTelemetry 追踪接入；② 日志异步化与降开销；③ 指标基数控制。

一、OpenTelemetry 追踪接入

// build.gradle.kts
dependencies {
    implementation("io.opentelemetry:opentelemetry-api:1.43.0")
    implementation("io.opentelemetry:opentelemetry-sdk:1.43.0")
    implementation("io.opentelemetry:opentelemetry-exporter-otlp:1.43.0")
    implementation("io.opentelemetry:opentelemetry-extension-kotlin:1.43.0")
    implementation("io.opentelemetry.instrumentation:opentelemetry-kotlin-coroutines:1.32.0-alpha")
}

// src/main/kotlin/tracing/Tracing.kt
package tracing

import io.opentelemetry.api.OpenTelemetry
import io.opentelemetry.api.common.AttributeKey
import io.opentelemetry.api.trace.Span
import io.opentelemetry.api.trace.SpanKind
import io.opentelemetry.api.trace.StatusCode
import io.opentelemetry.api.trace.Tracer
import io.opentelemetry.sdk.OpenTelemetrySdk
import io.opentelemetry.sdk.trace.SdkTracerProvider
import io.opentelemetry.sdk.trace.export.BatchSpanProcessor
import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor
import io.opentelemetry.exporter.otlp.http.trace.OtlpHttpSpanExporter
import io.opentelemetry.sdk.trace.samplers.Sampler
import kotlinx.coroutines.withContext
import kotlin.coroutines.CoroutineContext
import kotlin.coroutines.coroutineContext

object Tracing {
    lateinit var tracer: Tracer
        private set

    fun init(samplingRatio: Double = 0.1) {
        val exporter = OtlpHttpSpanExporter.builder()
            .setEndpoint("http://localhost:4318/v1/traces")
            .build()

        val provider = SdkTracerProvider.builder()
            // ⚠️ Head sampling：按比例采样。已知局限：会漏掉慢请求（见下方说明）
            .setSampler(Sampler.traceIdRatioBased(samplingRatio))
            .addSpanProcessor(BatchSpanProcessor.builder(exporter).build())
            .build()

        tracer = OpenTelemetrySdk.builder()
            .setTracerProvider(provider)
            .build()
            .getTracer("app")
    }
}

/**
 * 给一段挂起代码加 Span。
 * 注意：必须保证 Span 在【所有挂起点】都处于当前上下文，
 * 所以要用 withContext(span.asContextElement())（需要 otel-kotlin 扩展）。
 */
suspend fun <T> traced(
    name: String,
    kind: SpanKind = SpanKind.INTERNAL,
    attributes: Map<String, String> = emptyMap(),
    block: suspend () -> T,
): T {
    val span = Tracing.tracer.spanBuilder(name).setSpanKind(kind).apply {
        attributes.forEach { (k, v) -> setAttribute(AttributeKey.stringKey(k), v) }
    }.startSpan()

    return try {
        withContext(span.asContextElement()) {     // 让挂起点也继承这个 Span
            block()
        }
    } catch (e: Throwable) {
        span.setStatus(StatusCode.ERROR, e.message ?: "error")
        span.recordException(e)
        throw e
    } finally {
        span.end()
    }
}

在路由里使用：

get("/orders/{id}") {
    val id = call.parameters["id"]!!

    traced("GET /orders/{id}", SpanKind.SERVER) {
        val order = traced("db.query.orders") {
            repo.findById(id)                    // Span: 数据库查询
        }
        val user = traced("http.user-service", SpanKind.CLIENT) {
            userClient.fetch(order.userId)        // Span: 下游调用
        }
        call.respond(order.copy(userName = user.name))
    }
}

得到的 Span 树（在 Jaeger/Tempo 里查看）：

GET /orders/{id}                          ← 根 Span，200ms
├── db.query.orders                        80ms   ← 一眼看出大头
└── http.user-service                      95ms   ← 和它不相上下

二、采样策略的改进（解决「漏掉慢请求」）

Head sampling 的问题是「随机丢弃」，慢请求本来就少，很可能全被丢掉。三种改进：

// ① 关键路径 100% 采样，其他按比例
val sampler = Sampler.parentBased(
    Sampler.traceIdRatioBased(0.01)      // 默认 1%
)

// ② 在业务代码里对关键操作强制采样
fun createOrder(...) {
    val span = tracer.spanBuilder("createOrder")
        .setSampler(Sampler.alwaysOn())   // 下单必采
        .startSpan()
    // ...
}

// ③ 延迟自适应：请求完成后，如果发现很慢，就强制记录
//    （需要自定义 Sampler 或在应用层做，例如：慢请求额外写一条日志/指标）

生产推荐组合：

流量类型	采样率
核心链路（下单、支付）	100%
一般接口	1%–10%
健康检查、静态资源	0%（不采样）
慢请求 / 错误请求	100%（用 tail sampling 在 collector 侧实现）

Tail sampling 的配置思路（在 OTel Collector 里）：

# otel-collector-config.yaml
processors:
  tail_sampling:
    decision_wait: 10s
    policies:
      - name: errors
        type: status_code
        status_code: { status_codes: [ERROR] }
      - name: slow-requests
        type: latency
        latency: { threshold_ms: 500 }      # 超过 500ms 的请求全部保留
      - name: baseline
        type: probabilistic
        probabilistic: { sampling_percentage: 1 }

这是解决「追踪里看不到慢请求」的标准方案——慢请求 100% 保留，其余抽样。

三、日志：异步化与降开销

3.1 Logback 异步配置

<!-- src/main/resources/logback.xml -->
<configuration>
    <!-- 异步 appender：日志写入不阻塞业务线程 -->
    <appender name="ASYNC_FILE" class="ch.qos.logback.classic.AsyncAppender">
        <!-- 队列大小：太小会丢日志，太大会占内存 -->
        <queueSize>8192</queueSize>
        <!-- 丢弃 threshold：队列满时丢弃 TRACE/DEBUG/INFO，保留 WARN/ERROR -->
        <discardingThreshold>0</discardingThreshold>
        <!-- 不丢弃任何级别（适合排障期；生产可设为 20 让 INFO 可丢） -->
        <neverBlock>true</neverBlock>     <!-- ⭐ 队列满时不阻塞业务线程 -->
        <appender-ref ref="FILE"/>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>/var/log/app/app.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>/var/log/app/app.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <maxFileSize>100MB</maxFileSize>
            <maxHistory>7</maxHistory>
            <totalSizeCap>5GB</totalSizeCap>
        </rollingPolicy>
        <encoder>
            <!-- ⚠️ 不要用 %L / %line / %caller：获取行号需要构造调用栈，非常贵 -->
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <!-- 业务日志走异步 -->
    <logger name="com.example" level="INFO" additivity="false">
        <appender-ref ref="ASYNC_FILE"/>
    </logger>

    <root level="WARN">
        <appender-ref ref="ASYNC_FILE"/>
    </root>
</configuration>

四个关键配置的理由：

配置	理由
`AsyncAppender`	业务线程只把日志放进队列，不等落盘
`neverBlock=true`	⭐ 队列满时丢弃日志而不是阻塞业务——这是「宁可丢日志也不拖慢服务」的取舍
不用 `%L` / `%line`	获取行号要构造异常栈，单条日志可能贵 10 倍以上
`totalSizeCap`	防止日志写满磁盘

3.2 代码层面的日志优化

// ❌ 字符串在调用前就拼好了（即使级别不够也会拼接 + 分配）
log.debug("order=${order.id}, items=${order.items.map { it.name }}")

// ✅ 参数化：级别不够时不拼接
log.debug("order={}, itemCount={}", order.id, order.items.size)

// ✅ 真正昂贵的计算：先判断级别
if (log.isDebugEnabled) {
    log.debug("full dump={}", expensiveSerialize(order))
}

// ❌ 热路径上的 INFO 日志（每个请求都写）
log.info("processing order {}", order.id)

// ✅ 降级为 DEBUG，或采样记录
if (order.id % 1000 == 0L) log.info("sampled order {}", order.id)

3.3 验证日志开销

# 方法一：JFR 看文件写入事件
jfr print --events jdk.FileWrite /tmp/recording.jfr | grep -c "app.log"

# 方法二：async-profiler 看分配火焰图里有没有 StringBuilder / String.format
asprof -d 60 -e alloc -f alloc.html "$PID"

# 方法三：单变量实验——把日志级别降到 ERROR，对比 P99
# （这是最直接的因果验证）

四、指标基数控制

4.1 危险的标签

// ❌ 每一个都是灾难
registry.counter("req", "userId", userId)          // 用户 ID：无界
registry.counter("req", "orderId", orderId)        // 订单号：无界
registry.counter("req", "traceId", traceId)        // 追踪 ID：无界
registry.counter("req", "uri", "/orders/$id")      // 具体 URL：无界
registry.counter("req", "timestamp", now.toString()) // 时间戳：无界

// ✅ 可枚举维度
registry.counter("req",
    "uri", "/orders/{id}",        // 路由模板
    "method", "GET",              // 有限集合
    "status", "200",              // 有限集合（或归类为 2xx/4xx/5xx）
    "tenant_type", "free|paid")   // 有限集合

4.2 基数监控与告警

# ① 找出序列数最多的指标
topk(10, count by (__name__) ({__name__=~".+"}))

# ② 找出某个指标里基数最高的标签值
topk(10, count by (uri) (http_server_requests_seconds_count))

# ③ 总数趋势（持续增长 = 有基数泄漏）
sum(count by (__name__) ({__name__=~".+"}))

告警规则：

- alert: MetricCardinalityExplosion
  expr: |
    sum(count by (__name__) ({__name__=~".+"})) > 500000
  for: 10m
  annotations:
    summary: "Prometheus 时间序列总数超过 50 万，可能存在基数泄漏"

4.3 已经在生产踩坑后的处理

# 找出哪个指标贡献了最多序列
curl -s 'http://prometheus:9090/api/v1/query?query=topk(20,count by (__name__)({__name__=~".+"}))' \
  | python3 -m json.tool | head -40

找到后：① 修改埋点（去掉无界标签）；② 用 metric_relabel_configs 在抓取时丢弃该指标；③ 重启 Prometheus 或删除相关数据释放内存。

# prometheus.yml 里的应急配置
scrape_configs:
  - job_name: kotlin-app
    metric_relabel_configs:
      # 丢弃某个高基数指标
      - source_labels: [__name__]
        regex: 'some_high_cardinality_metric.*'
        action: drop

五、动手改造

改动	观察什么
把 head sampling 从 1% 改成 100%	collector 与存储的压力变化——理解采样的成本
给下单接口单独设 `alwaysOn()`	追踪里能看到完整的下单链路
把 `neverBlock` 改成 `false`	队列满时业务线程被阻塞，P99 上升——验证异步日志的价值
在 pattern 里加上 `%L`（行号）	用 JFR 的 `jdk.FileWrite` 对比写入耗时，或直接看 P99 变化
故意给指标加一个 `userId` 标签，压测 10 分钟	观察 Prometheus 内存与序列数增长——这是最直观的基数教训

六、这段代码的局限

OTel 的 Kotlin 协程支持仍在演进：asContextElement() 需要 opentelemetry-kotlin-coroutines 扩展，版本兼容性要注意。
Tail sampling 需要额外的 Collector（缓冲全部 span），资源成本不低——小规模场景可以先只用「关键路径 100% + 其余 1%」。
AsyncAppender 的 neverBlock=true 会丢日志：这在排障期是问题（关键日志可能丢），可以临时改成阻塞模式或提高队列大小。
基数问题一旦发生，处理成本很高（要清数据/重启 Prometheus），所以最好的策略是在埋点时就控制住。

4.6 配套代码：追踪、日志与基数控制#

一、OpenTelemetry 追踪接入#

二、采样策略的改进（解决「漏掉慢请求」）#

三、日志：异步化与降开销#

3.1 Logback 异步配置#

3.2 代码层面的日志优化#

3.3 验证日志开销#

四、指标基数控制#

4.1 危险的标签#

4.2 基数监控与告警#

4.3 已经在生产踩坑后的处理#

五、动手改造#

六、这段代码的局限#