日志明明已经写了,程序崩溃时最后几行为什么还是不见了?

线上服务在处理请求时打印了三条日志:

1
2
3
request accepted
calling upstream
upstream returned 500

随后进程崩溃,日志文件却只留下第一条。开发者第一反应通常是“日志库有 bug”,但异步日志中的“写了”可能只表示业务线程把字符串放进内存队列,既不代表日志线程已经消费,也不代表用户态缓冲已经刷新,更不代表数据已经持久化到存储设备。

本文从一个可运行的同步日志器开始,解释日志级别、稳定字段和 std::source_location;再实现一个有界队列的 C++20 异步日志器,重点处理初始化顺序、背压、正常关闭和丢弃统计。最后讨论 request ID、结构化日志、轮转、敏感信息以及 spdlog 的工程边界。目标不是手写一个功能齐全的日志库,而是理解成熟日志库必须替你解决哪些问题。

1. 当程序不在眼前时,日志需要回答什么?

日志最核心的价值是:

1
2
当程序不在你眼前、不能打断点、问题难以复现时,
仍然能还原关键行为和上下文。

服务端项目里,日志通常用于还原某次请求的入口、关键分支、上游调用、错误原因和退出结果。但日志并不是可观测性的全部:

  • 记录请求入口和出口
  • 定位错误路径
  • 记录上游调用耗时
  • 追踪异步任务状态
  • 排查连接断开、超时、限流
  • 压测时分析 p95 / p99 异常点
  • 复盘用户一次完整请求链路
手段 擅长回答的问题 不适合替代什么
日志 request_id=abc 为什么失败? 整体趋势和高效实时告警
指标 最近五分钟错误率、p99 是否异常? 单次请求的详细上下文
Trace 一次跨服务调用经过哪些节点? 所有业务字段和长期审计记录
Profiling CPU 时间、锁竞争、分配热点在哪里? 业务错误原因
测试 已知输入是否符合预期? 线上某次真实事件的复盘

一句话概括:

1
测试保证行为,指标发现趋势,日志解释细节。

这也解释了为什么不能靠“多打点日志”解决所有问题:日志越多,I/O、存储、查询成本和敏感信息风险越高,还可能反过来放大服务尾延迟。


2. 日志级别

常见日志级别:

级别 用途 示例
TRACE 极细粒度调试,默认关闭 每个包的解析细节
DEBUG 本地调试信息 路由命中、内部状态
INFO 正常关键事件 服务启动、请求完成、任务完成
WARN 可恢复异常 上游慢、重试、限流
ERROR 当前操作失败 上游超时、数据库写失败
FATAL 进程无法继续 配置缺失、端口绑定失败

建议:

  • 正常请求完成用 INFO
  • 用户输入错误通常不是 ERROR
  • 上游失败、数据库失败才更适合 ERROR
  • 高频路径不要打大量 DEBUG
  • FATAL 表达进程无法继续,但不同日志库是否自动终止并不一致;退出行为要由应用明确控制

日志级别是运维契约,不是情绪强度。把每个 404 都记为 ERROR 会淹没真正故障;把数据库写失败记成 INFO,又会让告警和排查失去入口。团队应为每一级定义稳定语义,并结合采样和告警规则评审。


3. 一条好日志应该包含什么

一条服务端日志至少要能回答:

1
谁在什么时候对哪个接口做了什么,结果如何,耗时多少,失败原因是什么。

推荐字段:

字段 说明
timestamp 时间
level 日志级别
service 服务名
request_id 请求 ID
user_id 用户 ID,没有就为空
method HTTP 方法
path 请求路径
status 响应状态码
duration_ms 耗时
error_code 业务错误码
upstream 上游服务名
file / line 代码位置

示例:

1
2026-05-12T10:01:03.123Z INFO service=gateway request_id=9f32 method=POST path=/v1/chat status=200 duration_ms=182 upstream=rag_api

4. 不建议这样打日志

