介绍
在openGauss中，遇到PL/pgSQL程序的性能瓶颈时，openGauss提供一个插件gms_profiler用于分析收集PL/pgSQL程序各个步骤执行情况，更加便捷。
使用限制：
-
仅支持Create extension命令方式加载插件。
-
插件中接口建议封装在存储过程中调用，直接调用可能会返回失败。
-
不支持存储过程中存在异常处理的场景，会导致收集信息不准确。
-
如果测试过程调用了flush_data接口，不支持其后调用ROOLBACK操作，会报错。如需使用ROOLBACK, 建议统一通过stop_profiler接口完成收集信息写表。
实践过程
gms_profiler安装
gms_profiler 默认已经在安装包中，直接通过create extension gms_profiler;加载插件，加载后，在gms_profiler模式下有几个存储过程和3张表。
[root@dmdem postgresql]# pwd
/opt/huawei/install/app/lib/postgresql
[root@dmdem postgresql]# ll gms_profiler.so
-rw------- 1 omm dbgrp 34744 Sep 29 18:53 gms_profiler.so
[omm@dmdem postgresql]$ gsql -d db1 -p 15400 -h 192.168.20.253 -U bicewow
Password for user bicewow:
gsql ((openGauss 6.0.0 build aee4abd5) compiled at 2024-09-29 18:38:08 commit 0 last mr )
SSL connection (cipher: ECDHE-RSA-AES128-GCM-SHA256, bits: 128)
Type "help" for help.
bicewow@192.168.20.253 [db1]=>create extension gms_profiler;
CREATE EXTENSION
bicewow@192.168.20.253 [db1]=>
bicewow@192.168.20.253 [db1]=>\df gms_profiler.*
List of functions
Schema | Name | Result data type | Argument data types
| Type | fencedmode | propackage | prokind
--------------+------------------------+------------------+--------------------------------------------------------------------------------------------------------------------------------------------
-----------------------------------+--------+------------+------------+---------
gms_profiler | flush_data | integer |
| normal | f | f | f
gms_profiler | get_version | record | OUT major integer, OUT minor integer
| normal | f | f | p
gms_profiler | internal_version_check | integer |
| normal | f | f | f
gms_profiler | pause_profiler | integer |
| normal | f | f | f
gms_profiler | resume_profiler | integer |
| normal | f | f | f
gms_profiler | start_profiler | integer | run_comment character varying DEFAULT NULL::character varying, run_comment1 character varying DEFAULT NULL::character varying, OUT run_resu
lt integer | normal | f | f | f
gms_profiler | start_profiler_1 | void | run_comment character varying DEFAULT NULL::character varying, run_comment1 character varying DEFAULT NULL::character varying
| normal | f | f | f
gms_profiler | start_profiler_ext | record | run_comment character varying DEFAULT NULL::character varying, run_comment1 character varying DEFAULT NULL::character varying, OUT run_numb
er integer, OUT run_result integer | normal | f | f | f
gms_profiler | start_profiler_ext_1 | integer | run_comment character varying DEFAULT NULL::character varying, run_comment1 character varying DEFAULT NULL::character varying, OUT run_numb
er integer | normal | f | f | f
gms_profiler | stop_profiler | integer |
| normal | f | f | f
(10 rows)
bicewow@192.168.20.253 [db1]=>\dt gms_profiler.*
List of relations
Schema | Name | Type | Owner | Storage
--------------+----------------------+-------+---------+----------------------------------
gms_profiler | plsql_profiler_data | table | bicewow | {orientation=row,compression=no}
gms_profiler | plsql_profiler_runs | table | bicewow | {orientation=row,compression=no}
gms_profiler | plsql_profiler_units | table | bicewow | {orientation=row,compression=no}
(3 rows)
bicewow@192.168.20.253 [db1]=>\ds gms_profiler.*
List of relations
Schema | Name | Type | Owner | Storage
--------------+--------------------------+----------+---------+---------
gms_profiler | plsql_profiler_runnumber | sequence | bicewow |
(1 row)
gms_profiler使用
创建测试存储过程并执行
分别创建1张测试表，1个存储过程，以及gms_profiler的test_profiler_start过程。
bicewow@192.168.20.253 [db1]=>\timing on
Timing is on.
bicewow@192.168.20.253 [db1]=>
bicewow@192.168.20.253 [db1]=>
bicewow@192.168.20.253 [db1]=>
bicewow@192.168.20.253 [db1]=>\dt
List of relations
Schema | Name | Type | Owner | Storage
--------+-------------+-------+---------+----------------------------------
public | zscard_info | table | bicewow | {orientation=row,compression=no}
(1 row)
bicewow@192.168.20.253 [db1]=>\df
List of functions
Schema | Name | Result data type | Argument data types | Type | fencedmode | propackage | prokind
--------+------+------------------+---------------------+------+------------+------------+---------
(0 rows)
创建测试表。
bicewow@192.168.20.253 [db1]=>CREATE TABLE zs_tab (id int); <============== 测试表
CREATE TABLE
Time: 7.222 ms
创建测试存储过程。
bicewow@192.168.20.253 [db1]=>CREATE OR REPLACE procedure proc_insert_zs_tab <============== 测试存储过程
as
db1-> db1$> begin
db1$> for x in 1..20000
db1$> loop
db1$> insert into zs_tab values(x);
db1$> commit;
db1$> end loop;
db1$> end proc_insert_zs_tab;
db1$> /
CREATE PROCEDURE
Time: 215.918 ms
创建gms_profiler分析存储过程。
bicewow@192.168.20.253 [db1]=>create or replace procedure test_profiler_start () as <============== gms_profiler分析存储过程
db1$> declare
db1$> l_result binary_integer;
db1$> l_runid binary_integer;
db1$>
db1$> begin
db1$> gms_output.enable;
db1$> gms_profiler.start_profiler_ext('test_profiler4', 'simple',l_runid,l_result);
db1$> gms_output.put_line('Run number id:'||l_runid);
db1$> proc_insert_zs_tab();
db1$> l_result := gms_profiler.stop_profiler();
db1$> end;
db1$> /
CREATE PROCEDURE
Time: 281.381 ms
调用gms_profiler的test_profiler_start进行分析。
bicewow@192.168.20.253 [db1]=>call test_profiler_start();
Run number id:11 <=========执行runid 为 11
test_profiler_start
---------------------
(1 row)
Time: 12766.902 ms <=========存储过程大概执行12.7s
数据分析
表 plsql_profiler_runs 汇总表，显示了运行的基本统计信息。
bicewow@192.168.20.253 [db1]=>\x
Expanded display is on.
bicewow@192.168.20.253 [db1]=>select * from gms_profiler.plsql_profiler_runs where runid = 11;
-[ RECORD 1 ]---+--------------------
runid | 11
related_run |
run_owner | bicewow
run_date | 2024-11-08 10:22:55
run_comment | test_profiler4
run_total_time | 12728555 <===== 总执行时间12.7s ，与gsql 自带timing on时间统计一致
run_system_info |
run_comment1 | simple
spare1 |
Time: 1.644 ms
表 plsql_profiler_units，可以看到执行proc_insert_zs_tab存储过程花费的总时间。
bicewow@192.168.20.253 [db1]=>select * from gms_profiler.plsql_profiler_units where runid =11;
runid | unit_number | unit_type | unit_owner | unit_name | unit_timestamp | total_time | spare1 | spare2
-------+-------------+-----------------+-------------+--------------------+---------------------+------------+--------+--------
11 | 1 | ANONYMOUS BLOCK | <anonymous> | <anonymous> | 2024-11-08 10:22:55 | 0 | |
11 | 2 | PROCEDURE | bicewow | proc_insert_zs_tab | 2024-11-08 10:22:55 | 12727763 | |
(2 rows)
表 plsql_profiler_data，显示存储过程proc_insert_zs_tab每行花费的时间。
bicewow@192.168.20.253 [db1]=>select * from gms_profiler.plsql_profiler_data where runid =11;
runid | unit_number | line# | total_occur | total_time | min_time | max_time | spare1 | spare2 | spare3 | spare4
-------+-------------+-------+-------------+------------+----------+----------+--------+--------+--------+--------
11 | 1 | 8 | 1 | 219 | 219 | 219 | | | |
11 | 1 | 9 | 1 | 12728078 | 12728078 | 12728078 | | | |
11 | 1 | 10 | 1 | 0 | 0 | 0 | | | |
11 | 2 | 0 | 1 | 2 | 2 | 2 | | | |
11 | 2 | 2 | 1 | 0 | 0 | 0 | | | |
11 | 2 | 4 | 20000 | 8553325 | 37 | 55882 | | | |
11 | 2 | 5 | 20000 | 3755445 | 17 | 77389 | | | |
(7 rows)
通过关联pg_catalog.pg_proc，可清晰看到每行代码执行的时间，对于分析存储过程执行瓶颈帮助比较大。
bicewow@192.168.20.253 [db1]=>select gd.line#,--代码行号
db1-> (select h_prosrc
db1(> from (SELECT rownum n_rows, h_prosrc
db1(> FROM regexp_split_to_table(gp.prosrc, E'\\n') as h_prosrc )
db1(> where n_rows = gd.line# ) h_prosrc,--源代码
db1-> gd.total_time,--总共运行时间(单位微妙。）
db1-> gd.total_occur,--总共运行次数
db1-> gd.min_time,--最小运行时间
db1-> gd.max_time--最大运行时间
db1-> from gms_profiler.plsql_profiler_data gd, gms_profiler.plsql_profiler_units gu, pg_catalog.pg_proc gp
WHERE gd.runid = 11 --运行号（上一步执行相关过程时显示号码）
db1-> db1-> AND gu.unit_name = 'proc_insert_zs_tab'--单元名，即被测试的存储过程名
db1-> AND gu.runid = gd.runid
db1-> AND gd.unit_number = gu.unit_number
db1-> AND gd.total_occur <> 0
db1-> AND pg_catalog.pg_get_userbyid(gp.proowner) = gu.unit_owner
db1-> AND gp.proname = gu.unit_name
db1-> ORDER BY gd.total_time desc, gu.unit_number, gd.line#;
line# | h_prosrc | total_time | total_occur | min_time | max_time
-------+--------------------------------------+------------+-------------+----------+----------
4 | insert into zs_tab values(x); | 8553325 | 20000 | 37 | 55882
5 | commit; | 3755445 | 20000 | 17 | 77389
0 | | 2 | 1 | 2 | 2
2 | for x in 1..20000 | 0 | 1 | 0 | 0
(4 rows)
Time: 19.614 ms
总结
gms_profiler 作为openGauss的存储过程性能分析工具，使用起来相对简单，作用巨大，免去了人工调试时，时间无法统计，人工埋点，调试繁琐的工作，对于运维开发人员来说，比较友好。此功能如果运用得当，完全可以嵌入到日常重要的业务场景中，生成运行基线，在出现性能问题时，快速定位异常代码。
「喜欢这篇文章，您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容，转载时必须标注文章的来源（墨天轮），文章链接，文章作者等基本信息，否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容，欢迎发送邮件至：contact@modb.pro进行举报，并提供相关证据，一经查实，墨天轮将立刻删除相关内容。
