企业官网建设流程全解析

先从一个真实的排查场景说起。有一次联调，前端同事跑过来跟我说某个列表接口特别慢，问我是不是SQL写得有问题。我打开控制台一看，日志里干干净净，连这条SQL的影子都没有。没有执行方法、没有完整SQL、没有耗时，我只能凭记忆把代码里拼好的SQL复制到数据库客户端里手动跑一遍，再回头看接口层到底慢在哪。整个排查流程基本靠猜，特别耽误事。

后来我在项目里认真整理了一套Mybatis控制台打印SQL执行信息的方案，覆盖了标题里说的三个核心要素：执行方法、执行SQL、执行时间。这套方案没有用外挂组件，也没有侵入业务代码，主要靠Mybatis的日志适配配置和自定义拦截器两条路走。今天就把整个思路、代码、踩过的坑都写出来，适合正在用Spring Boot + Mybatis或Mybatis-Plus做开发的兄弟们参考。

1. 为什么控制台需要这样一份SQL执行日志

1.1 没有SQL日志时的排查困境

后端开发里，“对不上数”的问题最让人头疼。比如前端说列表少了三条数据，你第一反应肯定是去查SQL条件，但代码里SQL是拼在XML里的，参数是从三层调用链一路传下来的，等到你真正想确认执行时，光靠人肉推演根本看不出来问题出在哪一环。更常见的是慢查询场景，一个接口响应要5秒，你无法判断是网络开销、服务间调用慢，还是数据库执行慢。如果没有一条带耗时的SQL日志，所有的推测都只能停留在猜阶段。

还有一个容易被忽略的场景：批量更新。比如遍历一千个订单做状态流转，万一中间某条数据更新失败，你只能在异常堆栈里看个大概，看不到到底是哪条SQL、哪个参数出的问题。这种情况下，能在控制台直接还原当时执行的SQL片段、参数值和耗时，定位成本就会低很多。

1.2 三种常见方案怎么选

围绕“打印SQL执行信息”，业内其实已经有几种成熟做法，我先列个表对比一下，后面再逐个展开。

个人建议是：如果你只想知道项目里有没有执行某条SQL，用StdOutImpl就够了，十秒钟搞定。但如果你像我一样，需要同时看到执行方法、完整的可执行SQL、执行时间，甚至想对慢SQL做标记，那必须上拦截器。上面两个方案不冲突，但一般建议选一个用，避免重复输出。

2. 先跑通官方方案：日志配置与原理

2.1 Mybatis的日志适配器是如何选型的

Mybatis内部有一套日志适配逻辑，核心在LogFactory这个类里。它会按顺序查找项目里可用的日志实现，常见的顺序是slf4j、commons-logging、log4j2、log4j、java.util.logging，最后兜底才用StdOutImpl。如果项目里同时存在多个日志框架，Mybatis会优先选择它认为更合适的，这一步是自动完成的。

我们可以通过配置参数强行指定日志实现，让它不再自动寻找。这也是解决“配置了logback但SQL日志死活不出来”的关键思路：直接告诉Mybatis，用哪一个日志适配器。

对应到配置上，就是log-impl这个参数。在Spring Boot项目里，如果是原生Mybatis，配置前缀是mybatis.configuration.log-impl；如果是Mybatis-Plus，前缀换成mybatis-plus.configuration.log-impl。它们的值都是完整的类名，常见两个：

• org.apache.ibatis.logging.stdout.StdOutImpl：直接打印到标准输出，不经过logback
• org.apache.ibatis.logging.slf4j.Slf4jImpl：输出到slf4j，再由logback或log4j2控制

2.2 配置文件实操

以我的一个模拟项目X为例，项目用的Spring Boot，数据库是MySQL，ORM是Mybatis-Plus。最快让SQL打出来的方式就是在application.yml里加上：

mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.stdout.StdOutImpl

改完重启项目，执行一个查询，控制台就会输出类似下面的内容：