4.1 只写一句失败

1
LOG_ERROR << "failed";

问题:不知道谁失败、为什么失败、哪个请求失败。

更好:

1
2
3
4
5
LOG_ERROR << "request_id=" << requestId
<< " operation=call_fastapi"
<< " upstream=rag_api"
<< " result=" << static_cast<int>(result)
<< " error=upstream_unavailable";

4.2 打印敏感信息

不要直接打印:

  • password
  • token
  • API key
  • Authorization header
  • 完整身份证 / 手机号
  • 私有文档全文

认证秘密最好完全不进入日志,而不是“只露出首尾几位”。例如只记录请求是否携带认证信息以及认证结果:

1
2
3
4
LOG_WARN << "event=authentication_failed"
<< " authorization_present=" << std::boolalpha
<< !authorizationHeader.empty()
<< " reason=expired_credential";

用户标识、IP 和文件名同样可能属于个人信息,应根据用途做假名化、访问控制和保留期限设计。脱敏规则不是日志函数里的临时字符串技巧,而是数据治理要求。

4.3 高频循环里打 INFO

比如每个 token、每个 UDP 包都打 INFO,压测时日志会反过来拖慢系统。

建议:

  • 高频细节用 TRACE / DEBUG
  • 默认关闭
  • 或按采样率打印

5. 如何写出一个可运行的同步日志器?

先用同步版本建立语义:调用返回前,当前线程已经把一整行交给输出流并执行 flush()。示例使用 C++20 的 std::source_location 自动捕获调用位置,避免依赖 <format> 的实现差异。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
#include <chrono>
#include <iostream>
#include <mutex>
#include <source_location>
#include <string_view>

enum class LogLevel {
Trace,
Debug,
Info,
Warn,
Error,
Fatal
};

constexpr std::string_view toString(LogLevel level) noexcept {
switch (level) {
case LogLevel::Trace: return "TRACE";
case LogLevel::Debug: return "DEBUG";
case LogLevel::Info: return "INFO";
case LogLevel::Warn: return "WARN";
case LogLevel::Error: return "ERROR";
case LogLevel::Fatal: return "FATAL";
}
return "UNKNOWN";
}

class SimpleLogger {
public:
void log(
LogLevel level,
std::string_view message,
std::source_location loc = std::source_location::current()) {

const auto now = std::chrono::system_clock::now();
const auto timestampMs =
std::chrono::duration_cast<std::chrono::milliseconds>(
now.time_since_epoch()
).count();

std::lock_guard<std::mutex> lock(mu_);
std::clog << "timestamp_ms=" << timestampMs
<< " level=" << toString(level)
<< " file=" << loc.file_name()
<< " line=" << loc.line()
<< " message=\"" << message << "\"\n";
std::clog.flush();
}

private:
std::mutex mu_;
};

int main() {
SimpleLogger logger;
logger.log(LogLevel::Info, "server started");
logger.log(LogLevel::Error, "upstream request failed");
}

编译运行:

1
2
3
clang++ -std=c++20 -O2 -Wall -Wextra -Wpedantic \
sync_logger.cpp -o sync_logger
./sync_logger

输出中的时间戳和源码行号会随运行变化,结构类似:

1
2
timestamp_ms=1770000000000 level=INFO file=sync_logger.cpp line=61 message="server started"
timestamp_ms=1770000000000 level=ERROR file=sync_logger.cpp line=62 message="upstream request failed"

互斥锁保证多个线程的一行内容不会相互穿插;source_location 作为默认实参求值时记录调用点,而不是 log() 函数定义的位置。这里每行都 flush,换来了清晰语义,也让业务线程承担格式化、锁竞争和输出等待。

这个最小示例只传入可信的固定消息;如果 message 或字段来自用户输入,必须先按第 9 节转义,否则换行和引号会破坏一行一事件的格式。

