文档中心MogDBMogDB StackUqbar
v3.1

文档:v3.1

支持的版本:

其他版本:

gstrace

功能介绍

gstrace是MogDB提供的用来跟踪内核代码执行路径、记录内核数据结构、分析代码性能的工具。gstrace允许用户指定一个或多个模块和函数进行追踪。Trace的有限点位和数据在版本中被固化,无法动态添加和删除。

img 警告:

  1. 对内核dump指定内存变量的数据用于诊断分析,不存在直接指定任意寄存器或者内存地址的行为。读取的内存地址均是在开发阶段硬编码,没有任意地读取或者修改寄存器或内存的操作。
  2. Trace点可能涉及敏感数据,收集trace信息前需要同用户协商,授权和许可后方可收集。
  3. MogDB不会在敏感信息上打点,不会TRACE和用户相关的数据。
  4. Trace仅用于诊断目的,开启trace将对性能产生一定影响,影响的大小视负载的高低,trace的模块而不同。
  5. Trace工具的权限为0700,仅限于数据库用户读、写和执行。

img 说明: 如果进程异常终止,/dev/shm/ 目录下将会有gstrace_trace_cfg_*残留,可以手动清除。

语法

  • 模块开关

    gstrace [start|stop|config|dump|detail|codepath|analyze] [-p <port>][-s <BUFFER_SIZE>] [-f <DUMP_FILE>] [-o <OUTPUT_FILE>] [-t <STEP_SIZE>] [-q <COMP_FUNC_PAIRS>]

    注意:由于语法定义中使用了‘,’,‘.’,‘&’作为分隔符,因此定义模块名时不可包括这些符号。除此之外,-q参数不能和原有的内部trace -m参数同时定义,因为两个选项都会影响trace结果,当同时定义时,会返回对应错误信息。

  • 连接执行状态导出

    gstrace dump_usess -p <port> -o <OUTPUT_FILE>
    gstrace analyze_usess -f <INPUT_FILE> -o <OUTPUT_FILE>

参数说明

  • 模块开关参数
参数 说明
start 开始记录trace。
stop 停止trace,释放存储信息的共享内存trace buffer。注意:trace buffer中已捕获trace信息会丢失。
config 显示trace的配置信息。
dump 将共享内存中的trace信息写入指定文件。若没有启动trace将报错。
detail 将dump出来的二进制文件解析成文本文件,显示trace点的线程、时间信息。
codepath 提取dump文件中的函数调用信息,按照调用栈的方式显示。
analyze 统计各个函数的执行次数、总耗时、平均耗时、最长耗时、最短耗时。
-p PORT 指定启动trace功能的实例侦听的端口号。
-f DUMP_FILE 指定dump导出的trace文件。
-o OUTPUT_FILE 指定写入的文件。
-t STEP_SIZE 指定分片分析的时间跨度(秒),可选。将生成单独的{OUTPUT_FILE}.step文件。
-m MASK 指定哪些模块、函数需要追踪,如果参数为空,则追踪添加trace接口的所有模块的所有函数。
格式:[comp…][ALL].[func…][ALL]
描述:
- comp 是模块列表,使用‘,’分隔,例如:executer,mogdb。也可以使用序号,例如:executer,2。
- func 是function列表,使用‘,’ 分隔。 例如:sql_execute_ddl, sql_execute_dcl。也可以使用序号指代模块中第几个function,例如:2。
- 设置成ALL表示所有模块或所有function被trace。
示例:
- executer,mogdb.ALL :所有定义定义在executer和mogdb模块下的function被trace。
- executer,mogdb.sql_execute_ddl :定义在executer 下的Function sql_execute_ddl被trace. mogdb模块被忽略,因为下面没有该function 。
- executer,mogdb.1 :定义在模块executer和mogdb下的第一个function被trace。
ALL.1,2 :定义在所有模块下的第一,二个function被trace。
-s BUFFER_SIZE 指定用于trace功能的共享内存大小,默认为1G。如果指定的BUFFER_SIZE小于最小值2048,系统将自动调整为最小值。如果指定的BUFFER_SIZE不是2^N^(二的N次方),则向下对齐2^N^;例如:指定BUFFER_SIZE=3072,由于2^11^<3072<2^12^,系统将调整为2048。
-q COMP_FUNC_PAIR 指定哪些模块、函数需要追踪。参数不得为空。
使用语法格式及描述:
<COMP_FUNC_PAIRS> -> <COMP_FUNC_PAIR>[,<COMP_FUNC_PAIR>]*
- COMP_FUNC_PAIRS由一组及以上的模块与函数组合组成

