达梦8 分析sqllog的一个实用脚本

日常运维进行性能调优时经常需要查找哪些SQL语句执行次数最多、时间最长。

达梦数据库跟ORACLE一样，有AWR报告功能模块用于DBA调优参考。但在实际应用中发现达梦的AWR功能存在诸多问题，原厂工程师答复正在开发中目前不要使用该功能。那么怎么分析SQL呢？如果数据库安装时打开了sqllog功能（SVR_LOG=1）,那么下面的实用脚本或许能带来一些帮助。

因为达梦的版本更新速度比较快，使用界面可能莫名变化。因此执行统计脚本前先使用如下方法查看时间统计是否为MS（毫秒）。如果时间计算单位混合MS和S，那么还需要改良脚本对不同单位的时间进行换算。

#dmsql_TEST2_20231223_000329.log为日志名，需要替换为实际名字
cat  dmsql_TEST2_20231223_000329.log | egrep '\[SEL\]|\[UPD\]|\[DEL\]|\[INS\]' | grep EXECTIME: | awk -FSEL] '{print $2 }' |  while read SQL_EXEC
do
   SQL=`echo $SQL_EXEC | awk -F\EXECTIME: '{print $1 }'`
   echo $SQL_EXEC | awk -F\EXECTIME: '{print $2 }' | awk '{print $1 }' | awk -F\( '{print $2}' | awk -F\) '{print $1 }'
done | sort -u

如果时间计算单位唯一，比如都是MS，则可以运行如下脚本进行统计：

#本次只统计select语句，如果统计update语句则将awk -FSEL]修改为awk -FUPD]
cat  dmsql_TEST2_20231223_000329.log | egrep '\[SEL\]|\[UPD\]|\[DEL\]|\[INS\]' | grep EXECTIME: | awk -FSEL] '{print $2 }' | grep -v ^$ | while read SQL_EXEC
do
   SQL=`echo "$SQL_EXEC" | awk -F\EXECTIME: '{print $1 }'`
   EXEC_TIME=`echo $SQL_EXEC | awk -F\EXECTIME: '{print $2 }' | awk '{print $1 }' | awk -F\( '{print $1}'`
   ROWCOUNT=`echo $SQL_EXEC | awk -F\ROWCOUNT: '{print $2 }' | awk -F\( '{print $1}'`
   echo "$SQL | $EXEC_TIME | $ROWCOUNT "
done | awk -F\| '{EXEC_COUNT[$1]++;EXEC_TIME[$1]+=$2;if(EXEC_TIME_MAX[$1]>$2){j=0}else{EXEC_TIME_MAX[$1]=$2};if(EXEC_COUNT[$1]==1){EXEC_TIME_MIN[$1]=$2}else{if(EXEC_TIME_MIN[$1]>$2){EXEC_TIME_MIN[$1]=$2}};ROWCOUNT[$1]+=$3}END{print "" ;printf("%-40s %-15s %-15s %-15s %-15s %-15s %-15s %-15s\n", "SQL","EXEC_COUNT" ,"elapsed" ,"elapsed_avg" ,"elapsed_max" ,"elapsed_min" ," rowcount"," rowcount_avg");for(i in EXEC_COUNT){printf("%-40s %-15s %-15s %-15s %-15s %-15s %-15s %-15s\n",i,EXEC_COUNT[i],EXEC_TIME[i],EXEC_TIME[i]/EXEC_COUNT[i],EXEC_TIME_MAX[i],EXEC_TIME_MIN[i],ROWCOUNT[i],ROWCOUNT[i]/EXEC_COUNT[i])}}'

输出如下：

如上图可见，可以统计出当前日志中记录的每条SQL语句的执行次数、累计执行时间、单次平均时间、最大单次执行时间，最小单次执行时间、累计处理行数，平均每次执行处理行数。

值得注意的是实际生产环境的SQL可能比较长，上面的报表很难按行整齐排列。因此我们把统计脚本改造成两个：

1、将SQL语句替换成md5校验码

cat  dmsql_TEST2_20231223_000329.log | egrep '\[SEL\]|\[UPD\]|\[DEL\]|\[INS\]' | grep EXECTIME: | awk -FSEL] '{print $2 }' | grep -v ^$ | while read SQL_EXEC
do
   SQL=`echo "$SQL_EXEC" | awk -F\EXECTIME: '{print $1 }'`
   SQL_MD5=`echo "$SQL" | md5sum | awk '{print $1 }'`
   EXEC_TIME=`echo $SQL_EXEC | awk -F\EXECTIME: '{print $2 }' | awk '{print $1 }' | awk -F\( '{print $1}'`
   ROWCOUNT=`echo $SQL_EXEC | awk -F\ROWCOUNT: '{print $2 }' | awk -F\( '{print $1}'`
   echo "$SQL_MD5 | $EXEC_TIME | $ROWCOUNT "
done | awk -F\| '{EXEC_COUNT[$1]++;EXEC_TIME[$1]+=$2;if(EXEC_TIME_MAX[$1]>$2){j=0}else{EXEC_TIME_MAX[$1]=$2};if(EXEC_COUNT[$1]==1){EXEC_TIME_MIN[$1]=$2;ROWCOUNT_MIN[$1]=$3;;ROWCOUNT_MAX[$1]=$3}else{if(EXEC_TIME_MIN[$1]>$2){EXEC_TIME_MIN[$1]=$2};if(ROWCOUNT_MAX[$1]<$3){ROWCOUNT_MAX[$1]=$3};if(ROWCOUNT_MIN[$1]>$3){ROWCOUNT_MIN[$1]=$3}};ROWCOUNT[$1]+=$3}END{print "" ;printf("%-35s %-12s %-12s %-12s %-12s %-12s %-12s %-12s %-12s %-12s\n", "SQL_MD5","EXEC_COUNT" ,"elapsed" ,"elapsed_avg" ,"elapsed_max" ,"elapsed_min" ," rowcount"," rowcount_avg","rowcount_max","rowcount_min");for(i in EXEC_COUNT){printf("%-35s %-12s %-12s %-12s %-12s %-12s %-12s %-12s %-12s %-12s\n",i,EXEC_COUNT[i],EXEC_TIME[i],EXEC_TIME[i]/EXEC_COUNT[i],EXEC_TIME_MAX[i],EXEC_TIME_MIN[i],ROWCOUNT[i],ROWCOUNT[i]/EXEC_COUNT[i],ROWCOUNT_MAX[i],ROWCOUNT_MIN[i])}}'

如上图可见，可以统计出当前日志中记录的每条SQL语句的执行次数、累计执行时间、单次平均时间、最大单次执行时间，最小单次执行时间、累计处理行数，平均每次执行处理行数、单次最大处理行数、单次最小处理行数

2、列出SQL语句和md5校验码对应关系

cat  dmsql_TEST2_20231223_000329.log | egrep '\[SEL\]|\[UPD\]|\[DEL\]|\[INS\]' | grep EXECTIME: | awk -FSEL] '{print $2 }' | grep -v ^$ | while read SQL_EXEC
do
   SQL=`echo "$SQL_EXEC" | awk -F\EXECTIME: '{print $1 }'`
   SQL_MD5=`echo "$SQL" | md5sum | awk '{print $1 }'`
   echo "${SQL_MD5}|${SQL}" 
done | sort -u | awk -F\| 'BEGIN{printf("%-35s %-80s\n","SQL_MD5","SQL");printf("%-35s %-80s\n","---------","---------")}{printf("%-35s %-80s\n",$1,$2)}'