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

文章目录

背景日志模块原理Syslogger 核心模块日志消息通信日志轮转问题一问题二问题三问题四问题五

存在的问题刷盘性能日志轮转

参考资料

背景

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.loglog_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

文章链接

评论可见,请评论后查看内容,谢谢!!!
 您阅读本篇文章共花了: