数据库日志分析是我们分析数据库性能最常用的手段。PG数据库的日志都是输出到一个文件，相对于MySQL区分错误日志和慢日志文件，PG的日志文件内容输出复杂。同时PG日志相关的配置参数很多，日志输出配置也比较多样性。 今天主要给大家讲一下怎么去分析PG的日志文件。

1． PG日志相关参数说明

1.参数说明

log_destination = 'csvlog'

PostgreSQL支持多种方法来记录服务器消息，包括stderr、csvlog和syslog。设置这个参数为一个由想要的日志目的地的列表，之间用逗号分隔。默认值是只记录到stderr，

如果csvlog被包括在log_destination中，日志项会以“逗号分隔值” （CSV）格式被输出，这样可以很方便地把日志载入到程序中。要产生 CSV 格式的日志输出，必须启用logging_collector。

如果log_destination = 'stderr' 日志输出格式为

[postgres@db65 pg_log]$ cat postgresql-15.log

2022-08-15 14:20:31.130 CST [163925] LOG:  database system was shut down at 2022-08-15 14:20:30 CST

2022-08-15 14:20:31.135 CST [163923] LOG:  database system is ready to accept connections

如果log_destination = 'csv' 日志输出格式为

[postgres@db65 pg_log]$ cat postgresql-15.csv

2022-08-15 14:20:31.130 CST,,,163925,,62f9e5af.28055,1,,2022-08-15 14:20:31 CST,,0,LOG,00000,"database system was shut down at 2022-08-15 14:20:30 CST",,,,,,,,,""

2022-08-15 14:20:31.135 CST,,,163923,,62f9e5ae.28053,1,,2022-08-15 14:20:30 CST,,0,LOG,00000,"database system is ready to accept connections",,,,,,,,,""

如果log_destination = 'syslog'日志会输出的到操作系统的日志文件/var/log/message中，但是一般不推荐这样配置。

logging_collector=on

这个参数启用日志收集器，它是一个捕捉被发送到stderr的日志消息的后台进程，并且它会将这些消息重定向到日志文件中。 另外打开后要设置日志记录存放的目录。

log_directory = 'log'

当logging_collector被启用时，这个参数决定日志文件将被在哪个目录下创建。它可以被指定为一个绝对路径，也可以被指定为一个相对于集簇数据目录$PGDATA的相对路径， 默认是log。

log_filename='postgresql-%Y-%m-%d_%H%M%S.log'

重启一次就生成一个新的文件，精确到天更好 'postgresql-%Y-%m-%d.log'。'postgresql-%d.log'设置这样每个月可以复用日志文件，不会导致日志文件一直积累。

默认是postgresql-%Y-%m-%d_%H%M%S.log。支持strftime格式

%d 返回的是当前时间是当前月的第几天

%w 当天在当周的天数，范围为[0, 6]，6表示星期天

log_truncate_on_rotation = on

当logging_collector被启用时，这个参数将导致PostgreSQL截断（覆盖而不是追加）任何已有的同名日志文件。不过截断只在一个新文件由于基于时间的轮转被打开时发生，在服务器启动或基于尺寸的轮转时不会发生。

log_rotation_size = 500MB

日志切换参数。设置为按天来，该参数没有作用。默认值是10兆字节。设置为零时将禁用基于大小创建新的日志文件

log_rotation_age = 1d

当logging_collector被启用时，这个参数决定使用一个单个日志文件的最大时间量，之后将创立一个新的日志文件。 如果指定值时没有单位，则以分钟为单位。默认为24小时

log_file_mode=0600

默认的权限是0600，表示只有服务器拥有者才能读取或写入日志文件。其他常用的设置是0640，它允许拥有者的组成员读取文件。不过要注意你需要修改log_directory为将文件存储在集簇数据目录之外的某个位置，才能利用这个设置。

log_min_messages=warning

控制哪些消息级别 被写入到服务器日志。有效值是DEBUG5、DEBUG4、 DEBUG3、DEBUG2、DEBUG1、 INFO、NOTICE、WARNING、 ERROR、LOG、FATAL和 PANIC。每个级别都包括以后的所有级别。级别越靠后，被发送的消息越少。默认值是WARNING。

log_min_error_statement = error

控制哪些导致一个错误情况的 SQL语句被记录在服务器日志中，默认值是ERROR，它表示导致错误、日志消息、致命错误或恐慌错误的语句将被记录在日志中。要有效地关闭记录失败语句，将这个参数设置为PANIC。只有超级用户可以改变这个设置。

log_min_duration_statement = 5s

