Topwo博客-mybatis打印的sql日志不写入到log文件问题解决

您现在的位置是：Topwo博客>>Java文章

mybatis打印的sql日志不写入到log文件问题解决

发布时间：2021-09-27作者：Topwo来源：原创点击：477

## 问题描述
#### 环境： java 1.8、spring boot 2.2.4、mybatis-spring-boot-starter 2.1.1
在一次上线调bug中，想看看执行的sql语句，结果tail -100f这个日志文件发现sql语句没有输出到这个文件里面，然后在本地运行从console中又能看到有sql打印。
## 问题分析
第一时间想到会不会是logback配置不对
```xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    
    
    <springProperty scope="context" name="springAppName" source="spring.application.name"/>

<property name="LOG_FILE" value="logs/${springAppName}-%d{yyyy-MM-dd}.log"/>

<property name="CONSOLE_LOG_PATTERN"
              value="%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n"/>

<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>DEBUG</level>
        </filter>
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>

<appender name="flatfile" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>DEBUG</level>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.gz</fileNamePattern>
            <maxHistory>3</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>

<root level="DEBUG">
        <appender-ref ref="console"/>
        <appender-ref ref="flatfile"/>
    </root>
</configuration>
```

logback配置如上，就是两个appender，一个输console一个输file，都是debug级别，所以这个配置文件是没有问题的

然后发现到，console中打印的日志好像是被直接sout在上面的，不是logback打印的，所以肯定就不会输出到上面配置的文件里面啦
![](http://uploadqn.topwo.com/topwo_site/f9aa7e738f0174e50a75c63cb4f24df7)
现在很好奇这个sout是从哪里打印出来的
下面使用了`arthas`的`redefine`
**关于arthas**： Arthas 是阿里巴巴最近才开源出来的一款 Java 诊断利器。主要是针对线上环境，也就是生产环境
**git地址**：[https://github.com/alibaba/arthas](https://github.com/alibaba/arthas)
由于字符串拼接基本都是通过StringBuilder来实现的，所以这里redefine StringBuilder
```java
@Override
public String toString() {
    // Create a copy, don't share the array
    String result = new String(value, 0, count);
    if(result.contains("Preparing:")) {
        System.err.println(result);
        new Throwable().printStackTrace();
    }
    return result;
}
```
这里将StringBuilder的toString方法加了点料，将preparing就是打印sql的地方，把堆栈打印了出来，javac编译后，然后**redefine StringBuilder.class**
![](http://uploadqn.topwo.com/topwo_site/4812b6a6b488acc369fd53318326773d)
redefine成功之后，再去触发sql打印
![](http://uploadqn.topwo.com/topwo_site/280865b3e7f88a1fcbc46d23cd468d8d)
发现是从BaseJdbcLogger这里调用的
```java
protected void debug(String text, boolean input) {
    if (this.statementLog.isDebugEnabled()) {
        this.statementLog.debug(this.prefix(input) + text);
    }
}
```
就是这个地方调用的debug，是statementLog这个对象的方法
```java
public abstract class BaseJdbcLogger {
    protected static final Set<String> SET_METHODS = new HashSet();
    protected static final Set<String> EXECUTE_METHODS = new HashSet();
    private final Map<Object, Object> columnMap = new HashMap();
    private final List<Object> columnNames = new ArrayList();
    private final List<Object> columnValues = new ArrayList();
    protected Log statementLog;
    protected int queryStack;

public BaseJdbcLogger(Log log, int queryStack) {
        this.statementLog = log;
        if (queryStack == 0) {
            this.queryStack = 1;
        } else {
            this.queryStack = queryStack;
        }

}
    ……
}
```
注意到这个statementLog和构造方法，statementLog是一个Log接口实现，是从构造方法中传入Log的实现类对象的
```java
package org.apache.ibatis.logging;

public interface Log {
    boolean isDebugEnabled();

boolean isTraceEnabled();

void error(String var1, Throwable var2);

void error(String var1);

void debug(String var1);

void trace(String var1);

void warn(String var1);
}
```
它包含了四种日志级别，以及debug、trace开关
![](http://uploadqn.topwo.com/topwo_site/e3e80636aa9013a796106b66b0779197)
Log接口的实现类就是我们常用的日志框架的日志门面类slf4j、log4j2等等，这些日志门面会找到具体的日志实现框架，目前的环境就是slf4j -> logback这种实现

接下来就在构造方法里打断点debug
![](http://uploadqn.topwo.com/topwo_site/76dd0361d158e76e598a5c53b1b37717)
发现传入的是一个StdOutImpl，一看就是sout的实现
```java
package org.apache.ibatis.logging.stdout;

import org.apache.ibatis.logging.Log;

public class StdOutImpl implements Log {
    public StdOutImpl(String clazz) {
    }

public boolean isDebugEnabled() {
        return true;
    }

public boolean isTraceEnabled() {
        return true;
    }

public void error(String s, Throwable e) {
        System.err.println(s);
        e.printStackTrace(System.err);
    }

public void error(String s) {
        System.err.println(s);
    }

public void debug(String s) {
        System.out.println(s);
    }

public void trace(String s) {
        System.out.println(s);
    }

public void warn(String s) {
        System.out.println(s);
    }
}
```
所以问题出在这里了，根据分析，这里应该传入**Slf4jImpl**这个实现才对，然后在spring boot的debug日志里输出了很多信息，搜索这个StdOutImpl
![](http://uploadqn.topwo.com/topwo_site/b529a0aec57f4a6d75beeb419eb3d227)
发现已经告诉了目前使用的是StdOutImpl，根据分析，问题很可能就出在了mybatis配置上
```xml
<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE configuration PUBLIC "-//mybatis.org//DTD Config 3.0//EN" "http://mybatis.org/dtd/mybatis-3-config.dtd">
<configuration>
    <settings>
        <setting name="cacheEnabled" value="true" />
        <setting name="lazyLoadingEnabled" value="true" />
        <setting name="multipleResultSetsEnabled" value="true" />
        <setting name="useColumnLabel" value="true" />
        <setting name="defaultExecutorType" value="REUSE" />
        <setting name="defaultStatementTimeout" value="25000" />
        <setting name="logImpl" value="STDOUT_LOGGING" />
        
        <setting name="mapUnderscoreToCamelCase" value="true"/>
    </settings>
</configuration>
```
这就是该项目使用的mybatis的配置，发现了logImpl，stdout，应该就是在这里配置的
![](http://uploadqn.topwo.com/topwo_site/1b18f65319f8afc8c909e06402d82181.png)
查文档发现这里可以配置这么多，所以改成SLF4J就ok了
![](http://uploadqn.topwo.com/topwo_site/60db99a8ea12bcb7126f3429967abac7)
这个实现类就成功变成了Slf4jImpl，日志文件里面也有了sql打印
## 问题解决
修改mybatis配置文件中的
```xml
<setting name="logImpl" value="STDOUT_LOGGING" />
```
变为
```xml
<setting name="logImpl" value="SLF4J" />
```
或者删掉也行

## 总结：
sout输出的是不会记录在日志文件中的，必须使用log的方式才能记录，这也是我们在捕获异常或全局异常处理，要使用`log.error("", e);`替代`e.printStackTrace();`的原因
spring boot中mybatis的sql打印实际上就把**logback配置修改为debug级别就可以了**，
像mybatis配置logImpl，application.properties中写logging.level.com.xxx.dao=debug都是不必要的，除非需要一些细粒度的控制
**特别注意:mybatis如果要配置logImpl的话尽量不要使用STDOUT_LOGGING！**

上一篇：linux安装java步骤

下一篇：Java Web中的mapper，service，controller，model