Springboot慢SQL日志输出改造

一. 前言

最近在优化日志记录方案，但发现输出到控制台的日志在只开启INFO的情况下看不到慢SQL是出自哪个接口，如下图所示。

因为我们的判断接口的日志是Debug层的，而Druid自带的ERROR层输出的慢SQL不显示调用来自于哪个mapper或者那里一个controller。

于是就想了两种方案：

1. 在所有接口调用前加一个INFO级别的接口输出
2. 修改慢SQL的ERROR控制台输出日志

比较了一下，肯定是后者更好，因为每一个接口都输出一次，也是无用的输出。其他ERROR级别的输出，都会把调用栈给输出出来，只有Druid的慢SQL没有该输出。

二. 方案实现

下面我将会一次展示一下两种方案的实现，都是在若依的架构下实现的。

但是脱离若依，前者用Spring自带的拦截器，后者用com.alibaba.druid的连接池实现，若依的慢SQL就是用的Druid，所以但凡使用的Druid都可以以此作为参考。

方案一：INFO统一加

INFO级别，每一个接口调用，就展示一次。这是要用Spring中的拦截器实现。需要两个类。

• 拦截器类：用于业务代码的实现
• 声明配置类：实现类托管给Spring容器

下面是两个具体实现：

A. 拦截器

package com.cockpit.framework.interceptor.impl;

import org.springframework.web.method.HandlerMethod;
import org.springframework.web.servlet.HandlerInterceptor;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import static com.cockpit.framework.datasource.DynamicDataSourceContextHolder.log;

public class ApiLogInterceptor implements HandlerInterceptor {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {

        // 确保拦截的是Controller方法，排除静态资源请求等
        if (handler instanceof HandlerMethod) {
            HandlerMethod handlerMethod = (HandlerMethod) handler;

            // 获取目标控制器类的全限定名
            String className = handlerMethod.getBeanType().getName();
            // 获取执行的方法名
            String methodName = handlerMethod.getMethod().getName();

            // 拼接成你需要的格式，例如：c.c.c.m.i.g.P.getArea
            String fullMethodName = className + "." + methodName;

            // 使用INFO级别输出日志
            log.info("API Access: {}", fullMethodName);
        }
        // 继续执行后续拦截器及控制器方法
        return true;
    }
}

B. 配置类

package com.cockpit.framework.config;

import com.cockpit.framework.interceptor.impl.ApiLogInterceptor;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

@Configuration
public class WebMvcConfig implements WebMvcConfigurer {
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(new ApiLogInterceptor())
                .addPathPatterns("/**"); // 拦截所有路径
    }
}

C. 结果

可以看到在上面加上了一个INFO级别的日志输出

方案二：单加慢SQL

ERROR级别的输出一般情况下出现问题，都会把调用栈返回。但是Druid的慢SQL报错没有，这边的方案是直接继承Druid的慢SQL过滤器中的实现方法进行过程的修改。

修改内容包括三方面。

• 过滤器：继承与重实现Druid中的StatFilter
• 声明配置类：讲实现类托管给Spring容器
• 配置文件修改：中加入需要输出的接口路径

下面的代码有些文件夹路径需要根据自己的文件夹修改。

A. 过滤器

因为一些其他的业务需求，加了很多其他的业务实现代码，包括了：

• 全限定名简化版：例如：com.cockpit.web.controller.UserController -> c.c.w.c.UserController
• 数据源信息：数据源url，直接把配置文件里的url给输出出来
• 表名：讲from、join等等后面的表名输出，包括了临时表名
• 正常SQL

package com.cockpit.framework.filter;

import com.alibaba.druid.DbType;
import com.alibaba.druid.filter.stat.StatFilter;
import com.alibaba.druid.proxy.jdbc.StatementProxy;
import com.alibaba.druid.sql.parser.SQLParserUtils;
import com.cockpit.framework.datasource.DynamicDataSourceContextHolder;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.core.env.Environment;

import javax.annotation.Resource;
import java.util.List;

public class SlowSqlLocationFilter extends StatFilter {

    @Resource
    private Environment environment;

    private static final Logger LOG = LoggerFactory.getLogger(SlowSqlLocationFilter.class);

    // 需要输出的接口路径
    @Value("${spring.datasource.druid.filter.stat.api-path}")
    private String filePathPrefix;