设置为 -1 （默认值）将停止记录语句持续时间，当 log_statement=all 和 log_min_duration_statement 同时设置时，将跟踪所有语句，忽略log_min_duration_statement 设置。

log_line_prefix= '%t [%p]: [%l-1] user=%u,db=%d,app=%a,client=%h'

默认值：%m [%p]

Stderr输出2022-08-15 17:30:21.948 CST [200988]

log_checkpoints = on

导致检查点和重启点被记录在服务器日志中。一些统计信息也被包括在日志消息中，包括写入缓冲区的数据和写它们所花的时间。

log_connections = off

导致每一次尝试对服务器的连接被记录，客户端认证的成功完成也会被记录。

log_disconnections = off

导致会话终止被记录。日志输出提供的信息类似于 log_connections，不过还外加会话的持续时间。

log_duration = off

导致每一个完成的语句的持续时间被记录。

对于使用扩展查询协议的客户端，解析、绑定和执行步骤的持续时间将被独立记录

对于苍穹中有大量连接无SQL的操作，会导致有大量的连接信息把log变得很大。

如果log_duration为on并且log_min_duration_statement为正值，所有持续时间都将被记录，但是只有超过阈值的语句才会被记录查询文本。

log_hostname = off

默认情况下，连接日志消息只显示连接主机的 IP 地址。打开这个参数将导致也记录主机名。

log_lock_waits=on    

在需要跟踪锁问题时打开选项。控制当一个会话为获得一个锁等到超过deadlock_timeout时，是否要产生一个日志消息。

log_statement='none'

控制哪些 SQL 语句被记录。有效值是 none (off)、ddl、mod和 all（所有语句）

即使使用log_statement = all设置，包含简单语法错误的语句也不会被记录。这是因为只有在完成基本语法解析并确定了语句类型之后才会发出日志消息。在扩展查询协议的情况下，在执行阶段之前（即在解析分析或规划期间）出错的语句也不会被记录。将log_min_error_statement设置为ERROR（或更低）来记录这种语句。

log_temp_files = 2GB  

控制记录临时文件名和尺寸。临时文件可以被创建用来排序、哈希和存储临时查询结果。只是控制记录日志，不控制临时文件大小。控制临时表的最大大小参数temp_file_limit

如果启用这个设置，当每一个临时文件被删除时都会产生一个日志项。 一个零值记录所有临时文件信息，而正值只记录尺寸大于或等于指定数据量的文件。默认设置为 -1，它禁用这种记录。

log_timezone='PRC'

设置在服务器日志中写入的时间戳的时区。（PRC指：People's Republic of China）

2.csvlog日志格式说明

一般情况我们的日志格式都设置为log_destination = 'csvlog'。

输出日志示例说明

2022-08-15 15:59:26.603 CST,"cosmic","prod_lianlianzby_fi",190581,"172.17.32.43:36198",62f9fcd5.2e875,1,"SELECT",2022-08-15 15:59:17 CST,28/75,0,LOG,00000,"duration: 3731.043 ms  execute <unnamed>:"

2022-08-15 15:59:26.603 CST：中国标准时间China Standard Time UT+8:00

"cosmic"：用户名

"prod_lianlianzby_fi"：数据库名

190581：进程ID

"172.17.32.43:36198"：客户端主机:端口号

62f9fcd5.2e875：会话 ID，后台进程的启动时间+PID，16进制

1：每个会话的行号

"SELECT"：命令标签

2022-08-15 15:59:17 CST：会话开始时间

28/75：虚拟事务 ID，分别是backendid和local transaction id

0：普通事务 ID

LOG：错误严重性

00000： SQLSTATE 代码

"duration: 3731.043 ms  execute <unnamed>:"  执行时间和执行的SQL命令

log_line_prefix='%t [%p]: [%l-1] user=%u,db=%d,app=%a,client=%h'

log_destination =stderr 输出

2022-08-16 13:38:41 CST [302100]: [2-1] user=cosmic,db=prod_lianlianzby_fi,app=PostgreSQL JDBC Driver,client=172.17.32.43

如果log_destination设置为csvlog格式则log_line_prefix参数忽略，输出格式还是为

2022-08-16 13:38:41.515 CST,"cosmic","prod_lianlianzby_fi",302100,"172.17.32.43:35384",62fb2cec.49c14,1,"SELECT",2022-08-16 13:36:44 CST,27/373,0,LOG,00000,"duration: 2021.528 ms  execute <unnamed>:...."

二．PG慢日志分析

1.csv文件导入数据库分析

1.1创建表

CREATE TABLE postgres_log