同步日志器优点:

  • 简单
  • 不容易丢日志
  • 相比异步队列,正常错误退出前更容易看到最后日志

缺点:

  • 多线程竞争锁
  • 写磁盘慢时阻塞业务线程
  • 高频日志影响延迟

即便 std::clog.flush() 返回,也通常只表示 C++ 流缓冲已经向下层提交,不等于数据已经物理落盘。SIGKILL、内核崩溃、断电和存储故障仍可能丢失数据;若审计记录要求持久性,需要专门的事务或可靠事件系统,不能把普通日志文件当数据库。


6. RAII 日志行

为了写出类似流式语法:

1
LOG_INFO << "request_id=" << id << " status=" << status;

可以用 RAII:构造收集内容,析构时写出。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
#include <sstream>

class LogLine {
public:
LogLine(
SimpleLogger& logger,
LogLevel level,
std::source_location loc = std::source_location::current())
: logger_(logger), level_(level), loc_(loc) {}

~LogLine() noexcept {
try {
logger_.log(level_, os_.str(), loc_);
} catch (...) {
// 日志失败不能从析构函数继续抛异常。
}
}

template <class T>
LogLine& operator<<(const T& value) {
os_ << value;
return *this;
}

private:
SimpleLogger& logger_;
LogLevel level_;
std::source_location loc_;
std::ostringstream os_;
};

SimpleLogger& globalLogger() {
static SimpleLogger logger;
return logger;
}

#define LOG_INFO LogLine(globalLogger(), LogLevel::Info)
#define LOG_WARN LogLine(globalLogger(), LogLevel::Warn)
#define LOG_ERROR LogLine(globalLogger(), LogLevel::Error)

使用:

1
2
LOG_INFO << "server started port=" << 8080;
LOG_ERROR << "request_id=" << requestId << " error=upstream_timeout";

注意:

  • 宏里使用临时对象,表达式结束时析构
  • 不要把 LogLine 存起来跨线程使用
  • 真实项目要处理日志级别过滤,否则即使关闭 DEBUG 也可能构造字符串
  • 析构函数不能向外抛异常;生产实现还应通过错误回调或指标暴露日志写入失败

7. 关闭 DEBUG 后,怎样避免仍然构造昂贵字符串?

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
#include <atomic>
#include <string>

class LogConfig {
public:
void setLevel(LogLevel level) {
minLevel_.store(level, std::memory_order_relaxed);
}

bool enabled(LogLevel level) const {
return static_cast<int>(level) >=
static_cast<int>(minLevel_.load(std::memory_order_relaxed));
}

private:
std::atomic<LogLevel> minLevel_{LogLevel::Info};
};

只在 logger 内部丢弃消息已经太晚,调用方可能完成了序列化和字符串拼接。一个不依赖脆弱 if/else 宏的最小做法,是把消息构造延迟到 lambda 中:

1
2
3
4
5
6
7
8
9
10
11
12
13
template <class MessageBuilder>
void logIfEnabled(
SimpleLogger& logger,
const LogConfig& config,
LogLevel level,
MessageBuilder&& buildMessage,
std::source_location loc = std::source_location::current()) {
if (!config.enabled(level)) {
return;
}
const auto message = buildMessage();
logger.log(level, message, loc);
}

使用:

1
2
3
logIfEnabled(logger, config, LogLevel::Debug, [&] {
return "packet decoded size=" + std::to_string(size);
});

当 DEBUG 关闭时,lambda 不执行,std::to_string 和拼接都不会发生。std::atomic<LogLevel> 让运行时调整级别与并发读取之间没有数据竞争;这里不需要跨对象同步,所以 relaxed 顺序足够。成熟库通常还提供编译期级别裁剪,能让低级别日志连分支都不进入。


8. 怎样实现一个不会在线程启动时就产生竞态的异步日志器?

异步日志的结构:

1
2
3
4
5
6
7
8
业务线程
-> 格式化日志行
-> push 到队列
-> 立即返回

