ARTICLE DETAIL

资讯详情

深耕网站视觉设计与运营推广的一线实战洞察。

MyBatis Plus SQL日志打印实战:配置、慢SQL监控与避坑指南

MyBatis Plus SQL日志打印实战:配置、慢SQL监控与避坑指南 先说个真事。去年接手一个老项目数据库时不时报一个“字段不存在”的错前端拿到的弹窗只有一句“服务器内部错误”。我对着Mapper里的SQL用肉眼看了半天硬是看不出问题在哪。后来下了个狠心把MyBatis Plus的SQL日志打开一条真实的预编译SQL直接打在控制台上再对照数据库表结构才发现是实体类升级后字段映射出了问题底层生成的SQL列名和表里的实际字段对不上。那是我第一次意识到SQL日志这个东西配置起来只要五分钟排查问题的时候却真的能救命。这篇文章就把我在项目里折腾MyBatis Plus打印SQL日志的全部经验写出来包括最简配置、日志框架整合、如何看懂打印出来的内容、怎么用拦截器做慢SQL监控以及几个相当隐蔽的坑。适合刚接触MyBatis Plus的初学者也适合项目里日志输出不理想、想折腾清爽一点的熟练工。1. 为什么要给MyBatis Plus打印SQL日志1.1 不看日志你根本不知道自己执行了什么SQLMyBatis Plus本身是一个增强工具很多SQL是框架帮你动态拼出来的。查询用户你可能就写了userService.list()但底层做了什么查询、哪些条件生效了、哪些条件被忽略了你是完全看不见的。如果业务结果和预期不一致最直接的手段就是看日志。我见过太多次这种情况页面上筛选条件明明选了“状态启用”查出来的数据里却有已停用的记录。代码看起来没毛病LambdaQueryWrapper也写了eq(User::getStatus, 1)但就是不生效。这种问题你要靠猜可能猜一下午。打开日志一看WHERE条件里压根没有status ?很快就能定位到是条件拼接顺序、and嵌套或者参数传递出了问题。SQL日志就是中间过程的“行车记录仪”它把你提交给数据库的那条SQL原原本本记录下来参数是什么、查出来多少行、执行花了多久全都有。1.2 打印SQL日志的底层原理MyBatis Plus本身是基于MyBatis实现的MyBatis在底层已经预留好了日志输出能力。它内部有一套日志适配体系org.apache.ibatis.logging.Log是一个统一接口下面有多个实现包括StdOutImpl、Slf4jImpl、Log4j2Impl等。框架在执行SQL的时候会先构建PreparedStatement然后把绑定参数、执行结果这些信息交给对应的日志实现。换句话说日志打印不是MyBatis Plus新发明的功能而是MyBatis原生能力的暴露。MyBatis Plus要做的只是通过configuration里的log-impl配置项告诉MyBatis“你该把日志交给谁输出”。这里有一个容易混淆的点log-impl和项目里的日志框架不是一回事。比如你用了Spring Boot没有单独引入Log4j2那把log-impl配成Log4j2Impl它是没法工作的因为类路径里根本没有对应的日志实现类。正确姿势是按项目已有的日志框架去选或者统一走SLF4J。1.3 哪些场景最需要SQL日志本地开发调试这是最常见的场景。写接口、写Mapper、调Wrapper条件的时候实时看到SQL变化效率会高很多。联调环境排障多系统联调时接口返回的数据不对到底是查错了还是别人给的数据不对SQL日志能帮你快速确认数据源头。线上问题复现生产环境不建议全量打印但可以针对某些慢接口临时开启或者只记录慢SQL这个后面细说。2. 最快上手的配置方案从零到一2.1 基于application.yml的极简配置在Spring Boot项目里最省事的方式是直接在application.yml里配mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.stdout.StdOutImpl重启应用执行一条查询你就能在控制台看到类似这样的输出 Preparing: SELECT id,name,phone,status FROM user WHERE status? Parameters: 1(Integer) Columns: id, name, phone, status Row: 1, 张三, 13800138000, 1 Total: 1这个配置的核心就是指定了MyBatis内部日志输出的实现类。StdOutImpl最简单粗暴直接通过System.out.println打到控制台不管你项目里用的是Logback还是Log4j2它都不关心输出效果立竿见影。但我不建议长期用这个配置原因后面会讲。2.2 三种常见log-impl实现对比用表格看一下这几种实现的区别实现类输出方式是否走项目日志框架适合场景StdOutImplSystem.out直接输出否本地快速调试临时用Slf4jImpl通过SLF4J接口输出是推荐可对接Logback/Log4j2Log4j2Impl依赖Log4j2输出是项目本身就全量用Log4j2NoLoggingImpl不输出任何SQL日志否生产环境关闭或全局静默重点说一下Slf4jImpl。如果你的项目用的日志框架是LogbackSpring Boot默认就是它推荐把配置改成mybatis-plus: configuration: log-impl: org.apache.ibatis.logging.slf4j.Slf4jImpl然后还需要在Logback配置里把Mapper接口所在的包日志级别调成debuglogger namecom.example.project.mapper leveldebug/因为MyBatis把SQL日志都输出在debug级别你自己日志框架的root级别如果配的是info那Spring Boot控制台什么都看不到。这一步是很多人开了配置却没反应的头号原因。2.3 配置生效的验证方法配置完之后不要急着写一大段业务代码去验证。最简单的方法是打开项目的单元测试随便调一个BaseMapper自带的selectById方法看控制台有没有输出。如果没输出按这个顺序排查确认配置项在mybatis-plus.configuration.log-impl下面而不是mybatis.configuration.log-impl这两个前缀看起来很像但完全不是一个地方。确认项目里引入了MyBatis Plus的starter包而不是只剩MyBatis原生依赖。确认执行SQL的那条链路真的走到了MyBatis而不是被缓存、拦截器或者其他中间层拦住了。如果用的是Slf4jImpl检查Mapper包名的日志级别是不是debug。我在项目里经常遇到配了StdOutImpl没反应的情况最后发现是application.yml被多环境配置文件覆盖了——application-prod.yml和application-dev.yml里配置不一样本地启动加载的是后者而后者压根没写log-impl。排查配置问题的时候最好先在启动日志里确认加载的是哪个配置文件。3. Logback与Log4j2整合日志不只是控制台3.1 用logback-spring.xml输出到文件本地开发控制台能看到SQL就够了但联调环境或者测试环境你人不在电脑前面控制台日志转瞬即逝最好的办法是把SQL日志落到文件里。项目如果用了Spring Boot默认的Logback在src/main/resources下建一个logback-spring.xml内容大致这样configuration appender nameCONSOLE classch.qos.logback.core.ConsoleAppender encoder pattern%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n/pattern /encoder /appender appender nameSQL_FILE classch.qos.logback.core.rolling.RollingFileAppender filelogs/sql.log/file rollingPolicy classch.qos.logback.core.rolling.TimeBasedRollingPolicy fileNamePatternlogs/sql.%d{yyyy-MM-dd}.log/fileNamePattern maxHistory7/maxHistory /rollingPolicy encoder pattern%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n/pattern /encoder /appender logger namecom.example.project.mapper leveldebug additivityfalse appender-ref refCONSOLE/ appender-ref refSQL_FILE/ /logger root levelinfo appender-ref refCONSOLE/ /root /configuration这里的核心是logger标签的name属性。它要和你Mapper接口所在的包名匹配或者更精准一点直接写到某个Mapper类全限定名。MyBatis的日志输出器是按namespace来命名的name写得太粗无关的日志也会被拉进来写得太细有一个新Mapper就得多配置一行。一般建议写到Mapper包这一层。additivityfalse的意思是这条logger输出的日志不再向root向上传递。如果不设SQL日志会既出现在SQL_FILE又出现在root的CONSOLE控制台会被刷屏。当然如果你就是想让SQL不管在哪都能看到那可以不加这个属性。3.2 生产环境的文件滚动策略日志文件一定要配滚动策略。我踩过一次大坑测试环境没有配RollingFileAppender日志文件从启动开始一直写一个月下来单文件到了好几个GB最后磁盘满了应用直接挂掉数据库连接池也被拖垮。生产环境的SQL日志文件建议按天滚动保留最近7天。单个文件加大小限制例如到了100MB就自动切分。如果SQL日志量特别大可以单独给SQL日志指定一个目录不要和业务日志混在一起方便后续按需清理和排查。3.3 精确控制特定Mapper的日志级别有些业务场景只需要跟踪某一张表的SQL执行情况其他表的日志不想看。这时候可以给单个Mapper单独开loggerlogger namecom.example.project.mapper.UserMapper leveldebug/比如排查订单超时问题你只关心OrderMapper那就把OrderMapper设为debug其他Mapper继续保持默认级别。这样控制台的输出噪音会小很多定位问题也更快。我一般会把这个能力做成“运维开关”。不是去线上改配置而是通过配置中心动态调整某个Mapper的日志级别。排查问题的时候开查完就关全程不影响业务。4. 看懂SQL日志一行日志里藏着哪些门道4.1 日志格式逐行拆解以这条日志为例 Preparing: SELECT id,name,phone,status FROM user WHERE status? AND name LIKE ? Parameters: 1(Integer), %张%(String) Columns: id, name, phone, status Row: 1, 张三, 13800138000, 1 Row: 2, 张小伟, 13912345678, 1 Total: 2第一行Preparing是预编译后的SQL参数位置用?占位。MyBatis Plus生成的就是这种带占位符的SQL它不会把参数直接拼进字符串这是JDBC标准做法能有效防止SQL注入。第二行Parameters是绑定到?上的实际参数值还带了Java类型。你看到的是1(Integer)实际传给数据库的是整数1看到的是%张%(String)实际传入的字符串是带模糊匹配通配符的。下面的Columns是返回结果的列名列表Row是每行数据的值Total是查询返回的总行数。通过这几行信息你能判断一张表里实际有哪些字段、查了几行、字段值是什么。4.2 为什么Parameters是问号而不是直接拼接很多新手有个疑问既然日志里能看到参数为什么不直接把SQL打印成WHERE status 1这种“可执行”的样子非要搞成?和参数分开其实这不是MyBatis Plus偷懒JDBC层面就是这样的机制。PreparedStatement先把SQL模板发给数据库做预编译然后再把参数单独传过去。MyBatis打印的参数和SQL模板对应的是这个协议的两次交互。如果你非要在日志里看到“完整可执行”的SQL那得在驱动层做参数替换比较常见的是引入P6Spy方案。P6Spy会把占位符替换成真实参数打印出来的是你复制到数据库客户端里直接能跑的那种SQL。效果举例SELECT id,name,phone,status FROM user WHERE status1 AND name%张%P6Spy的好处是方便复制执行坏处是多一层代理对性能有一定影响而且在生产环境一般不建议常驻。我的做法是本地开发用P6Spy环境配置默认关掉。4.3 从日志里定位慢查询日志里的 Total: N只告诉你行数不告诉你耗时。要看耗时有两个办法。一是看整体接口的执行时间比如Spring Boot的接口日志里打出了一次请求的总耗时。如果总耗时长而SQL日志只有一条且看不出问题那多半是某个SQL执行太久。二是自己加耗时统计。MyBatis本身不直接打印每条SQL的执行耗时但可以通过拦截器实现这也是后面第5节会演示的重点。另外一个非常容易被忽视的细节Preparing阶段也会耗时。如果数据库连接池里的连接失效了第一次请求会先做连接校验和重建这段时间不计入SQL执行本身但会体现在接口响应里。所以看到接口慢不要第一时间怀疑SQL先看是不是连接池问题。SQL日志能帮你把问题分层定位但它不是万能钥匙。5. 更优雅的做法拦截器实现慢SQL与脱敏5.1 通过Interceptor打印慢SQLlog-impl只能全量输出SQL日志生产环境如果全开日志量会非常大而且可能把敏感信息一起打出去。更实用的做法是自定义一个MyBatis拦截器只捕获执行时间超过阈值的SQL。依赖MyBatis本身的拦截器机制可以这样实现import org.apache.ibatis.executor.statement.StatementHandler; import org.apache.ibatis.mapping.BoundSql; import org.apache.ibatis.plugin.Interceptor; import org.apache.ibatis.plugin.Intercepts; import org.apache.ibatis.plugin.Invocation; import org.apache.ibatis.plugin.Signature; import org.apache.ibatis.session.ResultHandler; import org.springframework.stereotype.Component; import java.sql.Statement; import java.util.Properties; Component Intercepts({ Signature(type StatementHandler.class, method query, args {Statement.class, ResultHandler.class}), Signature(type StatementHandler.class, method update, args {Statement.class}) }) public class SlowSqlInterceptor implements Interceptor { /** * 慢SQL阈值单位毫秒可放到配置中心动态调整 */ private static final long SLOW_SQL_MS 500L; Override public Object intercept(Invocation invocation) throws Throwable { long start System.currentTimeMillis(); try { return invocation.proceed(); } finally { long cost System.currentTimeMillis() - start; if (cost SLOW_SQL_MS) { StatementHandler statementHandler (StatementHandler) invocation.getTarget(); BoundSql boundSql statementHandler.getBoundSql(); System.out.println([SLOW SQL] cost ms, sql: boundSql.getSql()); } } } Override public Object plugin(Object target) { return Plugin.wrap(target, this); } Override public void setProperties(Properties properties) { } }这个拦截器拦截的是StatementHandler的query和update方法。它在方法执行前记时间方法返回后算耗时超过阈值就打印SQL。用System.out.println只是个示例实际项目中应该接入日志框架。从这能看出一点MyBatis的插件机制本质上是对核心组件做动态代理理解了这一点你就能在任意环节插入自己的逻辑比如权限过滤、数据脱敏、SQL改写都是同一个套路。5.2 打印SQL时做敏感字段脱敏在生产环境打印SQL最大的风险是敏感数据泄露。日志文件如果被不该看到的人拿到身份证、手机号、地址等字段就全裸奔了。相比在SQL字符串层面硬替换更稳妥的做法是在日志输出源头脱敏。如果你用Slf4jImpl可以在Logback层面加一个Converter对消息内容做正则替换import ch.qos.logback.classic.pattern.MessageConverter; import ch.qos.logback.classic.spi.ILoggingEvent; public class SensitiveDataConverter extends MessageConverter { private static final String PHONE_REGEX (1[3-9]\\d{9}); private static final String ID_CARD_REGEX (\\d{6})\\d{8}(\\d{3}[0-9Xx]); Override public String convert(ILoggingEvent event) { String message super.convert(event); message message.replaceAll(PHONE_REGEX, $1****); message message.replaceAll(ID_CARD_REGEX, $1********$2); return message; } }然后在logback-spring.xml里这样绑定conversionRule conversionWordsafeMsg converterClasscom.example.project.log.SensitiveDataConverter/ encoder pattern%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %safeMsg%n/pattern /encoder这个方案的思路是SQL日志内容在经过Logback格式化输出前先做一层清洗。这样SQL文件里记录的是脱敏后的手机号和身份证片段既保留了排查问题需要的轮廓信息又不会泄露完整数据。5.3 拦截器和低代码查询的配合MyBatis Plus的QueryWrapper和LambdaQueryWrapper非常灵活但这也带来了一个副作用你不知道框架最终拼出的SQL到底是什么样。慢SQL拦截器和日志输出的组合能帮你把Wrapper翻译成真实的SQL语句这在排查“查询条件意外失效”时特别管用。举个例子你写了一段queryWrapper.eq(User::getStatus, status).like(User::getName, name)表面看起来没问题。但是慢SQL日志里打印出来的SQL如果只有SELECT * FROM user WHERE name LIKE ?没有status条件说明status字段因为某种原因被过滤掉了。常见的元凶是Entity里该字段加了TableField(condition )之类的注解或者字段设了fill自动填充策略拼条件时走了别的分支。拦截器在这里的意义是它不改变你的任何代码只告诉你真实发生在数据库上的事情。6. 常见问题与避坑清单6.1 SQL日志死活不输出的六个原因把我在社区和实际项目中见过的坑汇总一下现象根因解决办法控制台看不到SQLlog-impl没配置检查mybatis-plus.configuration.log-impl属性控制台看不到SQL用了Slf4jImpl但Mapper包日志级别不是debug在logback中设置该包为debug控制台看不到SQL项目是多环境配置dev文件没配检查启动时加载的profile能看到SQL但打印不完整日志被truncate检查日志框架的maxMessageSize配置生产环境打印正常没有持久化到文件增加RollingFileAppender日志打出来了但像乱码编码问题确保ConsoleAppender的encoding统一为UTF-8我特别提一下最后一条。曾经有个项目Windows服务器上控制台中文全变成???查了好久最后发现是Logback ConsoleAppender没有配charsetUTF-8/charsetWindows默认GBK解码闹的鬼。6.2 生产环境千万别全量打印SQL日志生产环境把log-impl配置成StdOutImpl你会得到什么控制台被SQL刷屏、日志文件一天几个GB、磁盘告警、应用响应变慢。因为每条SQL都要走一次额外的日志拼接逻辑在高并发下这个开销会被放大。生产环境我的标准化做法是默认关闭全量SQL日志log-impl配成NoLoggingImpl。保留慢SQL拦截器只在超过阈值时记录。给关键Mapper单独开debug排查问题用查完关闭。SQL日志只落文件不出控制台。这样既能在出问题时有据可查又不会对性能和磁盘造成不可控影响。6.3 用日志快速构造复现数据最后分享一个特别好用的小技巧。当你需要复现线上问题但本地数据缺失时先把线上问题接口的SQL日志打开把那条SQL的参数值、以及 Row里的返回结果完整复制下来。然后回到本地手动insert一条结构相同的数据再跑同样的SQL。这个方法我用了很多年几乎每次都能快速定位到底是不是数据问题。SQL日志在这里扮演的角色就是一只“时光机”它把问题现场的时间点、参数、数据快照全部记下来了。你不需要去猜数据变化的过程只要照着日志把现场“重演”一遍就行。写在最后SQL日志这件事看起来就是一个配置项的事真正做起来会发现它牵扯到日志框架、拦截器、数据安全、性能损耗各个方面。我在项目里踩过全量打印撑爆磁盘的坑也遇到过日志死活出不来最后发现是配置前缀写错的尴尬。现在的习惯很简单开发环境开全量方便调试测试环境只开慢SQL生产环境默认关闭所有SQL日志、保留拦截器真正遇到疑难杂症才会临时给某个Mapper开debug定位完立刻关掉。如果你还在为排查SQL问题发愁先别急着上各种花里胡哨的分析工具。把MyBatis Plus的SQL日志正确打开从看懂Preparing和Parameters开始很多问题其实一眼就能看穿。日志是程序员最诚实的伙伴前提是你得给它一个合适的位置。
返回列表