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.gz3.###解压缩
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 && makeinstall 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 1716:54 ./ drwxr-x--- 4 postgres postgres 4096 Oct 1513:42 ../ -rw-r--r-- 1 root root 1179610 Oct 1716:54 out.html -rwxr-x--- 1 postgres postgres 1443 Oct 1514:01 pgsql.log* -rw------- 1 postgres postgres 2877 Oct 1521:19 postgresql-2024-10-15_142057.log -rw------- 1 postgres postgres 16708 Oct 1623:57 postgresql-2024-10-16_000000.log -rw------- 1 postgres postgres 8273 Oct 1716: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中慢查询日志的记录和解析过程,通过对慢查询日志的记录和分析,可以为系统异常诊断提供可参考依据。

作者:MSSQL123原文地址:https://www.cnblogs.com/wy123/p/18472516

%s 个评论

要回复文章请先登录注册