PostgreSQL日志中的SQL记录时机 —— log_statement 和 log_min_duration_statement

2023-11-29 02:12
文章标签 sql 日志 记录 postgresql statement 时机 log database min duration

本文主要是介绍PostgreSQL日志中的SQL记录时机 —— log_statement 和 log_min_duration_statement，希望对大家解决编程问题提供一定的参考价值，需要的开发者们随着小编来一起学习吧！

       最近跟朋友讨论到PostgreSQL日志中的SQL记录时机，研究了下log_statement 和 log_min_duration_statement两个参数，记录一下。

一、 参数简介

1. log_statement

① 作用

控制记录SQL的类型，可选值为：

  • none：关闭（默认）
  • ddl：DDL语句
  • mod：DDL和所有涉及数据修改的语句（DML、COPY FROM、PREPARE、EXECUTE等）。对于explain和explain analyze，如果后面的语句类型符合，也会被记录
  • all：所有语句

② 记录时机

       SQL语句解析成功后，执行前。因此即使设置为all，也不会记录有语法错误的语句（如果想记录，应该使用log_min_error_statement参数）。

③ 记录内容

       记录SQL语句，包含参数，但不包含执行用户、主机名等信息，这些需要审计插件才有。

2. log_min_duration_statement

① 作用

记录超过指定执行时间阈值的SQL，可选值为：

  • -1：关闭（默认）
  • 0：所有语句
  • 正数：慢SQL阈值

② 记录时机

       SQL语句执行完成后，因此能记录到执行时间。

③ 记录内容

  • 记录SQL语句、执行时间，但不包含参数。
  • 对于使用扩展查询协议的客户端，对语法分析、绑定、执行每一步所花时间会独立记录。

3. 同时符合两者的SQL会如何？

  • 语句在解析完成后、执行开始前，即被记入日志（log_statement生效）
  • 语句执行完成后，单独将duration记入日志（log_min_duration_statement生效），但不再重复记录语句
  • 因此建议使用log_line_prefix记录PID或会话ID，避免duration和语句关联不上

二、 效果测试

1. 两者均设置

log_statement='all',log_min_duration_statement='0s'

2023-11-28 17:51:45.222 CST [2484] LOG:  statement: select pg_sleep(10);
2023-11-28 17:51:55.227 CST [2484] LOG:  duration: 10005.249 ms

       语句记录为开始时间（log_statement生效），duration在执行完成时单独记录（log_min_duration_statement生效），但不再重复记录语句。

2. 仅设置log_statement

log_statement='all',log_min_duration_statement='-1'（禁用）

2023-11-28 17:53:49.540 CST [2760] LOG:  statement: select pg_sleep(10);

仅记录语句，记录时间为开始时间，没有duration

3. 仅设置log_min_duration_statement

log_statement='none'（禁用）,log_min_duration_statement='0s'

2023-11-28 17:55:20.288 CST [2826] LOG:  duration: 15015.447 ms  statement: select pg_sleep(15);

记录语句和duration，记录时间为结束时间

三、 参数记录时机

         从上面文档可以知道，两个参数记录时机都在SQL执行阶段，只是一个在前一个在后。源码中SQL执行相关的函数主要是exec_simple_query，因此我们就看看这个函数。

         函数刚开头就可以看到 pg_parse_query 和 check_log_statement函数。

/** exec_simple_query** Execute a "simple Query" protocol message.*/
static void
exec_simple_query(const char *query_string)
{CommandDest dest = whereToSendOutput;MemoryContext oldcontext;List	   *parsetree_list;ListCell   *parsetree_item;bool		save_log_statement_stats = log_statement_stats;bool		was_logged = false;bool		use_implicit_block;char		msec_str[32];
.../** Do basic parsing of the query or queries (this should be safe even if* we are in aborted transaction state!)*/parsetree_list = pg_parse_query(query_string);/* Log immediately if dictated by log_statement */if (check_log_statement(parsetree_list)){ereport(LOG,(errmsg("statement: %s", query_string),errhidestmt(true),errdetail_execute(parsetree_list)));was_logged = true;}
  • pg_parse_query函数用于SQL解析，符合log_statement记录的语句发生在解析完成后
  • check_log_statement函数就用于检查log_statement的设置，标记是否需要记录
  • was_logged=true表示已记录SQL语句，主要是给后面的慢SQL记录函数，提示其不需重复记录SQL文本
/** check_log_statement*		Determine whether command should be logged because of log_statement** stmt_list can be either raw grammar output or a list of planned* statements*/
static bool
check_log_statement(List *stmt_list)
{ListCell   *stmt_item;if (log_statement == LOGSTMT_NONE)return false;if (log_statement == LOGSTMT_ALL)return true;/* Else we have to inspect the statement(s) to see whether to log */foreach(stmt_item, stmt_list){Node	   *stmt = (Node *) lfirst(stmt_item);if (GetCommandLogLevel(stmt) <= log_statement)return true;}return false;
}

       

       后面一大堆是SQL执行相关的代码，非本次重点，直接拉到函数末尾，可以看到check_log_duration函数，看名字都能猜到是它了，也符合在SQL执行完才记录。

.../** Emit duration logging if appropriate.*/switch (check_log_duration(msec_str, was_logged)){case 1:ereport(LOG,(errmsg("duration: %s ms", msec_str),errhidestmt(true)));break;case 2:ereport(LOG,(errmsg("duration: %s ms  statement: %s",msec_str, query_string),errhidestmt(true),errdetail_execute(parsetree_list)));break;}if (save_log_statement_stats)ShowUsage("QUERY STATISTICS");TRACE_POSTGRESQL_QUERY_DONE(query_string);debug_query_string = NULL;
}

