AI 助理
备案控制台
开发者社区 数据库 文章 正文

auto_explain扩展分析

2023-11-14 310
版权
版权声明：
本文内容由阿里云实名注册用户自发贡献，版权归原作者所有，阿里云开发者社区不拥有其著作权，亦不承担相应法律责任。具体规则请查看《 阿里云开发者社区用户服务协议》和 《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容，填写 侵权投诉表单进行举报，一经查实，本社区将立刻删除涉嫌侵权内容。
本文涉及的产品
日志服务 SLS，月写入数据量 50GB 1个月
简介： PostgreSQL官方提供的扩展auto_explain扩展可以将查询的执行计划记录到日志中，本文分析其实现原理。

PostgreSQL官方提供的扩展auto_explain扩展可以将查询的执行计划记录到日志中，便于查看、分析慢查询，找出瓶颈并优化。用到了executor模块、explain模块和guc（Grand Unified Configuration）模块。

一、实现原理

backend的executor模块提供了几个钩子可用于获取执行计划：

/* Hook for plugins to get control in ExecutorStart() */typedefvoid (*ExecutorStart_hook_type) (QueryDesc*queryDesc, inteflags);
externPGDLLIMPORTExecutorStart_hook_typeExecutorStart_hook;
/* Hook for plugins to get control in ExecutorRun() */typedefvoid (*ExecutorRun_hook_type) (QueryDesc*queryDesc,
ScanDirectiondirection,
uint64count,
boolexecute_once);
externPGDLLIMPORTExecutorRun_hook_typeExecutorRun_hook;
/* Hook for plugins to get control in ExecutorFinish() */typedefvoid (*ExecutorFinish_hook_type) (QueryDesc*queryDesc);
externPGDLLIMPORTExecutorFinish_hook_typeExecutorFinish_hook;
/* Hook for plugins to get control in ExecutorEnd() */typedefvoid (*ExecutorEnd_hook_type) (QueryDesc*queryDesc);
externPGDLLIMPORTExecutorEnd_hook_typeExecutorEnd_hook;
/* Hook for plugins to get control in ExecCheckRTPerms() */typedefbool (*ExecutorCheckPerms_hook_type) (List*, bool);
externPGDLLIMPORTExecutorCheckPerms_hook_typeExecutorCheckPerms_hook;

auto_explain hook了ExecutorStart_hook、ExecutorRun_hook、ExecutorFinish_hook、ExecutorEnd_hook 这四个钩子。

ExecutorStart_hook

每个顶层语句开始时，根据配置参数决定是否记录执行计划，并根据配置设置相关的参数。

ExecutorRun_hook

执行器运行时的hook，对于auto_explain，仅需要跟踪嵌套的层数。

ExecutorFinish_hook

执行器完成，对于auto_explain，也仅需要跟踪嵌套的层数。

ExecutorEnd_hook

执行器结束，在这里根据配置记录执行计划到日志中。

二、模块拆解

2.1 配置

auto_explain有如下配置选项：

auto_explain.log_min_duration - 最小执行时间，超过这个时间的查询才会记录，为0则记录所有的语句，-1则关闭，缺省-1
auto_explain.log_analyze - 为记录执行计划使用EXPLAIN ANALYZE，缺省为false
auto_explain.log_settings - 记录影响查询规划的已修改配置参数，缺省false
auto_explain.log_verbose - 为记录执行计划使用EXPLAIN VERBOSE，缺省false
auto_explain.log_buffers - 记录buffer使用情况，缺省false
auto_explain.log_wal - 记录wal使用，缺省false
auto_explain.log_triggers - 包含执行计划中的触发器统计，缺省false
auto_explain.log_format - 日志格式，缺省TEXT
auto_explain.log_level - 日志级别，缺省LOG
auto_explain.log_nested_statements - 是否记录嵌套语句，缺省false
auto_explain.log_timing - 是否记录时间指标，缺省false
auto_explain.sample_rate - 要处理的查询分值，大于此值才记录，缺省1.0

_PG_init函数加载配置并hook相应的钩子。

