Spring-boot with spring-mybatis - how to force it to logging all SQL queries

Question

I have a simple spring-boot-mybatis app (keep in mind, please). Mybatis is logging SQL queries only in case of failure (on excepions). Tell me please, how to force it to log all SQL query to console ?

At this moment I am using slf4j logger (automatically configured by spring-boot).
I find this link: http://www.mybatis.org/mybatis-3/logging.html
however I didnt manage to follow it. First of all configuration is shown for log4j, and I am not sure If I correctly understand: Is it sufficient to configure in application.properties ?

Thanks in advance

Transmittance

Answer 1

Spring boot uses logback as default logging provider for Slf4j. Ibatis internal log factory loads the SLF4j as the first choice logger. All you have to do is configure your spring boot logger to publish log messages for ibatis mapper.

Add the below lines in boot application properties.

logging.level.org.springframework=WARN
logging.level.com.spring.ibatis.UserMapper=DEBUG
logging.file=logs/spring-boot-logging.log

The second line is where you define the logging entry for ibatis mapper with DEBUG log level. com.spring.ibatis is package and the UserMapper is sample mapper.

The following logs will start to appear in the console and in the spring-boot-logging file. These are the log messages generated from saveUser and findByName method of ApplicationTest class.

2016-12-19 22:07:06.358  INFO 7248 --- [main] com.spring.ibatis.ApplicationTest        : Started ApplicationTest in 3.048 seconds (JVM running for 4.209)
2016-12-19 22:07:06.424 DEBUG 7248 --- [main] com.spring.ibatis.UserMapper.saveUser    : ==>  Preparing: insert into users(name) values(?) 
2016-12-19 22:07:06.444 DEBUG 7248 --- [main] com.spring.ibatis.UserMapper.saveUser    : ==> Parameters: ibatis(String)
2016-12-19 22:07:06.445 DEBUG 7248 --- [main] com.spring.ibatis.UserMapper.saveUser    : <==    Updates: 1
2016-12-19 22:07:06.457 DEBUG 7248 --- [main] com.spring.ibatis.UserMapper.findByName  : ==>  Preparing: select name from users WHERE name=? 
2016-12-19 22:07:06.470 DEBUG 7248 --- [main]  com.spring.ibatis.UserMapper.findByName  : ==> Parameters: ibatis(String)
2016-12-19 22:07:06.504 DEBUG 7248 --- [main]  com.spring.ibatis.UserMapper.findByName  : <==      Total: 1

You can of course configure any choice of logger you want. I can easily add an example for any other logger should you need.

You can find the complete code with Junit test cases at https://github.com/saagar2000/ibatis

Faze

Answer 2

SLF4J does not replace log4j, they work together. It removes the dependency on log4j from your library/app.

https://softwareengineering.stackexchange.com/questions/108683/slf4j-vs-log4j-which-one-to-prefer

So it is fine to use log4j configurations if you are using slf4j, as long as you are using log4j underneath slf4j.

Here's a guide I found that talks about using slf4j with log4j logger: http://saltnlight5.blogspot.ca/2013/08/how-to-configure-slf4j-with-different.html

Essentially you just need to create a properties file here: src/main/resources/log4j.properties and have it configured the same as the one in your link. And as your link says:

... For that purpose SQL statements are logged at the DEBUG level (FINE in JDK logging) and results at the TRACE level (FINER in JDK logging) ...

So make sure you have log4j.logger.org.mybatis.example=DEBUG set in your properties file.

Anglesite

Answer 3

try using the config below in application.properties file.

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

more informations can be found in the manual and details

Lilybel

Answer 4

An alternative approach is to use a proxy driver such as log4jdbc2 which has the advantage of logging the exact SQL going to the database with parameters in place unlike the other answers. This will work regardless of the persistence abastraction layer (e.g. iBatis, JPA etc).

https://code.google.com/archive/p/log4jdbc-log4j2/

One major convenience of this is that you can copy the SQL straight to your DB front-end and execute as is.

1 Add Maven Dependencies:

<dependency>
    <groupId>org.bgee.log4jdbc-log4j2</groupId>
    <artifactId>log4jdbc-log4j2-jdbc4.1</artifactId>
    <version>1.16</version>
</dependency>

2 Add logback configuration. Copy the relevant parts to your existing logback.xml

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
        </pattern>
    </encoder>
</appender>

<logger name="jdbc.audit" level="ERROR" />
<logger name="jdbc.connection" level="ERROR" />
<logger name="jdbc.sqltiming" level="ERROR" />
<logger name="jdbc.resultset" level="ERROR" />

<!-- UNCOMMENT THE BELOW TO HIDE THE RESULT SET TABLE OUTPUT -->
<!--<logger name="jdbc.resultsettable" level="ERROR" /> -->

<root level="debug">
    <appender-ref ref="STDOUT" />
</root>

3 Tell log4jdbc2 about your logging config:

Create a file named log4jdbc.log4j2.properties at the root of the classpath src/test/resources or src/main/resources in a Maven project. This file has one line which is the below:

log4jdbc.spylogdelegator.name=net.sf.log4jdbc.log.slf4j.Slf4jSpyLogDelegator

4 Change your DB driver class and URL as below:

spring.database.driverClassName=net.sf.log4jdbc.sql.jdbcapi.DriverSpy
#append log4jdbc after jdbc part of the URL: hsql example
spring.datasource.url=jdbc:log4jdbc:hsqldb:mem:db_name 

In addition to logging SQL it will also log, in tabular format, the results of all queries executed. This can be disabled as per the comment in the sample logging config.

Sample Output:

10:44:29.400 [main] DEBUG jdbc.sqlonly -
5. select memberrole0_.member_id as member_i2_12_0_, memberrole0_.id as id1_12_0_, memberrole0_.id 
as id1_12_1_, memberrole0_.member_id as member_i2_12_1_, memberrole0_.role_id as role_id3_12_1_, 
role1_.id as id1_17_2_, role1_.name as name2_17_2_ from member_roles memberrole0_ left outer 
join roles role1_ on memberrole0_.role_id=role1_.id where memberrole0_.member_id=104 

10:44:29.402 [main] INFO  jdbc.resultsettable - 
|----------|---|---|----------|--------|---|-----|
|member_id |id |id |member_id |role_id |id |name |
|----------|---|---|----------|--------|---|-----|
|----------|---|---|----------|--------|---|-----|

Legionary

Thanks you very much! – Transmittance

Thanks. I was stuggling to get it working in springboot application .This helped – Dodger

Answer 5

The accepted answer didn't quite work for me (I am guessing things change in 6 years!!). I am using YAML and not properties files, and have logback configured via logback-spring.xml. I had what I thought was equivalent to the accepted answer but didn't get the mybatis logging to be sent to the console logs. The main issue was I was using the DEBUG level, and it seems to need TRACE (The Mybatis Documentation pointed me in that direction).

In case anyone is using logback-spring.xml to configure their logging, you should be looking like this:

<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml" />
    <springProfile name="local">
        <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
        <logger name="org.springframework" level="DEBUG" additivity="false">
            <appender-ref ref="CONSOLE"/>
        </logger>
        <logger name="com.mycompany" level="DEBUG" additivity="false">
            <appender-ref ref="CONSOLE"/>
        </logger>
        <!-- Important to have TRACE as the level, and the package where the mybatis logic is specified in the logger name-->
        <logger name="com.mycompany.myapp.dataaccess" level="TRACE" additivity="false">
            <appender-ref ref="CONSOLE"/>
        </logger>
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
        </root>
    </springProfile>
</configuration>

Fadil