结构化日志正在成为后端服务的标配。相比于一行行自然语言文本，它以键值对形式记录事件，方便聚合分析。对网络API来说，光有JSON格式还不够，关键要让每条日志都能关联到产生它的那个HTTP请求。否则当多个用户同时访问时，日志文件会变成交错的时间线，无法还原单个请求的完整路径。本文以Ruby生态为例，介绍如何在请求进入应用的第一时间注入请求标签，并把这些标签自动带到后续所有日志输出中。
一、为什么需要请求上下文标签
传统的Rails日志默认会输出类似 Started GET "/orders" 这样的信息，但后续业务代码里的 logger.info 并不会自动带上请求方法或请求ID。一旦出现性能抖动或异常，你只能靠时间戳人工猜测哪些日志属于同一次请求。并发量大时，这种方法基本失效。
请求上下文标签的作用，是在请求开始处生成或读取一个唯一ID，并把请求方法、路径、用户身份等附加字段保存到当前线程。之后所有日志输出都从上下文中取出这些字段，合并到结构化字段里。这样一来，在Kibana、Datadog或Loki中，只要按 request_id 过滤，就能看到这个请求从进入到结束的所有日志。
不同团队对标签的叫法可能不同，常见字段包括 request_id、trace_id、span_id、user_id、client_ip、user_agent。需要注意的是，request_id 是链路追踪的最小单位，trace_id 可以串联跨服务的调用，不要混用。
二、基于ActiveSupport::TaggedLogging的轻量方案
如果只是想快速在Rails日志中增加可读性较好的前缀，可以使用 Rails 内置的 ActiveSupport::TaggedLogging。它在不改变日志结构的情况下，用方括号把标签加在每条日志开头。可以通过配置 config.log_tags 来声明要注入的标签。
# config/initializers/logging.rb
Rails.application.configure do
config.log_tags = [
:request_id,
->(request) { request.headers["X-User-Id"] || "anonymous" }
]
end这里的 :request_id 会使用 ActionDispatch::RequestId 分配的请求ID，第二个lambda从请求头读取用户ID。配置完成后，一条典型的日志会变成 [0e8f3e1a-2e1a-4f8d-8c44-11d8dfc9e21b] [user_123] Processing by OrdersController#show as JSON。这个方案最简单，因为Rails已经内置了对应中间件，不需要额外依赖。
但这种方案的缺点也很明显：标签只是拼在文本里的前缀，并没有成为JSON字段。当日志被采集到中心化平台后，如果想按用户ID聚合慢请求，只能靠正则解析字符串，效率和准确性都不理想。因此它适合开发环境和日志量较小的内部系统，不适合严格的结构化日志需求。
三、用自定义Rack中间件输出JSON结构化标签
要得到真正可搜索的结构化日志，可以把请求上下文放进 Thread.current，然后让应用的日志模块统一读取并合并这些字段。Rack中间件适合完成这件事，因为它位于请求链路最前端，可以先于控制器执行。
下面是一个使用 RequestContextMiddleware 的示例，它会生成请求ID，并保存请求方法、路径、用户ID等字段。
class RequestContextMiddleware
def initialize(app)
@app = app
end
def call(env)
request = Rack::Request.new(env)
request_id = env["HTTP_X_REQUEST_ID"] || SecureRandom.uuid
Thread.current[:log_context] = {
request_id: request_id,
method: request.request_method,
path: request.path,
user_id: env["HTTP_X_USER_ID"] || "anonymous"
}
@app.call(env)
ensure
Thread.current[:log_context] = nil
end
end中间件里最重要的一项是 ensure 块。无论请求正常结束还是抛出异常，都必须清理线程局部变量。Ruby的线程可能被连接池复用，如果上下文残留，下一个被分配到同一线程的请求就会错误继承上一个请求的标签，产生污染。
接下来在日志模块中合并上下文字段。假设已经配置了 JSON logger，可以这样封装：
module AppLogger
def self.info(event, extra = {})
payload = { level: "info", event: event }.merge(log_context).merge(extra)
logger.info(JSON.generate(payload))
end
def self.log_context
Thread.current[:log_context] || {}
end
end在控制器或服务对象中调用时，只需要传入本次事件特有的字段，例如 AppLogger.info("order_created", order_id: order.id, duration_ms: 42)。最终输出的JSON会包含 request_id、method、path、user_id，以及 order_id 和 duration_ms。这种结构可以直接被日志平台索引，无需额外解析。
如果不想自己拼JSON，也可以使用 logstash-logger 或 semantic_logger，它们都支持在日志条目上设置默认字段。核心思路仍然是“入口设置上下文，输出时合并”，只是封装方式不同。
四、异步任务中的上下文传播与避免串号
Rails应用几乎都会用到异步任务，比如ActiveJob或Sidekiq。异步线程不会自动继承Web请求的 Thread.current，如果直接把 user_id 存入线程变量，然后在后台任务里读取，大概率得到 nil。更糟糕的是，某些线程池复用场景下还有可能读到已经清理不干净的旧值。
处理方式通常有两种。第一种是在入队时把请求上下文作为参数传给任务，任务启动时再写入当前线程的日志上下文。以 ActiveJob 为例，可以在 ApplicationJob 中定义统一的包装：
class ApplicationJob < ActiveJob::Base
around_perform do |job, block|
context = job.arguments.last.is_a?(Hash) ? job.arguments.last[:log_context] : nil
if context
Thread.current[:log_context] = context
begin
block.call
ensure
Thread.current[:log_context] = nil
end
else
block.call
end
end
end这样每次执行后台任务时，都会先恢复上下文，再执行业务逻辑。Sidekiq 也类似，可以在 worker 的 perform 方法开头从参数中取出 request_id 或 trace_id，并设置到当前线程。
另一种更自动化的方式是使用 RequestStore 这类库，它同样基于线程局部变量，但提供了更清晰的 API。不过 RequestStore 也不能跨线程传播，只是管理更规范。跨服务传播则需要引入 OpenTelemetry 或自定义 trace_id 透传，通过 HTTP 头把 trace_id 一路传下去。
无论采用哪种方式，异步任务中的清理仍然不可省略。后台线程往往比Web线程生命周期更长，一旦忘记清理，后面的任务就会串上上一个任务的用户ID，导致日志查询时出现张冠李戴。
五、生产环境的性能与安全实践
为每个请求注入日志标签本身开销很小，通常只是几次哈希写入。但在高并发场景下，需要注意不要在每个日志输出前做重复且昂贵的计算。例如不要在 log_context 方法里解析用户代理字符串或查询数据库，这些操作应在中间件里一次性完成并缓存。
字段数量也需要克制。请求ID、方法、路径、状态码、用户ID、耗时已经足够覆盖大多数排障场景。把整个请求头、响应体或SQL参数塞进日志，不仅会让日志体积暴涨，还可能把密码、Token等敏感信息泄露到日志系统。写入生产日志前应做一遍字段白名单过滤。
另一个容易忽略的点是耗时统计。如果在日志标签里加入 duration_ms，最好用 Process.clock_gettime(Process::CLOCK_MONOTONIC) 而不是 Time.now，因为系统时间可能被NTP调整，计算出的耗时会失真。中间件可以在请求开始时记录时间，在 ensure 中计算差值并与日志上下文一起输出。
最后，日志级别也要按环境区分。开发环境可以把标签打印成人类可读的文本，生产环境则使用JSON日志并关闭不必要的debug输出。只要入口上下文注入和输出合并做得规范，整个系统的日志就会从难以追踪的流水账，变成可以按 request_id 拉取的完整调用记录。