日志线程
-> 从队列 pop
-> 批量写文件 / stderr

如果输出到普通文件,一条消息大致经过:

1
2
3
4
5
6
7
业务线程
→ 进程内日志队列
→ 日志线程
→ C++ stream / C stdio 缓冲
→ write 系统调用
→ 内核页缓存
→ 存储设备

不同失败发生在不同位置。正常关闭可以排空进程内队列;用户态 flush 可以把流缓冲交给操作系统;要讨论断电持久性,还需要操作系统和文件系统级同步语义。普通业务日志通常不会为每行执行昂贵的持久化同步,因此必须明确可接受的数据丢失窗口。

原稿中最容易忽略的坑,是在成员初始化列表里直接启动 worker_。C++ 成员按声明顺序初始化,线程一旦启动就可能访问排在它后面、尚未初始化的状态。安全做法是先构造全部成员并检查文件,再在构造函数体中启动线程。

下面的 C++20 最小实现采用有界队列,队列满时丢弃最新消息,并把丢弃量暴露出来:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
#include <atomic>
#include <condition_variable>
#include <cstddef>
#include <fstream>
#include <iostream>
#include <mutex>
#include <queue>
#include <stdexcept>
#include <string>
#include <thread>
#include <utility>

class AsyncLogger {
public:
explicit AsyncLogger(std::string file, std::size_t maxQueue = 8192)
: maxQueue_(maxQueue),
out_(std::move(file), std::ios::app) {
if (maxQueue_ == 0) {
throw std::invalid_argument("maxQueue must be positive");
}
if (!out_) {
throw std::runtime_error("cannot open log file");
}
// 到构造函数体时,下面声明的全部成员都已经初始化完成。
worker_ = std::thread([this] { run(); });
}

~AsyncLogger() {
shutdown();
}

AsyncLogger(const AsyncLogger&) = delete;
AsyncLogger& operator=(const AsyncLogger&) = delete;

bool log(std::string line) {
{
std::lock_guard<std::mutex> lock(mu_);
if (stopping_) {
return false;
}
if (queue_.size() >= maxQueue_) {
dropped_.fetch_add(1, std::memory_order_relaxed);
return false;
}
queue_.push(std::move(line));
}
cv_.notify_one();
return true;
}

// 只能由拥有 logger 生命周期的线程调用;调用后不再接受新日志。
void shutdown() noexcept {
{
std::lock_guard<std::mutex> lock(mu_);
if (stopping_) {
return;
}
stopping_ = true;
}
cv_.notify_one();
if (worker_.joinable()) {
worker_.join();
}
}

std::size_t dropped() const noexcept {
return dropped_.load(std::memory_order_relaxed);
}

std::size_t writeErrors() const noexcept {
return writeErrors_.load(std::memory_order_relaxed);
}

private:
void run() noexcept {
while (true) {
std::queue<std::string> batch;
{
std::unique_lock<std::mutex> lock(mu_);
cv_.wait(lock, [&] {
return stopping_ || !queue_.empty();
});

if (queue_.empty() && stopping_) {
break;
}
batch.swap(queue_);
}

while (!batch.empty()) {
out_ << batch.front() << '\n';
batch.pop();
}
out_.flush();
if (!out_) {
writeErrors_.fetch_add(1, std::memory_order_relaxed);
}
}
}

// worker_ 必须最后声明,确保它启动时依赖状态已经初始化。
std::mutex mu_;
std::condition_variable cv_;
std::queue<std::string> queue_;
bool stopping_{false};
const std::size_t maxQueue_;
std::atomic_size_t dropped_{0};
std::atomic_size_t writeErrors_{0};
std::ofstream out_;
std::thread worker_;
};