==> Preparing: SELECT id,name,age FROM user WHERE id = ? ==> Parameters: 1001(String) <== Columns: id, name, age <== Row: 1001, 张三, 18

注意一件事：StdOutImpl是绕过了logback直接打印的，所以你再怎么调logback的级别都拦不住它，输出格式也被写死，没法自定义。而且它看不到耗时，参数也是单独打印，和标题里要求的“执行方法、执行SQL、执行时间”还有差距。

如果不想用StdOutImpl，想走logback的日志体系，配置改成Slf4jImpl：

mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl

然后必须保证mapper接口所在的包日志级别是DEBUG。logback.xml里加一行：

<logger name="com.example.mapper" level="DEBUG"/>

这样配置后，SQL日志才会通过slf4j进入logback，并按你设定的appender输出到控制台或文件。很多人在这里踩坑：配了Slf4jImpl，但logback的root级别是INFO，mapper包也没单独调级别，结果SQL日志被过滤掉了。

2.3 官方方案的两个局限

官方方案最大的问题是跟“排查慢SQL”绑定不深。它只能告诉你SQL是什么、参数是什么，但不会告诉你这条SQL从发起到返回总共花了多久。第二个问题是SQL文本里带的还是?占位符，参数单独一行输出，你没法直接从日志里复制一条可以扔进客户端执行的完整SQL，每次还得人工把参数替换进去。

这就回到了文章开头说的场景：你查一个问题，需要把执行方法、完整可执行SQL、耗时放在同一屏里看。官方方案给不了，就只能自己动手写拦截器。

3. 核心进阶：自定义拦截器打印方法、SQL与耗时

3.1 为什么选择拦截Executor层

Mybatis把一次数据库操作拆成了多个层次：SqlSession、Executor、StatementHandler、ParameterHandler、ResultSetHandler。很多人一听说打印SQL，第一反应是去拦截StatementHandler，因为它是处理PreparedStatement的地方，SQL在这里最接近JDBC形态。

但真正落地时我更推荐拦截Executor。原因有两点。第一，Executor是Mybatis执行增删改查的顶层调度者，不管是Mapper接口方法还是SqlSession直接调用，最终都走Executor的query或update方法，拦截它就能覆盖全部操作，漏网概率最低。第二，Executor方法的入参里有MappedStatement，这个对象里保存了完整的SQL信息，同时它的getId()方法返回的恰好是Mapper接口的全限定名加上方法名，这就是我们要的“执行方法”字段，天然匹配标题需求。

对比之下，拦截StatementHandler虽然也能拿到SQL，但拿到的是预编译后的SQL，要往上追溯执行方法还得再绕一步，而且它是Executor内部调用的，同一个SQL会经过多次，容易重复拦截。综合下来，Executor是性价比最高的拦截点。

3.2 拦截器的完整实现

我直接贴一份我在项目里用的完整代码，这是基于常见开源方案简化后稳定运行过的版本，注释都写在里面了。