#include "postgres.h"#include <limits.h>#include "access/parallel.h"#include "commands/explain.h"#include "common/pg_prng.h"#include "executor/instrument.h"#include "jit/jit.h"#include "utils/guc.h"PG_MODULE_MAGIC;
/* GUC variables */staticintauto_explain_log_min_duration=-1; /* msec or -1 */staticboolauto_explain_log_analyze=false;
staticboolauto_explain_log_verbose=false;
staticboolauto_explain_log_buffers=false;
staticboolauto_explain_log_wal=false;
staticboolauto_explain_log_triggers=false;
staticboolauto_explain_log_timing=true;
staticboolauto_explain_log_settings=false;
staticintauto_explain_log_format=EXPLAIN_FORMAT_TEXT;
staticintauto_explain_log_level=LOG;
staticboolauto_explain_log_nested_statements=false;
staticdoubleauto_explain_sample_rate=1;
staticconststructconfig_enum_entryformat_options[] = {
    {"text", EXPLAIN_FORMAT_TEXT, false},
    {"xml", EXPLAIN_FORMAT_XML, false},
    {"json", EXPLAIN_FORMAT_JSON, false},
    {"yaml", EXPLAIN_FORMAT_YAML, false},
    {NULL, 0, false}
};
staticconststructconfig_enum_entryloglevel_options[] = {
    {"debug5", DEBUG5, false},
    {"debug4", DEBUG4, false},
    {"debug3", DEBUG3, false},
    {"debug2", DEBUG2, false},
    {"debug1", DEBUG1, false},
    {"debug", DEBUG2, true},
    {"info", INFO, false},
    {"notice", NOTICE, false},
    {"warning", WARNING, false},
    {"log", LOG, false},
    {NULL, 0, false}
};
/* Current nesting depth of ExecutorRun calls */staticintnesting_level=0;
/* Is the current top-level query to be sampled? */staticboolcurrent_query_sampled=false;
#define auto_explain_enabled() \(auto_explain_log_min_duration >= 0 && \(nesting_level == 0 || auto_explain_log_nested_statements) && \current_query_sampled)/* Saved hook values in case of unload */staticExecutorStart_hook_typeprev_ExecutorStart=NULL;
staticExecutorRun_hook_typeprev_ExecutorRun=NULL;
staticExecutorFinish_hook_typeprev_ExecutorFinish=NULL;
staticExecutorEnd_hook_typeprev_ExecutorEnd=NULL;
void_PG_init(void);
staticvoidexplain_ExecutorStart(QueryDesc*queryDesc, inteflags);
staticvoidexplain_ExecutorRun(QueryDesc*queryDesc,
ScanDirectiondirection,
uint64count, boolexecute_once);
staticvoidexplain_ExecutorFinish(QueryDesc*queryDesc);
staticvoidexplain_ExecutorEnd(QueryDesc*queryDesc);
/** Module load callback*/void_PG_init(void)
{
/* Define custom GUC variables. */DefineCustomIntVariable("auto_explain.log_min_duration",
"Sets the minimum execution time above which plans will be logged.",
"Zero prints all plans. -1 turns this feature off.",
&auto_explain_log_min_duration,
-1,
-1, INT_MAX,
PGC_SUSET,
GUC_UNIT_MS,
NULL,
NULL,
NULL);
DefineCustomBoolVariable("auto_explain.log_analyze",
"Use EXPLAIN ANALYZE for plan logging.",
NULL,
&auto_explain_log_analyze,
false,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomBoolVariable("auto_explain.log_settings",
"Log modified configuration parameters affecting query planning.",
NULL,
&auto_explain_log_settings,
false,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomBoolVariable("auto_explain.log_verbose",
"Use EXPLAIN VERBOSE for plan logging.",
NULL,
&auto_explain_log_verbose,
false,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomBoolVariable("auto_explain.log_buffers",
"Log buffers usage.",
NULL,
&auto_explain_log_buffers,
false,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomBoolVariable("auto_explain.log_wal",
"Log WAL usage.",
NULL,
&auto_explain_log_wal,
false,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomBoolVariable("auto_explain.log_triggers",
"Include trigger statistics in plans.",
"This has no effect unless log_analyze is also set.",
&auto_explain_log_triggers,
false,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomEnumVariable("auto_explain.log_format",
"EXPLAIN format to be used for plan logging.",
NULL,
&auto_explain_log_format,
EXPLAIN_FORMAT_TEXT,
format_options,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomEnumVariable("auto_explain.log_level",
"Log level for the plan.",
NULL,
&auto_explain_log_level,
LOG,
loglevel_options,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomBoolVariable("auto_explain.log_nested_statements",
"Log nested statements.",
NULL,
&auto_explain_log_nested_statements,
false,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomBoolVariable("auto_explain.log_timing",
"Collect timing data, not just row counts.",
NULL,
&auto_explain_log_timing,
true,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
DefineCustomRealVariable("auto_explain.sample_rate",
"Fraction of queries to process.",
NULL,
&auto_explain_sample_rate,
1.0,
0.0,
1.0,
PGC_SUSET,
0,
NULL,
NULL,
NULL);
MarkGUCPrefixReserved("auto_explain");
/* Install hooks. */prev_ExecutorStart=ExecutorStart_hook;
ExecutorStart_hook=explain_ExecutorStart;
prev_ExecutorRun=ExecutorRun_hook;
ExecutorRun_hook=explain_ExecutorRun;
prev_ExecutorFinish=ExecutorFinish_hook;
ExecutorFinish_hook=explain_ExecutorFinish;
prev_ExecutorEnd=ExecutorEnd_hook;
ExecutorEnd_hook=explain_ExecutorEnd;
}

2.2 explain_ExecutorStart

/** ExecutorStart hook: start up logging if needed*/staticvoidexplain_ExecutorStart(QueryDesc*queryDesc, inteflags)
{
/** At the beginning of each top-level statement, decide whether we'll* sample this statement.  If nested-statement explaining is enabled,* either all nested statements will be explained or none will.** When in a parallel worker, we should do nothing, which we can implement* cheaply by pretending we decided not to sample the current statement.* If EXPLAIN is active in the parent session, data will be collected and* reported back to the parent, and it's no business of ours to interfere.*/if (nesting_level==0)
    {
if (auto_explain_log_min_duration>=0&&!IsParallelWorker())
current_query_sampled= (pg_prng_double(&pg_global_prng_state) <auto_explain_sample_rate);
elsecurrent_query_sampled=false;
    }
if (auto_explain_enabled())
    {
/* Enable per-node instrumentation iff log_analyze is required. *//* 根据配置设置相应的选项 */if (auto_explain_log_analyze&& (eflags&EXEC_FLAG_EXPLAIN_ONLY) ==0)
        {
if (auto_explain_log_timing)
queryDesc->instrument_options|=INSTRUMENT_TIMER;
elsequeryDesc->instrument_options|=INSTRUMENT_ROWS;
if (auto_explain_log_buffers)
queryDesc->instrument_options|=INSTRUMENT_BUFFERS;
if (auto_explain_log_wal)
queryDesc->instrument_options|=INSTRUMENT_WAL;
        }
    }
/* 调用钩子链上的其他钩子 */if (prev_ExecutorStart)
prev_ExecutorStart(queryDesc, eflags);
elsestandard_ExecutorStart(queryDesc, eflags);
if (auto_explain_enabled())
    {
/** Set up to track total elapsed time in ExecutorRun.  Make sure the* space is allocated in the per-query context so it will go away at* ExecutorEnd.*/if (queryDesc->totaltime==NULL)
        {
MemoryContextoldcxt;
oldcxt=MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
queryDesc->totaltime=InstrAlloc(1, INSTRUMENT_ALL, false);
MemoryContextSwitchTo(oldcxt);
        }
    }
}

2.3 explain_ExecutorRun

/** ExecutorRun hook: all we need do is track nesting depth*/staticvoidexplain_ExecutorRun(QueryDesc*queryDesc, ScanDirectiondirection,
uint64count, boolexecute_once)
{
nesting_level++;
PG_TRY();
    {
if (prev_ExecutorRun)
prev_ExecutorRun(queryDesc, direction, count, execute_once);
elsestandard_ExecutorRun(queryDesc, direction, count, execute_once);
    }
PG_FINALLY();
    {
nesting_level--;
    }
PG_END_TRY();
}

2.4 explain_ExecutorFinish

/** ExecutorFinish hook: all we need do is track nesting depth*/staticvoidexplain_ExecutorFinish(QueryDesc*queryDesc)
{
nesting_level++;
PG_TRY();
    {
if (prev_ExecutorFinish)
prev_ExecutorFinish(queryDesc);
elsestandard_ExecutorFinish(queryDesc);
    }
PG_FINALLY();
    {
nesting_level--;
    }
PG_END_TRY();
}

2.5 explain_ExecutorEnd

/** ExecutorEnd hook: log results if needed*/staticvoidexplain_ExecutorEnd(QueryDesc*queryDesc)
{
if (queryDesc->totaltime&&auto_explain_enabled())
    {
MemoryContextoldcxt;
doublemsec;
/** Make sure we operate in the per-query context, so any cruft will be* discarded later during ExecutorEnd.*/oldcxt=MemoryContextSwitchTo(queryDesc->estate->es_query_cxt);
/** Make sure stats accumulation is done.  (Note: it's okay if several* levels of hook all do this.)*/InstrEndLoop(queryDesc->totaltime);
/* Log plan if duration is exceeded. */msec=queryDesc->totaltime->total*1000.0;
if (msec>=auto_explain_log_min_duration)
        {
ExplainState*es=NewExplainState();
es->analyze= (queryDesc->instrument_options&&auto_explain_log_analyze);
es->verbose=auto_explain_log_verbose;
es->buffers= (es->analyze&&auto_explain_log_buffers);
es->wal= (es->analyze&&auto_explain_log_wal);
es->timing= (es->analyze&&auto_explain_log_timing);
es->summary=es->analyze;
es->format=auto_explain_log_format;
es->settings=auto_explain_log_settings;
ExplainBeginOutput(es);
ExplainQueryText(es, queryDesc);
ExplainPrintPlan(es, queryDesc);
if (es->analyze&&auto_explain_log_triggers)
ExplainPrintTriggers(es, queryDesc);
if (es->costs)
ExplainPrintJITSummary(es, queryDesc);
ExplainEndOutput(es);
/* Remove last line break */if (es->str->len>0&&es->str->data[es->str->len-1] =='\n')
es->str->data[--es->str->len] ='\0';
/* Fix JSON to output an object */if (auto_explain_log_format==EXPLAIN_FORMAT_JSON)
            {
es->str->data[0] ='{';
es->str->data[es->str->len-1] ='}';
            }
/** Note: we rely on the existing logging of context or* debug_query_string to identify just which statement is being* reported.  This isn't ideal but trying to do it here would* often result in duplication.*/ereport(auto_explain_log_level,
                    (errmsg("duration: %.3f ms  plan:\n%s",
msec, es->str->data),
errhidestmt(true)));
        }
MemoryContextSwitchTo(oldcxt);
    }
if (prev_ExecutorEnd)
prev_ExecutorEnd(queryDesc);
elsestandard_ExecutorEnd(queryDesc);
}
文章标签：
日志服务
关系型数据库
PostgreSQL
相关实践学习
【涂鸦即艺术】基于云应用开发平台CAP部署AI实时生图绘板
【涂鸦即艺术】基于云应用开发平台CAP部署AI实时生图绘板
t-25772328213-6-45193
目录
相关文章
德哥
|
SQL 关系型数据库 分布式数据库
PostgreSQL 在线修改数据类型 - online ddl 方法之一
标签 PostgreSQL , online ddl , trigger , ddl 事务 背景 有张表的主键id是serial，但现在不够了，需要升级成bigserial，有什么优雅的方法吗？我看下来好像会锁表很久（因为数据量挺大） 如果直接alter table，由于数据类型从4字节改成了8字节，而tuple结构是在METADATA里面的，不是每行都有，所以DEFORM需要依赖METADATA，目前来说，这种操作需要rewrite table。
德哥
4503 0
左诗右码
|
存储 JSON 监控
Viper，一个Go语言配置管理神器！
Viper 是一个功能强大的 Go 语言配置管理库，支持从多种来源读取配置，包括文件、环境变量、远程配置中心等。本文详细介绍了 Viper 的核心特性和使用方法，包括从本地 YAML 文件和 Consul 远程配置中心读取配置的示例。Viper 的多来源配置、动态配置和轻松集成特性使其成为管理复杂应用配置的理想选择。
左诗右码
485 2
t-25772328213-6-45193
|
缓存 负载均衡 关系型数据库
Pgpool-II实现高可用+读写分离+负载均衡（一）---- 规划及安装
Pgpool-II是一款工作在PostgreSQL服务器和PostgreSQL数据库客户端之间的中间件。提供了连接池、复制、负载均衡、限制过多连接、看门狗、查询缓存等功能。
t-25772328213-6-45193
2168 0
云技术达人
|
2月前
|
存储 关系型数据库 Apache
Flink CDC 3.5 正式发布，新增 PostgreSQL Source 和 Fluss Sink 连接器
Apache Flink CDC 3.5 正式发布，支持万表同步性能优化、PostgreSQL 整库同步至 Apache Fluss 流存储，增强 MySQL、Paimon 等连接器稳定性，并修复 GTID 数据正确性等关键问题，提升实时 ETL 可靠性与易用性。
云技术达人
394 0
软件求生
|
11月前
|
安全 Java 程序员
面试必看：如何设计一个可以优雅停止的线程？
嘿，大家好！我是小米。今天分享一篇关于“如何停止一个正在运行的线程”的面试干货。通过一次Java面试经历，我明白了停止线程不仅仅是技术问题，更是设计问题。Thread.stop()已被弃用，推荐使用Thread.interrupt()、标志位或ExecutorService来优雅地停止线程，避免资源泄漏和数据不一致。希望这篇文章能帮助你更好地理解Java多线程机制，面试顺利！ 我是小米，喜欢分享技术的29岁程序员。欢迎关注我的微信公众号“软件求生”，获取更多技术干货！
软件求生
278 53
肥猪肥猪-17824
|
人工智能 运维 监控
自动化运维：从脚本到工具的演变之路
【10月更文挑战第8天】在数字化时代的浪潮中，运维不再是简单的硬件维护，它已经演变成一场关于效率、稳定性和创新的技术革命。本文将带您领略自动化运维的魅力，从最初的脚本编写到现代复杂的自动化工具，我们将一探究竟，看看这些工具如何帮助运维人员简化日常任务，提升工作效率，并最终推动业务发展。
肥猪肥猪-17824
405 2
进军全栈攻城狮
|
SQL JavaScript 关系型数据库
Sequelize操作MySQL基本用法1
Sequelize操作MySQL基本用法
进军全栈攻城狮
329 0
1387503158665997
|
Unix Linux
linux中在进程之间传递文件描述符的实现方式
linux中在进程之间传递文件描述符的实现方式
1387503158665997
369 0
源码星辰
|
存储 消息中间件 运维
单体应用与微服务的优缺点
单体应用（monolith application）就是将应用程序的所有功能都打包成一个独立的单元，可以是 JAR、WAR、EAR 或其它归档格式。
源码星辰
612 0
站大爷
|
编解码 Python
python怎么提取视频中的音频
python怎么提取视频中的音频
站大爷
620 0

热门文章

最新文章

  • 1
    Pycharm2022最新版安装破解与激活教程，亲测可用
  • 2
    Linux的root账号忘记密码怎么办？看这一篇就够了！
  • 3
    【IntelliJ IDEA】idea修改设置默认maven，解决每次新建和导入项目都需要重新配置maven
  • 4
    介绍几款高级DAC解码芯片（整编）
  • 5
    Skia深入分析8——Skia的GPU绘图
  • 6
    使用阿里云容器服务Jenkins 2.0实现持续集成之the tag you want篇(updated on 2017.09.06)
  • 7
    四十万个数据库上云，阿里云支持了银泰、最多跑一次
  • 8
    【知云】第十期：如何保障云上游戏安全？云盾+高防IP筑起云上安全高墙
  • 9
    开源日志分析工具
  • 10
    百度动作不断推出，百科TA说
  • 1
    边界已死，信任重构：零信任架构的真相与落地心法
    53
  • 2
    日志别乱滚！从“日志即事件”到 Loki 的低成本集中化日志实战心法
    45
  • 3
    脏数据不脏心：大数据平台的数据质量（DQ）入门实战与自动修复心法
    57
  • 4
    Joplin：一款真正属于你的开源笔记与待办事项应用
    54
  • 5
    基于深度学习+NLP豆瓣电影数据爬虫可视化推荐系统
    54
  • 6
    多模态融合 AI 视频识别技术：高精度合规
    45
  • 7
    【Azure Policy】借助 Azure Resource Graph 查询策略分配、符合性状态以及策略定义
    35
  • 8
    RAG系统的随机失败问题排查：LLM的非确定性与表格处理的工程实践
    34
  • 9
    IDEA配置包括：代码快捷键或页面显示设置和常用安装插件介绍
    38
  • 10
    NeurIPS 2025 | Code Graph Model (CGM)：图融合架构重塑代码大模型，探索AI代码研发新范式
    55

    • 相关电子书

    更多
  • 低代码开发师（初级）实战教程
  • 冬季实战营第三期：MySQL数据库进阶实战
  • 阿里巴巴DevOps 最佳实践手册
    • 下一篇
    全面了解阿里云OSS使用方法