(

log_time timestamp(3) with time zone,

user_name text,

database_name text,

process_id integer,

connection_from text,

session_id text,

session_line_num bigint,

command_tag text,

session_start_time timestamp with time zone,

virtual_transaction_id text,

transaction_id bigint,

error_severity text,

sql_state_code text,

message text,

detail text,

hint text,

internal_query text,

internal_query_pos integer,

context text,

query text,

query_pos integer,

location text,

application_name text,

PRIMARY KEY (session_id, session_line_num)

);

在log_destination列表中包括csvlog提供了一种便捷方式将日志文件导入到一个数据库表。这个选项发出逗号分隔值（CSV）格式的日志行，包括这些列： 带毫秒的时间戳、 用户名、 数据库名、 进程 ID、 客户端主机:端口号、 会话 ID、 每个会话的行号、 命令标签、 会话开始时间、 虚拟事务 ID、 普通事务 ID、 错误严重性、 SQLSTATE 代码、 错误消息、 错误消息详情、 提示、 导致错误的内部查询（如果有）、 错误位置所在的字符计数、 错误上下文、 导致错误的用户查询（如果有且被log_min_error_statement启用）、 错误位置所在的字符计数、 在 PostgreSQL 源代码中错误的位置（如果log_error_verbosity被设置为verbose）以及应用名。

COPY postgres_log FROM '/var/postgresql/pg5438/data/pg_log/postgresql-15.csv' WITH csv;

1.3 SQL分析

--找出执行时间最长的sql

select cast(split_part(split_part(message, ':',2),'ms',1) as numeric) as duration,session_start_time,message,detail,query, * from postgres_log

where message ~'duration'

and session_start_time>'2022-08-17'

order by 1  desc

--查看同类型SQL，可以用来发现高频慢sql

select cast(split_part(split_part(message, ':',2),'ms',1) as numeric) as duration,split_part(message, '*/',2),session_start_time,message,detail,query, * from postgres_log

where message ~'duration'

and session_start_time>'2022-08-17'

order by 2  desc

--找出非SQL操作的日志

select * from postgres_log where command_tag not in ('SELECT','UPDATE','DELETE','INSERT')

2. pgbadger工具分析

2.1安装部署

下载地址

https://github.com/darold/pgbadger

安装依赖

yum -y install perl-ExtUtils-CBuilder perl-ExtUtils-MakeMaker

tar zxvf pgbadger-11.6.tar.gz

cd pgbadger-11.6

perl Makefile.PL

make && make install

默认情况下，这会将 Perl 脚本 pgbadger 复制到 /usr/local/bin/pgbadger

无网络安装依赖包的处理方式：

yum install --downloadonly --downloaddir=/root/httpd httpd

yum localinstall httpd --nogpgcheck

查看依赖安装情况

rpm -ap | grep ExtUtils

下载依赖包

yum install --downloadonly --downloaddir=/root/pgbagder_yilai perl-ExtUtils-MakeMaker

yum install --downloadonly --downloaddir=/root/pgbagder_yilai perl-ExtUtils-CBuilder

yum install --downloadonly --downloaddir=/root/pgbagder_yilai perl-JSON-XS

安装rpm包

yum localinstall perl-ExtUtils-CBuilder-0.28.2.6-299.el7_9.noarch.rpm --nogpgcheck

yum localinstall perl-ExtUtils-MakeMaker-6.68-3.el7.noarch.rpm --nogpgcheck

yum localinstall perl-JSON-XS-3.01-2.el7.x86_64.rpm –nogpgcheck

2.2使用举例

pgbadger --dump-all-queries -o all_sql.txt 但是这种只能导出sql，sql执行duration执行时间没有了

pgbadger -b "2022-06-25 10:56:11" -e "2022-06-25 10:59:11"

pgbadger -b "2022-06-25 10:56:11" -e "2022-06-25 10:59:11" -o a.txt

pgbadger -b "2022-06-25 10:56:11" -e "2022-06-25 10:59:11" t 50 -o a.txt  ##输出50个问题sql，默认是20个

#使用我的 8 个 CPU 更快地解析我的 10GB 文件

pgbadger -j 8 /pglog/postgresql-10.1-main.log

#pgBadger 可以使用自动检测 RDS 和 cloudwatch PostgreSQL 日志 rds 格式：

pgbadger -f rds -o rds\_out.html rds.log

pgbadger  -L a.txt  ##a.txt是要分析的多个文件名称列表

pgbadger postgresql-16.csv -t 50 -T "联联优品日志分析" --dump-all-queries -o 4.txt  指定网页标题

# 凌晨2点10分分析前天统计日志

10 2 * * * root /usr/local/bin/pgbadger -I -q /data/pgdata/pg_log/postgresql-`date -d "now -1 days" "+%w"`.csv -O /var/www/html/pgbadger/

