MyBatis 日志信息打印

Logback 打印日志信息

以下配置只会直接打印 MyBatis 的 SQL,不会自动替换 SQL 中的 ? 为真实参数值,如果需要打印完整的 SQL,请参考下面介绍的 P6Spy 使用教程。更多的 Logback 配置内容,可参考 SpringBoot2.0 整合 Logback

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="60 seconds" debug="false">

<!-- 日志级别从低到高:trace < debug < info < warn < error < fatal -->

<!-- 日志上下文名称-->
<contextName>logback</contextName>

<!-- 全局的日志级别,下面的所有配置只记录大于或等于此级别的日志信息(除了MyBatis) -->
<property name="log.level" value="info"/>

<!-- 日志文件的目录路径-->
<property name="log.path" value="/var/log/spring-cloud"/>

<!--输出到控制台-->
<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
<!--此日志Filter在开发环境才启用,只配置最低级别,控制台输出的日志级别是大于或等于此级别的日志信息 -->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>${log.level}</level>
</filter>
<!-- 日志输出格式 -->
<encoder>
<charset>UTF-8</charset>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %contextName [%thread] %-5level %logger{36}.%M\(%line\) - %msg%n
</pattern>
</encoder>
</appender>

<!--输出到文件-->
<appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
<!-- 正在记录的日志文件的路径 -->
<file>${log.path}/${log.level}.log</file>
<!-- 日志输出格式 -->
<encoder>
<charset>UTF-8</charset>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %contextName [%thread] %-5level %logger{36}.%M\(%line\) - %msg%n
</pattern>
</encoder>
<!-- 控制日志文件只记录大于或等于此级别的日志信息 -->
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>${log.level}</level>
</filter>
<!-- 日志滚动策略 -->
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<!--日志文件保留天数-->
<maxHistory>30</maxHistory>
<!-- 日志归档 -->
<fileNamePattern>${log.path}/${log.level}/${log.level}-%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
<timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
<maxFileSize>100MB</maxFileSize>
</timeBasedFileNamingAndTriggeringPolicy>
</rollingPolicy>
</appender>

<!-- 指定最基础的日志输出级别 -->
<root level="${log.level}">
<appender-ref ref="console"/>
<appender-ref ref="file"/>
</root>

<!--将MyBatis的日志信息输出到控制台-->
<appender name="mybatis_console" class="ch.qos.logback.core.ConsoleAppender">
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>debug</level>
</filter>
<!-- 日志输出格式 -->
<encoder>
<charset>UTF-8</charset>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %contextName [%thread] %-5level %logger{36}.%M\(%line\) - %msg%n
</pattern>
</encoder>
</appender>

<!-- 打印MyBatis的日志信息,开发环境才启用 -->
<logger name="com.springcloud.demo.dao" level="debug" additivity="false">
<appender-ref ref="mybatis_console"/>
</logger>

</configuration>

P6Spy 打印 MyBatis 日志

引入 Maven 依赖

1
2
3
4
5
<dependency>
<groupId>p6spy</groupId>
<artifactId>p6spy</artifactId>
<version>3.9.1</version>
</dependency>

数据库连接配置

以下內容是在 SpringBoot 2.0 的 application.yml 文件中配置,主要的配置内容是指定 driver-class-namejdbc-url

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
spring:
datasource:
username: root
password: 123456
driver-class-name: com.p6spy.engine.spy.P6SpyDriver
type: com.alibaba.druid.pool.DruidDataSource
filters: stat
initialSize: 100
maxActive: 1000
maxOpenPreparedStatements: 20
maxWait: 60000
minEvictableIdleTimeMillis: 300000
minIdle: 500
poolPreparedStatements: true
testOnBorrow: false
testOnReturn: false
testWhileIdle: true
validationQuery: select 'x'
timeBetweenEvictionRunsMillis: 60000
url: jdbc:p6spy:mysql://127.0.0.1:3306/spring_cloud?useUnicode=true&characterEncoding=utf-8&allowMultiQueries=true&useSSL=false&serverTimezone=Asia/Shanghai
...

提示

  • driver-class-name 为 P6Spy 提供的驱动类
  • url 前缀为 jdbc:p6spy,后面跟着冒号为对应数据库的连接地址

创建 P6Spy 配置文件

在项目的 src/main/resources 目录下创建 spy.properties 配置文件(如下),主要的配置内容为数据库驱动、日期格式化、单行或多行打印,日志输出方式(控制台、日志文件等)。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
#################################################################
# P6Spy Options File #
# See documentation for detailed instructions #
# http://p6spy.github.io/p6spy/2.0/configandusage.html #
#################################################################