int main() {
AsyncLogger logger("async_demo.log");
logger.log("level=INFO event=server_started");
logger.log("level=ERROR event=upstream_failed request_id=abc");
logger.shutdown();

std::cout << "dropped=" << logger.dropped()
<< " write_errors=" << logger.writeErrors() << '\n';
}
1
2
3
4
clang++ -std=c++20 -O2 -Wall -Wextra -Wpedantic -pthread \
async_logger.cpp -o async_logger
./async_logger
cat async_demo.log

正常运行时,统计应为 dropped=0 write_errors=0,文件中能看到两行日志。shutdown() 先在锁内停止接收,再通知工作线程;工作线程把队列交换到局部 batch,释放锁后执行慢 I/O,因此生产者不会在整个文件写入期间持有队列锁。当队列为空且 stopping_ 为真时,线程退出,调用方 join 后才继续销毁文件流。

log() 返回 false 表示消息未被接受:可能是队列已满,也可能已经进入关闭阶段。真实接口可以把两种原因拆成枚举;无论如何,调用方或独立指标必须能观察失败,不能默默假设消息已经记录。

异步日志必须考虑:

  • 队列满了怎么办:丢弃、阻塞、降级同步?
  • 进程崩溃时允许丢多少条、多少毫秒的数据
  • 可控 FATAL 路径是否需要同步应急输出并执行有界等待
  • 日志线程退出时要刷完队列
  • 日志量太大时要限速或采样

这个实现只保证正常调用 shutdown() 时排空已接收队列。std::terminate、段错误、abort()SIGKILL、容器强制终止或断电都可能绕过析构;也不要从 POSIX 信号处理函数调用普通 C++ logger,因为锁、分配器、iostream 和大多数日志库 API 都不是 async-signal-safe。崩溃转储、外部进程采集和同步应急通道是另一层设计。


9. 结构化日志

普通文本日志方便人看,但机器分析更喜欢结构化字段。

推荐风格:

1
level=INFO service=gateway request_id=abc method=POST path=/v1/chat status=200 duration_ms=183

或者 JSON Lines:

1
{"level":"INFO","service":"gateway","request_id":"abc","method":"POST","path":"/v1/chat","status":200,"duration_ms":183}

简单 key-value 编码:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
#include <string>
#include <string_view>

std::string escapeLogValue(std::string_view s) {
std::string out;
out.reserve(s.size());
for (unsigned char c : s) {
switch (c) {
case '\\': out += "\\\\"; break;
case '"': out += "\\\""; break;
case '\n': out += "\\n"; break;
case '\r': out += "\\r"; break;
case '\t': out += "\\t"; break;
default:
// 其他 ASCII 控制字符用占位符替换,避免伪造新日志行。
out.push_back(c < 0x20 ? '?' : static_cast<char>(c));
}
}
return out;
}

std::string kv(std::string_view key, std::string_view value) {
return std::string(key) + "=\"" + escapeLogValue(value) + "\"";
}

使用:

1
2
3
4
LOG_INFO << kv("request_id", requestId)
<< " " << kv("path", req->path())
<< " status=" << status
<< " duration_ms=" << durationMs;

换行、回车和制表符必须转义,否则用户提供的 path 或 header 可以伪造第二条日志,这叫日志注入(log injection)。上面的 key 假设是代码中写死的稳定字段名;若要输出严格 JSON,应使用项目已有的 JSON 序列化库,不要继续扩展手写转义器。


10. request id

跨服务链路一定要有 request id:

1
2
3
4
Gateway log request_id=abc
FastAPI log request_id=abc
Celery log request_id=abc
vLLM client log request_id=abc

请求 ID 来自 header 时仍是不可信输入,至少限制长度和字符集:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
#include <algorithm>

bool validRequestId(std::string_view id) {
return !id.empty() && id.size() <= 64 &&
std::all_of(id.begin(), id.end(), [](unsigned char c) {
return (c >= 'a' && c <= 'z') ||
(c >= 'A' && c <= 'Z') ||
(c >= '0' && c <= '9') || c == '-' || c == '_';
});
}

