Mybatis - 统计SQL执行时间

古城微笑少年丶 2023-09-27 19:19 5阅读 0赞

由于系统数据量较大，SQL执行十分低效，我们在做数据库优化时，想在日志中看到每个SQL执行的时间，以方便针对性的优化

## 一、切面编程@Aspect ##

此方案主要是通过环绕切面的方式将mapper包下的接口方法，然后前后计算时间差即可

1、引入aop包，使用[aspect][]切面编程

<dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-aop</artifactId>
        </dependency>

2、声明环绕通知方法

@Aspect
    @Component
    @Slf4j
    public class MapperAspect {
    
        @AfterReturning("execution(* com.xx.mapper.*Mapper.*(..))")
        public void logServiceAccess(JoinPoint joinPoint) {
            log.info("Completed: " + joinPoint);
        }
    
    
        /**
         * 监控com.xx.mapper..*Mapper包及其子包的所有public方法
         */
        @Pointcut("execution(* com.xx.mapper.*Mapper.*(..))")
        private void pointCutMethod() {
        }
    
        /**
         * 声明环绕通知
         *
         * @param pjp
         * @return
         * @throws Throwable
         */
        @Around("pointCutMethod()")
        public Object doAround(ProceedingJoinPoint pjp) throws Throwable {
            long begin = System.nanoTime();
            Object obj = pjp.proceed();
            long end = System.nanoTime();
    
            log.info("调用Mapper方法：{}，参数：{}，执行耗时：{}纳秒，耗时：{}毫秒",
                    pjp.getSignature().toString(), Arrays.toString(pjp.getArgs()),
                    (end - begin), (end - begin) / 1000000);
            return obj;
        }
    }

## 二、Mybatis插件 ##

理论上，业务开发过程中，要关注的是对mapper的接口方法耗时统计，mybatis执行sql的耗时统计应该是没有管sql[编译过程][Link 1]

MyBatis在四大对象的创建过程中，都会有插件进行介入。插件可以利用动态代理机制一层层的包装目标对象，而实现在目标对象执行目标方法之前进行拦截的效果。

MyBatis 允许在已映射语句执行过程中的某一点进行拦截调用。

默认情况下，MyBatis 允许使用插件来拦截的方法调用包括：

> 1、Executor(update, query, flushStatements, commit, rollback, getTransaction, close, isClosed) 　　
> 
> 2、ParameterHandler(getParameterObject, setParameters) 　　
> 
> 3、ResultSetHandler(handleResultSets, handleOutputParameters) 　
> 
> 4、StatementHandler(prepare, parameterize, batch, update, query)

import org.apache.ibatis.executor.statement.StatementHandler;
    import org.apache.ibatis.mapping.BoundSql;
    import org.apache.ibatis.mapping.ParameterMapping;
    import org.apache.ibatis.plugin.Interceptor;
    import org.apache.ibatis.plugin.Intercepts;
    import org.apache.ibatis.plugin.Invocation;
    import org.apache.ibatis.plugin.Plugin;
    import org.apache.ibatis.plugin.Signature;
    import org.apache.ibatis.session.ResultHandler;
    import org.slf4j.Logger;
    import org.slf4j.LoggerFactory;
    import org.springframework.stereotype.Component;
    
    import java.sql.Statement;
    import java.util.List;
    import java.util.Properties;
    
    /**
     * Sql执行时间记录拦截器
     */
    @Intercepts({@Signature(type = StatementHandler.class, method = "query", args = {Statement.class, ResultHandler.class}),
            @Signature(type = StatementHandler.class, method = "update", args = {Statement.class}),
            @Signature(type = StatementHandler.class, method = "batch", args = {Statement.class})})
    @Component
    public class SqlExecuteTimeCountInterceptor implements Interceptor {
    
        private static Logger logger = LoggerFactory.getLogger(SqlExecuteTimeCountInterceptor.class);
    
        /**
         * 打印的参数字符串的最大长度
         */
        private final static int MAX_PARAM_LENGTH = 50;
    
        /**
         * 记录的最大SQL长度
         */
        private final static int MAX_SQL_LENGTH = 200;
    
    
        @Override
        public Object intercept(Invocation invocation) throws Throwable {
            Object target = invocation.getTarget();
            long startTime = System.currentTimeMillis();
            StatementHandler statementHandler = (StatementHandler) target;
            try {
                return invocation.proceed();
            } finally {
                long endTime = System.currentTimeMillis();
                long timeCount = endTime - startTime;
    
                BoundSql boundSql = statementHandler.getBoundSql();
                String sql = boundSql.getSql();
                Object parameterObject = boundSql.getParameterObject();
                List<ParameterMapping> parameterMappingList = boundSql.getParameterMappings();
    
                // 格式化Sql语句，去除换行符，替换参数
                sql = formatSQL(sql, parameterObject, parameterMappingList);
    
                logger.info("执行 SQL：[ , {} ]执行耗时[ {} ms]", sql, timeCount);
            }
        }
    
    
        /**
         * 格式化/美化 SQL语句
         *
         * @param sql                  sql 语句
         * @param parameterObject      参数的Map
         * @param parameterMappingList 参数的List
         * @return 格式化之后的SQL
         */
        private String formatSQL(String sql, Object parameterObject, List<ParameterMapping> parameterMappingList) {
            // 输入sql字符串空判断
            if (sql == null || sql.length() == 0) {
                return "";
            }
            // 美化sql
            sql = beautifySql(sql);
            // 不传参数的场景，直接把sql美化一下返回出去
            if (parameterObject == null || parameterMappingList == null || parameterMappingList.size() == 0) {
                return sql;
            }
            return LimitSQLLength(sql);
        }
    
    
        /**
         * 返回限制长度之后的SQL语句
         *
         *
         * @param sql 原始SQL语句
         */
        private String LimitSQLLength(String sql) {
            if (sql == null || sql.length() == 0) {
                return "";
            }
            if (sql.length() > MAX_SQL_LENGTH) {
                return sql.substring(0, MAX_SQL_LENGTH);
            } else {
                return sql;
            }
        }
    
    
        @Override
        public Object plugin(Object target) {
            return Plugin.wrap(target, this);
        }
    
        @Override
        public void setProperties(Properties properties) {
    
        }
    
    
    
    
        /**
         * 替换SQL 中? 所对应的值, 只保留前50个字符
         *
         * @param sql     sql语句
         * @param valueOf ?对应的值
         */
        private String replaceValue(String sql, String valueOf) {
            //超过50个字符只取前50个
            if (valueOf != null && valueOf.length() > MAX_PARAM_LENGTH) {
                valueOf = valueOf.substring(0, MAX_PARAM_LENGTH);
            }
            sql = sql.replaceFirst("\\?", valueOf);
            return sql;
        }
    
        /**
         * 美化sql
         *
         * @param sql sql语句
         */
        private String beautifySql(String sql) {
            sql = sql.replaceAll("[\\s\n ]+", "  ");
            return sql;
        }
     }

