PostgreSQL Log日志模块原理及存在的问题详解

背景

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

日志模块原理

Syslogger 核心模块

PG 有各种各样的进程，其中 syslogger 进程专门用于打印日志信息。

而其余进程打印日志的方法如出一辙：将需要打印的信息发送给 syslogger 进程，由其统一负责打印。

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

• postmaster 进程在 SysLogger_Start 函数完成部分初始化；
• 由 postmaster 进程 fork 出 syslogger 进程；
• 进入 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

总结

到此这篇关于PostgreSQL Log日志模块原理及存在的问题详解的文章就介绍到这了,更多相关PostgreSQL Log日志模块内容请搜索脚本之家以前的文章或继续浏览下面的相关文章希望大家以后多多支持脚本之家！