關(guān)于Logback+MyBatis日志輸出問題的一些思考

更新時間：2023年09月22日 14:35:20 作者：EverSpring007

這篇文章主要介紹了關(guān)于Logback+MyBatis日志輸出問題的一些思考,具有很好的參考價值,希望對大家有所幫助,

一.環(huán)境

MyBatis-Plus：3.4.3.4
SpringBoot：2.5.8
Logback：1.2.9（SpringBoot自動依賴）

二.問題

sql語句和業(yè)務(wù)日志合在一起，sql太多會影響業(yè)務(wù)日志分析，因為平時不需要看，出問題的時候才用上，所以sql日志和業(yè)務(wù)日志應(yīng)該分成不同的文件記錄
有些場景需要開發(fā)的時候同時在IDE控制臺打印sql執(zhí)行語句、輸出sql到日志文件中
日志分開后，又會導(dǎo)致查問題時不容易分清楚是否是同一次請求交易，簡單通過線程名、時間點來區(qū)分也不方便而且容易出錯
有時數(shù)據(jù)會因為事務(wù)等原因?qū)е聦懭胧?，需要查看事?wù)日志
業(yè)務(wù)模塊很多的單體應(yīng)用，所以日志糅雜在一起，查看不方便，按照業(yè)務(wù)模塊記錄到不同的日志文件中

三.解答

先貼出logback.xml的配置，后面的解答就是此配置文件中的內(nèi)容

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="60 seconds" debug="false">
    <property name="logger.path" value="/home/logs" />
    <!-- 彩色日志 -->
    <conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter" />
    <conversionRule conversionWord="wex" converterClass="org.springframework.boot.logging.logback.WhitespaceThrowableProxyConverter" />
    <conversionRule conversionWord="wEx" converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter" />
    <!-- 彩色日志格式 -->
    <property name="CONSOLE_LOG_PATTERN" value="${CONSOLE_LOG_PATTERN:-%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}-%line){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}"/>
    <!--輸出到控制臺-->
    <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>UTF-8</charset>
        </encoder>
    </appender>
    <!--輸出到文件-->
    <!-- 時間滾動輸出 level為 DEBUG 日志 -->
    <appender name="DEBUG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${logger.path}/log_debug.log</file>
        <!--日志文件輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50}-%line - %m%n</pattern>
            <charset>UTF-8</charset> <!-- 設(shè)置字符集 -->
        </encoder>
        <!-- 日志記錄器的滾動策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 日志歸檔 -->
            <fileNamePattern>${logger.path}/debug/log-debug-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日志文件保留天數(shù)-->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日志文件只記錄debug級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>debug</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>
    <!-- 時間滾動輸出 level為 INFO 日志 -->
    <appender name="INFO_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的日志文件的路徑及文件名 -->
        <file>${logger.path}/log_info.log</file>
        <!--日志文件輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50}-%line - %m%n</pattern>
            <charset>UTF-8</charset>
        </encoder>
        <!-- 日志記錄器的滾動策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 每天日志歸檔路徑以及格式 -->
            <fileNamePattern>${logger.path}/info/log-info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日志文件保留天數(shù)-->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日志文件只記錄info級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>info</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>
    <!-- 時間滾動輸出 level為 WARN 日志 -->
    <appender name="WARN_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的日志文件的路徑及文件名 -->
        <file>${logger.path}/log_warn.log</file>
        <!--日志文件輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50}-%line - %m%n</pattern>
            <charset>UTF-8</charset> <!-- 此處設(shè)置字符集 -->
        </encoder>
        <!-- 日志記錄器的滾動策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${logger.path}/warn/log-warn-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日志文件保留天數(shù)-->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日志文件只記錄warn級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>warn</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>
    <!-- 時間滾動輸出 level為 ERROR 日志 -->
    <appender name="ERROR_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的日志文件的路徑及文件名 -->
        <file>${logger.path}/log_error.log</file>
        <!--日志文件輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50}-%line - %m%n</pattern>
            <charset>UTF-8</charset> <!-- 此處設(shè)置字符集 -->
        </encoder>
        <!-- 日志記錄器的滾動策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${logger.path}/error/log-error-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日志文件保留天數(shù)-->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日志文件只記錄ERROR級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>
    <!--
        root節(jié)點是必選節(jié)點，用來指定最基礎(chǔ)的日志輸出級別，只有一個level屬性
        level:用來設(shè)置打印級別，大小寫無關(guān)：TRACE, DEBUG, INFO, WARN, ERROR, ALL 和 OFF，
        不能設(shè)置為INHERITED或者同義詞NULL。默認是DEBUG
        可以包含零個或多個元素，標(biāo)識這個appender將會添加到這個logger。
    -->
    <!-- 打印sql，但不打印事務(wù)等 com.bank.mapper為我自己mapper存放的包名-->
    <logger name="com.bank.mapper" level="DEBUG"  additivity="false">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="DEBUG_FILE"/>
    </logger>
    <!-- 打印事務(wù)、mapper注冊等信息，打印到控制臺、記錄到debug_file -->
    <logger name="org.mybatis.spring.SqlSessionUtils" level="DEBUG"  additivity="false">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="DEBUG_FILE"/>
    </logger>
    <root level="info">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="DEBUG_FILE" />
        <appender-ref ref="INFO_FILE" />
        <appender-ref ref="WARN_FILE" />
        <appender-ref ref="ERROR_FILE" />
    </root>
</configuration>

1.把業(yè)務(wù)日志代碼記錄到info級別的log中，即配置中的log_info.log；sql日志和事務(wù)日志記錄到debug級別中，即log_debug.log。通過兩個不同的appender實現(xiàn)。

