ARTICLE · INTELLIGENCE

战地情报 · 详情页

来自尧图项目组的一线实战观察与深度解析

达梦数据库-学习-09-SQL跟踪日志

达梦数据库-学习-09-SQL跟踪日志 目录一、环境信息二、简述三、参数介绍四、sqllog.ini介绍1、使用条件2、文件位置3、参数介绍4、动态加载5、相关视图1V$DM_SQLLOG_INIsqllog.ini 文件2V$DM_SQLLOG_CONFIGsqllog.ini 内存五、SQL日志路径六、虚机实验1、SVR_LOG参数开启1SP_SET_PARA_VALUE介绍2验证参数2、修改sqllog.ini3、重新加载sqllog.ini4、执行测试SQL1测试DDL2测试DML3测试DQL5、SVR_LOG参数关闭6、性能监视工具1启动2登录3SQL日志文件分析一、环境信息名称值CPU12th Gen Intel(R) Core(TM) i7-12700H操作系统CentOS Linux release 7.9.2009 (Core)内存2G逻辑核数2DM版本1 DM Database Server 64 V82 DB Version: 0x7000c3 03134284194-20240703-234060-201084 Msg Version: 125 Gsu level(5) cnt: 0二、简述我们经常被客户问道我这个应用卡顿的厉害有什么好的办法帮忙优化一下吗作为DBA的我们可能就会想到是否有慢SQL导致应用卡顿这时SQL跟踪日志这个功能就非常有必要了让我们知道应用跑了哪些SQL而不用去了解客户应用的代码逻辑省去很多时间提高了我们的工作效率。三、参数介绍四、sqllog.ini介绍1、使用条件sqllog.ini用于SQL日志的配置当且仅当INI参数SVR_LOG1时使用。2、文件位置sqllog.ini在数据文件目录下和dm.ini在同一级目录下。举例如下[dmdbaczg2 DAMENG]$ ll 总用量 4542564 drwxrwxr-x 2 dmdba dmdba 6 2月 11 14:52 bak drwxrwxr-x 2 dmdba dmdba 150 2月 12 09:40 ctl_bak -rw-rw-r-- 1 dmdba dmdba 2147483648 2月 12 10:18 DAMENG01.log -rw-rw-r-- 1 dmdba dmdba 2147483648 2月 12 09:39 DAMENG02.log -rw-rw-r-- 1 dmdba dmdba 5632 2月 12 09:40 dm.ctl -rw-rw-r-- 1 dmdba dmdba 79454 2月 11 15:51 dm.ini -rw-rw-r-- 1 dmdba dmdba 940 2月 11 14:52 dminit20250211145213.log -rw-rw-r-- 1 dmdba dmdba 633 2月 11 14:52 dm_service.prikey drwxrwxr-x 2 dmdba dmdba 6 2月 11 14:52 HMAIN -rw-rw-r-- 1 dmdba dmdba 134217728 2月 11 14:52 MAIN.DBF -rw-rw-r-- 1 dmdba dmdba 134217728 2月 12 10:18 ROLL.DBF -rw-rw-r-- 1 dmdba dmdba 714 2月 11 14:52 sqllog.ini -rw-rw-r-- 1 dmdba dmdba 77594624 2月 12 09:45 SYSTEM.DBF -rw-r--r-- 1 dmdba dmdba 10485760 2月 12 09:39 TEMP.DBF drwxr-xr-x 2 dmdba dmdba 6 2月 11 15:45 trace [dmdbaczg2 DAMENG]$ pwd /opt/Dm8/Data/DAMENG3、参数介绍参数名默认值属性描述SQL_TRACE_MASK1系统级动态参数指定SQL日志中需要被记录的语句类型。指定方式为SQL_TRACE_MASK位号:位号:位号……。例如3:5:7表示第3第5第 7 位号代表的类型需要被记录在SQL日志中。动态 SQL_TRACE_MASK 1 系统级 以下位号均可以单独使用也可以搭配使用其中位号2~17与23、24、25、26、28搭配使用时表示取其交集。例如SQL_TRACE_MASK2表示记录DML语句SQL_TRACE_MASK24表示记录执行语句SQL_TRACE_MASK29表 示记录事务相关语句SQL_TRACE_MASK2:3:24:29表示记录DML和DDL的执行语句以及事务相关语句。位号的含义如下所示1 全部记录等同于同时设置4~312 DML类型相关语句等同于同时设置4~103 DDL类型相关语句等同于同时设置11~174 UPDATE类型语句更新5 DELETE类型语句删除6 INSERT类型语句插入7 SELECT类型语句查询8 COMMIT类型语句提交9 ROLLBACK类型语句回滚10 CALL类型语句过程调用11 BACKUP类型语句备份12 RESTORE类型语句恢复13 创建对象操作CREATE DDL14 修改对象操作ALTER DDL15 删除对象操作DROP DDL16 授权操作GRANT DDL17 回收操作REVOKE DDL22 记录绑定参数23 记录存在错误的语句语法错误语义分析错误等24 记录执行语句25 记录执行语句、执行语句的时间、语句的影响行数只有增删改查有行数其它语句无行数26 记录执行语句的时间、语句的影响行数只有增删改查有行数其它语句无行数。25和26二者只能选择其一。25和26 同时存在时只有25有效27 记录原始语句服务器从客户端收到的未加分析的语句28 记录参数信息包括参数的序号、数据类型和值29 记录事务相关事件包括锁类型、锁等待时间等30 记录XA事务31 记录数据库登录操作包括登录成功、登录失败、退出登录FILE_NUM5系统级动态参数总共记录多少个日志文件当日志文件达到这个设定值以后再生成新的文件时会删除最早的那个日志文件。取值范围2~1024。日志文件名称中将包含日期时间信息关于日志文件命名格式的详细介绍请参考《DM8系统管理员手册》2.9 SQL日志文件SWITCH_MODE2系统级动态参数表示SQL日志文件切换的模式0不切换1按文件中记录数量切换2按文件大小切换3按时间间隔切换SWITCH_LIMIT与参数SWITCH_MODE有关系统级动态参数不同切换模式SWITCH_MODE下意义不同SWITCH_MODE为1 按数量切换时一个日志文件中的SQL记录条数达到多少条之后系统自动将日志切换到另一个文件中。取值范围 1000~10000000缺省为100000SWITCH_MODE为2按文件大小切换时一个日志文件达到该大小后系统自动将日志切换到另一个文件中单位MB。取值范围1~2000缺省 为128SWITCH_MODE为3按时间间隔切换时每隔指定的时间间隔系统自动将日志切换到另一个文件中单位分钟。取值范围1~30000缺省为 60ASYNC_FLUSH1系统级动态参数是否打开SQL日志异步刷盘功能。0否采用实时刷盘1是采用异步刷盘MIN_EXEC_TIME0系统级动态参数记录的最小语句执行时间单位毫秒。执行时间小于该值的语句不记录在日志文件中。取值范围0~2147483647FILE_PATH../log系统级动态参数SQL日志文件所在的文件夹路径。缺省生成在DM安装目录的log子目录下面BUF_TOTAL_SIZE10240系统级动态参数SQL日志BUFFER占用空间的上限单位KB取值范围1024~1024000BUF_SIZE1024系统级动态参数一块SQL日志BUFFER的空间大小单位KB取值范围50~409600BUF_KEEP_CNT6系统级动态参数系统保留的SQL日志缓存的个数取值范围1~100PART_STOR0系统级动态参数SQL日志分区存储表示SQL日志进行分区存储的划分条件。0表示不划分1表示USER根据不同用户分布存储ITEMS0系统级动态参数指定一条SQL日志中应包含的内容。指定方式为ITEMS位号:位号:位号……。例如ITEMS3:5:7。表示应包含第3、第5、第7 位代表的内容。0 表示记录所有的列等同于同时设置1~121 TIME 执行的时间2 SEQNO 服务器的站点号3 SESS 操作的SESS地址4 USER 执行的用户5 TRXID 事务ID6 STMT 语句地址7 APPNAME 客户端工具8 IP 客户端IP9 STMT_TYPE 语句类型。分别为[ORA]表示原始语句服务器从客户端收到的未加分析的语句 、[DDL]表示DDL 语句、[INS]表示INSERT语句、[DML]表示DML语句、[CAL]表示CALL语句、[UPD] 表示UPDATE语句、[DEL] 表示DELETE 语句、[SEL]表示SELECT语句、[LGN]表示登录登出语句10 INFO 记录内容记录当前执行的SQL语句11 RESULT 运行结果包括运行用时、影响行数和EXEC_ID可能没有12 THRD 线程地址USER_MODE0系统级动态参数SQL日志按用户过滤时的过滤模式取值0关闭用户过滤1白名单模式只记录列出的用户操作的SQL日志2黑名单模式列出的用户不记录SQL日志USERS空字符串系统级动态参数打开USER_MODE时指定的用户列表。格式为用户名用户名用户名EXECTIME_PREC_FLAG0系统级动态参数设置SQL日志中执行时间EXECTIME的时间单位。0单位为毫秒MS1单位为微秒US4、动态加载SQL CALL SP_REFRESH_SVR_LOG_CONFIG(); DMSQL 过程已成功完成 已用时间: 1.502(毫秒). 执行号:601.5、相关视图1V$DM_SQLLOG_INIsqllog.ini 文件SQL SELECT * FROM V$DM_SQLLOG_INI WHERE MODE_NAME SLOG_ALL; 行号 MODE_NAME PARA_NAME PARA_VALUE IS_DEFAULT ---------- --------- -------------- ---------- ---------- 1 SLOG_ALL SQL_TRACE_MASK 1 Y 2 SLOG_ALL FILE_NUM 5 Y 3 SLOG_ALL SWITCH_MODE 2 Y 4 SLOG_ALL SWITCH_LIMIT 128 Y 5 SLOG_ALL ASYNC_FLUSH 1 Y 6 SLOG_ALL MIN_EXEC_TIME 0 Y 7 SLOG_ALL FILE_PATH ../log Y 8 SLOG_ALL PART_STOR 0 Y 9 SLOG_ALL ITEMS 0 Y 10 SLOG_ALL USER_MODE 0 Y 11 SLOG_ALL USERS Y 行号 MODE_NAME PARA_NAME PARA_VALUE IS_DEFAULT ---------- --------- ------------------ ---------- ---------- 12 SLOG_ALL EXECTIME_PREC_FLAG 0 Y 12 rows got 已用时间: 2.312(毫秒). 执行号:603.2V$DM_SQLLOG_CONFIGsqllog.ini 内存-- 视情况执行默认是SLOG_ALL。 SQL SP_SET_PARA_STRING_VALUE(1,SVR_LOG_NAME,SLOG_ALL); SQL SP_SET_PARA_VALUE(1,SVR_LOG,1); SQL SELECT * FROM V$DM_SQLLOG_CONFIG; 行号 MODE_NAME PARA_NAME PARA_VALUE ---------- --------- -------------- ---------- 1 PUBLIC BUF_TOTAL_SIZE 10240 2 PUBLIC BUF_SIZE 1024 3 PUBLIC BUF_KEEP_CNT 6 4 SLOG_ALL SQL_TRACE_MASK 1 5 SLOG_ALL FILE_NUM 5 6 SLOG_ALL SWITCH_MODE 2 7 SLOG_ALL SWITCH_LIMIT 128 8 SLOG_ALL ASYNC_FLUSH 1 9 SLOG_ALL MIN_EXEC_TIME 0 10 SLOG_ALL FILE_PATH ../log 11 SLOG_ALL PART_STOR 0 行号 MODE_NAME PARA_NAME PARA_VALUE ---------- --------- ------------------ ---------- 12 SLOG_ALL ITEMS 0 13 SLOG_ALL USER_MODE 0 14 SLOG_ALL USERS 15 SLOG_ALL EXECTIME_PREC_FLAG 0五、SQL日志路径默认是在log目录下。[dmdbalocalhost log]$ ll dmsql_DMSERVER_20250213_17* -rw-r--r--. 1 dmdba dmdba 936 2月 13 17:47 dmsql_DMSERVER_20250213_173325.log -rw-r--r--. 1 dmdba dmdba 1141 2月 13 17:54 dmsql_DMSERVER_20250213_174800.log [dmdbalocalhost log]$ pwd /opt/Dm8/log六、虚机实验1、SVR_LOG参数开启SQL SP_SET_PARA_VALUE(1,SVR_LOG,1); DMSQL 过程已成功完成 已用时间: 12.192(毫秒). 执行号:621.1SP_SET_PARA_VALUE介绍SP_SET_PARA_VALUE (scope int, paraname varchar(256), value bigint)该过程用于修改整型静态配置参数和动态配置参数。SCOPE参数为0表示修改内存中 的动态配置参数值参数为1表示修改内存和INI文件中的动态配置参数值参数为2表示 只在INI文件中修改配置参数此时可修改静态配置参数和动态配置参数。当SCOPE等于0 或1试图修改静态配置参数时服务器会返回错误信息。只有具有DBA角色的用户才有权限 调用SP_SET_PARA_VALUE。2验证参数SQL SELECT * FROM V$DM_INI WHERE PARA_NAME SVR_LOG; 行号 PARA_NAME PARA_VALUE MIN_VALUE MAX_VALUE DEFAULT_VALUE MPP_CHK SESS_VALUE FILE_VALUE ---------- --------- ---------- --------- --------- ------------- ------- ---------- ---------- DESCRIPTION --------------------------------------------------------------------------------------------------------------------------- PARA_TYPE SYNC_FLAG SYNC_LEVEL --------- --------- ---------- 1 SVR_LOG 1 0 3 0 N 1 1 Whether the Sql Log sys Is open or close. 1:open, 0:close, 2:use switch and detail mode. 3:use not switch and simple mode. SYS ALL_SYNC CAN_SYNC 已用时间: 8.692(毫秒). 执行号:609.2、修改sqllog.ini我们只用修改SLOG_ALL标签下的参数SQL_TRACE_MASK和MIN_EXEC_TIME。[dmdbalocalhost DAMENG]$ cat sqllog.ini BUF_TOTAL_SIZE 10240 #SQLs Log Buffer Total Size(K)(1024~1024000) BUF_SIZE 1024 #SQLs Log Buffer Size(K)(50~102400) BUF_KEEP_CNT 6 #SQLs Log buffer keeped count(1~100) [SLOG_ALL] FILE_PATH ../log PART_STOR 0 SWITCH_MODE 2 SWITCH_LIMIT 128 ASYNC_FLUSH 1 FILE_NUM 5 ITEMS 0 SQL_TRACE_MASK 1 MIN_EXEC_TIME 5 USER_MODE 0 USERS EXECTIME_PREC_FLAG 0 [SLOG_ERROR] SQL_TRACE_MASK 23 FILE_PATH ../log [SLOG_DDL] SQL_TRACE_MASK 3 [SLOG_LONG_SQL] SQL_TRACE_MASK 25 MIN_EXEC_TIME 600003、重新加载sqllog.iniSQL CALL SP_REFRESH_SVR_LOG_CONFIG(); DMSQL 过程已成功完成 已用时间: 0.520(毫秒). 执行号:607. SQL SELECT * FROM V$DM_SQLLOG_CONFIG; 行号 MODE_NAME PARA_NAME PARA_VALUE ---------- --------- -------------- ---------- 1 PUBLIC BUF_TOTAL_SIZE 10240 2 PUBLIC BUF_SIZE 1024 3 PUBLIC BUF_KEEP_CNT 6 4 SLOG_ALL SQL_TRACE_MASK 1 5 SLOG_ALL FILE_NUM 5 6 SLOG_ALL SWITCH_MODE 2 7 SLOG_ALL SWITCH_LIMIT 128 8 SLOG_ALL ASYNC_FLUSH 1 9 SLOG_ALL MIN_EXEC_TIME 5 10 SLOG_ALL FILE_PATH ../log 11 SLOG_ALL PART_STOR 0 行号 MODE_NAME PARA_NAME PARA_VALUE ---------- --------- ------------------ ---------- 12 SLOG_ALL ITEMS 0 13 SLOG_ALL USER_MODE 0 14 SLOG_ALL USERS 15 SLOG_ALL EXECTIME_PREC_FLAG 0 15 rows got 已用时间: 0.323(毫秒). 执行号:1002.4、执行测试SQL1测试DDLSQL CREATE TABLE ZXJ.TEST(A INT); 操作已执行 已用时间: 4.727(毫秒). 执行号:1005./opt/Dm8/log/dmsql_DMSERVER_20250214_091928.log日志记录2025-02-14 09:45:11.737 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18049 stmt:0x7f3dc40151e0 appname:disql ip:::1) [ORA]: CREATE TABLE ZXJ.TEST(A INT); 2025-02-14 09:45:11.737 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18049 stmt:0x7f3dc40151e0 appname:disql ip:::1) [DDL] CREATE TABLE ZXJ.TEST(A INT); 2025-02-14 09:45:11.739 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18049 stmt:NULL appname:disql ip:::1) TRX: COMMIT 2025-02-14 09:45:11.739 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18050 stmt:NULL appname:disql ip:::1) TRX: START 2025-02-14 09:45:11.739 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18050 stmt:NULL appname:disql ip:::1) trx[18050] alloc pseg page[0, 575], page_lsn[48385], n_pages[1] 2025-02-14 09:45:11.739 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18050 stmt:NULL appname:disql ip:::1) TRX: COMMIT 2025-02-14 09:45:11.739 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18050 stmt:NULL appname:disql ip:::1) trx[18050]: pseg_page_free_for_insert_only_trx free pseg page (0, 575), page_lsn 48415 2025-02-14 09:45:11.742 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:0 stmt:NULL appname:disql ip:::1) TRX: COMMIT LSN[48414]2测试DMLSQL INSERT INTO ZXJ.TEST SELECT LEVEL FROM DUAL CONNECT BY LEVEL 10000; 影响行数 10000 已用时间: 2.813(毫秒). 执行号:1006. SQL COMMIT; 操作已执行 已用时间: 2.554(毫秒). 执行号:1007.SQL日志2025-02-14 09:45:58.811 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:0 stmt:0x7f3dc40151e0 appname:disql ip:::1) [ORA]: INSERT INTO ZXJ.TEST SELECT LEVEL FROM DUAL CONNECT BY LEVEL 10000; 2025-02-14 09:45:58.811 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18051 stmt:NULL appname:disql ip:::1) TRX: START 2025-02-14 09:45:58.812 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18051 stmt:0x7f3dc40151e0 appname:disql ip:::1) [INS] INSERT INTO ZXJ.TEST SELECT LEVEL FROM DUAL CONNECT BY LEVEL 10000; 2025-02-14 09:45:58.812 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18051 stmt:0x7f3dc40151e0 appname:disql ip:::1) DLCK used time:2(us) 2025-02-14 09:45:58.812 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18051 stmt:NULL appname:disql ip:::1) trx[18051] alloc pseg page[0, 624], page_lsn[48433], n_pages[1] 2025-02-14 09:46:20.224 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18051 stmt:0x7f3dc40151e0 appname:disql ip:::1) [ORA]: COMMIT; 2025-02-14 09:46:20.224 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18051 stmt:0x7f3dc40151e0 appname:disql ip:::1) [DML] COMMIT; 2025-02-14 09:46:20.225 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18051 stmt:NULL appname:disql ip:::1) TRX: COMMIT 2025-02-14 09:46:20.225 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18051 stmt:NULL appname:disql ip:::1) trx[18051]: pseg_page_free_for_insert_only_trx free pseg page (0, 624), page_lsn 48658 2025-02-14 09:46:20.227 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:0 stmt:NULL appname:disql ip:::1) TRX: COMMIT LSN[48657]3测试DQLSQL SELECT * FROM (SELECT /*USE_NL(TAB1,TAB2)*/ ROWNUM,TAB1.* FROM ZXJ.TEST TAB1 FULL JOIN ZXJ.TEST TAB2 ON TAB1.A TAB2.A) PUB LIMIT 10;2 3 行号 ROWNUM A ---------- -------------------- ----------- 1 1 1 2 2 2 3 3 3 4 4 4 5 5 5 6 6 6 7 7 7 8 8 8 9 9 9 10 10 10 10 rows got 已用时间: 7.769(毫秒). 执行号:1013.SQL日志记录了此SQL的执行时间上面的例子没有是因为我们设置了最小执行时间MIN_EXEC_TIME 52025-02-14 10:06:46.961 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18052 stmt:0x7f3dc40151e0 appname:disql ip:::1) [ORA]: SELECT * FROM (SELECT /*USE_NL(TAB1,TAB2)*/ ROWNUM,TAB1.* FROM ZXJ.TEST TAB1 FULL JOIN ZXJ.TEST TAB2 ON TAB1.A TAB2.A) PUB LIMIT 10; 2025-02-14 10:06:46.964 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18052 stmt:0x7f3dc40151e0 appname:disql ip:::1) [SEL] SELECT * FROM (SELECT /*USE_NL(TAB1,TAB2)*/ ROWNUM,TAB1.* FROM ZXJ.TEST TAB1 FULL JOIN ZXJ.TEST TAB2 ON TAB1.A TAB2.A) PUB LIMIT 10; 2025-02-14 10:06:46.964 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18052 stmt:0x7f3dc40151e0 appname:disql ip:::1) DLCK used time:1(us) 2025-02-14 10:06:46.970 (EP[0] sess:0x7f3dc4019440 thrd:19112 user:SYSDBA trxid:18052 stmt:0x7f3dc40151e0 appname:disql ip:::1) [SEL] SELECT * FROM (SELECT /*USE_NL(TAB1,TAB2)*/ ROWNUM,TAB1.* FROM ZXJ.TEST TAB1 FULL JOIN ZXJ.TEST TAB2 ON TAB1.A TAB2.A) PUB LIMIT 10; EXECTIME: 6(ms) ROWCOUNT: 10(rows) EXEC_ID: 1013.5、SVR_LOG参数关闭SQL SP_SET_PARA_VALUE(1,SVR_LOG,0); DMSQL 过程已成功完成 已用时间: 12.938(毫秒). 执行号:1014.6、性能监视工具1启动[dmdbalocalhost tool]$ pwd /opt/Dm8/tool [dmdbalocalhost tool]$ ./monitor2登录3SQL日志文件分析
RELATED READING

延伸阅读

更多一线实战笔记与深度复盘,助您持续精进