@Intercepts({ @Signature( type = Executor.class, method = "update", args = {MappedStatement.class, Object.class} ), @Signature( type = Executor.class, method = "query", args = {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class} ) }) public class SqlLogInterceptor implements Interceptor { private static final Logger log = LoggerFactory.getLogger(SqlLogInterceptor.class); /** * 慢SQL阈值，单位毫秒，通过properties配置 */ private long slowSqlMillis = 2000; @Override public Object intercept(Invocation invocation) throws Throwable { long startTime = System.currentTimeMillis(); try { return invocation.proceed(); } finally { long costTime = System.currentTimeMillis() - startTime; printSql(invocation, costTime); } } private void printSql(Invocation invocation, long costTime) { MappedStatement mappedStatement = (MappedStatement) invocation.getArgs()[0]; Object parameter = invocation.getArgs()[1]; // 执行方法，也就是Mapper接口的全限定名+方法名 String methodId = mappedStatement.getId(); // 通过MappedStatement获取绑定的SQL，这里拿到的还是带?占位符的原始SQL BoundSql boundSql = mappedStatement.getBoundSql(parameter); // 压缩空白字符，方便控制台阅读 String originalSql = boundSql.getSql().replaceAll("\\s+", " ").trim(); // 把参数绑定到SQL上，生成一条可直接执行的完整SQL String executedSql = assembleSql(originalSql, boundSql, parameter); // 根据耗时决定日志级别 String logLine = String.format( "方法:[%s]\nSQL:[%s]\n耗时:[%d ms]", methodId, executedSql, costTime ); if (costTime > slowSqlMillis) { log.warn("慢SQL，耗时超过 {} ms\n{}", slowSqlMillis, logLine); } else { log.info("SQL执行详情\n{}", logLine); } } private String assembleSql(String sql, BoundSql boundSql, Object parameter) { List<ParameterMapping> mappings = boundSql.getParameterMappings(); for (ParameterMapping mapping : mappings) { String property = mapping.getProperty(); Object value = getParamValue(boundSql, parameter, property); String valueStr = formatParamValue(value); // 只替换第一个未处理的占位符，保留前面的处理结果 sql = sql.replaceFirst("\\?", valueStr); } return sql; } private Object getParamValue(BoundSql boundSql, Object parameter, String property) { // 先从额外参数中取，比如foreach循环产生的参数 if (boundSql.hasAdditionalParameter(property)) { return boundSql.getAdditionalParameter(property); } // 单参数直接返回 if (parameter == null) { return null; } // 处理Map参数，Mybatis多参数会包装成ParamMap if (parameter instanceof Map) { Map<?, ?> map = (Map<?, ?>) parameter; if (map.containsKey(property)) { return map.get(property); } // 兼容@Param注解外的单参数场景，比如直接用collection/array return map; } // 普通POJO参数，通过MetaObject反射取值 Configuration configuration = mappedStatement.getConfiguration(); MetaObject metaObject = configuration.newMetaObject(parameter); if (metaObject.hasGetter(property)) { return metaObject.getValue(property); } return parameter; } private String formatParamValue(Object value) { if (value == null) { return "NULL"; } if (value instanceof Number) { return value.toString(); } if (value instanceof Boolean) { return value.toString(); } if (value instanceof java.util.Date) { return "'" + new java.text.SimpleDateFormat("yyyy-MM-dd HH:mm:ss").format(value) + "'"; } // 字符串及其它类型统一加单引号 return "'" + value + "'"; } @Override public Object plugin(Object target) { return Plugin.wrap(target, this); } @Override public void setProperties(Properties properties) { String slow = properties.getProperty("slowSqlMillis"); if (slow != null && slow.matches("\\d+")) { this.slowSqlMillis = Long.parseLong(slow); } } }

这段代码里最值得留意的几个点，我拆开说。

3.3 SQL参数绑定的实现细节

参数绑定是核心难点。Mybatis默认输出的SQL是PreparedStatement的形式，?占位符，参数单独走参数处理器。我们想让控制台直接出现一条“看起来能自己跑”的SQL，就得把?替换成真实参数值。

上面代码里assembleSql做的事就是这个。它的原理很简单：遍历BoundSql里的参数映射，依次把每个?替换成格式化后的参数值。格式化时区分了数字、布尔、日期和字符串：数字和布尔不加引号，字符串和日期加单引号，null就打印NULL。这样生成的SQL不仅能看，还能直接丢进数据库客户端执行。

注意一个容易踩的坑：字符串参数里如果本身带单引号，比如姓名叫O'Brien，直接拼接SQL会把语法破坏。我现在的处理方式没有做转义，因为设计目标只是“方便人肉眼排查”，不是真的拿去执行。如果你想更严谨，可以在formatParamValue里对单引号做一次替换，把单引号替换成两个单引号，但打印出来会显得有点怪，个人觉得没必要。

getParamValue方法的处理逻辑也值得说清楚。Mybatis在执行时，参数封装情况有三种：

• 单值参数：比如方法签名是selectById(Long id)，参数对象往往就是Long本身，但BoundSql里的参数映射property可能是id，也可能是一个自定义的占位名。此时直接返回parameter即可。
• Map参数：多参数方法或带有@Param注解的方法，Mybatis会包装成一个Map，key是参数名或param1、param2这类下标。
• POJO参数：直接传入对象，Mybatis会通过反射取属性值。

所以我用了一个兜底逻辑：先看BoundSql的附加参数，再看是不是Map，最后通过MetaObject反射取属性值，实在取不到就直接返回整个参数对象。这套逻辑覆盖了大多数增删改查场景，实测下来没有大问题。

另外，如果遇到foreach批量插入这种复杂SQL，参数映射里会出现list[0].name、list[1].age这类索引路径，上面的MetaObject取值也能处理，因为它内部能解析下标访问。实在取不到的时候，返回整个list或数组也能看出大概，毕竟定位问题不差这一步。

3.4 执行耗时统计与慢SQL输出

耗时统计在intercept方法里就做了，调用invocation.proceed()前后各取一个时间戳。这个耗时看起来简单，但含义要说清楚：它是整个Executor执行链路的时间，包含获取数据库连接、预编译、执行、结果映射的全过程。它不是数据库执行SQL的纯耗时，但对定位接口慢已经足够了，因为它是从应用视角看到的最真实成本。

这里有个排障技巧。某次我负责一个统计报表接口，页面数据一直出得慢，用System.currentTimeMillis()统计后发现SQL执行要1.8秒，但把这条SQL拿到数据库客户端里手动执行只花了300毫秒。这说明瓶颈不在SQL本身，而在连接获取或事务处理。后来查下来是连接池配置过小，线程在排队拿连接。如果只盯SQL执行时长的表面数字，这个方向很难想到。

时间统计还有另一个细节，就是finally块里做日志输出。这样做的好处是，就算SQL执行抛了异常，控制台也能看到方法、SQL和耗时，对排查执行失败的问题特别有帮助。日志级别上，超过慢SQL阈值就用warn，标记出来；正常SQL就用info，避免刷屏。

慢SQL阈值通过setProperties方法注入，在Spring Boot注册Bean的时候指定。示例配置：

@Bean public SqlLogInterceptor sqlLogInterceptor() { SqlLogInterceptor interceptor = new SqlLogInterceptor(); Properties properties = new Properties(); properties.setProperty("slowSqlMillis", "2000"); interceptor.setProperties(properties); return interceptor; }

如果你用的是XML配置，也可以在mybatis-config.xml里这样注册：

<plugins> <plugin interceptor="com.example.interceptor.SqlLogInterceptor"> <property name="slowSqlMillis" value="2000"/> </plugin> </plugins>

注册完成后，控制台输出效果大概是这样的：

方法:[com.example.mapper.UserMapper.selectByCondition] SQL:[SELECT id,name,age FROM user WHERE name = '张三' AND status = 1] 耗时:[182 ms]

同一行里能看到方法、完整SQL、耗时，排查效率比官方方案高一个档次。

4. 踩坑记录与排查实战

4.1 日志不打印，检查这三个地方

先说最常见的“为什么配置了半天控制台还是没输出”。

第一，检查配置前缀。Spring Boot里用原生Mybatis是mybatis.configuration.log-impl，用Mybatis-Plus是mybatis-plus.configuration.log-impl。这两个命名不一样，搞混了配置直接不生效。第二，检查是否有多个日志框架。如果项目里同时有logback和log4j2，Mybatis的LogFactory自动选型可能选到你不期望的那个适配器，导致日志进了一个你根本没配置的文件。这种情况最好直接显式指定log-impl，别让它自动猜。第三，检查Maven依赖里是否把mybatis-spring-boot-starter和mybatis-plus-boot-starter同时引入了。一个老项目改造时最容易出现这种重复依赖，会导致Mybatis的SqlSessionFactory被覆盖，配置项被吃掉，日志配置自然就不稳定。

另一个隐蔽问题：StdOutImpl无视logback级别，这没问题，但如果你的logback里有一个过滤器把标准输出流重定向了，比如抽日志组件把System.out引到日志采集端，那么“控制台”其实是空的，日志跑去了采集系统。遇到这种场景，建议逐步排查，先确定日志到底输出到了哪里。

4.2 自定义拦截器不生效或拦截到奇怪的SQL

拦截器不生效，优先检查注解签名，特别是query方法的参数列表。Mybatis Executor的query方法签名必须严格匹配为MappedStatement、Object、RowBounds、ResultHandler这四个参数，顺序不能变。ResultHandler是org.apache.ibatis.session.ResultHandler，不要引入成别的包下的同名类。

还有一个常见问题：多个拦截器之间互相影响。典型的是和分页插件一起使用时，如果分页插件先注册，它会把查询SQL改写成带limit的形式，然后才轮到我们的拦截器执行，此时从BoundSql里拿到的SQL已经被改过了。如果你更希望看到业务代码里原本的SQL，就在注册顺序上把SqlLogInterceptor放在前面，让分页逻辑在它之后执行。我在某项目里因为顺序问题排查了很久，最后发现打印出来的SQL总是带着LIMIT子句，误以为业务代码被人改过，其实只是拦截器顺序闹的乌龙。

再补充一个性能上的观察：自定义拦截器本质上是在每次SQL执行路径上增加了一段获取参数、拼接SQL的逻辑，对高并发接口会有少量性能损耗。这个损耗通常可忽略，但如果你每天请求量几千万，建议把日志功能做成可配置开关，上线一段时间后调低日志级别或者关闭，只保留慢SQL告警。

4.3 日志刷屏与敏感信息问题

把SQL日志打开后，最直观的问题就是日志量陡增。特别是批量操作，一条批量插入就可能打出几百行“==> Preparing”，直接淹没正常业务日志。这种情况我不会用全量SQL监控，而是靠慢SQL阈值来控制，只关注耗时异常的语句。正常业务日志级别保持INFO，只有SQL模块单独开DEBUG，甚至可以在生产环境完全不开启，等排查问题时再临时打开。

关于敏感信息，打印SQL参数时要格外留意。用户表查询条件里带上身份证号、手机号、密码哈希值，如果完整打印到日志文件里，容易产生数据泄露风险。我现在的做法是，对参数打印做一层脱敏：遇到password、token、mobile这类命名字段，统一打印成******。实现不复杂，在formatParamValue之前根据property名做判断即可。如果你所在的业务合规要求比较严格，建议不要在生产环境打印完整参数，只输出SQL骨架和耗时。

另外说一个排查技巧：当你怀疑数据查不出来是参数本身有问题时，打印出来的SQL可以直接判断。比如一个查询条件穿了空字符串进去，绑定的SQL就变成WHERE name = ''，一眼就知道是前端参数没传对。还遇到过status字段穿了个null进去，拼接结果是WHERE status = NULL，这种SQL永远查不出数据。在日志里看见NULL就知道不是Mybatis的问题，而是业务代码传参逻辑有疏漏。

最后聊一下后续扩展方向。这套拦截器稍加改造，还能把每次执行SQL对应的连接ID、事务ID打出来，方便定位同一事务内的多条SQL。也可以把慢SQL信息单独输出到独立日志文件，用logback的异步appender落盘，再配合告警系统自动扫描。我最近在做的就是把慢SQL统计后上报到监控平台，每天生成一份TOP20慢SQL清单，数据库优化和索引调整基本就看这份清单来决策。排查问题这件事，先把SQL看清楚，就已经赢了一半。