check_log_duration函数

         可以看到注释中给出了上面case 1,2的含义：

  • 1：仅记录duration，即前面提到的两个参数均生效的场景
  • 2：记录duration和语句：即前面提到的仅log_min_duration_statement生效的场景

另外是否记录慢sql与 log_duration、log_min_duration_sample 这些参数也有关。

/** check_log_duration*		Determine whether current command's duration should be logged*		We also check if this statement in this transaction must be logged*		(regardless of its duration).** Returns:*		0 if no logging is needed*		1 if just the duration should be logged*		2 if duration and query details should be logged** If logging is needed, the duration in msec is formatted into msec_str[],* which must be a 32-byte buffer.** was_logged should be true if caller already logged query details (this* essentially prevents 2 from being returned).*/
int
check_log_duration(char *msec_str, bool was_logged)
{if (log_duration || log_min_duration_sample >= 0 ||log_min_duration_statement >= 0 || xact_is_sampled){long		secs;int			usecs;int			msecs;bool		exceeded_duration;bool		exceeded_sample_duration;bool		in_sample = false;TimestampDifference(GetCurrentStatementStartTimestamp(),GetCurrentTimestamp(),&secs, &usecs);msecs = usecs / 1000;/** This odd-looking test for log_min_duration_* being exceeded is* designed to avoid integer overflow with very long durations: don't* compute secs * 1000 until we've verified it will fit in int.*/exceeded_duration = (log_min_duration_statement == 0 ||(log_min_duration_statement > 0 &&(secs > log_min_duration_statement / 1000 ||secs * 1000 + msecs >= log_min_duration_statement)));exceeded_sample_duration = (log_min_duration_sample == 0 ||(log_min_duration_sample > 0 &&(secs > log_min_duration_sample / 1000 ||secs * 1000 + msecs >= log_min_duration_sample)));/** Do not log if log_statement_sample_rate = 0. Log a sample if* log_statement_sample_rate <= 1 and avoid unnecessary random() call* if log_statement_sample_rate = 1.*/if (exceeded_sample_duration)in_sample = log_statement_sample_rate != 0 &&(log_statement_sample_rate == 1 ||random() <= log_statement_sample_rate * MAX_RANDOM_VALUE);if (exceeded_duration || in_sample || log_duration || xact_is_sampled){snprintf(msec_str, 32, "%ld.%03d",secs * 1000 + msecs, usecs % 1000);if ((exceeded_duration || in_sample || xact_is_sampled) && !was_logged)return 2;elsereturn 1;}}return 0;
}

参考：

https://www.postgresql.org/docs/current/runtime-config-logging.html#GUC-LOG-STATEMENT
https://www.postgresql.org/docs/current/protocol-flow.html#PROTOCOL-FLOW-EXT-QUERY
https://blog.csdn.net/qq_35423190/article/details/129138740
https://iwmj.wordpress.com/2018/04/03/postgresql-%E5%89%8D%E5%90%8E%E7%AB%AF%E5%8D%8F%E8%AE%AE%E4%B8%AD%E7%9A%84%E6%9F%A5%E8%AF%A2%E6%96%B9%E5%BC%8F%EF%BC%9A%E7%AE%80%E5%8D%95%E6%9F%A5%E8%AF%A2%E3%80%81%E6%89%A9%E5%B1%95%E6%9F%A5%E8%AF%A2/

这篇关于PostgreSQL日志中的SQL记录时机 —— log_statement 和 log_min_duration_statement的文章就介绍到这儿，希望我们推荐的文章对编程师们有所帮助！


http://www.chinasem.cn/article/431078。

相关文章

SQL中的外键约束

SQL中的外键约束

外键约束用于表示两张表中的指标连接关系。外键约束的作用主要有以下三点： 1.确保子表中的某个字段（外键）只能引用父表中的有效记录2.主表中的列被删除时，子表中的关联列也会被删除3.主表中的列更新时，子表中的关联元素也会被更新 子表中的元素指向主表 以下是一个外键约束的实例展示
阅读更多...
基于MySQL Binlog的Elasticsearch数据同步实践

基于MySQL Binlog的Elasticsearch数据同步实践