#################################################################
# MODULES #
# #
# Module list adapts the modular functionality of P6Spy. #
# Only modules listed are active. #
# (default is com.p6spy.engine.logging.P6LogFactory and #
# com.p6spy.engine.spy.P6SpyFactory) #
# Please note that the core module (P6SpyFactory) can't be #
# deactivated. #
# Unlike the other properties, activation of the changes on #
# this one requires reload. #
#################################################################
#modulelist=com.p6spy.engine.spy.P6SpyFactory,com.p6spy.engine.logging.P6LogFactory,com.p6spy.engine.outage.P6OutageFactory

################################################################
# CORE (P6SPY) PROPERTIES #
################################################################

# A comma separated list of JDBC drivers to load and register.
# (default is empty)
#
# Note: This is normally only needed when using P6Spy in an
# application server environment with a JNDI data source or when
# using a JDBC driver that does not implement the JDBC 4.0 API
# (specifically automatic registration).
driverlist=com.mysql.jdbc.Driver

# for flushing per statement
# (default is false)
#autoflush = false

# sets the date format using Java's SimpleDateFormat routine.
# In case property is not set, milliseconds since 1.1.1970 (unix time) is used (default is empty)
dateformat=yyyy-MM-dd HH:mm:ss.SSS

# prints a stack trace for every statement logged
#stacktrace=false
# if stacktrace=true, specifies the stack trace to print
#stacktraceclass=

# determines if property file should be reloaded
# Please note: reload means forgetting all the previously set
# settings (even those set during runtime - via JMX)
# and starting with the clean table
# (default is false)
#reloadproperties=false

# determines how often should be reloaded in seconds
# (default is 60)
#reloadpropertiesinterval=60

# specifies the appender to use for logging
# Please note: reload means forgetting all the previously set
# settings (even those set during runtime - via JMX)
# and starting with the clean table
# (only the properties read from the configuration file)
# (default is com.p6spy.engine.spy.appender.FileLogger)
#appender=com.p6spy.engine.spy.appender.Slf4JLogger
appender=com.p6spy.engine.spy.appender.StdoutLogger
#appender=com.p6spy.engine.spy.appender.FileLogger

# name of logfile to use, note Windows users should make sure to use forward slashes in their pathname (e:/test/spy.log)
# (used for com.p6spy.engine.spy.appender.FileLogger only)
# (default is spy.log)
#logfile=/var/log/spy.log
# append to the p6spy log file. if this is set to false the
# log file is truncated every time. (file logger only)
# (default is true)
#append=true

# class to use for formatting log messages (default is: com.p6spy.engine.spy.appender.SingleLineFormat)
logMessageFormat=com.p6spy.engine.spy.appender.MultiLineFormat

# Custom log message format used ONLY IF logMessageFormat is set to com.p6spy.engine.spy.appender.CustomLineFormat
# default is %(currentTime)|%(executionTime)|%(category)|connection%(connectionId)|%(sqlSingleLine)
# Available placeholders are:
# %(connectionId) the id of the connection
# %(currentTime) the current time expressing in milliseconds
# %(executionTime) the time in milliseconds that the operation took to complete
# %(category) the category of the operation
# %(effectiveSql) the SQL statement as submitted to the driver
# %(effectiveSqlSingleLine) the SQL statement as submitted to the driver, with all new lines removed
# %(sql) the SQL statement with all bind variables replaced with actual values
# %(sqlSingleLine) the SQL statement with all bind variables replaced with actual values, with all new lines removed
#customLogMessageFormat=%(currentTime)|%(executionTime)|%(category)|connection%(connectionId)|%(sqlSingleLine)

# format that is used for logging of the java.util.Date implementations (has to be compatible with java.text.SimpleDateFormat)
# (default is yyyy-MM-dd'T'HH:mm:ss.SSSZ)
#databaseDialectDateFormat=yyyy-MM-dd'T'HH:mm:ss.SSSZ

# format that is used for logging of the java.sql.Timestamp implementations (has to be compatible with java.text.SimpleDateFormat)
# (default is yyyy-MM-dd'T'HH:mm:ss.SSSZ)
#databaseDialectTimestampFormat=yyyy-MM-dd'T'HH:mm:ss.SSSZ

# format that is used for logging booleans, possible values: boolean, numeric
# (default is boolean)
#databaseDialectBooleanFormat=boolean

# whether to expose options via JMX or not
# (default is true)
#jmx=true

# if exposing options via jmx (see option: jmx), what should be the prefix used?
# jmx naming pattern constructed is: com.p6spy(.<jmxPrefix>)?:name=<optionsClassName>
# please note, if there is already such a name in use it would be unregistered first (the last registered wins)
# (default is none)
#jmxPrefix=

# if set to true, the execution time will be measured in nanoseconds as opposed to milliseconds
# (default is false)
#useNanoTime=false

#################################################################
# DataSource replacement #
# #
# Replace the real DataSource class in your application server #
# configuration with the name com.p6spy.engine.spy.P6DataSource #
# (that provides also connection pooling and xa support). #
# then add the JNDI name and class name of the real #
# DataSource here #
# #
# Values set in this item cannot be reloaded using the #
# reloadproperties variable. Once it is loaded, it remains #
# in memory until the application is restarted. #
# #
#################################################################
#realdatasource=/RealMySqlDS
#realdatasourceclass=com.mysql.jdbc.jdbc2.optional.MysqlDataSource

