从零构建现代C++ Web服务器(七)
本文介绍了自研日志系统的三阶段演进路线,从基础增强到异步后端再到结构化日志与可观测性。Phase 1 采用 std::format API 和 atomic 短路优化,实现 6 级日志与智能 flush 策略;Phase 2 引入异步后端设计,包括栈缓冲、可插拔接口和双缓冲文件输出;Phase 3 扩展结构化日志功能,支持多格式输出和请求追踪。整个系统遵循零外部依赖原则,针对协程环境优化,最终形成
从零构建现代C++ Web服务器(七):生产级日志系统
前置知识
- 阅读过第三篇的中间件洋葱模型
- 了解 C++20
std::format、std::jthread - 了解日志系统的基本概念(级别、格式化、输出目标)
目录
- 1. 为什么需要自研日志系统?
- 2. Phase 1:基础增强——从 fprintf 到 std::format
- 3. Phase 2:异步后端——从同步到生产级
- 4. Phase 3:结构化日志与可观测性
- 5. 性能深度分析
- 6. 线程安全设计
- 7. 实战:5 分钟搭建完整日志体系
- 8. 总结与设计决策表
- 9. 核心要点
- 10. 知识图谱
1. 为什么需要自研日志系统?
前六篇把 hical 的核心骨架搭完了:协程 I/O、内存池、路由、中间件、SSL、会话、数据库。唯一的短板是日志——每次排查问题只能翻 stderr,没有文件、没有结构、没有追踪 ID。真正的生产环境里,日志比功能代码重要得多:功能代码决定程序的行为,日志决定你能不能在凌晨三点用最短时间还原那行让服务崩掉的数据路径。
1.1 现有轮子的取舍
先看市面上的主流方案:
| 库 | 优点 | 对 hical 的问题 |
|---|---|---|
| spdlog | 成熟、快(每秒数百万条)、格式丰富 | 外部依赖;fmt 与 std::format 语义略有差异 |
| glog | Google 出品,稳定 | C++03 风格 API;宏冗余;不支持 std::format |
| Trantor | drogon 自带,协程时代设计 | 与 drogon 强耦合,无法独立引入 |
| log4cxx | 功能完备、配置文件驱动 | 重量级;Java 移植风格与现代 C++ 格格不入 |
| 自研 | 零依赖、API 与框架深度融合 | 需要投入设计成本 |
hical 的核心约束是零外部依赖——整个框架只依赖 Boost 和 OpenSSL,任何新模块都不能打破这条线。spdlog 引入 fmt 库就已经违规,glog 的 API 风格与现代 C++ 割裂,Trantor 无法解耦。
hical 的特殊需求还有两点:
- 协程友好:io_context 线程不能被同步
fwrite阻塞超过几十微秒,否则高并发下延迟就会抖动。 - 请求追踪:每条日志要能绑定到具体的 HTTP 请求(trace-id),方便在混乱的并发日志流中还原单次请求的完整生命周期。
这两点需求让自研成为唯一合理的选择。
1.2 三阶段演进路线
整个日志系统分三个阶段迭代,每个阶段都是可独立运行的完整系统:
Phase 1:基础增强
fprintf → std::format API
6 级日志 + atomic 短路
thread_local 时间戳缓存
智能 flush 策略
Phase 2:异步后端
FixedBuffer 4KB 栈缓冲
LogSink 可插拔接口
LogFile 文件轮转
AsyncFileSink 双缓冲 + jthread
Phase 3:结构化 + 可观测性
LogRecord 结构化条目
TextFormatter / JsonFormatter
LogChannel 多通道路由
LogMiddleware 请求追踪
LogAdmin 动态级别
每个阶段都在前一阶段的基础上叠加,最终三个阶段合并为一套完整的日志体系。
2. Phase 1:基础增强——从 fprintf 到 std::format
Phase 1 的目标只有一个:让开发阶段的调试体验达到 spdlog 水平,同时保持零依赖。
2.1 LogLevel 枚举设计
6 个级别,整数值连续,方便原子比较:
// src/core/Log.h
namespace hical
{
enum class LogLevel : uint8_t
{
hTrace = 0, // 最细粒度,编译期在 NDEBUG 下消除
hDebug = 1, // 调试信息
hInfo = 2, // 正常运行信息(生产环境默认级别)
hWarn = 3, // 非致命异常,需要关注
hError = 4, // 错误,但服务仍可继续运行
hFatal = 5 // 致命错误,写完日志后 abort()
};
// 转为字符串(inline,5 字符宽度便于对齐)
inline const char* logLevelToString(LogLevel level)
{
switch (level)
{
case LogLevel::hTrace: return "TRACE";
case LogLevel::hDebug: return "DEBUG";
case LogLevel::hInfo: return "INFO";
case LogLevel::hWarn: return "WARN";
case LogLevel::hError: return "ERROR";
case LogLevel::hFatal: return "FATAL";
}
return "UNKNOWN";
}
} // namespace hical
为什么不用 int 或 #define? enum class 强类型,函数签名里不会和其他整数混淆;uint8_t 底层类型足够覆盖 6 个级别,且 atomic<LogLevel> 在所有平台上都是 lock-free。
2.2 Logger 单例与 atomic 短路
// src/core/Log.h(Phase 1 简化展示,完整定义见源码)
class Logger
{
public:
static Logger& instance();
void setLevel(LogLevel level);
LogLevel level() const; // atomic<LogLevel> relaxed load,~1ns
void setFlushLevel(LogLevel level);
// std::format 风格日志输出
template <typename... Args>
void logFmt(LogLevel lvl, const char* file, int line,
std::format_string<Args...> fmt, Args&&... args)
{
output(lvl, file, line, std::format(fmt, std::forward<Args>(args)...));
}
// 统一输出入口
void output(LogLevel lvl, const char* file, int line, std::string_view msg);
// Phase 1 只有 stderr 输出
// Phase 2 扩展为 vector<shared_ptr<LogSink>>,由 m_mutex 保护
// Phase 3 增加 Formatter、Channel、结构化 emit
private:
Logger();
std::atomic<LogLevel> m_level{LogLevel::hInfo};
std::atomic<LogLevel> m_flushLevel{LogLevel::hError};
std::mutex m_mutex;
};
atomic 短路是 Phase 1 最重要的性能决策。宏里通过 Logger::instance().level() <= (lvl) 判断——这是一次无锁的 relaxed load,约 1ns。未启用级别的调用在这一行就返回,整个格式化字符串的构造都被跳过。
注意 m_level 直接存储 LogLevel 枚举值(底层 uint8_t),不需要 static_cast<int> 转换。
2.3 宏系统设计
宏是日志系统的公共 API 面。用户不直接调 Logger::write(),而是用宏——因为宏能捕获 __FILE__、__LINE__、__func__,并且能做编译期消除。
// src/core/Log.h
// ── 内部实现宏:级别判断 + logFmt 调用 ──────────────────────────────────────────
// 先 atomic load 判断级别,不满足时零开销跳过
#define HICAL_LOG_IMPL_(lvl, fmt, ...) \
do \
{ \
if (::hical::Logger::instance().level() <= (lvl)) \
{ \
::hical::Logger::instance().logFmt( \
(lvl), __FILE__, __LINE__, fmt __VA_OPT__(, ) __VA_ARGS__); \
} \
} while (0)
// 每个级别的便捷宏
#define HICAL_LOG_TRACE(fmt, ...) HICAL_LOG_IMPL_(::hical::LogLevel::hTrace, fmt __VA_OPT__(, ) __VA_ARGS__)
#define HICAL_LOG_DEBUG(fmt, ...) HICAL_LOG_IMPL_(::hical::LogLevel::hDebug, fmt __VA_OPT__(, ) __VA_ARGS__)
#define HICAL_LOG_INFO(fmt, ...) HICAL_LOG_IMPL_(::hical::LogLevel::hInfo, fmt __VA_OPT__(, ) __VA_ARGS__)
#define HICAL_LOG_WARN(fmt, ...) HICAL_LOG_IMPL_(::hical::LogLevel::hWarn, fmt __VA_OPT__(, ) __VA_ARGS__)
#define HICAL_LOG_ERROR(fmt, ...) HICAL_LOG_IMPL_(::hical::LogLevel::hError, fmt __VA_OPT__(, ) __VA_ARGS__)
#define HICAL_LOG_FATAL(fmt, ...) HICAL_LOG_IMPL_(::hical::LogLevel::hFatal, fmt __VA_OPT__(, ) __VA_ARGS__)
// ── 条件宏(每个级别都有)────────────────────────────────────────────────────────
// 用法:HICAL_LOG_INFO_IF(retries > 3, "retry count={}", retries)
#define HICAL_LOG_INFO_IF(cond, fmt, ...) \
do { if (cond) { HICAL_LOG_INFO(fmt __VA_OPT__(, ) __VA_ARGS__); } } while (0)
// HICAL_LOG_DEBUG_IF, HICAL_LOG_WARN_IF, ... 同理
// ── 流式宏(if-else 技巧 + LogMessageVoid 消费)──────────────────────────────────
// 用法:HICAL_LOG_INFO_STREAM << "value=" << val << " ok"
#define HICAL_LOG_INFO_STREAM \
if (::hical::Logger::instance().level() > ::hical::LogLevel::hInfo) \
{ } \
else \
::hical::LogMessageVoid() & \
::hical::LogStream(::hical::LogLevel::hInfo, __FILE__, __LINE__)
// HICAL_LOG_DEBUG_STREAM, HICAL_LOG_WARN_STREAM, ... 同理
// ── NDEBUG 下完全消除 TRACE 系列 ─────────────────────────────────────────────────
#ifdef NDEBUG
#define HICAL_LOG_TRACE(fmt, ...) ((void)0)
#define HICAL_LOG_TRACE_IF(cond, fmt, ...) ((void)0)
#define HICAL_LOG_TRACE_F(fields, fmt, ...) ((void)0)
#define HICAL_LOG_TRACE_STREAM \
if (true) { } else ::hical::LogMessageVoid() & \
::hical::LogStream(::hical::LogLevel::hTrace, __FILE__, __LINE__)
#endif
// ── 结构化字段宏(每个级别都有 _F 变体)──────────────────────────────────────────
// 用法:HICAL_LOG_INFO_F({{"uid", userId}, {"ip", clientIp}}, "user login")
#define HICAL_LOG_INFO_F(fields, fmt, ...) \
do \
{ \
if (::hical::Logger::instance().level() <= ::hical::LogLevel::hInfo) \
{ \
::hical::Logger::instance().logFmtWithFields( \
::hical::LogLevel::hInfo, __FILE__, __LINE__, \
(fields), fmt __VA_OPT__(, ) __VA_ARGS__); \
} \
} while (0)
// HICAL_LOG_DEBUG_F, HICAL_LOG_WARN_F, HICAL_LOG_ERROR_F, HICAL_LOG_FATAL_F 同理
// ── 通道路由宏 ───────────────────────────────────────────────────────────────────
// 用法:HICAL_LOG_TO("db", Info, "query time={}ms", ms)
#define HICAL_LOG_TO(channel, lvlName, fmt, ...) \
do \
{ \
auto hCh_ = ::hical::Logger::instance().channels().get(channel); \
if (hCh_ && hCh_->level() <= ::hical::LogLevel::h##lvlName) \
{ \
::hical::LogRecord hRec_; \
hRec_.level = ::hical::LogLevel::h##lvlName; \
hRec_.timestamp = std::chrono::system_clock::now(); \
hRec_.file = __FILE__; \
hRec_.line = __LINE__; \
hRec_.message = std::format(fmt __VA_OPT__(, ) __VA_ARGS__); \
hCh_->emit(hRec_); \
} \
} while (0)
// 通道 + 结构化字段变体
// 用法:HICAL_LOG_TO_F("access", Info, {{"status", 200}}, "GET /api")
#define HICAL_LOG_TO_F(channel, lvlName, fields, fmt, ...) // ... 同理
注意几个关键设计点:
HICAL_LOG_IMPL_内部宏:std::format的调用在logFmt模板内部执行(利用std::format_string<Args...>编译期校验),而非在宏展开处直接调用。- 流式宏用
if-else+LogMessageVoid:LogMessageVoid的operator&消费LogStream对象,确保级别不满足时编译器可以完全消除LogStream的构造。 - NDEBUG 消除:不只消除
TRACE,还一并消除TRACE_IF、TRACE_F、TRACE_STREAM。用((void)0)而非do {} while (0)。
2.4 thread_local 时间戳缓存
时间格式化是日志的热路径,每次都调 localtime_r + strftime 开销约 200-500ns。高频写日志时,同一秒内会重复格式化完全相同的字符串。
// src/core/LogFormatter.cpp — 时间戳缓存(TextFormatter/JsonFormatter 共用)
namespace
{
struct TsCache
{
time_t cachedSec{0};
struct tm cachedTm{}; // 缓存的是 struct tm,而非格式化后的字符串
};
thread_local TsCache tsFmtCache; // 每个线程独立的缓存,无需加锁
struct tm cachedLocaltime(time_t nowSec)
{
auto& cache = tsFmtCache;
if (nowSec != cache.cachedSec)
{
cache.cachedSec = nowSec;
#if defined(_WIN32)
localtime_s(&cache.cachedTm, &nowSec);
#else
localtime_r(&nowSec, &cache.cachedTm);
#endif
}
return cache.cachedTm;
}
} // namespace
// src/core/Log.cpp — 线程 ID 缓存
namespace
{
struct ThreadIdCache
{
bool initialized{false};
uint64_t threadId{0}; // 数值类型,非字符串
};
thread_local ThreadIdCache tidTlsCache;
uint64_t cachedThreadId()
{
auto& cache = tidTlsCache;
if (!cache.initialized)
{
std::ostringstream oss;
oss << std::this_thread::get_id();
try
{
cache.threadId = std::stoull(oss.str());
}
catch (...)
{
cache.threadId = std::hash<std::thread::id>{}(std::this_thread::get_id());
}
cache.initialized = true;
}
return cache.threadId;
}
} // namespace
两处缓存的设计思路一致:同一秒/同一线程内无论调用多少次,昂贵的操作只发生一次。
注意几个细节差异:
- 时间戳缓存位于
LogFormatter.cpp(供 TextFormatter/JsonFormatter 共用),而非Log.cpp。缓存的是struct tm而非格式化后的字符串——因为 TextFormatter 和 JsonFormatter 需要不同的格式(local time vs UTC)。 - 线程 ID 缓存在
Log.cpp中,存储为uint64_t(数值类型),避免每次 format 时还要做std::to_string转换。
2.5 智能 flush 策略
// src/core/Log.cpp(Phase 1 简化展示)
void Logger::output(LogLevel lvl, const char* file, int line, std::string_view msg)
{
auto now = std::chrono::system_clock::now();
auto ms = /* 毫秒部分 */;
// Phase 1:格式化整行文本,直接写 stderr
// 实际代码中此处构造 LogRecord 后调用 emit(),详见 §6.1 最终锁策略
std::string line_str = std::format(
"[{}.{:03d}] [{}] [{}] [{}:{}] {}\n",
cachedLocaltime(now), ms,
logLevelToString(lvl),
cachedThreadId(),
extractFilename(file), line,
msg);
{
std::lock_guard lock(m_mutex);
std::fwrite(line_str.data(), 1, line_str.size(), stderr);
// 仅 Error 及以上才 flush
if (lvl >= m_flushLevel.load(std::memory_order_relaxed))
std::fflush(stderr);
}
if (lvl == LogLevel::hFatal)
{
std::fflush(stderr);
std::abort();
}
}
注意:实际代码中
output()已演进为构造LogRecord→ 调用emit()的 snapshot 模式(锁内仅拷贝 shared_ptr,锁外格式化+分发)。这里展示的是 Phase 1 的原始设计,帮助理解从同步 stderr 到异步 Sink 的演进思路。最终实现见 §6.1。
flush 策略决策表:
| 级别 | flush 行为 | 原因 |
|---|---|---|
| Trace/Debug | 不 flush | 高频,flush 开销不可接受;调试时可降 flushLevel |
| Info/Warn | 不 flush(默认) | 由 OS 缓冲区聚合写出,减少系统调用 |
| Error | 立即 flush(默认) | 错误信息不能因崩溃而丢失 |
| Fatal | flush + abort() | 最后一条日志,必须确保落盘 |
2.6 Phase 1 关键设计决策总结
| 决策点 | 选择 | 备选方案 | 原因 |
|---|---|---|---|
| 单例模式 | Meyer’s singleton | DCLP + atomic | C++11 标准保证线程安全,代码更简洁 |
| 级别短路 | atomic<LogLevel> relaxed |
mutex | 读多写少,relaxed 语义已满足可见性要求 |
| 时间戳缓存 | thread_local TsCache |
全局 mutex + cache | 消除线程竞争,每线程独立缓存 struct tm |
| TRACE 消除 | #ifdef NDEBUG → ((void)0) |
if constexpr |
彻底消除,连 level() 调用都不会发生 |
| Fatal 行为 | flush + std::abort() |
throw exception | 对应 POSIX 信号,coredump 更易于事后分析 |
| emit 锁策略 | snapshot + 锁外格式化/分发 | 锁内格式化+写入 | 临界区从 ~500ns 缩短到 ~50ns,多线程不排队 |
3. Phase 2:异步后端——从同步到生产级
Phase 1 解决了 API 体验问题,但同步 fwrite 还在 io_context 线程上执行。高并发时,一次 fwrite 约 1-5μs,加上 mutex 竞争,对协程延迟的影响不可忽视。Phase 2 的目标是把所有磁盘 I/O 移出 io_context 线程。
3.1 FixedBuffer 栈缓冲
日志格式化的中间结果需要一块缓冲区。如果每条日志都 new 一个 std::string,高频写日志时堆分配的开销会很明显。FixedBuffer 把这块缓冲区放在栈上:
// src/core/FixedBuffer.h
namespace hical
{
// N 为缓冲区大小(字节),默认 4096(覆盖绝大多数日志行)
template <std::size_t N = 4096>
class FixedBuffer
{
public:
FixedBuffer() = default;
// 追加原始字节
void append(const char* data, std::size_t len)
{
if (!m_overflowed && m_used + len <= N)
{
std::memcpy(m_stackBuf + m_used, data, len);
m_used += len;
}
else
{
// 首次溢出时,先迁移栈上已有数据到堆(保证数据完整)
if (!m_overflowed)
{
m_heapBuf.assign(m_stackBuf, m_used);
m_overflowed = true;
}
m_heapBuf.append(data, len);
}
}
// 流式 API:operator<< 重载(支持 string_view, const char*, char, bool, 整数, 浮点)
FixedBuffer& operator<<(std::string_view sv) { append(sv.data(), sv.size()); return *this; }
FixedBuffer& operator<<(const char* s) { return *this << std::string_view(s ? s : "(null)"); }
FixedBuffer& operator<<(char c) { append(&c, 1); return *this; }
FixedBuffer& operator<<(bool b) { return *this << (b ? "true" : "false"); }
// 整数:用 std::to_chars,避免 snprintf 开销
template <typename T>
requires std::is_integral_v<T>
FixedBuffer& operator<<(T val)
{
char tmp[24];
auto [ptr, ec] = std::to_chars(tmp, tmp + sizeof(tmp), val);
if (ec == std::errc{})
append(tmp, static_cast<std::size_t>(ptr - tmp));
return *this;
}
// 浮点:to_chars general 格式
FixedBuffer& operator<<(double val)
{
char tmp[32];
auto [ptr, ec] = std::to_chars(tmp, tmp + sizeof(tmp), val,
std::chars_format::general);
if (ec == std::errc{})
append(tmp, static_cast<std::size_t>(ptr - tmp));
return *this;
}
// 获取最终视图(溢出后返回堆内容,否则返回栈内容)
std::string_view view() const
{
return m_overflowed ? std::string_view(m_heapBuf)
: std::string_view(m_stackBuf, m_used);
}
std::size_t size() const { return m_overflowed ? m_heapBuf.size() : m_used; }
const char* data() const { return m_overflowed ? m_heapBuf.data() : m_stackBuf; }
void clear()
{
m_used = 0;
m_overflowed = false;
m_heapBuf.clear();
}
private:
char m_stackBuf[N]{}; // 栈上缓冲
std::size_t m_used{0}; // 当前写入位置
bool m_overflowed{false};
std::string m_heapBuf; // 溢出 fallback
};
} // namespace hical
关键设计点:
std::to_chars的价值:它是 C++17 最低级的整数/浮点格式化函数,没有 locale、没有虚调用、不抛异常,速度比snprintf快 3-5 倍。- 溢出时迁移已有数据:首次溢出通过
m_heapBuf.assign(m_stackBuf, m_used)把栈上已有数据完整迁移到堆,不丢失任何内容。后续 append 全部走堆路径。 operator<<是公共 API:LogStream的流式宏通过<<操作符收集日志内容到FixedBuffer,析构时调用Logger::output()输出。
3.2 LogSink 可插拔后端
Phase 2 引入 LogSink 抽象,让 Logger 与具体输出目标解耦:
// src/core/LogSink.h
namespace hical
{
class LogSink
{
public:
virtual ~LogSink() = default;
// 写入一条已格式化的日志行(含换行符)
// 实现必须保证线程安全(Logger 的 snapshot 模式下会在锁外并发调用)
virtual void write(std::string_view formattedLine) = 0;
// 强制刷盘
virtual void flush() = 0;
// 每个 Sink 可以有独立的最低级别
void setLevel(LogLevel lvl)
{
m_sinkLevel.store(lvl, std::memory_order_relaxed);
}
LogLevel sinkLevel() const
{
return m_sinkLevel.load(std::memory_order_relaxed);
}
private:
std::atomic<LogLevel> m_sinkLevel{LogLevel::hTrace};
};
// ── 内置实现 ──────────────────────────────────────────────────────────────────
// 输出到 stderr(线程安全,依赖 stdio 内部锁)
class StderrSink : public LogSink
{
public:
void write(std::string_view formattedLine) override
{
fwrite(formattedLine.data(), 1, formattedLine.size(), stderr);
}
void flush() override { fflush(stderr); }
};
// 同步文件 Sink(带轮转,自有 mutex 保护)
class FileSink : public LogSink
{
public:
explicit FileSink(LogFile::Options opts);
void write(std::string_view formattedLine) override; // 加锁 + fwrite
void flush() override; // 加锁 + fflush
private:
std::mutex m_mutex;
LogFile m_logFile;
};
// 输出到任意 std::ostream(测试用,自有 mutex 保护)
class OStreamSink : public LogSink
{
public:
explicit OStreamSink(std::ostream& os) : m_os(os) {}
void write(std::string_view formattedLine) override; // 加锁 + ostream::write
void flush() override; // 加锁 + ostream::flush
private:
std::ostream& m_os;
std::mutex m_mutex;
};
} // namespace hical
注意 Sink 的线程安全约定:LogSink::write() 的文档要求"实现必须保证线程安全"。这是因为 Logger::emit() 使用 snapshot 模式——格式化和写入在锁外执行,多个线程可能同时调用同一个 Sink 的 write()。StderrSink 依赖 stdio 内部锁,FileSink 和 OStreamSink 有自己的 mutex。
Logger 的 Sink 管理 API 已在上面的类定义中展示(addSink/setSink/clearSinks),实现在 Log.cpp 中,通过 lock_guard 保护 m_sinks vector。
3.3 LogFile 文件轮转
LogFile 封装基于 FILE* 的文件写入,并实现按大小轮转:
// src/core/LogFile.h
namespace hical
{
class LogFile
{
public:
struct Options
{
std::string basePath;
size_t maxFileSize = 100 * 1024 * 1024; // 默认 100MB
size_t maxFiles = 10;
};
explicit LogFile(Options opts);
~LogFile();
// 写入数据(非线程安全,由 FileSink/AsyncFileSink 加锁调用)
void append(const char* data, size_t len);
void flush();
size_t writtenBytes() const { return m_writtenBytes; }
private:
void rotate();
void openFile();
std::string makeRotatedName() const;
void cleanOldFiles();
Options m_opts;
FILE* m_fp{nullptr};
size_t m_writtenBytes{0};
uint64_t m_rotationSeq{0}; // 递增序列号,避免同秒轮转冲突
// 预解析的路径组件(避免每次轮转重新解析)
std::filesystem::path m_dir;
std::string m_stem;
std::string m_ext;
};
} // namespace hical
// src/core/LogFile.cpp
std::string LogFile::makeRotatedName() const
{
// 轮转文件名格式:stem.YYMMDD-HHMMSS.NNNNNN.ext
// 例:server.260501-142505.000001.log
auto now = std::chrono::system_clock::now();
auto t = std::chrono::system_clock::to_time_t(now);
struct tm tm{};
#ifdef _WIN32
localtime_s(&tm, &t);
#else
localtime_r(&t, &tm);
#endif
char suffix[32];
std::snprintf(suffix, sizeof(suffix), ".%02d%02d%02d-%02d%02d%02d.%06u",
tm.tm_year % 100, tm.tm_mon + 1, tm.tm_mday,
tm.tm_hour, tm.tm_min, tm.tm_sec,
static_cast<unsigned>(m_rotationSeq));
return m_stem + suffix + m_ext;
}
void LogFile::cleanOldFiles()
{
// 扫描同目录下匹配 stem.*.ext 的文件
std::vector<std::filesystem::path> rotated;
for (auto& entry : std::filesystem::directory_iterator(m_dir))
{
auto name = entry.path().filename().string();
// 严格匹配:stem 开头 + ext 结尾 + 20 字符中间段格式校验
if (name.starts_with(m_stem) && name.ends_with(m_ext)
&& name != (m_stem + m_ext))
rotated.push_back(entry.path());
}
if (rotated.size() < m_opts.maxFiles)
return;
// 按文件名字典序排列(时间戳编码在名称中,字典序等于时间序)
std::sort(rotated.begin(), rotated.end());
auto toDelete = rotated.size() - m_opts.maxFiles + 1;
for (size_t i = 0; i < toDelete; ++i)
std::filesystem::remove(rotated[i]);
}
关键细节:
- Options 结构体聚合参数:避免构造函数参数列表过长,扩展新选项时不破坏调用方。
- 递增序列号
m_rotationSeq代替微秒时间戳,彻底避免同一秒内多次轮转的命名冲突。 - 文件名字典序排序代替
last_write_time()——因为时间戳编码在文件名中,字典序天然等于时间序,且不需要额外的文件系统元数据查询。
3.4 AsyncFileSink 双缓冲异步
AsyncFileSink 是 Phase 2 的核心:把日志写入从 io_context 线程解耦到专用后台线程。
┌─────────────────────────────────────────────────────────────────┐
│ io_context 线程 │
│ │
│ Logger::emit() │
│ │ │
│ ▼ │
│ ┌─────────────┐ lock_guard ┌──────────────────────────┐ │
│ │ 前台缓冲区 │────append()────▶│ m_current (4MB string) │ │
│ └─────────────┘ └──────────────────────────┘ │
│ │ notify_one() │
└──────────────────────────────────────────┼─────────────────────┘
│
┌────────────────▼──────────────────────┐
│ 后台 jthread │
│ │
│ wait_for(flushInterval) │
│ │ │
│ ▼ │
│ ┌─────────────────┐ │
│ │ swap(current, │ O(1) 交换指针 │
│ │ backup) │ │
│ └────────┬────────┘ │
│ │ mutex 释放,前台可继续写 │
│ ▼ │
│ LogFile::write(backup) 真正 fwrite │
│ │ │
│ ▼ │
│ backup.clear() │
└────────────────────────────────────────┘
// src/core/AsyncFileSink.h
namespace hical
{
class AsyncFileSink : public LogSink
{
public:
struct Options
{
LogFile::Options file; // 文件轮转配置
size_t bufferSize = 4 * 1024 * 1024; // 前后缓冲区大小(4MB)
size_t backpressureLimit = 8 * 1024 * 1024; // 背压阈值(8MB)
std::chrono::milliseconds flushInterval{1000}; // 定时 flush 间隔
};
explicit AsyncFileSink(Options opts);
~AsyncFileSink() override; // jthread 析构自动 request_stop + join
void write(std::string_view formattedLine) override;
void flush() override;
// 查询因背压丢弃的日志条数(原子读取)
uint64_t droppedCount() const;
private:
void backgroundLoop(std::stop_token stopToken);
Options m_opts;
LogFile m_logFile;
std::mutex m_bufMutex;
std::string m_curBuf; // 前台写入缓冲
std::string m_flushBuf; // 后台刷写缓冲
std::condition_variable_any m_cond;
std::jthread m_bgThread;
std::atomic<uint64_t> m_dropped{0}; // 丢弃计数
};
} // namespace hical
// src/core/AsyncFileSink.cpp
AsyncFileSink::AsyncFileSink(Options opts)
: m_opts(std::move(opts)), m_logFile(m_opts.file)
{
m_curBuf.reserve(m_opts.bufferSize); // 预分配 4MB
m_flushBuf.reserve(m_opts.bufferSize);
m_bgThread = std::jthread([this](std::stop_token st) { backgroundLoop(std::move(st)); });
}
void AsyncFileSink::write(std::string_view formattedLine)
{
std::lock_guard<std::mutex> lock(m_bufMutex);
// 背压保护:前台缓冲超过 8MB 时丢弃,记录丢弃数量
if (m_curBuf.size() > m_opts.backpressureLimit)
{
m_dropped.fetch_add(1, std::memory_order_relaxed);
return;
}
m_curBuf.append(formattedLine.data(), formattedLine.size());
// 仅在缓冲区接近满时通知后台线程(减少无谓唤醒)
if (m_curBuf.size() >= m_opts.bufferSize)
m_cond.notify_one();
}
void AsyncFileSink::backgroundLoop(std::stop_token stopToken)
{
while (true)
{
{
std::unique_lock<std::mutex> lock(m_bufMutex);
m_cond.wait_for(lock, stopToken, m_opts.flushInterval,
[this] { return !m_curBuf.empty(); });
if (stopToken.stop_requested() && m_curBuf.empty())
break;
if (!m_curBuf.empty())
{
// O(1) 交换:string::swap 只交换指针
m_curBuf.swap(m_flushBuf);
m_curBuf.clear();
}
else
{
continue;
}
} // lock 释放,前台可以继续写
// 锁外批量写盘
if (!m_flushBuf.empty())
{
// 输出丢弃统计
auto dropped = m_dropped.exchange(0, std::memory_order_relaxed);
if (dropped > 0)
{
char dropMsg[128];
auto n = snprintf(dropMsg, sizeof(dropMsg),
"[WARN] AsyncFileSink: %llu log lines dropped due to backpressure\n",
static_cast<unsigned long long>(dropped));
m_logFile.append(dropMsg, static_cast<size_t>(n));
}
m_logFile.append(m_flushBuf.data(), m_flushBuf.size());
m_logFile.flush();
m_flushBuf.clear();
}
}
// 优雅关闭:把剩余数据全部刷盘
{
std::lock_guard<std::mutex> lock(m_bufMutex);
if (!m_curBuf.empty())
{
m_curBuf.swap(m_flushBuf);
m_curBuf.clear();
}
}
if (!m_flushBuf.empty())
{
m_logFile.append(m_flushBuf.data(), m_flushBuf.size());
m_logFile.flush();
}
}
void AsyncFileSink::flush()
{
// 通知后台线程立即刷盘
{
std::lock_guard<std::mutex> lock(m_bufMutex);
m_cond.notify_one();
}
std::this_thread::yield(); // 让出 CPU 给后台线程
}
关键变更对比早期设计:
- Options 聚合参数:用嵌套
Options结构体代替 5 个独立构造参数。 - 双缓冲使用
std::string:直接m_curBuf.swap(m_flushBuf)交换(也是 O(1) 指针交换),比unique_ptr<string>更简洁。 - 丢弃计数:
m_dropped原子计数器,背压时递增,后台刷盘时输出统计信息并清零。 - 按需通知:只在
m_curBuf.size() >= bufferSize时notify_one(),减少无谓的线程唤醒。
4. Phase 3:结构化日志与可观测性
Phase 2 解决了性能问题,Phase 3 解决可观测性问题。可观测性在分布式系统里意味着:给每条日志加上足够的上下文,让你能用工具(ELK、Loki)自动聚合、过滤、关联,而不是靠人眼看文本。
4.1 LogRecord 结构化日志条目
// src/core/LogRecord.h(字段类型与实际源码一致)
namespace hical
{
struct LogRecord
{
// 基本字段
LogLevel level;
std::chrono::system_clock::time_point timestamp;
uint64_t threadId{0}; // 数值类型,非字符串
const char* file{nullptr}; // 裸指针,零拷贝(指向 __FILE__ 字面量)
int line{0};
std::string message;
// 追踪字段(由 LogMiddleware 注入)
std::string traceId; // 请求级唯一 ID,128-bit hex(thread_local PRNG)
// 业务字段:自由扩展(由 HICAL_LOG_INFO_F 宏填充)
boost::json::object fields;
};
} // namespace hical
LogRecord 的设计选择:
threadId用uint64_t而非std::string——数值类型避免每条日志一次字符串构造,Formatter 在输出时再转为字符串。file用const char*而非std::string——__FILE__宏展开为字符串字面量,生命周期与程序一致,不需要拷贝到堆上。fields用boost::json::object承载业务字段,不预定义 schema,完全自由扩展。
结构化字段宏和通道路由宏已在 §2.3 宏系统中完整展示(HICAL_LOG_INFO_F、HICAL_LOG_TO、HICAL_LOG_TO_F)。这里补充几个使用示例:
// 带结构化字段的日志
HICAL_LOG_INFO_F({{"uid", userId}, {"ip", clientIp}}, "user login");
// 路由到命名通道
HICAL_LOG_TO("db", Debug, "query sql={} elapsed={}ms", sql, elapsed);
// 通道 + 结构化字段
HICAL_LOG_TO_F("access", Info, {{"status", 200}, {"latency_ms", 3}}, "GET /api");
4.2 Formatter 层
Formatter 把 LogRecord 转换为最终的字符串:
// src/core/LogFormatter.h(简化展示,完整实现见源码)
namespace hical
{
class LogFormatter
{
public:
virtual ~LogFormatter() = default;
virtual std::string format(const LogRecord& record) = 0; // 非 const
};
// 输出格式:[2026-05-01 14:25:05.123] [INFO] [12345] [trace=abc123] [file.cpp:42] message
class TextFormatter : public LogFormatter
{
public:
std::string format(const LogRecord& record) override
{
// 手动拼接(比 std::format 快,避免格式解析开销)
// thread_local cachedLocaltime() 避免同秒重复调用 localtime_r
std::string result;
result.reserve(256);
result += "[ts] [";
result += logLevelToString(record.level);
result += "] [";
result += std::to_string(record.threadId); // uint64_t → string
result += "] ";
// ... traceId、file:line、message、'\n'
return result;
}
};
// 每行一个 JSON 对象(newline-delimited JSON,兼容 ELK/Loki)
// key 使用全称("timestamp"、"thread_id"、"message"),与 ELK 标准字段名对齐
class JsonFormatter : public LogFormatter
{
public:
std::string format(const LogRecord& record) override
{
boost::json::object obj;
obj["timestamp"] = /* UTC ISO 8601 + Z */;
obj["level"] = logLevelToString(record.level);
obj["thread_id"] = record.threadId; // uint64_t 数值
obj["message"] = record.message;
if (!record.traceId.empty())
obj["trace_id"] = record.traceId;
// 合并 record.fields(扁平化到同一层)
return boost::json::serialize(obj) + "\n";
}
};
} // namespace hical
几个设计要点:
format()不带const——允许子类内部使用thread_local缓存。- TextFormatter 用手动
result +=拼接——避免std::format的运行时格式解析开销。 - JsonFormatter 时间戳用 UTC
gmtime+"Z"后缀——无时区歧义,ELK/Loki 直接解析。
两种 Formatter 的适用场景:
| Formatter | 输出格式 | 适用场景 |
|---|---|---|
| TextFormatter | 人类可读文本 | 开发调试、运维直接 tail -f 查看 |
| JsonFormatter | Newline-JSON | 生产环境接 ELK/Loki/Datadog,自动解析字段 |
4.3 LogChannel 多通道路由
LogChannel 允许不同模块把日志路由到不同的 Sink/级别/格式化器组合:
// src/core/LogChannel.h(简化展示,签名与实际源码一致)
namespace hical
{
class LogChannel
{
public:
explicit LogChannel(std::string name); // 默认 Formatter = TextFormatter
void emit(const LogRecord& record); // 线程安全,内部也用 snapshot 模式
void setLevel(LogLevel lvl); // atomic,运行时动态调整
LogLevel level() const;
void setFormatter(std::shared_ptr<LogFormatter> formatter);
void addSink(std::shared_ptr<LogSink> sink);
void clearSinks();
private:
std::string m_name;
std::atomic<LogLevel> m_level{LogLevel::hTrace};
std::mutex m_mutex;
std::shared_ptr<LogFormatter> m_formatter;
std::vector<std::shared_ptr<LogSink>> m_sinks;
};
// 通道注册表(Logger 的成员,非全局单例)
// 通过 Logger::instance().channels() 访问
class LogChannelRegistry
{
public:
std::shared_ptr<LogChannel> getOrCreate(const std::string& name);
std::shared_ptr<LogChannel> get(const std::string& name) const; // 不存在返回 nullptr
std::vector<std::pair<std::string, LogLevel>> listChannels() const;
private:
mutable std::shared_mutex m_mutex; // 多读一写 + 双重检查
std::unordered_map<std::string, std::shared_ptr<LogChannel>> m_channels;
};
} // namespace hical
几个关键设计点:
- Registry 是 Logger 成员而非全局单例,通过
Logger::instance().channels()访问。 get()和getOrCreate()分离——HICAL_LOG_TO宏内部用get(),通道不存在时静默跳过。m_level默认hTrace——通道默认接受所有级别,粒度控制交给 Sink 的sinkLevel()。
通道的典型用法:
// 初始化:db 通道写到专用文件,格式为 JSON
auto& channels = Logger::instance().channels();
auto dbCh = channels.getOrCreate("db");
dbCh->setFormatter(std::make_shared<JsonFormatter>());
dbCh->addSink(std::make_shared<AsyncFileSink>(AsyncFileSink::Options{
.file = {.basePath = "/var/log/hical/db.log"}
}));
dbCh->setLevel(LogLevel::hDebug);
// 使用
HICAL_LOG_TO("db", Debug, "query sql={} elapsed={}ms", sql, elapsed);
4.4 LogMiddleware 请求追踪
LogMiddleware 是洋葱模型中的一层,它在请求进入时生成 trace-id,注入到 HttpRequest 的属性里,让后续的所有日志调用都能带上这个 ID:
// src/core/LogMiddleware.h(简化展示,签名与实际源码一致)
namespace hical
{
struct LogMiddlewareOptions
{
std::string accessLogChannel = "access";
bool autoTraceId = true;
std::string traceIdHeader = "X-Trace-Id";
};
inline constexpr const char* hTraceIdKey = "hical.trace_id";
std::string generateTraceId(); // thread_local PRNG,128 位 hex
MiddlewareHandler makeLogMiddleware(LogMiddlewareOptions opts = {});
std::string getTraceId(const HttpRequest& req);
} // namespace hical
makeLogMiddleware 的洋葱模型行为:
before next():
1. 优先从请求头提取 trace-id(分布式追踪透传)
2. 没有时用 thread_local PRNG 生成 128-bit hex
3. req.setAttribute(hTraceIdKey, traceId)
4. 记录 startTime
co_await next(req) → response
after next():
5. 计算 latencyMs
6. 发射结构化 LogRecord 到 access 通道
fields: method, path, status, latency_ms, trace_id
为什么用 req.setAttribute 而不用 thread_local?
这是协程环境里的经典陷阱。thread_local 变量与线程绑定,但 co_await 之后协程可能在不同线程上恢复(取决于 executor 的调度策略)。用 req.setAttribute 把 trace-id 绑定到请求对象,与线程完全解耦,协程挂起/恢复后依然能正确取到 trace-id。
为什么 trace-id 不用 OpenSSL RAND_bytes?
trace-id 的安全需求是全局唯一性,不是不可预测性——它用于日志追踪,不用于认证或防篡改。OpenSSL 3.x 的 RAND_bytes 内部有全局 DRBG 锁,高并发下每请求 ~1-3μs 的锁竞争开销不可忽视。改用 thread_local std::mt19937_64 后,trace-id 生成降到 ~10ns,零锁竞争。需要密码学安全的场景(如 Session ID)仍然使用 RAND_bytes。
4.5 LogAdmin 动态级别
LogAdmin 把日志级别管理暴露为 HTTP API,支持在不重启服务的情况下动态调整:
// src/core/LogAdmin.h(简化展示)
namespace hical
{
// 注册管理端点(同步路由处理器,非协程)
// GET {prefix}/log-level → {"default":"INFO","channels":{"db":"DEBUG",...}}
// PUT {prefix}/log-level → body: {"channel":"db","level":"warn"}
// channel 为空时修改全局级别;channel 不存在时返回 404
void registerLogAdminEndpoints(Router& router, const std::string& prefix = "/admin");
} // namespace hical
LogAdmin 的价值在于零停机调试:生产环境出现奇怪行为时,直接 curl -X PUT /admin/log-level -d '{"channel":"db","level":"debug"}' 打开 db 通道的 debug 日志,复现后再关掉,全程不需要重启服务。
5. 性能深度分析
5.1 各阶段性能数据
以下测试在 i7-12700H、16GB RAM、Windows 11 下进行,单线程写日志:
| 指标 | Phase 1 (同步 stderr) | Phase 2 (AsyncFileSink) | 提升倍数 |
|---|---|---|---|
| 吞吐量(条/秒) | ~180,000 | ~2,400,000 | 13.3x |
| 平均写入延迟(μs) | 5.2 | 0.38 | 13.7x |
| P99 写入延迟(μs) | 18.4 | 1.2 | 15.3x |
| 10 线程竞争延迟 P99(μs) | 62.1 | 2.8 | 22.2x |
| 内存占用(稳态) | ~0.5MB | ~10MB(4+4MB 双缓冲) | - |
关键结论:AsyncFileSink 的 P99 延迟从 18.4μs 降到 1.2μs,对 io_context 线程的延迟影响从"可感知"变成"不可感知"。
5.2 与主流日志库的对比
| 对比项 | hical Phase 2 | spdlog (async) | Trantor |
|---|---|---|---|
| 外部依赖 | 无(只用 Boost) | fmt 库 | drogon 框架 |
| 协程安全 | 是 | 是 | 是 |
| 请求追踪 ID | 内置 | 需手动扩展 | 内置 |
| 动态调整级别 API | HTTP REST | 需手动扩展 | 无 |
| JSON 格式 | 内置 | 需 custom sink | 无 |
| 文件轮转 | 内置 | 内置 | 内置 |
| 多通道路由 | 内置 | logger hierarchy | 无 |
5.3 FixedBuffer 与 std::string 的格式化对比
格式化 "port=8080 threads=4 started" 这样的日志行:
方式 平均耗时 备注
─────────────────────────────────────────────────────
std::string + format() 42ns 每次 new(可能堆分配)
FixedBuffer + to_chars 11ns 栈上操作,无堆分配
ostringstream + << 185ns locale 开销 + 多次堆分配
snprintf 38ns 无 locale,但有 %格式解析
4KB 栈缓冲覆盖了 99.9% 的日志行(实测单行日志超过 4KB 的极其罕见),溢出时的 fallback 到堆分配性能与 std::string 相同。
6. 线程安全设计
日志系统是典型的高竞争共享资源,线程安全设计的每一个决策都有明确的理由。
6.1 Logger 的锁策略
Logger 内部状态(类型签名与实际源码一致):
m_level → atomic<LogLevel> relaxed : 只需原子性,不需要 happens-before
m_flushLevel → atomic<LogLevel> relaxed : 同上
m_sinks → vector<shared_ptr<LogSink>>,由 m_mutex 保护
m_formatter → shared_ptr<LogFormatter>,由 m_mutex 保护
写入路径(emit)— snapshot + 锁外格式化:
1. level() <= → relaxed load,无锁,~1ns
2. lock_guard → 快照 m_formatter + m_sinks(shallow copy shared_ptr)→ ~50ns
3. 锁外格式化 → formatter->format(record),纯函数
4. 锁外分发到 Sink → Sink 接口要求实现线程安全
5. 锁外条件 flush
管理路径(addSink/setSink/clearSinks):
lock_guard → 修改 m_sinks vector
为什么不把格式化放在锁内? TextFormatter::format() 涉及 snprintf + 字符串拼接,约 200-500ns。锁内执行时多线程排队等待,临界区膨胀 10 倍。snapshot 模式:锁内只做 shared_ptr 浅拷贝(~50ns),格式化和写入全在锁外并行执行。LogChannel::emit() 也采用相同的 snapshot 模式。
6.2 AsyncFileSink 的双缓冲安全性
lock_guard 保护范围分析:
前台线程 write():
├─ lock_guard lock(m_bufMutex)
├─ 检查 m_curBuf.size() > backpressureLimit → 超限丢弃 + m_dropped 计数
├─ m_curBuf.append(formattedLine)
├─ 缓冲区接近满时 cv.notify_one()(按需通知)
└─ lock 释放
后台线程 backgroundLoop():
├─ unique_lock lock(m_bufMutex)
├─ cv.wait_for(lock, stopToken, flushInterval, predicate)
├─ 检查 m_curBuf.empty()
├─ m_curBuf.swap(m_flushBuf) ← O(1),string::swap 指针交换
├─ m_curBuf.clear()
└─ lock 释放
├─ 输出丢弃统计(m_dropped.exchange(0))
├─ m_logFile.append(m_flushBuf) ← 真正 I/O,在锁外
└─ m_flushBuf.clear()
双缓冲的不变量:m_curBuf 始终是前台写入缓冲,m_flushBuf 始终是后台刷写缓冲,两者永远不会同时被访问。swap 发生在锁内,string::swap 只交换指针(O(1))。
6.3 LogChannel 的线程安全
LogChannelRegistry:
m_mutex (shared_mutex)
m_channels (unordered_map<string, shared_ptr<LogChannel>>)
读路径(get,日志写入时调用):
shared_lock → 只读 m_channels,多线程并发不阻塞
写路径(getOrCreate,首次使用时):
先 shared_lock 查 → miss → 升级到 unique_lock → 双重检查 → 创建
LogChannel 内部(emit 也使用 snapshot 模式,与 Logger 一致):
m_level → atomic<LogLevel> : 动态调整级别,无锁
m_mutex → std::mutex : 保护 m_formatter + m_sinks(仅 snapshot 拷贝)
emit():
1. 级别检查(atomic load)
2. lock → snapshot m_formatter + m_sinks → unlock
3. 锁外格式化 + 分发
shared_mutex 在这里的价值:通道一旦创建,后续的 getChannel 调用全是读操作(找到已有通道即返回)。用 shared_lock 允许并发读,大幅减少竞争。
7. 实战:5 分钟搭建完整日志体系
一个完整的生产配置示例:
// main.cpp:5 分钟完整日志配置(简化展示,API 调用方式与实际源码一致)
#include <hical/Log.h>
#include <hical/AsyncFileSink.h>
#include <hical/LogMiddleware.h>
#include <hical/LogAdmin.h>
#include <hical/HttpServer.h>
using namespace hical;
void setupLogging()
{
auto& logger = Logger::instance();
logger.setLevel(LogLevel::hInfo);
logger.setFlushLevel(LogLevel::hError);
// 默认 Formatter(TextFormatter)
logger.setFormatter(std::make_shared<TextFormatter>());
// 主日志文件(异步 Sink,Options 聚合参数)
logger.addSink(std::make_shared<AsyncFileSink>(AsyncFileSink::Options{
.file = {.basePath = "/var/log/hical/server.log"}}));
// access 通道:JSON 格式(LogMiddleware 自动输出到此通道)
auto accessCh = logger.channels().getOrCreate("access");
accessCh->setFormatter(std::make_shared<JsonFormatter>());
accessCh->addSink(std::make_shared<AsyncFileSink>(AsyncFileSink::Options{
.file = {.basePath = "/var/log/hical/access.json.log"}}));
// db 通道:独立文件 + Debug 级别
auto dbCh = logger.channels().getOrCreate("db");
dbCh->setFormatter(std::make_shared<JsonFormatter>());
dbCh->addSink(/* AsyncFileSink for db.log */);
dbCh->setLevel(LogLevel::hDebug);
}
int main()
{
setupLogging();
HttpServer server(8080);
server.use(makeLogMiddleware()); // 洋葱最外圈
registerLogAdminEndpoints(server.router()); // 动态级别管理
server.router().get("/api/users/{id}",
[](const HttpRequest& req) -> Awaitable<HttpResponse>
{
auto traceId = getTraceId(req);
auto id = req.param("id");
HICAL_LOG_INFO("fetching user id={} [trace={}]", id, traceId);
HICAL_LOG_TO("db", Debug, "SELECT * FROM users WHERE id={}", id);
HICAL_LOG_INFO_F({{"user_id", std::stoll(id)}}, "user query");
co_return HttpResponse::json(/* ... */);
});
server.start();
}
运行后的日志效果:
# server.log(TextFormatter)
[2026-05-01 14:25:05.042] [INFO] [4872] [main.cpp:38] logging system initialized
[2026-05-01 14:25:05.043] [INFO] [4872] [main.cpp:81] server listening on port=8080
[2026-05-01 14:25:06.114] [INFO] [4872] [main.cpp:60] fetching user id=42 [trace=a3f8c2d1e5b9047f1234567890abcdef]
# access.json.log(JsonFormatter,由 LogMiddleware 通过 access 通道输出)
{"timestamp":"2026-05-01T06:25:06.116Z","level":"INFO","thread_id":4872,"message":"GET /api/users/42","trace_id":"a3f8c2d1e5b9047f1234567890abcdef","method":"GET","path":"/api/users/42","status":200,"latency_ms":3}
# db.log(JsonFormatter)
{"timestamp":"2026-05-01T06:25:06.114Z","level":"DEBUG","thread_id":4872,"message":"SELECT * FROM users WHERE id=42"}
动态调整 db 通道级别(不重启服务):
# 关闭 db Debug 日志(生产环境减少 I/O)
curl -X PUT http://localhost:8080/admin/log-level \
-H 'Content-Type: application/json' \
-d '{"channel":"db","level":"warn"}'
# 查询当前所有通道级别
curl http://localhost:8080/admin/log-level
# {"default":"INFO","channels":{"access":"INFO","db":"WARN"}}
8. 总结与设计决策表
三阶段演进总结
| 阶段 | 核心模块 | 解决的核心问题 | 代码量 |
|---|---|---|---|
| Phase 1 | Logger + 6级别 + 宏系统 + thread_local 缓存 | API 体验;zero-cost 短路 | ~300 行 |
| Phase 2 | FixedBuffer + LogSink + LogFile + AsyncFileSink | io_context 线程不阻塞 | ~500 行 |
| Phase 3 | LogRecord + Formatter + Channel + Middleware + Admin | 可观测性;请求追踪;动态运维 | ~400 行 |
关键设计决策汇总
| 决策点 | 最终选择 | 核心理由 |
|---|---|---|
| 级别短路机制 | atomic<LogLevel> relaxed load |
无锁、纳秒级、适合多线程读多写少场景 |
| 时间戳缓存 | thread_local TsCache |
消除线程竞争;缓存 struct tm,TextFormatter/JsonFormatter 按需格式化 |
| 异步后端 | 双缓冲 string::swap + std::jthread |
O(1) 指针交换;自动生命周期管理;背压丢弃+计数 |
| 整数格式化 | std::to_chars(FixedBuffer operator<<) |
无 locale、无异常、比 snprintf 快 3-5 倍 |
| 请求追踪 | req.setAttribute + thread_local PRNG |
协程安全(不绑线程);trace-id 只需唯一性,PRNG 零锁竞争 |
| 通道注册表 | Logger 成员 + shared_mutex |
非全局单例,生命周期与 Logger 绑定;读多写少 |
| Logger/Channel 锁 | snapshot + 锁外格式化/分发 | 临界区从 ~500ns 缩短到 ~50ns |
| 背压保护 | 超过 8MB 丢弃 + 原子计数 | 保护服务稳定性;丢弃数量可观测 |
| Fatal 行为 | flush + std::abort() |
确保最后日志落盘;coredump 易于事后分析 |
| JSON 时间戳 | UTC + ISO 8601 + Z | ELK/Loki 标准格式;无时区歧义 |
| LogAdmin 接口 | HTTP REST PUT/GET(同步处理器) | 零停机动态调整;不存在的通道返回 404 |
9. 核心要点
-
零开销级别短路:
atomic<LogLevel> relaxedload 约 1ns,未启用级别的日志调用在宏的第一行就返回,格式化字符串完全不会构造。 -
双缓冲是核心:AsyncFileSink 的
string::swap是 O(1) 指针交换,mutex 持有时间在微秒级,真正的fwrite在锁外执行。io_context 线程写日志的 P99 延迟从 18μs 降到 1.2μs。背压时丢弃日志并通过m_dropped原子计数器记录丢弃数量。 -
协程安全的 trace-id:
thread_local在co_await后可能读到错误值(线程可能换了),必须用req.setAttribute把 trace-id 绑定到请求对象,与线程解耦。trace-id 使用thread_local std::mt19937_64(PRNG)而非 OpenSSLRAND_bytes——日志追踪只需唯一性,不需要密码学安全,PRNG 零锁竞争、每次 ~10ns。Session ID 等安全敏感场景仍用RAND_bytes。 -
Logger 的 snapshot 锁模式:
emit()在锁内仅做 formatter + sinks 的 shared_ptr 浅拷贝(~50ns),格式化和 Sink 写入全在锁外执行。多线程模式下不再因为格式化串行排队,临界区从 ~500ns 缩短到 ~50ns。 -
std::jthread的优雅关闭:析构时自动request_stop()+join(),配合condition_variable_any::wait_for的 stop_token 重载,后台线程能正确感知停止信号并刷完剩余日志。 -
NDEBUG 消除 TRACE 全系列:通过重新
#define为((void)0),不只消除TRACE,还消除TRACE_IF、TRACE_F、TRACE_STREAM,让编译器完全不生成相关代码。 -
多通道 + 动态调整 是生产运维的必需品:按模块分通道(通过
Logger::instance().channels()访问,非全局单例),用 HTTP API(registerLogAdminEndpoints())随时调整级别。不存在的通道返回 404,不会自动创建。
10. 知识图谱
日志系统知识图谱
│
├── 基础设施层
│ ├── LogLevel(6 级枚举 uint8_t,hTrace=0..hFatal=5)
│ ├── FixedBuffer(4KB 栈缓冲,to_chars 无堆分配,溢出迁移到堆)
│ └── thread_local 缓存(TsCache struct tm + ThreadIdCache uint64_t)
│
├── API 层(宏系统)
│ ├── HICAL_LOG_INFO(fmt, ...) → HICAL_LOG_IMPL_ 内部宏 + logFmt 模板
│ ├── HICAL_LOG_INFO_IF(cond, fmt, ...) → 条件日志(每级别都有)
│ ├── HICAL_LOG_INFO_STREAM << val → if-else + LogMessageVoid + LogStream
│ ├── HICAL_LOG_INFO_F(fields, fmt, ...) → logFmtWithFields(每级别都有 _F 变体)
│ ├── HICAL_LOG_TO("ch", Info, fmt, ...) → channels().get() + LogRecord + ch->emit()
│ └── HICAL_LOG_TO_F("ch", Info, fields, fmt, ...) → 通道 + 结构化字段
│
├── 核心(Logger 单例)
│ ├── atomic<LogLevel> m_level → 无锁级别检查
│ ├── atomic<LogLevel> m_flushLevel → 智能 flush 策略
│ ├── mutex m_mutex → 保护 sinks/formatter(仅 snapshot 拷贝)
│ ├── emit(LogRecord) → snapshot + 锁外格式化 + 锁外分发
│ ├── m_formatter (shared_ptr) → 默认 TextFormatter
│ └── m_channels (unique_ptr<Registry>) → 通道注册表,非全局单例
│
├── Sink 层(可插拔后端,接口要求线程安全)
│ ├── LogSink(抽象接口:write + flush + sinkLevel)
│ ├── StderrSink → 开发调试(依赖 stdio 锁)
│ ├── OStreamSink → 测试环境(自有 mutex)
│ ├── FileSink(同步,自有 mutex) → 简单场景
│ └── AsyncFileSink(生产级)
│ ├── std::jthread + stop_token → 自动生命周期
│ ├── 双缓冲 string::swap(O(1)) → 最小化 io_context 阻塞
│ ├── condition_variable_any → stop_token 感知 + 按需唤醒
│ ├── 背压保护(8MB 阈值 + 丢弃计数) → 稳定性优先
│ └── Options 聚合参数 → LogFile::Options 嵌套
│
├── 文件管理层
│ └── LogFile(Options 聚合参数)
│ ├── FILE* I/O(append/flush)
│ ├── 按大小轮转(默认 100MB)
│ ├── 时间戳+序列号命名(YYMMDD-HHMMSS.seq)
│ └── 最大文件数限制 + 字典序排序清理
│
├── 结构化层(Phase 3)
│ ├── LogRecord(level+ts+threadId:uint64+file:const char*+line+msg+traceId+fields)
│ ├── TextFormatter → [ts] [LVL] [tid] [trace=x] [file:line] msg(手动拼接)
│ └── JsonFormatter → {"timestamp":..,"level":..,"thread_id":N,"message":..}(UTC ISO8601)
│
├── 通道层
│ ├── LogChannel(独立 level + formatter + sinks,emit 也用 snapshot 模式)
│ └── LogChannelRegistry(Logger 成员,shared_mutex,getOrCreate/get/listChannels)
│
└── 可观测性层
├── LogMiddleware(LogMiddlewareOptions 配置)
│ ├── thread_local PRNG → 128-bit trace-id(零锁竞争,~10ns)
│ ├── 优先从请求头提取(分布式追踪透传)
│ ├── req.setAttribute → 协程安全绑定
│ └── 结构化访问日志 → access 通道(method/path/status/latency_ms)
└── LogAdmin(registerLogAdminEndpoints,同步路由处理器)
├── GET {prefix}/log-level → {"default":"INFO","channels":{...}}
└── PUT {prefix}/log-level → 按通道动态调整(不存在返回 404)
附录:文中示例代码与实际源码的差异
本文采用渐进式叙述,各阶段的代码示例是为讲解设计思路而简化的版本。实际源码经过多轮迭代,已是三个阶段合并后的终态。以下列出关键差异,方便对照源码阅读:
| 本文简化展示 | 实际源码 | 差异原因 |
|---|---|---|
Phase 1 Logger 只有 output() + stderr |
Logger 有完整的 emit(LogRecord)、Sink/Formatter/Channel 管理 |
三阶段合并为一个类 |
Phase 1 output() 在锁内 fwrite(stderr) |
output() 构造 LogRecord → emit() snapshot 锁外格式化 |
Phase 3 引入 snapshot 模式后统一 |
| Phase 2 AsyncFileSink 展示了完整构造代码 | 实际构造方式相同(Options 聚合参数) |
文中已使用正确 API |
| Phase 3 Formatter 展示简化版 format() | 实际有完整的时间戳格式化、文件名提取、条件字段输出 | 简化聚焦设计思路 |
| Phase 3 LogMiddleware 用伪代码描述行为 | 实际有完整的 before/after 实现 | 简化聚焦洋葱模型流程 |
| Phase 3 LogAdmin 只展示声明 | 实际有完整的 GET/PUT 路由处理器实现 | 简化聚焦 API 设计 |
| Phase 3 LogChannel 展示简化版 | 实际 emit() 也用 snapshot 模式(与 Logger 一致) |
简化聚焦通道架构 |
| §6.1 锁策略用伪代码描述 | 实际有完整的 emit() 函数实现 |
简化聚焦 snapshot 思路 |
| §7 实战省略了部分配置细节 | 实际有更多 Options 参数(maxFileSize、maxFiles 等) | 简化聚焦配置流程 |
所有类型签名(
LogLevel : uint8_t、atomic<LogLevel>、LogRecord字段类型、Formatter 不带 const、registerLogAdminEndpoints函数名等)已对齐实际源码。
完整代码请参考 GitHub 仓库 的src/core/Log*.h/cpp文件。
系列完结
七篇文章,从第一篇的"为什么用 C++ 写 Web 框架"到这篇的生产级日志系统,我们完整走过了一个现代 C++ Web 框架从架构设计到可观测性的全部环节——协程、内存池、路由、中间件、SSL、反射、Cookie/Session、数据库、日志,每一层都用现代 C++ 特性替代了传统方案里的样板代码和心智负担。
感谢你读到这里。如果这个系列对你有启发,欢迎在 GitHub 上给个 Star,或者提个 Issue 聊聊你的想法。
hical — 基于 C++20/26 的现代高性能 Web 框架 | GitHub
openEuler 是由开放原子开源基金会孵化的全场景开源操作系统项目,面向数字基础设施四大核心场景(服务器、云计算、边缘计算、嵌入式),全面支持 ARM、x86、RISC-V、loongArch、PowerPC、SW-64 等多样性计算架构
更多推荐

所有评论(0)