一、为什么要做 随着马蜂窝的逐渐发展，我们的业务数据越来越多，单纯使用 MySQL 已经不能满足我们的数据查询需求，例如对于商品、订单等数据的多维度检索。 使用 Elasticsearch 存储业务数据可以很好的解决我们业务中的搜索需求。而数据进行异构存储后，随之而来的就是数据同步的问题。 二、现有方法及问题 对于数据同步，我们目前的解决方案是建立数据中间表。把需要检索的业务数据，统一放到一张M
阅读更多...
如何去写一手好SQL

如何去写一手好SQL

MySQL性能 最大数据量 抛开数据量和并发数，谈性能都是耍流氓。MySQL没有限制单表最大记录数，它取决于操作系统对文件大小的限制。 《阿里巴巴Java开发手册》提出单表行数超过500万行或者单表容量超过2GB，才推荐分库分表。性能由综合因素决定，抛开业务复杂度，影响程度依次是硬件配置、MySQL配置、数据表设计、索引优化。500万这个值仅供参考，并非铁律。 博主曾经操作过超过4亿行数据
阅读更多...
性能分析之MySQL索引实战案例

性能分析之MySQL索引实战案例

文章目录 一、前言二、准备三、MySQL索引优化四、MySQL 索引知识回顾五、总结 一、前言 在上一讲性能工具之 JProfiler 简单登录案例分析实战中已经发现SQL没有建立索引问题，本文将一起从代码层去分析为什么没有建立索引？ 开源ERP项目地址：https://gitee.com/jishenghua/JSH_ERP 二、准备 打开IDEA找到登录请求资源路径位置
阅读更多...
MySQL数据库宕机，启动不起来，教你一招搞定！

MySQL数据库宕机，启动不起来，教你一招搞定！

作者介绍：老苏，10余年DBA工作运维经验，擅长Oracle、MySQL、PG、Mongodb数据库运维（如安装迁移，性能优化、故障应急处理等）公众号：老苏畅谈运维欢迎关注本人公众号，更多精彩与您分享。 MySQL数据库宕机，数据页损坏问题，启动不起来，该如何排查和解决，本文将为你说明具体的排查过程。 查看MySQL error日志 查看 MySQL error日志，排查哪个表（表空间
阅读更多...
内核启动时减少log的方式

内核启动时减少log的方式

内核引导选项 内核引导选项大体上可以分为两类：一类与设备无关、另一类与设备有关。与设备有关的引导选项多如牛毛，需要你自己阅读内核中的相应驱动程序源码以获取其能够接受的引导选项。比如，如果你想知道可以向 AHA1542 SCSI 驱动程序传递哪些引导选项，那么就查看 drivers/scsi/aha1542.c 文件，一般在前面 100 行注释里就可以找到所接受的引导选项说明。大多数选项是通过"_
阅读更多...
MySQL高性能优化规范

MySQL高性能优化规范

前言：      笔者最近上班途中突然想丰富下自己的数据库优化技能。于是在查阅了多篇文章后，总结出了这篇！ 数据库命令规范 所有数据库对象名称必须使用小写字母并用下划线分割 所有数据库对象名称禁止使用mysql保留关键字（如果表名中包含关键字查询时，需要将其用单引号括起来） 数据库对象的命名要能做到见名识意，并且最后不要超过32个字符 临时库表必须以tmp_为前缀并以日期为后缀，备份
阅读更多...
[MySQL表的增删改查-进阶]

[MySQL表的增删改查-进阶]

🌈个人主页：努力学编程’ ⛅个人推荐： c语言从初阶到进阶 JavaEE详解 数据结构 ⚡学好数据结构，刷题刻不容缓：点击一起刷题 🌙心灵鸡汤：总有人要赢，为什么不能是我呢 💻💻💻数据库约束 🔭🔭🔭约束类型 not null: 指示某列不能存储 NULL 值unique: 保证某列的每行必须有唯一的值default: 规定没有给列赋值时的默认值.primary key:
阅读更多...
MySQL-CRUD入门1

MySQL-CRUD入门1

文章目录 认识配置文件client节点mysql节点mysqld节点 数据的添加(Create)添加一行数据添加多行数据两种添加数据的效率对比 数据的查询(Retrieve)全列查询指定列查询查询中带有表达式关于字面量关于as重命名 临时表引入distinct去重order by 排序关于NULL 认识配置文件 在我们的MySQL服务安装好了之后, 会有一个配置文件, 也就
阅读更多...
Node.js学习记录（二）

Node.js学习记录（二）

目录 一、express 1、初识express 2、安装express 3、创建并启动web服务器 4、监听 GET&POST 请求、响应内容给客户端 5、获取URL中携带的查询参数 6、获取URL中动态参数 7、静态资源托管 二、工具nodemon 三、express路由 1、express中路由 2、路由的匹配 3、路由模块化 4、路由模块添加前缀 四、中间件
阅读更多...

Copyright China编程 23002807@qq.com

沪ICP备2023033072号-2