2.3结果解释

生成txt文档格式分析结果

- Request per database ------------------------------------------------------

Database     Request type     Count    Duration

prod_lianlianzby_fi - 2,074 2h4m52s

select 2,074 2h4m52s

prod_lianlianzby_sys - 301 9m49s

select 301 9m49s

生成最多临时文件的查询

- Queries generating the most temporary files (N) ---------------------------

生成最大临时文件的查询

- Queries generating the largest temporary files ----------------------------

最慢的SQL

- Slowest queries ------------------------------------------------------

占用时间最多的查询

- Queries that took up the most time (N) -------------------------------

执行最多次查询

- Most frequent queries (N) --------------------------------------------

- Slowest queries (N) --------------------------------------------------

最常见的事件

- Most frequent events (N) ---------------------------------------------

1) 1 - FATAL:  the database system is starting up

--

- Date: 2022-08-16 16:24:34

Database: prod_lianlianzby_sys

2) 1 - LOG:  database system was shut down at 2022-08-16 16:24:28 CST

--

- Date: 2022-08-16 16:24:34

日志类型

- Logs per type ---------------------------------------------

Logs type       Count   Percentage

FATAL           1       0.03%

LOG             2,875   99.97%

生成html格式报告分析

overview(概述)

Global Stats

global stats 部分包含在 PostgreSQL 日志中的一些基本信息

Queries:主要是查询的数量，时间，第一次查询时间和最后一次查询时间，查询高峰时间点。

Events：事件相关信息

Vacuums：收集vacuum次数

Temporary Files：临时表文件的个数，大小和平均大小

Session：session相关的信息

Connections：连接相关的信息

注意：这里记录的是日志文件中的信息，如果参数log_min_duration_statement>0，不会记录所有的日志，所以涉及查询、查询计数或查询持续时间的结果将不准确。

SQL Traffic，SELECT Traffic，INSERT/UPDATE/DELETE Traffic，这个几个是分析日志中的QPS，TPS，但是由于日志不是全部的SQL日志，不能说明整个数据库的QPS和TPS量，参考意义不大。

Queries duration

查询时间的分布图

Prepared queries ratio

记录prepare sql 的比率，prepare sql 是sql的预处理模式。

General Activity

记录Queries，Connection和session相关时间段统计，一个小时汇总一次。

Connections(连接)

详细说明日志中找到的连接信息的图表。需要 log_connections 和 log_disconnections 参数都打开，这里的值就会准确。

Established Connections：显示一段时间内的最大、最小和平均连接数。

Connections per database：饼图和表格视图显示找到的每个数据库的连接数。

Connections per user：饼图和表格视图显示找到的每个用户的连接数。

Connections per host：饼图和表格视图显示找到的每个源主机的连接数。

Sessions(会话)

会话(Session) 是通信双方从开始通信到通信结束期间的一个上下文（Context）。这个上下文是一段位于服务器端的内存：记录了本次连接的客户端机器、通过哪个应用程序、哪个用户登录等信息连接（Connection）：连接是从客户端到ORACLE实例的一条物理路径。连接可以在网络上建立，或者在本机通过IPC机制建立。通常会在客户端进程与一个专用服务器或一个调度器之间建立连接会话(Session) 是和连接(Connection)是同时建立的，两者是对同一件事情不同层次的描述。简单讲，连接(Connection)是物理上的客户端同服务器的通信链路，会话(Session)是逻辑上的用户同服务器的通信交互。

Simultaneous sessions：显示会话数量随时间变化的折线图。

Histogram of session times：显示会话时间的条形图和表格。

Sessions per database：饼图和表格视图显示找到的每个数据库的会话数。

Sessions per user：饼图和表格视图显示找到的每个用户的会话数。

Sessions per host：饼图和表格视图显示找到的每个源主机的会话数。

Sessions per application：每个应用程序连接的会话数。

Checkpoints(检查点)

检查点页面提供有关检查点进程的信息，包括写入的缓冲区数量、WAL 文件和其他一般信息。

Checkpoints Buffers：显示检查点进程随时间写入的缓冲区数量的折线图。

Checkpoints Wal files：显示检查点随时间添加、删除或回收的 WAL 文件数量的折线图。

Checkpoints distance：显示检查点距离和估计值的折线图。

Checkpoints Activity：以表格形式显示前四个数据点的表格，按照时间1个小时统计一次。

Tempfiles(临时文件)

临时文件页面包含临时文件的信息，这些信息是在查询用完work_mem并需要使用磁盘对结果进行排序或过滤后再返回给应用程序时创建的。 这些文件在查询完成时自动删除，了解临时文件活动有助于管理员调优work_mem参数