## 三、Druid ##

平时用的最多的一种方案

Druid是一个非常好用的[数据库连接池][Link 2]，但是他的好并不止体现在作为一个连接池加快数据访问性能上和连接管理上，他带有一个强大的监控工具：**Druid Monitor**。不仅可以监控数据源和慢查询，还可以监控Web应用、URI监控、Session监控、Spring监控

#### 1、引入依赖 ####

<dependency>
                <groupId>com.alibaba</groupId>
                <artifactId>druid-spring-boot-starter</artifactId>
                <version>1.1.10</version>
            </dependency>
            
             <dependency>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-starter-web</artifactId>
            </dependency>

#### 2、Springboot+druid的配置application.yml文件如下 ####

spring:
        datasource:
            url: jdbc:mysql://localhost:3306/testdb1?characterEncoding=utf-8&useUnicode=true&useSSL=false&serverTimezone=UTC
            driver-class-name: com.mysql.jdbc.Driver  # mysql8.0以前使用com.mysql.jdbc.Driver
            username: root
            password: root
            platform: mysql
            #通过这句配置将druid连接池引入到我们的配置中，spring会尽可能判断类型是什么，然后根据情况去匹配驱动类。
            type: com.alibaba.druid.pool.DruidDataSource
            druid:
                initial-size: 5  # 初始化大小
                min-idle: 5  # 最小
                max-active: 100  # 最大
                max-wait: 60000  # 配置获取连接等待超时的时间
                time-between-eviction-runs-millis: 60000  # 配置间隔多久才进行一次检测，检测需要关闭的空闲连接，单位是毫秒
                min-evictable-idle-time-millis: 300000  # 指定一个空闲连接最少空闲多久后可被清除，单位是毫秒
                validationQuery: select 'x'
                test-while-idle: true  # 当连接空闲时，是否执行连接测试
                test-on-borrow: false  # 当从连接池借用连接时，是否测试该连接
                test-on-return: false  # 在连接归还到连接池时是否测试该连接
                filters: config,wall,stat  # 配置监控统计拦截的filters，去掉后监控界面sql无法统计，'wall'用于防火墙
                poolPreparedStatements: true # 打开PSCache，并且指定每个连接上PSCache的大小
                maxPoolPreparedStatementPerConnectionSize: 20
                maxOpenPreparedStatements: 20
                # 通过connectProperties属性来打开mergeSql功能；慢SQL记录
                connectionProperties: druid.stat.slowSqlMillis=200;druid.stat.logSlowSql=true;config.decrypt=false
                 # 合并多个DruidDataSource的监控数据
                
                #监控信息   localhost:${server.port}/druid/login.html
                #StatViewServlet配置，说明请参考Druid Wiki，配置_StatViewServlet配置
                stat-view-servlet:
                    enabled: true #是否启用StatViewServlet默认值true
                    url-pattern: /druid/*
                    reset-enable: true
                    login-username: admin
                    login-password: admin
                #url监控
                #use-global-data-source-stat: true
                #WebStatFilter配置，说明请参考Druid Wiki，配置_配置WebStatFilter
                web-stat-filter:
                    enabled: true #是否启用StatFilter默认值true
                    url-pattern: /*
                    exclusions: /druid/*,*.js,*.gif,*.jpg,*.bmp,*.png,*.css,*.ico
                    session-stat-enable: true
                    session-stat-max-count: 10

#### 3、spring.datasource.druid配置监控的属性如下 ####

<table style="width:650px;"> 
 <tbody> 
  <tr> 
   <th>属性</th> 
   <th>功能描述</th> 
  </tr> 
  <tr> 
   <td>login-username,login-password</td> 
   <td>设置登录的帐号密码</td> 
  </tr> 
  <tr> 
   <td>allow</td> 
   <td>设置登录的机器</td> 
  </tr> 
  <tr> 
   <td>stat-view-servlet.enabled</td> 
   <td>设置sql监控的开关</td> 
  </tr> 
  <tr> 
   <td>web-stat-filter.enabled</td> 
   <td>设置url监控开关</td> 
  </tr> 
  <tr> 
   <td>session-stat-enable</td> 
   <td>设置session监控的开关</td> 
  </tr> 
  <tr> 
   <td>log-slow-sql</td> 
   <td>设置打印慢sql 日志</td> 
  </tr> 
 </tbody> 
</table>

#### 4、访问druid监控页面 ####

端口号需要换成你项目的  
访问：

**http://localhost:port/druid/login.html**

输入 配置文件配置的帐号密码登录

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21pbmcxOTk1MTIyNA_size_16_color_FFFFFF_t_70]

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21pbmcxOTk1MTIyNA_size_16_color_FFFFFF_t_70 1]

#### 5、去除广告 ####

@Configuration
    @ConditionalOnWebApplication
    @AutoConfigureAfter(DruidDataSourceAutoConfigure.class)
    @ConditionalOnProperty(name = "spring.datasource.druid.stat-view-servlet.enabled", havingValue = "true",
            matchIfMissing = true)
    public class RemoveDruidAdConfig {
    
        /**
         * 除去页面底部的广告
         */
        @Bean
        public FilterRegistrationBean removeDruidAdFilterRegistrationBean(DruidStatProperties properties) {
            // 获取web监控页面的参数
            DruidStatProperties.StatViewServlet config = properties.getStatViewServlet();
            // 提取common.js的配置路径
            String pattern = config.getUrlPattern() != null ? config.getUrlPattern() : "/druid/*";
            String commonJsPattern = pattern.replaceAll("\\*", "js/common.js");
    
            final String filePath = "support/http/resources/js/common.js";
    
            //创建filter进行过滤
            Filter filter = new Filter() {
                @Override
                public void init(FilterConfig filterConfig) throws ServletException {
                }
    
                @Override
                public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws
                        IOException, ServletException {
                    chain.doFilter(request, response);
                    // 重置缓冲区，响应头不会被重置
                    response.resetBuffer();
                    // 获取common.js
                    String text = Utils.readFromResource(filePath);
                    // 正则替换banner, 除去底部的广告信息
                    text = text.replaceAll("<a.*?banner\"></a><br/>", "");
                    text = text.replaceAll("powered.*?shrek.wang</a>", "");
                    response.getWriter().write(text);
                }
    
                @Override
                public void destroy() {
                }
            };
            FilterRegistrationBean registrationBean = new FilterRegistrationBean();
            registrationBean.setFilter(filter);
            registrationBean.addUrlPatterns(commonJsPattern);
            return registrationBean;
        }
    
    }

