PostgreSQL如何查找某一事务中的完整SQL

1. 问题的提出

DBA 经常需要排查某一个事务中有哪些 SQL 的场景。典型的 case 就是 DB 有一个 lock 报警，从系统表中查看发现是1个 update 等待的 SQL 是1个 select。熟悉 PostgreSQL 的同学都知道：在 PostgreSQL 中，由于特有的 MVCC 机制，读不阻塞写，写不堵塞读。

那么为什么会产生这种 lock？

实际就是因为这个 select 处于一个事务中，事务中有其他 update/delete 等写入操作持有后面的其他事务中的 update 操作所需要的 lock。此时就需要到 DB log 去排查这个 select 所处的事务的完整的全部 SQL，反馈给业务线的开发同学，以便于进一步优化。

2. Log 相关参数

既然需要研究 DB log，先看看 log 的相关参数配置。

PostgreSQL 的 log 相关配置参数如下：

可见，PostgreSQL 的 log 相关配置参数非常丰富，本文限于篇幅不做展开讨论。

本文重点讨论几个生产中常用的参数 logging_collector , log_min_duration_statement, log_statement, log_duration, log_line_prefix

2.1 logging_collector

设置为 on 才可记录 log 至文件，对此参数的更改需要重启生效。

2.2 log_min_duration_statement

可取值及含义如下：

取值	含义
-1	关闭
0	记录所有的语句及其运行时间
>0	仅记录超过此阈值的语句

2.3 log_statement

可选值有 none, ddl, mod, all。这个参数在 log_min_duration_statement >0 时决定记录到哪个级别的语句，在 log_min_duration_statement =0 时，不会影响是否记录全量 log。

2.4 log_duration

是否记录每个执行完成语句的时间。可取值为 on 或 off。

2.5 log_line_prefix

log_line_prefix 是一个 printf 风格的字符串，在日志的每行开头输出。其中各逃逸参数含义如下：

会话 ID 是每个会话的唯一标识符。它是两个 4 字节的十六进制数字(没有前导零)，用句点分开。数值是会话开始时间和进程 ID ，因此也可以用做一种打印这些项目的节约空间的方法。

例如，想要从表 pgstatactivity 中生成一个会话的标识符，使用下面的查询语句：

SELECT to_hex(trunc(EXTRACT(EPOCH FROM backend_start))::integer) || '.' ||
       to_hex(pid)
FROM pg_stat_activity;

记录的 log 是按照时间戳的前后进行的，一个事务里有很多操作语句，这样当多个并发事务并发执行，哪个statement 是哪个 pid/session 的，是哪个 virtual transaction 的，是哪个 transaction 的，如果不记录这些信息，我们就无从查起。

所以彻查某个问题需要详细查日志的时候，log_line_prefix 必须配置足够的参数。

定位事务中的 SQL，需要重点关注的是 %p %c %l %v %x。

3. log 配置 case

log_min_duration_statement，log_statement，log_duration 之间会相互影响。

由于篇幅所限，本文仅列举2个生产用常用的 case 看一下 DB log 的记录示例。

3.1 case 1 记录全量 log 模式

全量 log 模式 一般在需要调查问题的时候开启。

注意：全量 log 模式不仅有一种配置方式，现只列举其一。

参数配置如下：

postgres@localhost ~$ psql mydb
psql (12.3)
Type "help" for help.

mydb=# show logging_collector ;
 logging_collector
-------------------
 on
(1 row)

mydb=# show log_min_duration_statement ;
 log_min_duration_statement
----------------------------
 0
(1 row)

mydb=#  show log_statement;
 log_statement
---------------
 none
(1 row)

postgres=# show log_duration ;
 log_duration
--------------
 off
(1 row)

mydb=# show log_line_prefix ;
         log_line_prefix        
---------------------------------
 [%u %d %a %h %m %p %c %l %v %x]
(1 row)

SQL 执行情况

postgres@localhost ~$ psql mydb
psql (12.3)
Type "help" for help.

mydb=# select pg_backend_pid();
 pg_backend_pid
----------------
           7106
(1 row)

mydb=# begin;
BEGIN
mydb=# select 1;
 ?column?
----------
        1
(1 row)

mydb=# create table if not exists test(id int);
NOTICE:  relation "test" already exists, skipping
CREATE TABLE
mydb=# truncate table test;
TRUNCATE TABLE
mydb=# commit;
COMMIT
mydb=#
mydb=# begin;
BEGIN
mydb=# select * from test;
 id
----
(0 rows)

mydb=# insert into test select 1;
INSERT 0 1
mydb=# insert into test select 2;
INSERT 0 1
mydb=# select * from test;
 id
----
  1
  2
(2 rows)

mydb=# commit;
COMMIT
mydb=#
mydb=# begin;
BEGIN
mydb=# select 1;
 ?column?
----------
        1
(1 row)

mydb=# select * from test;
 id
----
  1
  2
(2 rows)

mydb=# update test set id = -1 where id =0;
UPDATE 0
mydb=# update test set id = -2 where id =1;
UPDATE 1
mydb=# select * from test;
 id
----
  2
 -2
(2 rows)

my