PostgreSQL Log 日志模块详解

本文讲的是操作日志，非 WAL 日志。

背景

PG 的日志模块是一个相对独立的模块，主要功能就是打印用户的操作日志以及一些异常报错信息。本文仅讲述 logging_collector 参数开启的情况。

日志模块原理

Syslogger 核心模块

PG 有各种各样的进程，其中 syslogger 进程专门用于打印日志信息。
而其余进程打印日志的方法如出一辙：将需要打印的信息发送给 syslogger 进程，由其统一负责打印。

syslogger 的大体逻辑如下图所示：

1. postmaster 进程在 SysLogger_Start 函数完成部分初始化；
2. 由 postmaster 进程 fork 出 syslogger 进程；
3. 进入 syslogger 的主逻辑函数 SysLoggerMain 中，大循环监听其他进程发送来的日志消息，处理打印逻辑。在大循环中同时也根据时间和大小，来判断是否进行日志轮转。

日志消息通信

PG 的其余进程如果有需要打印的日志，通常会调用 elog 或者 ereport 来打印。而这两个函数会将日志消息分成若干个 chunk 发送给 syslogger 进程，每个 chunk 的结构可参考下图（源码中的 PipeProtoChunk 结构）

• 开头两个 \0 ，表示是日志开头
• length：用于记录当前 chunk 的长度
• pid：发送该 chunk 的进程号
• is_last：是否是本条日志消息的最后一个 chunk；
• data：具体的日志消息。
• chunk 大小：PIPE_CHUNK_SIZE ，源码 define 出的一个值，由 OS 的 PIPE_BUF 决定。具体细节可参考这部分定义的代码。
  注： PG 15 在 pipe 协议格式中做了一些变化，由 flags 代替 is_last 标记。

syslogger 在接收到日志消息后，将其按照 pid 进行分组，相同的 pid 说明日志消息来源于同一进程，将其组装起来，当收到包含 is_last 标记的最后一个 chunk 后，将整条日志消息打印到日志文件。

日志轮转

所谓日志轮转，指的就是不想继续写当前日志文件了，需要新找一个日志文件继续写日志。

PG 的日志轮转是一个坑非常多的地方，因为它由下面四个参数同时控制：

• log_filename ：日志文件格式，我们以其设定为 postgres_%d_%h 为例，某个月 14 号 15 点的日志文件名就是 postgres_14_15.log
• log_rotation_age：如果距离当前日志文件已经超过设定的时间，那么就新开一个日志文件；
• log_rotation_size：如果距离当前日志文件还没有超过 log_rotation_age 设定的时间，但是已经超过了 log_rotation_size 设定的大小，那么就新开一个日志文件；
• log_truncate_on_rotation：是否在按时间轮转后做截断。即如果下一个日志文件的同名文件已经存在了，是否直接清空该文件并从头开始写；

这几个参数的具体使用可参考 PG 官方文档。看完上面的介绍，想必大家已经精通日志参数设置了，那么接下来做几道题检验自己的学习成果。

假如，我们按照以下值设定日志相关参数

log_filename='postgres_%d_%h.log'
log_rotation_age = 2h
log_rotation_size = 10MB
log_truncate_on_rotation = on

问题一

• Q：此时时间刚到 14 号下午 17 点 ，日志文件为 postgres_14_16.log，且大小为 5MB，请问接下来要写的日志文件是什么？
• A：postgres_14_16.log 。因为此时距离 15 点仅过了 1h，没有超过 log_rotation_age；大小并没有超过 log_rotation_size ，所以并不发生轮转。

问题二

• Q：此时时间为 14 号下午 16 点 30 分 ，日志文件为 postgres_14_16.log，且大小刚刚超过 10MB 到达 10.9MB，请问接下来要写的日志文件是什么？
• A：postgres_14_16.log 。因为 log_filename 参数的最小精度值就到小时，哪怕当前日志文件大小变成 1TB 也只会继续追加写这个文件。

问题三

• Q：此时时间刚到 14 号下午 17 点 ，日志文件为 postgres_14_16.log，且大小刚刚超过 10MB 到达 10.9MB，请问接下来要写的日志文件是什么？
• A：postgres_14_17.log 。因为满足 log_rotation_size 的轮转条件了。

问题四

• Q：此时时间刚到 14 号下午 17 点 ，日志文件为 postgres_14_16.log，且大小刚刚超过 10MB 到达 10.9MB，但是名为 postgres_14_17.log 的文件已经存在了（上个月日志创建的），那么是追加写还是覆盖写该文件？
• A：追加写，因为这是按大小轮转。

问题五

• Q：此时时间刚到 14 号下午 18 点 ，日志文件为 postgres_14_16.log，且大小只有 0.1MB。但是名为 postgres_14_18.log 的文件已经存在了，那么是追加写还是覆盖写该文件？
• A：覆盖写，log_rotation_age 强制触发按时间轮转逻辑。

上面问题都能搞懂，基本也没什么坑了。

存在的问题

刷盘性能

当前情况下，在 log_statement 参数设置成 all 时，性能下降会非常厉害。因为 PG 的日志在刷盘时的默认策略为：每写一行就刷盘。Linux 提供的刷盘模式可分为以下三种：

• _IOFBF：全缓冲模式，缓冲区写满后才刷盘
• _IOLBF：行缓冲模式，一行写满就刷盘
• _IONBF：不缓冲，直接刷

当前 PG 采用第二种行缓冲模式，优点是日志出来的即时性更高，缺点就是对性能有不小的影响。

日志轮转

日志轮转的逻辑设计虽然勉强算是合理的（不会丢日志），但是理解成本很高，且有可能出现某个日志文件存在了非常非常久（上一节问题 4 的变种），一直没被删掉，需要依赖人工手动删除。

参考资料

[1] https://www.postgresql.org/docs/current/logfile-maintenance.html
[2] https://github.com/postgres/postgres