<COMP_FUNC_PAIR> -> <COMP_NAME>.<FUNC_NAMES>
- COMP_FUNC_PAIR代表一组模块与函数组合
- COMP_NAME 代表一个模块名

<FUNC_NAMES> -> ALL|[<FUNC_NAME>[&<FUNC_NAME>]*]
- FUNC_NAMES 可由用户指定为ALL 或者一个及以上的函数名。由于FUNC_NAMES一定是与COMP_NAME组合,因此,ALL代表追踪以COMP_NAME为名的模块的所有函数;而如果用户指定的是一个及以上的函数名,则是追踪以COMP_NAME为名的模块中的这几个指定FUNC_NAME对应的函数名
- FUNC_NAME 代表一个函数
示例:
- “access.StartTransaction”:追踪一个模块及一个对应函数
- “executer.ExecutorStart&ExecInitExpr”: 追踪一个模块及多个对应函数
- “executer.ExecutorStart,tcop.PortalStart&PortalRun”: 追踪多个模块及多个对应函数
- “executer.ALL,access.ALL”:使用ALL关键字追踪所有executor和access两个模块中的全部函数
注意:如果需要追踪所有模块及函数,不使用-q参数即可。举例:gstrace start -p 8000
COMP_NAME 使用语法格式及描述:指定模块名称。
FUNC_NAME <COMP_FUNC_PAIRS> -> <COMP_FUNC_PAIR>[,<COMP_FUNC_PAIR>]* 指定函数名称。
  • 连接执行状态导出参数
参数 说明
dump_usess 表示导出连接相关状态数据信息。
采用原始二进制格式。
analyze_usess 表示分析生成可阅读文件。
采用文本可阅读格式。
-p 指定控制MogDB服务器端口。
-o 指定输出的文件,可包含路径。输出文件需要不存在,否则报错。
-f 指定输入的文件,可包含路径。输入文件必须存在且符合格式要求,否则报错。

示例

  1. 启动trace

    gstrace start -p 8000
  2. 停止trace

    gstrace stop -p 8000
  3. 查看trace配置

    gstrace config -p 8000
  4. dump trace

    gstrace dump -p 8000 -o /data/8000.dump
  5. 解析dump detail信息

    gstrace detail -f /data/8000.dump -o /data/8000.detail
  6. 解析dump codepath

    gstrace codepath -f /data/8000.dump -o /data/8000.codepath
  7. 分析全局性能

    gstrace analyze -f /data/8000.dump -o /data/8000.perf
  8. 分析分片性能

    gstrace analyze -f /data/8000.dump -o /data/8000.perf -t 1
  9. 跟踪executer模块的全部函数

    gstrace start -p 7654 -q executer.ALL
  10. 导出获得二进制user_session文件

    gstrace dump_usess -p 7654 -o /home/mogdbuser/dump1.bin
  11. 创建可阅读json版本的user_session信息文件

    gstrace analyze_usess -f /home/mogdbuser/dump1.bin -o /home/mogdbuser/analyze1.json

SQL trace

MogDB gstrace自3.1版本提供新的观测能力SQL trace,能够在生产不停库的情况下提供对SQL运行实际性能和行为统计的捕获分析,提高性能调优和故障诊断效率。

SQL trace在已有的gstrace模块上增加一项功能,可以在用户指定的一段时间内追踪SQL运行过程和内容。 用户可以开启、导出、关闭gstrace的SQL trace功能。SQL trace导出的内容包括机器和数据库相关的基本信息、PARSE(解析)、EXEC(执行)语句的总执行时间,以及主要算子SCAN、SORT AGGREGATE的执行时间、执行条数等。