std::string ensureRequestId(const drogon::HttpRequestPtr& req) {
const auto id = req->getHeader("x-request-id");
if (validRequestId(id)) {
return id;
}
return drogon::utils::getUuid();
}

转发给上游:

1
upstreamReq->addHeader("x-request-id", requestId);

返回给客户端:

1
resp->addHeader("x-request-id", requestId);

在可信网关内部可以透传同一个 ID;面向公网的边缘服务还应考虑客户端故意复用 ID 的情况。需要严格分布式追踪时,应采用团队统一的 trace context 规范,而不是让每个服务各自发明 header。


11. 请求访问日志

Gateway 建议每个请求完成时打一条访问日志:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
class RequestTimer {
public:
RequestTimer() : start_(std::chrono::steady_clock::now()) {}

std::int64_t elapsedMs() const {
auto now = std::chrono::steady_clock::now();
return std::chrono::duration_cast<std::chrono::milliseconds>(
now - start_)
.count();
}

private:
std::chrono::steady_clock::time_point start_;
};

墙上时间(system_clock)用于回答事件发生在什么时候,单调时钟(steady_clock)用于测耗时。系统校时可能让墙上时间跳变,因此不能用两个 UTC 时间戳简单相减来计算可靠延迟。完整源文件还需包含 <chrono><cstdint>

示例:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
void logAccess(
const drogon::HttpRequestPtr& req,
const drogon::HttpResponsePtr& resp,
std::string_view requestId,
std::int64_t durationMs) {

LOG_INFO << "type=access"
<< " request_id=" << requestId
<< " method=" << req->methodString()
<< " path=" << req->path()
<< " status=" << static_cast<int>(resp->statusCode())
<< " duration_ms=" << durationMs
<< " peer=" << req->peerAddr().toIp();
}

访问日志通常应在响应真正完成或连接确定终止时记录,否则异步响应可能只记录“开始处理”,却没有最终状态和耗时。客户端 IP 可能属于个人信息;query、header 和请求体还可能包含秘密,不能为了排障无差别写入。


12. 日志和指标的边界

日志适合查一次具体请求:

1
request_id=abc 为什么失败?

指标适合看整体趋势:

1
2
3
过去 5 分钟 502 比例是否升高?
p99 是否变差?
活跃 SSE 连接多少?

不要试图只靠日志做监控,否则:

  • 成本高
  • 查询慢
  • 不适合实时告警

建议:

场景 用日志 用指标
某次请求失败原因 辅助
错误率趋势 辅助
慢请求定位
任务状态变化
token 逐个输出 通常否 可计数

尤其不要只靠日志报告“日志写入失败”,因为故障通道就是日志本身。队列深度、dropped_logs_totallog_write_errors_total 和最近一次成功写入时间应通过独立指标或健康检查暴露。request_id、用户 ID 等高基数字段适合日志和 trace,不应直接作为时序指标标签,否则会造成指标系统基数爆炸。


13. 日志滚动

长期运行服务不能只写一个无限增长文件。

常见策略:

  • 按大小滚动:超过 100MB 切新文件
  • 按时间滚动:每天一个文件
  • 保留最近 N 天
  • 压缩旧日志

核心流程看起来简单:

1
2
3
4
5
6
7
8
9
编码一整行

检查单行是否超过上限

用 max_bytes - required_bytes 判断剩余空间,避免加法溢出

空间不足:flush → close → 原子地切换到新文件

写入并检查 I/O 状态 → 更新实际字节数

真正困难的是重启后如何恢复当前大小、文件名如何避免覆盖、多进程是否同时写同一文件、rename 失败怎么办、超长单行如何处理、磁盘满时采用什么降级策略,以及压缩/删除线程会不会和写线程竞争。几十行示例无法可靠覆盖这些情况。

真实项目优先使用成熟库,比如:

  • spdlog
  • glog
  • Boost.Log
  • Drogon 自带日志能力

14. 为什么理解原理后仍应优先使用 spdlog?