    /**
     * 只要 SQL 达到慢查询阈值，Druid 就会回调这个方法（空实现留给用户扩展）
     */
    @Override
    protected void handleSlowSql(StatementProxy statement) {
        /* 1. 拿执行耗时（毫秒） */
        long millis = statement.getLastExecuteTimeNano() / 1_000_000;

        /* 2. 拿 SQL */
        String sql = statement.getLastExecuteSql();

        /* 3. 从当前线程堆栈里找第一条业务代码 */
        String location = parseLocation();

        String dataSourceInfo = DynamicDataSourceContextHolder.getDataSourceType();

        String url = getUrlByDataSourceType(dataSourceInfo);

        List<String> tables = SQLParserUtils.getTables(sql, DbType.mysql);
        String tablesStr = !tables.isEmpty() ?
                "[" + tables.stream()
                        .filter(table -> table != null && !table.trim().isEmpty())
                        .collect(java.util.stream.Collectors.joining(",")) + "]"
                : "[]";

        /* 4. 拼日志 */
        LOG.error("slow sql {} millis , " +
                        "location => {}, " +
                        "dataSourceInfo => {}, " +
                        "url => {}, " +
                        "tables => {}, " +
                        "sql => {}"
                , millis, location, dataSourceInfo, url, tablesStr, sql);
    }

    /**
     * 简单定位：第一个业务包名
     */
    private String parseLocation() {
        StackTraceElement[] arr = Thread.currentThread().getStackTrace();
        for (StackTraceElement e : arr) {
            String clazz = e.getClassName();
            if (clazz.startsWith(filePathPrefix)) {
                // 获取类名并转换为首字母缩写
                String className = e.getClassName();
                String abbreviatedPath = getAbbreviatedPath(className);
                return abbreviatedPath + "." + e.getMethodName() + ":" + e.getLineNumber();
            }
        }
        return "unknown";
    }

    /**
     * 将完整类路径转换为首字母缩写
     * 例如：com.cockpit.web.controller.UserController -> c.c.w.c.UserController
     */
    private String getAbbreviatedPath(String fullClassName) {
        String[] packages = fullClassName.split("\\.");
        StringBuilder sb = new StringBuilder();

        for (int i = 0; i < packages.length - 1; i++) { // 排除最后一个部分（类名）
            if (!packages[i].isEmpty()) {
                sb.append(packages[i].charAt(0));
                if (i < packages.length - 2) { // 不是最后一个包部分时添加点
                    sb.append(".");
                }
            }
        }

        // 获取类名部分（最后一个部分）
        String className = packages[packages.length - 1];

        // 如果有包路径，返回缩写路径 + 点 + 类名；否则只返回类名
        return sb.length() > 0 ? sb.toString() + "." + className : className;
    }

    /**
     * 动态获取数据源url
     *
     * @param dataSourceType
     * @return
     */
    private String getUrlByDataSourceType(String dataSourceType) {
        if (dataSourceType == null) {
            return "unknown";
        }

        String configKey = "spring.datasource.druid." + dataSourceType.toLowerCase() + ".url";
        return environment.getProperty(configKey, "unknown");
    }

    /**
     * 测试方法
     * @param args
     */
    public static void main(String[] args) {
        String sql = "with t as (select a.id from user a join order_info b on a.id=b.user_id) " +
                "insert into stat_user select * from t inner join (select from cake) t2 ";
        List<String> tables = SQLParserUtils.getTables(sql, DbType.mysql);
        System.out.println(tables);
    }
}

B. 配置类

里面动态注入了很多原本就写在配置文件里的配置类，保持原本的慢SQL配置不变。

package com.cockpit.framework.config;

import com.alibaba.druid.filter.stat.StatFilter;
import com.cockpit.framework.filter.SlowSqlLocationFilter;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class DruidFilterConfig {

    @Value("${spring.datasource.druid.filter.stat.slow-sql-millis}")
    private int slowSqlMillis;

    @Value("${spring.datasource.druid.filter.stat.log-slow-sql}")
    private boolean logSlowSql;

    @Value("${spring.datasource.druid.filter.stat.merge-sql}")
    private boolean mergeSql;

    /**
     * 注意：必须返回 StatFilter 才能替换掉 Druid 内置的 stat
     */
    @Bean
    public StatFilter statFilter() {
        StatFilter filter = logSlowSql ? new SlowSqlLocationFilter() : new StatFilter();
        filter.setLogSlowSql(false);    // 关闭原生的 slowSqlLog
        filter.setSlowSqlMillis(slowSqlMillis);   // 与 yml 里保持一致
        filter.setMergeSql(mergeSql);
        return filter;                 // 返回 StatFilter 类型，Druid 会自动识别
    }
}

C. 配置文件修改

在配置文件application-prod、application-test中对应路径下加入变量api-path，值为我们controller的路径。（PS：两个配置文件中都要加，各个项目中路径可能略有不同）。其余的一些配置是Druid原本就需要配置的。

D. 结果

如图所示，将所需的内容都进行了相应的输出，到时候使用时，只需通过excel或者正则提取相应的内容即可。

三. 后记

• 问题解决回顾：成功解决了Druid慢SQL日志无法定位接口的问题，通过自定义过滤器实现了详细的调用位置追踪
• 方案对比分析：
  • 方案一（拦截器）：简单直接，但会产生大量冗余日志
  • 方案二（自定义过滤器）：精准定位，只在慢SQL时输出，更加高效实用