PostgreSQL慢查询SQL收集和解析
postgresql通过log_statement参数记录慢SQL语句
PostgreSQL可以不借助任何扩展实现对SQL日志的记录，主要依赖于两个参数，也即log_statement和log_min_duration_statement，
1，记录的sql类型
log_statement='all' 可以是none, ddl, mod, all
2，记录的sql执行时间阈值
log_min_duration_statement='1000'，单位毫秒，记录超出该单位时间的log_statement中定义类型的SQL
以上两个参数规定了记录超出log_min_duration_statement时间的log_statement类型的SQL语句到日志文件中
3，PostgreSQL日志行前缀的格式，
log_line_prefix = '%m [%p] ' # special values:
# %a = application name
# %u = user name
# %d = database name
# %r = remote host and port
# %h = remote host
# %b = backend type
# %p = process ID
# %P = process ID of parallel group leader
# %t = timestamp without milliseconds
# %m = timestamp with milliseconds
# %n = timestamp with milliseconds (as a Unix epoch)
# %Q = query ID (0 if none or not computed)
# %i = command tag
# %e = SQL state
# %c = session ID
# %l = session line number
# %s = session start timestamp
# %v = virtual transaction ID
# %x = transaction ID (0 if none)
# %q = stop here in non-session
# processes
# %% = '%'
# e.g. '<%u%%%d> '
需要注意的是，PostgreSQL慢日志信息是一个过程，有多行文本组成，每个步骤在日志里都是一行文本信息，大概步骤如下，
step 1，执行开始前，即被记入日志（log_statement生效）
step 2，语句执行的过程中，会涉及变量的parser，rewrite，绑定变量解析等等已发个或者多个步骤（生成多行文本）
step 3，语句执行完成后，将duration记入日志
由于以上过程存在并发Session交叉写入的情况，因此要考虑如何解析（记录足够详细的log_line_prefix ）。由于慢日志都以文本的方式分行存储，以上日志会存在交叉存储的场景，也即session1和Session2会并行地往log里写入日志信息，从而导致两者的日志交叉写入，类似于如下这样，真正写代码做过解析的都知道（如果不记录SessionID）这个难点。
session1 begin
session2 begin
session1 execute
session3 begin
session2 execute
session2 end
session1 end
session3 end
:param file_name:
:return
因此为了方便解析，需要记录尽可能详细的一些信息，比如远程主机名，session ID等信息，可以判断判断那些信息是某个客户端的某个session发起的。
通过auto_explain扩展记录慢查询日志
尽管可以通过log_statement记录到所谓的慢查询日志，但auto_explain可以记录慢查询的SQL语句以及执行计划信息，为了异常的诊断提供了更多的参考依据。
auto_explain 并没有 .sql 、.control 文件，所以是无法通过 create extension 来完成。需要通过设置 shared_preload_librariess 参数预先加载auto_explain到某些或者所有会话中。
###查看已加载的扩展
如果setting字段是否有auto_explain
select name, setting, pending_restart FROM pg_settings WHERE name = 'shared_preload_libraries';
###临时加载
###session级打开auto_plain，需要超级用户权限
load 'auto_explain';
###设置SQL记录执行计划的时间阈值
set auto_explain.log_min_duration = '200000'
set auto_explain.log_analyze = true;
当然如果是动态加载auto_explain，退出当前sql session则auto_explain失效。
###全局加载
##编辑配置文件$ vi postgresql.conf
shared_preload_libraries = 'auto_explain' # (change requires restart)，shared_preload_libraries 的修改需要重启数据库
##配置项 #------------------------------------------------------------------------------ # CUSTOMIZED OPTIONS #------------------------------------------------------------------------------ # Add settings for extensions here # auto_explain auto_explain.log_min_duration = '100' auto_explain.log_timing = on auto_explain.log_verbose = on
###如何取消auto_explain
根据上面配置，做反向操作，也即取消shared_preload_libraries中的auto_explain配置，取消auto_explain相关配置项，同样需要重启
###auto_explain相关的参数
auto_explain相关参数 auto_explain.log_min_duration log_min_duration是导致记录语句执行计划的最小的执行时间(以毫秒为单位)。如果设置为0，会记录所有的执行计划。默认值是-1，即不记录。比如，如果设置为250ms，即记录运行时间超过250ms的语句的执行计划(包含250ms) auto_explain.log_analyze 布尔类型的值。如果设置为true，在记录的执行计划的时候，输出的内容是explain analyze的结果，而不是explain的结果。默认值是off。开启后对性会有影响， auto_explain.log_buffers 布尔类型的值。控制是否统计在执行计划中，对buffer的使用统计信息。等价于explain buffers。默认是off的。该选项只有在开启了auto_explain.log_analyze后才有效。 auto_explain.log_timing 布尔类型的值。控制执行计划中是否统计每个节点的时间信息。等价于explain timing。在有些系统中，重复地读取系统锁信息会降低查询性能。一般不建议开启。要想生效，必须先开启auto_explain.log_analyze。默认设置是on。 auto_explain.log_triggers 布尔类型的值。在记录执行计划时包含触发器执行统计信息。这个参数没有作用，除非auto_explain.log_analyze被启用。该参数默认关闭。只有超级用户才能更改此设置。 auto_explain.log_verbose 布尔类型的值。控制在记录执行计划时是否打印详细信息;它相当于冗长的EXPLAIN VERBOSE选项。该参数默认关闭。只有超级用户才能更改此设置。 auto_explain.log_format 枚举类型。定义explain的输出格式。支持的格式有：text、xml、json、yaml。默认是text。 auto_explain.log_nested_statements 布尔类型的值。考虑对嵌套语句(在函数中执行的语句)进行日志记录。当它关闭时，只记录顶级查询计划。该参数默认关闭。只有超级用户才能更改此设置。 auto_explain.sample_rate real类型的值。只解释每个会话中的一小部分语句。默认值是1，表示解释所有查询。在嵌套语句的情况下，要么全部解释，要么全部不解释。只有超级用户才能更改此设置。
pgbadger解析慢日志
通过以上两种方式，可以将PostgreSQL中会将慢日志写入PostgreSQL log文件中，但是PostgreSQL日志中也包含系统日志等一系列信息，因此解析PostgreSQL日志并不是一个太容易的工作。
这里采用pgBDger这个工具来实现日志的解析，pgbadger的安装和使用都非常简单，更多详情参考 https://github.com/darold/pgbadger
1.###自行安装相关依赖包 ...... 2.###下载最新版的pgbadger wget https://github.com/darold/pgbadger/archive/refs/tags/v12.4.tar.gz 3.###解压缩 tar -xzvf v12.4.tar.gz 4.###Makefile PL创建Makefile文件 cd pgbadger-12.4 /pgbadger-12.4# perl Makefile.PL Checking if your kit is complete... Looks good Generating a Unix-style Makefile Writing Makefile for pgBadger Writing MYMETA.yml and MYMETA.json 5.###编译安装 /pgbadger-12.4# perl Makefile.PL Checking if your kit is complete... Looks good Generating a Unix-style Makefile Writing Makefile for pgBadger Writing MYMETA.yml and MYMETA.json
/pgbadger-12.4# make && make install Makefile:899: You must install pod2markdown to generate README.md from doc/pgBadger.pod cp pgbadger blib/script/pgbadger "/usr/bin/perl" -MExtUtils::MY -e 'MY->fixin(shift)' -- blib/script/pgbadger echo "=head1 SYNOPSIS" > doc/synopsis.pod ./pgbadger --help >> doc/synopsis.pod echo "=head1 DESCRIPTION" >> doc/synopsis.pod sed -i.bak 's/ +$//g' doc/synopsis.pod rm doc/synopsis.pod.bak sed -i.bak '/^=head1 SYNOPSIS/,/^=head1 DESCRIPTION/d' doc/pgBadger.pod sed -i.bak '4r doc/synopsis.pod' doc/pgBadger.pod rm doc/pgBadger.pod.bak Manifying 1 pod document rm doc/synopsis.pod Makefile:899: You must install pod2markdown to generate README.md from doc/pgBadger.pod echo "=head1 SYNOPSIS" > doc/synopsis.pod ./pgbadger --help >> doc/synopsis.pod echo "=head1 DESCRIPTION" >> doc/synopsis.pod sed -i.bak 's/ +$//g' doc/synopsis.pod rm doc/synopsis.pod.bak sed -i.bak '/^=head1 SYNOPSIS/,/^=head1 DESCRIPTION/d' doc/pgBadger.pod sed -i.bak '4r doc/synopsis.pod' doc/pgBadger.pod rm doc/pgBadger.pod.bak Manifying 1 pod document Installing /usr/local/man/man1/pgbadger.1p Installing /usr/local/bin/pgbadger Appending installation info to /usr/local/lib/x86_64-linux-gnu/perl/5.34.0/perllocal.pod rm doc/synopsis.pod
6.###默认安装路径 /pgbadger-12.4# whereis pgbadger pgbadger: /usr/local/bin/pgbadger
7.###切换到PostgreSQL日志目录 /local/pgsql16/pg9000/log# ll total 1204 drwxr-x--- 2 postgres postgres 4096 Oct 17 16:54 ./ drwxr-x--- 4 postgres postgres 4096 Oct 15 13:42 ../ -rw-r--r-- 1 root root 1179610 Oct 17 16:54 out.html -rwxr-x--- 1 postgres postgres 1443 Oct 15 14:01 pgsql.log* -rw------- 1 postgres postgres 2877 Oct 15 21:19 postgresql-2024-10-15_142057.log -rw------- 1 postgres postgres 16708 Oct 16 23:57 postgresql-2024-10-16_000000.log -rw------- 1 postgres postgres 8273 Oct 17 16:02 postgresql-2024-10-17_000000.log 8.###运行pgbadger，后面可以跟一个或者多个PostgreSQL日志文件 /local/pgsql16/pg9000/log# pgbadger postgresql-2024-10-15_142057.log postgresql-2024-10-16_000000.log postgresql-2024-10-17_000000.log [========================>] Parsed 27858 bytes of 27858 (100.00%), queries: 0, events: 69 LOG: Ok, generating html report...
9.###会将日志报告out.html生成在当前目录下
可以看到pgbadger解析出来的日志报告非常详细，这里是auto_explain捕获到的慢查询的结果，包含了执行计划信息
这个是错误日志，包括SQL错误信息（解析失败，执行失败等等等等）
pgbadger解析出来的日志有多种维护的汇总和呈现，不限于以上两种截图中的内容，可以为日志分析提供给多个维度的参考。
以上简要总结了PostgreSQL中慢查询日志的记录和解析过程，通过对慢查询日志的记录和分析，可以为系统异常诊断提供可参考依据。