轮转、格式化、sink 组合和异步队列都有大量边界,业务项目通常应复用已有日志库。下面以 spdlog 1.17.0 API 为参照;如果项目锁定其他版本,应以依赖文件和对应版本文档为准,不要为了笔记擅自升级。

同步轮转示例:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
#include <spdlog/spdlog.h>
#include <spdlog/sinks/rotating_file_sink.h>

int main() {
auto logger = spdlog::rotating_logger_mt(
"gateway",
"logs/gateway.log",
100 * 1024 * 1024,
10);

spdlog::set_default_logger(logger);
spdlog::set_level(spdlog::level::info);
spdlog::flush_on(spdlog::level::err);

spdlog::info("server started port={}", 8080);
spdlog::warn("upstream slow request_id={} duration_ms={}", "abc", 1200);
}

异步轮转示例:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
#include <spdlog/async.h>
#include <spdlog/pattern_formatter.h>
#include <spdlog/spdlog.h>
#include <spdlog/sinks/rotating_file_sink.h>

#include <memory>

void initLogger() {
// 一个进程通常只初始化一次全局线程池。
spdlog::init_thread_pool(8192, 1);

auto sink = std::make_shared<spdlog::sinks::rotating_file_sink_mt>(
"logs/gateway.log",
100 * 1024 * 1024,
10,
false); // false 表示启动时不截断现有文件

auto logger = std::make_shared<spdlog::async_logger>(
"gateway",
sink,
spdlog::thread_pool(),
spdlog::async_overflow_policy::overrun_oldest);

logger->set_formatter(std::make_unique<spdlog::pattern_formatter>(
"%Y-%m-%dT%H:%M:%S.%eZ %l %n tid=%t %v",
spdlog::pattern_time_type::utc));
logger->flush_on(spdlog::level::err);

spdlog::register_logger(logger);
spdlog::set_default_logger(logger);
}

注意:

  • overrun_oldest 表示队列满时丢旧日志
  • 如果不能丢日志,可以改为 block,但业务线程会承受背压,必须压测尾延迟
  • 日志目录需要可创建、可写,并监控磁盘空间和 sink 错误
  • 所有生产者停止后,正常退出路径应调用 spdlog::shutdown() 清理全局线程池

必须特别区分“请求 flush”和“确认持久化”。在 spdlog 1.x 的异步 logger 中,flush() 本身走异步队列,调用返回不能简单理解为此前消息已经同步落盘;即使 sink 完成用户态 flush,也不是 fsync 级别的断电保证。对于应用可控的致命错误,可以先走独立同步应急通道,再执行有时间上限的正常关闭;对于段错误或信号上下文,不要调用非 async-signal-safe 的日志 API。


15. RAG Gateway 日志清单

建议你在 RAG 项目记录:

15.1 Gateway

1
2
3
4
5
6
7
8
9
10
request_id
user_id
method
path
status
duration_ms
rate_limited
upstream
upstream_status
upstream_duration_ms

15.2 文档上传

1
2
3
4
5
6
7
8
request_id
user_id
filename
content_type
file_size
doc_id
task_id
result

15.3 RAG 检索

1
2
3
4
5
6
7
8
9
request_id
session_id
message_id
query_len
top_k
rerank_top_k
retrieve_ms
rerank_ms
prompt_tokens_estimated

15.4 SSE

1
2
3
4
5
6
7
request_id
message_id
active_connections
ttft_ms
total_tokens
duration_ms
disconnect_reason

16. UDP 权威同步项目日志清单

建议记录:

1
2
3
4
5
6
7
8
9
10
11
12
13
match_id
player_id
addr
tick
seq
ack
ack_bits
state_hash
rollback_count
packet_type
decode_error
latency_ms
drop_rate

注意:

  • 不要每个 tick 默认打 INFO
  • 压测时可以聚合后定期输出
  • hash mismatch 时要打详细状态