2.MyBatis-Plus的配置中默認支持打印日志到控制臺或者輸出到日志文件，但不能同時支持，要么只在控制臺打印，要么只輸出到日志文件。

默認配置即可能以下配置實現(xiàn)：

mybatis-plus:
  configuration:
    logImpl: org.apache.ibatis.logging.slf4j.Slf4jImpl # 默認輸出到日志文件
    logImpl: org.apache.ibatis.logging.stdout.StdOutImpl #默認輸出到控制臺

如果嚴(yán)格區(qū)分環(huán)境，一般是不需要同時輸出的。

解決方式，通過logback配置處理

a) 控制臺的appender的filter level為debug，因為mybatis代碼中事務(wù)打印和sql打印都是debug級別；
b)指定 <logger> 配置。

  <logger name="com.bank.mapper" level="DEBUG">
          <appender-ref ref="CONSOLE"/>
          <appender-ref ref="DEBUG_FILE"/>
      </logger>
      <!-- 打印事務(wù)、mapper注冊等信息，打印到控制臺、記錄到debug_file -->
      <logger name="org.mybatis.spring.SqlSessionUtils" level="DEBUG">
          <appender-ref ref="CONSOLE"/>
          <appender-ref ref="DEBUG_FILE"/>
      </logger>

其中 org.mybatis.spring.SqlSessionUtils 是事務(wù)開啟、關(guān)閉的日志打印類，如果還需打印mapper的注冊信息等，可以按package打印 org.mybatis.spring 。

以下為事務(wù)打印的實現(xiàn)方法，可以看出都是debug級別的

 if (environment.getTransactionFactory() instanceof SpringManagedTransactionFactory) {
          LOGGER.debug(() -> "Registering transaction synchronization for SqlSession [" + session + "]");
          holder = new SqlSessionHolder(session, executorType, exceptionTranslator);
          TransactionSynchronizationManager.bindResource(sessionFactory, holder);
          TransactionSynchronizationManager
              .registerSynchronization(new SqlSessionSynchronization(holder, sessionFactory));
          holder.setSynchronizedWithTransaction(true);
          holder.requested();
        } else {
          if (TransactionSynchronizationManager.getResource(environment.getDataSource()) == null) {
            LOGGER.debug(() -> "SqlSession [" + session
                + "] was not registered for synchronization because DataSource is not transactional");
          } else {
            throw new TransientDataAccessResourceException(
                "SqlSessionFactory must be using a SpringManagedTransactionFactory in order to use Spring transaction synchronization");
          }
        }
      } else {
        LOGGER.debug(() -> "SqlSession [" + session
            + "] was not registered for synchronization because synchronization is not active");
      }

3.關(guān)于sql日志和業(yè)務(wù)日志分成不同文件，日志查看連貫性受影響，可以通過MDC處理，見我另一篇文章MDC在多線程中的使用，寫好MDC實現(xiàn)后，在日志中配置好即可。也可引用輕量日志組件TLog，就可以不用再自己實現(xiàn)MDC，參考文章：TLog MDC模式下logback的配置

4.Logback的 <appender> + <logger> 可以很好的解決按照不同模塊記錄日志。

有兩種方式：

a) 工程按照業(yè)務(wù)模塊劃分成了不同package，可以通過 <appender> + <logger name="包名"> 組合實現(xiàn)，此方式不需要修改java代碼；
b) 如果不能按照package劃分，就需要通過代碼中 Logger LOGGER = LoggerFactory.getLogger("logger name的值"); 來指定（如用了Lombok，可用 @Slf4j(topic="logger name的值") ）

    <!-- 時間滾動輸出 level為 pbc模塊INFO 日志 -->
    <appender name="user_module_appender" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <!-- 正在記錄的日志文件的路徑及文件名 -->
        <file>${logger.path}/pbc_log_info.log</file>
        <!--日志文件輸出格式-->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %C.%M-%line - %m%n</pattern>
            <charset>UTF-8</charset>
        </encoder>
        <!-- 日志記錄器的滾動策略，按日期，按大小記錄 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- 每天日志歸檔路徑以及格式 -->
            <fileNamePattern>${logger.path}/info/pbc_log-info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <!--日志文件保留天數(shù)-->
            <maxHistory>15</maxHistory>
        </rollingPolicy>
        <!-- 此日志文件只記錄info級別的 -->
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>info</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
    </appender>
    <!-- 業(yè)務(wù)模塊 -->
    <logger name="user_module_logger" level="info" additivity="false">
        <appender-ref ref="user_module_appender"/>
    </logger>

**注意：**

如果用了代碼方式匹配logger name，日志可能打印出來沒有類、方法信息，打印出的是user_module_logger，因為很多時候encoder配置的是%logger，而%logger會被logger name替換。

如要打印出類、方法信息，%logger應(yīng)改為%C.%M，%C代表class，%M代表方法，具體的變量可見ch.qos.logback.classic.PatternLayout類

DEFAULT_CONVERTER_MAP.put("lo", LoggerConverter.class.getName());
DEFAULT_CONVERTER_MAP.put("logger", LoggerConverter.class.getName());
DEFAULT_CONVERTER_MAP.put("c", LoggerConverter.class.getName());
DEFAULT_CONVERTER_MAP.put("C", ClassOfCallerConverter.class.getName());
DEFAULT_CONVERTER_MAP.put("class", ClassOfCallerConverter.class.getName());
CONVERTER_CLASS_TO_KEY_MAP.put(ClassOfCallerConverter.class.getName(), "class");
DEFAULT_CONVERTER_MAP.put("M", MethodOfCallerConverter.class.getName());
DEFAULT_CONVERTER_MAP.put("method", MethodOfCallerConverter.class.getName());
CONVERTER_CLASS_TO_KEY_MAP.put(MethodOfCallerConverter.class.getName(), "method");