Size of temporary files：显示临时文件随时间使用的空间的折线图。

Number of temporary files：显示随时间使用的临时文件数的折线图。

Temporary Files Activity：以表格形式显示先前图表中提供的信息的表格

Vacuums(清理)

此页面显示有关vacuum和分析数据库中发生的信息。这些信息有助于了解自动清理过程是否做得足够好，或者是否陷入困境，需要更多的资源。

Vacuums / Analyzes Distribution：显示 VACUUM 和 ANALYZE 随时间变化的折线图，以及消耗 CPU 处理能力最多的表上的信息。

Analyzes per table：饼图和表格显示分析最多的表，表明这些表处于高度变化状态。

Vacuums per table：饼图和表格显示了真空度最高的表，表明这些表处于高度变化状态。

Tuples removed per table：饼图和表格显示在表的真空过程中删除的元组和页面的数量。

Pages removed per table：饼图和表格显示在表的真空过程中删除的页数和元组数。

Autovacuum Activity：显示每小时 VACUUM 和 ANALYZE 随时间变化的表格。

Locks(锁)

锁页面只包含少量的数据，但它是有用的信息，可以了解何时有进程可能在较长的时间内阻碍其他查询

Locks by types

Most frequent waiting queries：发现正在等待的查询列表，从最频繁到最不频繁排列。

Queries that waited the most：查询列表以及它们等待的时间，按从最长到最短的顺序排列

Queries(查询)

查询页面显示了来自应用程序和用户的查询类型的信息。 这些信息有助于更多地了解应用程序或用户对数据库系统的影响，这有助于将来的调优。 与前面一样，这些数字的准确性取决于log_min_duration_statement的值，因为任何高于0的值都不会记录查询。

Queries by type：饼图和表格显示不同类型查询的数量，例如 INSERT、UPDATE、DELETE、SELECT 等。

Queries by database：饼图和表格显示每个数据库找到的查询数量。

Queries by application：饼图和表格显示每个应用程序找到的查询数量。

Number of cancelled queries：有关已取消的任何查询的信息。

Top(头部)

top页面有查询时间、整体最慢查询、查询频率等信息。 在这里可能会发现特定的问题查询:

Histogram of query times：表示有多少查询属于每个时序分组的直方图。

Slowest individual queries：找到的最慢查询的列表，按最长到最短排序。【最慢的SQL】

Time consuming queries：规范化查询及其总持续时间的列表，按消耗时间最长到最少排序。【总的消耗时间最长】

Most frequent queries：规范化查询的列表以及它们被执行的次数，从多到少排序。【执行次数】

Normalized slowest queries：规范化查询及其平均持续时间的列表，按最长到最短排序【按照平均时间】

Event(事件)

事件页面，包含关于日志本身的信息，以及任何非查询、vacuum或检查点的信息

Log levels：按行出现的不同级别的日志，如CONTEXT、LOG、STATEMENT、HINTs、WARNINGs等。

Events distribution：PANIC、FATAL、ERROR 和 WARNING 事件随时间变化的折线图。

Most Frequent Errors/Events：事件及其频率的列表，从最常见到最少排序。

Pgbadger日志分析工具功能很强大，推荐使用这个工具分析慢日志。

3.shell命令分析

1.cat postgresql-2021-03-29_142024.log | perl -e 'while(<>){ if($_ !~ /^\t/ig) { chomp; print "\n",$_;} else {chomp; print;}}' | grep ' 6061856f.1621 ' | grep '3/516'

[postgres mydb psql [local] 2021-03-29 15:51:48.958 CST 5665 6061856f.1621 7 3/516 0]LOG: duration: 0.061 ms statement: begin;

[postgres mydb psql [local] 2021-03-29 15:52:09.311 CST 5665 6061856f.1621 8 3/516 954]LOG: duration: 1.646 ms statement: update test set id = 0 where id =1;

[postgres mydb psql [local] 2021-03-29 15:52:12.030 CST 5665 6061856f.1621 9 3/516 954]LOG: duration: 0.181 ms statement: select txid_current_if_assigned();

[postgres mydb psql [local] 2021-03-29 15:53:01.613 CST 5665 6061856f.1621 10 3/516 954]LOG: duration: 0.213 ms statement: select id from test;

使用perl读写文件速度更快，最终也是通过grep过滤

2.cat  postgresql-23.csv|grep duration|awk -F'duration:' '{print $2}' | awk -F'ms' '{print $1}' | sort -rn | head -n 50  >>  time23.txt

提取时间