示例:

1
2
3
4
5
6
LOG_WARN << "type=hash_mismatch"
<< " match_id=" << matchId
<< " player_id=" << playerId
<< " tick=" << tick
<< " local_hash=" << localHash
<< " remote_hash=" << remoteHash;

17. 常见误区

17.1 误区:日志只是顺手写文件,不会影响主流程

同步日志会直接阻塞业务线程;异步日志也要格式化、分配、竞争队列并消耗磁盘带宽。高频请求里打太多日志会影响 p99。应使用级别过滤、采样、聚合和压测验证,而不是凭“异步”二字假设没有成本。

17.2 误区:错误堆栈足够,不需要 request ID

错误堆栈说明代码位置,却无法自动指出它属于哪个用户请求和哪次上游重试。正确做法是在入口生成或验证 ID,并在异步任务、上游请求和最终响应中持续传递。

17.3 误区:只在异常处记录就够了

没有少量正常完成日志,就无法判断请求是否根本没有进入服务,还是在某一步静默退出。入口不必和出口各打一条 INFO;通常一条包含最终状态和耗时的访问日志更紧凑。

17.4 误区:内部日志可以记录完整请求,反正用户看不到

日志往往会被集中采集、长期保存并开放给更多运维人员,泄露面可能比业务数据库更大。认证信息、请求体和私有文档默认不记录,确有审计需求时也要做字段级策略、权限和保留期限控制。

17.5 误区:调用了异步 log() 就算记录成功

调用成功可能只表示进入内存队列;队列满、进程崩溃、磁盘写失败都会让消息消失。要定义 overflow policy,并通过独立指标暴露丢弃、队列深度和写入错误。

17.6 误区:字段名只是文本,随时改也没关系

日志字段实际上是下游查询和告警依赖的数据契约。今天写 requestId、明天写 request_id 会破坏仪表盘和检索。字段变更应像 API 变更一样评审,必要时并行输出过渡版本。

18. 什么时候用同步日志,什么时候用异步日志?

场景 更合适的起点 原因
CLI、小工具、低频管理进程 同步日志 实现和退出语义简单,性能通常足够
高并发服务的一般访问日志 有界异步日志 把大部分文件 I/O 移出请求线程,但必须定义背压
启动失败、配置错误 同步 stderr 异步线程池和文件系统可能尚未就绪
可控的致命业务错误 同步应急输出 + 有界关闭 尽量保留上下文,但不能无限等待
审计、计费、资金变更 事务事件或可靠消息系统 普通日志不提供所需的持久性和幂等保证
POSIX 崩溃信号处理函数 极小的 async-signal-safe 通道 普通 logger 的锁、分配和格式化都不安全

同步与异步不是“慢”和“快”的简单标签。低频服务使用同步日志往往更可靠、更容易维护;只有压测证明日志 I/O 是明显成本时,才值得承担异步队列的丢失策略、线程生命周期和监控复杂度。

19. 总结:真正要定义的是日志交付语义

回到开头,崩溃前最后几行消失,往往是因为团队把“调用了日志 API”“进入异步队列”“写入内核缓存”和“持久化到设备”混成了一件事。一个可维护的日志系统至少要明确:

  1. 同步与异步路径分别保证到哪一层,哪些退出方式可能丢数据。
  2. 有界队列满时阻塞、丢新还是覆盖旧,以及如何独立统计损失。
  3. 字段、级别、request ID 和时间语义必须稳定,耗时使用单调时钟。
  4. 用户输入要防日志注入,秘密和个人信息要在进入日志前治理。
  5. 轮转、异步线程池和 sink 错误优先交给成熟库,但仍要核对版本语义。

可以立即落地的一条建议是:人为把异步队列压满并执行一次正常关闭测试,确认服务的背压策略、dropped_logs_total、文件内容和退出时限都符合预期。没有演练过的“不会丢日志”,通常只是一种假设。


20. 参考