接口和语法描述

  1. 开始追踪SQL语句的执行。

    gstrace start -p <port> -q sqltrace.ALL
  2. 导出追踪的SQL相关内容到二进制文件。

    gstrace dump -p <port> -o <OUTPUT_FILE>
  3. 停止追踪。

    gstrace stop -p <port>
  4. 根据输入的二进制SQL追踪文件内容生成可读的.txt版本SQL trace文件

    gstrace analyze_sqltrace -f <INPUT_FILE> -o <OUTPUT_FILE> [-t]

参数说明

  • -q:指定SQL追踪相关模块。

  • -p:指定控制MogDB服务器端口。

  • -o:指定输出的文件,可包含路径。输出文件需要不存在,如果输出文件存在则会清空该文件,并重新输出,即覆盖原有文件。如果指定了-t参数,则只需要指定输出路径即可。

    指定-o参数有两种情况:

    • 接口和语法描述第二步中导出到二进制文件的-o参数的文件名需要指定为output_file_name.bin。如果指定的输出文件无法打开会报错,报错的msg code为TRACE_OPEN_OUTPUT_FILE_ERR。报错信息为"Failed to open trace output file."
    • 第四步中analyze sqltrace的-o参数的文件名需要指定为output_file_name.txt。如果指定的输出文件无法打开会报错,报错信息为"Cannot open file <OUTPUT_FILE_NAME>"
  • -f:指定输入的文件,可包含路径。输入文件必须是第二步执行完成后获得的二进制文件,否则报错。报错的msg code为TRACE_COMMON_ERROR,报错信息为"Failed to open trace file."

  • -t:此为可选项,如果指定,则SQL trace的可读文本文件会按照thread id来分开生成多个文本文件,如果不指定,则所有SQL trace的结果会生成在一个文本文件中。

analyze_sqltrace导出文件格式说明

  1. trace文件从“=====SQL TRACE START=====”字样开始,是SQL trace文件的头部信息, 包含MogDB的版本号、安装位置、时间等基本信息。
  2. SQL trace文件的头部信息之后为trace文件的主体部分,每个线程所完成的所有SQL命令的解析和执行由进程号(pid)和线程号(tid)的组合划分,该线程所完成的所有SQL命令的解析与执行按照时间顺序存放在 “WORKER pid=xxx tid=xxx” 字样之后。
  3. 每个线程完成的所有SQL语句中,可能会出现不完整的SQL语句执行,原因有二:
    • SQL trace打开的时候该SQL语句正好执行到一半,因此会不完整;
    • 有些SQL是系统SQL语句,可能对应一条直接系统命令,不会跟数据库交互。
  4. 每个线程所完成的所有SQL命令用“=====================”分隔。
  5. 对于一个完整的SQL语句执行,从“=====================”之后开始,一条SQL语句运行的所有过程及相关信息可分为5个block,每个block所表示的内容和识别方法见下表。
BLOCK 内容 识别方法
1 用户输入的query tag为SQL QUERY + #session_id 和END OF QUERY中间的部分
2 RAW PARSE时间信息 tag为RAW PARSE + #session_id 开头这一行的信息
3 ANALYZE REWRITE时间信息 tag为ANALYZE REWRITE + #session_id 开头这一行的信息
4 用户输入的query tag为SQL QUERY + #session_id + #unique_query_id和END OF QUERY中间的部分
5 执行计划的信息 tag为EXEC START+ #session_id+ #unique_query_id和END OF EXEC中间的部分

analyze_sqltrace导出文件格式样例

以下为analyze_sqltrace导出文件格式样例,其中最上面是SQL trace文件的头部信息,包含MogDB的版本号、安装位置、时间等基本信息。“WORKER pid=24826 tid=3149”下面的内容为thread id = 3149的线程所执行的sql语句,用“============”分隔开。 本样例只显示了一个线程的SQL语句的解析和执行,实际情况下应该有多个线程的信息。例如"WORKER pid=24826 tid=3168"后面省略的内容为thread id = 3168线程所执行的sql语句。