[【SpringBoot框架篇】12.使用druid的monitor工具查看sql执行性能\_druid moniter的端口如何修改\_皓亮君的博客-CSDN博客][SpringBoot_12._druid_monitor_sql_druid moniter_-CSDN]

[aspect]: https://so.csdn.net/so/search?q=aspect&spm=1001.2101.3001.7020
[Link 1]: https://so.csdn.net/so/search?q=%E7%BC%96%E8%AF%91%E8%BF%87%E7%A8%8B&spm=1001.2101.3001.7020
[Link 2]: https://so.csdn.net/so/search?q=%E6%95%B0%E6%8D%AE%E5%BA%93%E8%BF%9E%E6%8E%A5%E6%B1%A0&spm=1001.2101.3001.7020
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21pbmcxOTk1MTIyNA_size_16_color_FFFFFF_t_70]: https://img-blog.csdnimg.cn/20200524173233542.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21pbmcxOTk1MTIyNA==,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21pbmcxOTk1MTIyNA_size_16_color_FFFFFF_t_70 1]: https://img-blog.csdnimg.cn/20200524173641415.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21pbmcxOTk1MTIyNA==,size_16,color_FFFFFF,t_70
[SpringBoot_12._druid_monitor_sql_druid moniter_-CSDN]: https://blog.csdn.net/ming19951224/article/details/106317893/