#################################################################
# DataSource properties #
# #
# If you are using the DataSource support to intercept calls #
# to a DataSource that requires properties for proper setup, #
# define those properties here. Use name value pairs, separate #
# the name and value with a semicolon, and separate the #
# pairs with commas. #
# #
# The example shown here is for mysql #
# #
#################################################################
#realdatasourceproperties=port;3306,serverName;myhost,databaseName;jbossdb,foo;bar

#################################################################
# JNDI DataSource lookup #
# #
# If you are using the DataSource support outside of an app #
# server, you will probably need to define the JNDI Context #
# environment. #
# #
# If the P6Spy code will be executing inside an app server then #
# do not use these properties, and the DataSource lookup will #
# use the naming context defined by the app server. #
# #
# The two standard elements of the naming environment are #
# jndicontextfactory and jndicontextproviderurl. If you need #
# additional elements, use the jndicontextcustom property. #
# You can define multiple properties in jndicontextcustom, #
# in name value pairs. Separate the name and value with a #
# semicolon, and separate the pairs with commas. #
# #
# The example shown here is for a standalone program running on #
# a machine that is also running JBoss, so the JNDI context #
# is configured for JBoss (3.0.4). #
# #
# (by default all these are empty) #
#################################################################
#jndicontextfactory=org.jnp.interfaces.NamingContextFactory
#jndicontextproviderurl=localhost:1099
#jndicontextcustom=java.naming.factory.url.pkgs;org.jboss.naming:org.jnp.interfaces

#jndicontextfactory=com.ibm.websphere.naming.WsnInitialContextFactory
#jndicontextproviderurl=iiop://localhost:900

################################################################
# P6 LOGGING SPECIFIC PROPERTIES #
################################################################

# filter what is logged
# please note this is a precondition for usage of: include/exclude/sqlexpression
# (default is false)
#filter=false

# comma separated list of strings to include
# please note that special characters escaping (used in java) has to be done for the provided regular expression
# (default is empty)
#include=
# comma separated list of strings to exclude
# (default is empty)
#exclude=

# sql expression to evaluate if using regex
# please note that special characters escaping (used in java) has to be done for the provided regular expression
# (default is empty)
#sqlexpression=

#list of categories to exclude: error, info, batch, debug, statement,
#commit, rollback, result and resultset are valid values
# (default is info,debug,result,resultset,batch)
#excludecategories=info,debug,result,resultset,batch

#whether the binary values (passed to DB or retrieved ones) should be logged with placeholder: [binary] or not.
# (default is false)
#excludebinary=false

# Execution threshold applies to the standard logging of P6Spy.
# While the standard logging logs out every statement
# regardless of its execution time, this feature puts a time
# condition on that logging. Only statements that have taken
# longer than the time specified (in milliseconds) will be
# logged. This way it is possible to see only statements that
# have exceeded some high water mark.
# This time is reloadable.
#
# executionThreshold=integer time (milliseconds)
# (default is 0)
#executionThreshold=

################################################################
# P6 OUTAGE SPECIFIC PROPERTIES #
################################################################
# Outage Detection
#
# This feature detects long-running statements that may be indicative of
# a database outage problem. If this feature is turned on, it will log any
# statement that surpasses the configurable time boundary during its execution.
# When this feature is enabled, no other statements are logged except the long
# running statements. The interval property is the boundary time set in seconds.
# For example, if this is set to 2, then any statement requiring at least 2
# seconds will be logged. Note that the same statement will continue to be logged
# for as long as it executes. So if the interval is set to 2, and the query takes
# 11 seconds, it will be logged 5 times (at the 2, 4, 6, 8, 10 second intervals).
#
# outagedetection=true|false
# outagedetectioninterval=integer time (seconds)
#
# (default is false)
#outagedetection=false
# (default is 60)
#outagedetectioninterval=30

日志打印结果

简单执行 CRUD 操作后,P6Spy 打印的日志信息如下:

1
2
3
4
5
6
7
8
==>  Preparing: SELECT id,email,last_name,gender,age FROM t_employee WHERE id=?
==> Parameters: 1(Long)
Consume Time:2 ms 2022-09-17 19:38:30
Execute SQL:SELECT id,email,last_name,gender,age FROM t_employee WHERE id=1

<== Columns: id, email, last_name, gender, age
<== Row: 1, empty@gmai.com, Clion, 1, 26
<== Total: 1

可以发现 P6Spy 组件会打印出完整的 SQL 语句和执行 SQL 语句所耗费的时间,而且它会自动替换 SQL 中的 ? 为真实参数值并输出。

P6Spy 打印 MyBatis-Plus 日志

参考博客