=====SQL TRACE START=====
(MogDB 3.1.0 build ceca2000) compiled at 2022-11-18 13:30:35 commit 0 last mr 1171  on x86_64-unknown-linux-gnu, compiled by g++ (GCC) 7.3.0, 64-bit
MogDB home: /data/haolan/application/mogdb
Unix process pid: 24826
Timestamp: Fri Nov 18 15:40:27 2022 MicroSecond: 947063

WORKER pid=24826 tid=3149

  ============
  SQL QUERY #140195849041664
    CREATE TABLE test(id int, c text);
  END OF SQL QUERY
  RAW PARSE #140195849041664 time=1668757241586602 elapsed_time=65 cpu_cycles=97192266412712896
  ANALYZE REWRITE #140195849041664 time=1668757241586669 elapsed_time=18 cpu_cycles=97192266412773136

  ============
  SQL QUERY #140195849041664
    INSERT INTO test VALUES(1,'a');
  END OF SQL QUERY
  RAW PARSE #140195849041664 time=1668757241597425 elapsed_time=32 cpu_cycles=97192266445083712
  ANALYZE REWRITE #140195849041664 time=1668757241597461 elapsed_time=171 cpu_cycles=97192266445609328

  ============
  SQL QUERY #140195849041664
    INSERT INTO test VALUES(2,'abcd');
  END OF SQL QUERY
  RAW PARSE #140195849041664 time=1668757241599196 elapsed_time=11 cpu_cycles=97192266450334784
  ANALYZE REWRITE #140195849041664 time=1668757241599210 elapsed_time=25 cpu_cycles=97192266450417696

  ============
  SQL QUERY #140195849041664
    SELECT * from test;
  END OF SQL QUERY
  RAW PARSE #140195849041664 time=1668757242464205 elapsed_time=23 cpu_cycles=97192269045367856
  ANALYZE REWRITE #140195849041664 time=1668757242464235 elapsed_time=65 cpu_cycles=97192269045583968
  SQL QUERY #140195849041664 #1470662059
    SELECT * from test;
  END OF SQL QUERY
  EXEC START #140195849041664 #1470662059
  Seq Scan on public.test  (cost=0.00..22.38 rows=1238 p-time=0 p-rows=0 width=36) (actual time=0.011..0.011 rows=2 loops=1)
    Output: id, c
    (Buffers: shared hit=1)
    (CPU: ex c/r=145788403569276800, ex row=2, ex cyc=291576807138553600, inc cyc=291576807138553600)
  END OF EXEC
  EXEC #140195849041664 #1470662059 time=1668757242464421 elapsed_time=144

WORKER pid=24826 tid=3168

功能用例

启动MogDB,保持活跃的客户连接或gsql连接,并使用SQL语句查询数据库。

  1. 使用gstrace start命令开始SQL语句的执行追踪

    gstrace start -p 7654 -q sqltrace.ALL
  2. 使用gstrace dump命令导出目前为止SQL语句的执行内容

    gstrace dump -p 7654 -o /home/mogdbuser/dump_sql_trace.bin
  3. 使用gstrace stop命令停止SQL语句的执行追踪

    gstrace stop -p 7654
  4. 根据输入的二进制SQL追踪文件内容生成可读的.txt版本SQL trace文件

    gstrace analyze_sqltrace -f /home/mogdbuser/dump_sql_trace.bin -o /home/mogdbuser/analyzed_sql_trace.txt
  5. 根据输入的二进制SQL追踪文件内容,按照线程号解析成多个结果文件

    gstrace analyze_sqltrace -f /home/mogdbuser/dump_sql_trace.bin -o /home/mogdbuser -t

测试结束后,MogDB仍然能够正常运行各种功能,即gstrace的sql_trace相关功能不干扰MogDB的正常运行。

Copyright © 2011-2024 www.enmotech.com All rights reserved.