Mogdb SQL 通过plan_node_id来监测慢sql执行步骤
Oracle可以通过 v$active_session_history中的SQL_PLAN_LINE_ID来标识采样来自于sql执行计划的哪一步,可以通过count数来说明哪一步耗时久,同理在mogdb中也有此功能。
这个功能主要用于那些耗时慢sql的排查,即执行时间很长不能通过explain analyze分析的语句
本特性自MogDB 3.0.0版本开始引入。
特性简介
采样线程默认1s采样一次,可通过guc参数asp_sample_interval控制,内存中最多采样100000行数据,通过asp_sample_num控制,到达上限就会刷新到磁盘上。
客户价值
当发现某条SQL语句存在性能瓶颈,且无法在采样视图中查询到该SQL每个算子的执行情况时,可以通过plan_node_id定位性能问题。
算子:SQL语句执行过程中各个步骤的具体动作(例如:SELECT、SUM、WHERE、Group By、Having、Order By、Limit等)
特性描述
在dbe_perf.local_active_session和GS_ASP中新增一列plan_node_id来记录SQL语句每个算子操作的执行情况。
现有的监控级别由guc参数resource_track_level控制,该参数按照级别存在三个值,分别是:
none:不开启资源记录功能;
query:开启query级别资源记录功能;
operator:开启query级别和算子级别资源记录功能,所以只有当将resource_track_level设成operator的时候才会对SQL语句每个算子操作进行采样。
同样要开启asp
enable_asp=on
resource_track_level=operator
enable_resource_track=on
MogDB启动后会启动一个后台worker采样线程,为避免浪费资源,该采样线程不会时刻采样,而是每隔一个采样周期对MogDB进行采样,收集MogDB当时的运行快照保存到内存中,查询视图dbe_perf.local_active_session可以查询到实时的采样信息,该采样周期由guc参数asp_sample_interval控制,默认采样周期为1s,MogDB每在内存中采样100000行(由guc参数asp_sample_num控制)会将内存中的采样数据刷新到GS_ASP表中以供历史查询,只有语句执行时间大于采样时间,才会被采样线程收集到运行信息。
使用场景
官方例子
首先在session1中创建表test,并执行插入操作:
MogDB=# create table test(c1 int);
CREATE TABLE
MogDB=# insert into test select generate_series(1, 1000000000);
当前还没执行完的sql在pg_stat_activity中查询
在session2中,从活跃会话视图中查询出该SQL的query_id
MogDB=# select query,query_id from pg_stat_activity where query like ‘insert into test select%’;
query | query_id
-----------------------------------------------------------±----------------
insert into test select generate_series(1, 100000000000); | 562949953421368
(1 row)
在session2中,根据该query_id从活跃作业管理视图中查询出该语句的带plan_node_id的执行计划(该语句执行cost需要大于guc值resource_track_cost才会被记录到该视图中,该guc参数默认值为100000,session级别可更新,所以为了方便测试,可在测试中将该值改成10)
Set resource_track_cost=10;
MogDB=# select query_plan from dbe_perf.statement_complex_runtime where queryid = 562949953421368;
query_plan
Coordinator Name: datanode1 +
1 | Insert on test (cost=0.00…17.51 rows=1000 width=8) +
2 | -> Subquery Scan on “SELECT” (cost=0.00…17.51 rows=1000 width=8) +
3 | -> Result (cost=0.00…5.01 rows=1000 width=0) +
(1 row)
在session2中,根据query_id从采样视图dbe_perf.local_active_session中查询出该语句的采样情况,结合上面查询的执行计划做性能分析。
MogDB=# select plan_node_id, count(plan_node_id) from dbe_perf.local_active_session where query_id = 562949953421368 group by plan_node_id;
plan_node_id | count
--------------±------
3 | 12
1 | 366
2 | 2
(3 rows)
在session2中执行,当内存数据到达上限值(由guc参数asp_sample_num控制)的时候,则会将现有内存的采样数据刷新到gs_asp表中,刷盘后查询gs_asp表也会查到该语句的算子采样的数据。
MogDB=# select plan_node_id, count(plan_node_id) from gs_asp where query_id = 562949953421368 group by plan_node_id;
plan_node_id | count
--------------±------
3 | 19
1 | 582
2 | 3
当发现insert into test select generate_series(1, 1000000000)存在性能瓶颈,通过以上的步骤定位发现,insert操作在整个SQL语句执行过程中被采样的数值最高( plan_node_id =1 ,count=366),可以对其进行优化。
相关表
GS_ASP、LOCAL_ACTIVE_SESSION
实际应用例子:
select count(*)
from test2 t2, test3 t3
where t2.id = t3.id;
在postgres库中查询
select state,a.query,a.query_id,a.unique_sql_id,a.*
from pg_stat_activity a where a.state=‘active’ and usename=‘tpcc_user’;
unique_sql_id=‘3007706519’
query_id=‘1407374883554139’
此表中unique_sql_id 同dbe_perf中的unique_query_id
查询在内存中的执行计划
enable_asp=on
resource_track_level=operator
enable_resource_track=on
select query_plan ,a.*
from dbe_perf.statement_complex_runtime a
where queryid=‘1407374883554139’;
如果执行完,同样可查历史
select query_plan,sch.*
from dbe_perf.statement_complex_history sch
where sch.queryid=‘1407374883554873’;
查询哪步慢
select las.plan_node_id ,count(las.plan_node_id)
from dbe_perf.local_active_session las
where las.unique_query_id =‘3007706519’
group by las.plan_node_id
order by count(*) desc;
select las.query_id,las.unique_query_id,las.*
from dbe_perf.local_active_session las
where las.unique_query_id =‘3007706519’
order by sample_time desc;
如果查询历史执行计划,必须打开如下参数
必须在postgres库内查询,其它库中不存数据。
此系统表受track_stmt_stat_level控制,默认为“OFF,L0”,第一部分控制Full SQL,第二部分控制Slow SQL,具体字段记录级别见下表。
对于Slow SQL,当track_stmt_stat_level的值为非OFF时,且SQL执行时间超过log_min_duration_statement,会记录为慢SQL。
配置参数:
track_stmt_stat_level=‘L2,L0’
log_min_duration_statement=1000ms
执行完可以查到相应的信息
select a.unique_query_id,a.query,a.query_plan,a.debug_query_id ,a.*
from dbe_perf.statement_history a
–where a.query like ‘%hashjoin%’;
where a.unique_query_id =‘3007706519’;
select a.unique_query_id,a.query,a.query_plan,a.debug_query_id ,a.*
from pg_catalog.statement_history a
–where a.query like ‘%hashjoin%’;
where a.unique_query_id =‘3007706519’;
debug_query_id =‘1125899906854472’;
select *
from pg_settings
where name like ‘%track_stmt_stat_level%’
or name like ‘%log_min_duration_statement%’
or name like ‘%asp_sample_interval%’
or name like ‘%resource_track_level%’;
执行完可以查到相应的信息
select query,unique_query_id,query_plan,a.*
from DBE_PERF.get_global_slow_sql_by_timestamp(‘2020-12-01 09:25:22’, ‘2023-12-31 23:54:41’) a
where a.unique_query_id =‘3007706519’;
select query,unique_query_id,query_plan,a.*
from DBE_PERF.get_global_full_sql_by_timestamp(‘2020-12-01 09:25:22’, ‘2023-12-31 23:54:41’) a
where a.unique_query_id =‘3007706519’;
select * from pg_settings where name like ‘%asp%’;
DBE_PERF.get_global_full_sql_by_timestamp() 这些系统存储过程可以在相应模式下查看基表
查询执行不完的sql的query_id
根据query_id查询在内存中的执行计划
根据plan_node_id统计在哪些步骤采样次数多
采样次数多的证明执行时间长
注意:在sql执行完毕后,才会将执行计划等信息写入到
dbe_perf.statement_history
pg_catalog.statement_history
这时这些历史表的执行计划才可以查询,在内存中的按上文查找
算子采样实现原理
- 新增一个pgstat_report_plan_node_id的轻量函数对session状态监控结构体PgBackendStatus中的plan_node_id赋值
- 每个执行器算子的执行都会分Init(初始化),Exec(执行),End(结束收尾)三个阶段,真正的执行阶段是在Exec中,在每个算子的Exec函数中调用上述pgstat_report_plan_node_id函数,将本算子的plan_node_id赋值到session的状态监控结构体中
- 采样框架定期采样从session的状态监控结构体数组中获取每个session的状态,将值赋值到全局采样数组中以便查询
采样线程的工作函数为SubAspWorker,该工作线程会每隔固定时间,默认1s(间隔时间可通过guc参数asp_sample_interval配置,最小为1s,最大为10s)的时间去遍历BackendStatusArray数组,并且将内容写到全局数组active_sess_hist_arrary中,以及检查是否需要进行刷盘操作,当内存中数量达到上限值默认10w(10-10w可通过asp_sample_num配置)行的时候,就会触发刷出机制,持久化到gs_asp表中。




