title: SpringBoot结合LogBack打印Sql tags:
- SpringBoot
- Mybatis
- logback
- druid categories: springboot date: 2017-12-05 22:09:38
背景
不同的profile下我们需要不同的配置 SpringBoot关于配置在profile玩的飞起
通常我们在开发或者测试环境下都会打开sql日志方便开发调试
方案
mybatis日志
系统中采用mybatis做orm框架我们自然可以通过mybatis的日志来输出
mybatis作为十分优秀的orm中间件自然对于日志多个平台进行了适配
本例中我们采用logback【事实上调用均采用slf4j最佳 这是日志的门面】
protected SqlSessionFactoryBean getSqlSessionFactoryBean(DataSource dataSource) { SqlSessionFactoryBean factory = new SqlSessionFactoryBean(); factory.setDataSource(dataSource); factory.setTypeAliasesPackage(MODEL_PACKAGE); //配置分页插件，详情请查阅官方文档 PageHelper pageHelper = new PageHelper(); Properties properties = new Properties(); properties.setProperty("pageSizeZero", "true"); //分页尺寸为0时查询所有纪录不再执行分页 properties.setProperty("reasonable", "true"); //页码<=0 查询第一页，页码>=总页数查询最后一页 properties.setProperty("supportMethodsArguments", "false"); //支持通过 Mapper 接口参数来传递分页参数 pageHelper.setProperties(properties); //添加插件 factory.setPlugins(new Interceptor[]{pageHelper, new SoInterceptor(), new MybatisTransactionTimeoutInterceptor()}); org.apache.ibatis.session.Configuration config = new org.apache.ibatis.session.Configuration(); config.setDefaultStatementTimeout(5); config.setDefaultFetchSize(10000); config.setDefaultExecutorType(ExecutorType.REUSE); config.setLogImpl(Slf4jImpl.class); config.setLogPrefix("dao."); factory.setConfiguration(config); return factory; }复制代码 注意我们在mybatis的config中使用了Slf4jImpl的实现 同时针对mybatis的日志均加了dao的前缀方便在日志中收集
在logback-spring.xml中定义如下log
复制代码 ${LOG_PATH}/${myAppName}-sql.log %d [%level] [%thread] %logger{15}:%line %msg%n DEBUG ${LOG_PATH}/${myAppName}-sql.log.%d{yyyy-MM-dd} 30 512
可以看到我们在dev,local-test,re 三个环境进行了日志的输出
2017-12-05 13:02:51,944 [DEBUG] [XNIO-2 task-1] d.c.f.b.d.u.T.selectAll_COUNT:? ==> Preparing: SELECT count(0) FROM tb_user 2017-12-05 13:02:51,970 [DEBUG] [XNIO-2 task-1] d.c.f.b.d.u.T.selectAll_COUNT:? ==> Parameters: 2017-12-05 13:02:51,984 [DEBUG] [XNIO-2 task-1] d.c.f.b.d.u.T.selectAll_COUNT:? <== Total: 1 2017-12-05 13:02:51,988 [DEBUG] [XNIO-2 task-1] d.c.f.b.d.u.T.selectAll:? ==> Preparing: SELECT pk_id,username,cell_phone,password,is_admin,id_role,creator,modifier,modifiedtime,creationtime,id_own_org,id_employee,is_del,is_guide_open,id_wxb_user,id_wxb_station,openid,limit_mac FROM tb_user limit ?,? 2017-12-05 13:02:51,994 [DEBUG] [XNIO-2 task-1] d.c.f.b.d.u.T.selectAll:? ==> Parameters: 0(Integer), 10(Integer) 2017-12-05 13:02:52,008 [DEBUG] [XNIO-2 task-1] d.c.f.b.d.u.T.selectAll:? <== Total: 10 2017-12-05 13:03:34,582 [DEBUG] [XNIO-2 task-2] d.c.f.b.d.u.T.selectAll_COUNT:? ==> Preparing: SELECT count(0) FROM tb_user 2017-12-05 13:03:34,582 [DEBUG] [XNIO-2 task-2] d.c.f.b.d.u.T.selectAll_COUNT:? ==> Parameters: 2017-12-05 13:03:34,585 [DEBUG] [XNIO-2 task-2] d.c.f.b.d.u.T.selectAll_COUNT:? <== Total: 1 2017-12-05 13:03:34,585 [DEBUG] [XNIO-2 task-2] d.c.f.b.d.u.T.selectAll:? ==> Preparing: SELECT pk_id,username,cell_phone,password,is_admin,id_role,creator,modifier,modifiedtime,creationtime,id_own_org,id_employee,is_del,is_guide_open,id_wxb_user,id_wxb_station,openid,limit_mac FROM tb_user limit ?,? 2017-12-05 13:03:34,586 [DEBUG] [XNIO-2 task-2] d.c.f.b.d.u.T.selectAll:? ==> Parameters: 0(Integer), 10(Integer) 2017-12-05 13:03:34,602 [DEBUG] [XNIO-2 task-2] d.c.f.b.d.u.T.selectAll:? <== Total: 10 复制代码
这样开发者就可以看到对应的sql
Druid日志
我们使用了druid作为db连接池 druid也提供了相关日志的输出
因此我们也可以通过druid的日志进行输出
我们在application.properties中可以定义如下
spring.datasource.initialSize=5 spring.datasource.minIdle=5 spring.datasource.maxActive=20 # 配置获取连接等待超时的时间 spring.datasource.maxWait=60000 # 配置间隔多久才进行一次检测，检测需要关闭的空闲连接，单位是毫秒 spring.datasource.timeBetweenEvictionRunsMillis=60000 # 配置一个连接在池中最小生存的时间，单位是毫秒 spring.datasource.minEvictableIdleTimeMillis=300000 spring.datasource.validationQuery=SELECT 1 FROM DUAL spring.datasource.testWhileIdle=true spring.datasource.testOnBorrow=false spring.datasource.testOnReturn=false # 打开PSCache，并且指定每个连接上PSCache的大小 spring.datasource.poolPreparedStatements=true spring.datasource.maxPoolPreparedStatementPerConnectionSize=20 # 配置监控统计拦截的filters，去掉后监控界面sql无法统计，'wall'用于防火墙 spring.datasource.filters=stat,wall,slf4j # 通过connectProperties属性来打开mergeSql功能；慢SQL记录 spring.datasource.connectionProperties=druid.stat.mergeSql=true;druid.stat.slowSqlMillis=5000 spring.datasource.useGlobalDataSourceStat=true 复制代码
注意在filter中存在slf4j
同样的道理找logback-spring中声明如下
复制代码 ${LOG_PATH}/${myAppName}-druid.log %d [%level] [%thread] %logger{15}:%line %msg%n DEBUG ${LOG_PATH}/${myAppName}-druid.log.%d{yyyy-MM-dd} 30 512
这样也可以完成sql的输出
2017-12-05 13:02:42,665 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10001} connected 2017-12-05 13:02:42,680 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10002} connected 2017-12-05 13:02:42,694 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10003} connected 2017-12-05 13:02:42,712 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10004} connected 2017-12-05 13:02:42,724 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10005} connected 2017-12-05 13:02:42,764 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10005} pool-connect 2017-12-05 13:02:42,776 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10005} pool-recycle 2017-12-05 13:02:42,847 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10005} pool-connect 2017-12-05 13:02:42,940 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.sql.Statement:? {conn-10005, stmt-20000} created 2017-12-05 13:02:43,169 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.sql.Statement:? {conn-10005, stmt-20000, rs-50000} query executed. 224.655264 millis. SELECT 1 FROM DUAL 2017-12-05 13:02:43,174 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.sql.Statement:? {conn-10005, stmt-20000} closed 2017-12-05 13:02:43,174 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10005} pool-recycle 2017-12-05 13:02:43,175 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10005} pool-connect 2017-12-05 13:02:43,175 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10005} pool-recycle 2017-12-05 13:02:43,175 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10005} pool-connect 2017-12-05 13:02:43,175 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.sql.Statement:? {conn-10005, stmt-20001} created 2017-12-05 13:02:43,176 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.sql.Statement:? {conn-10005, stmt-20001, rs-50001} query executed. 1.123842 millis. SELECT 1 FROM DUAL 2017-12-05 13:02:43,176 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.sql.Statement:? {conn-10005, stmt-20001} closed 2017-12-05 13:02:43,176 [DEBUG] [RMI TCP Connection(11)-127.0.0.1] d.s.Connection:? {conn-10005} pool-recycle 2017-12-05 13:02:51,543 [DEBUG] [XNIO-2 task-1] d.s.Connection:? {conn-10005} pool-connect 2017-12-05 13:02:51,550 [DEBUG] [XNIO-2 task-1] d.s.Connection:? {conn-10005} setAutoCommit false 2017-12-05 13:02:51,590 [DEBUG] [XNIO-2 task-1] d.s.Connection:? {conn-10004} pool-connect 2017-12-05 13:02:51,590 [DEBUG] [XNIO-2 task-1] d.s.Connection:? {conn-10004} pool-recycle 2017-12-05 13:02:51,958 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20002} created. SELECT count(0) FROM tb_user 2017-12-05 13:02:51,970 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20002} Parameters : [] 2017-12-05 13:02:51,970 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20002} Types : [] 2017-12-05 13:02:51,975 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20002} executed. 4.634146 millis. SELECT count(0) FROM tb_user 2017-12-05 13:02:51,992 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20003} created. SELECT pk_id,username,cell_phone,password,is_admin,id_role,creator,modifier,modifiedtime,creationtime,id_own_org,id_employee,is_del,is_guide_open,id_wxb_user,id_wxb_station,openid,limit_mac FROM tb_user limit ?,? 2017-12-05 13:02:51,994 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20003} Parameters : [0, 10] 2017-12-05 13:02:51,994 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20003} Types : [INTEGER, INTEGER] 2017-12-05 13:02:51,997 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20003} executed. 2.940797 millis. SELECT pk_id,username,cell_phone,password,is_admin,id_role,creator,modifier,modifiedtime,creationtime,id_own_org,id_employee,is_del,is_guide_open,id_wxb_user,id_wxb_station,openid,limit_mac FROM tb_user limit ?,? 2017-12-05 13:02:52,035 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20002} clearParameters. 2017-12-05 13:02:52,035 [DEBUG] [XNIO-2 task-1] d.sql.Statement:? {conn-10005, pstmt-20003} clearParameters. 2017-12-05 13:02:52,036 [DEBUG] [XNIO-2 task-1] d.s.Connection:? {conn-10005} commited 2017-12-05 13:02:52,036 [DEBUG] [XNIO-2 task-1] d.s.Connection:? {conn-10005} setAutoCommit true 2017-12-05 13:02:52,039 [DEBUG] [XNIO-2 task-1] d.s.Connection:? {conn-10005} pool-recycle 2017-12-05 13:03:34,570 [DEBUG] [XNIO-2 task-2] d.s.Connection:? {conn-10005} pool-connect 2017-12-05 13:03:34,573 [DEBUG] [XNIO-2 task-2] d.s.Connection:? {conn-10005} setAutoCommit false 2017-12-05 13:03:34,582 [DEBUG] [XNIO-2 task-2] d.sql.Statement:? {conn-10005, pstmt-20002} Parameters : [] 2017-12-05 13:03:34,582 [DEBUG] [XNIO-2 task-2] d.sql.Statement:? {conn-10005, pstmt-20002} Types : [] 2017-12-05 13:03:34,584 [DEBUG] [XNIO-2 task-2] d.sql.Statement:? {conn-10005, pstmt-20002} executed. 1.864303 millis. SELECT count(0) FROM tb_user 2017-12-05 13:03:34,586 [DEBUG] [XNIO-2 task-2] d.sql.Statement:? {conn-10005, pstmt-20003} Parameters : [0, 10] 2017-12-05 13:03:34,586 [DEBUG] [XNIO-2 task-2] d.sql.Statement:? {conn-10005, pstmt-20003} Types : [INTEGER, INTEGER] 2017-12-05 13:03:34,589 [DEBUG] [XNIO-2 task-2] d.sql.Statement:? {conn-10005, pstmt-20003} executed. 2.872636 millis. SELECT pk_id,username,cell_phone,password,is_admin,id_role,creator,modifier,modifiedtime,creationtime,id_own_org,id_employee,is_del,is_guide_open,id_wxb_user,id_wxb_station,openid,limit_mac FROM tb_user limit ?,? 2017-12-05 13:03:34,603 [DEBUG] [XNIO-2 task-2] d.sql.Statement:? {conn-10005, pstmt-20002} clearParameters. 2017-12-05 13:03:34,603 [DEBUG] [XNIO-2 task-2] d.sql.Statement:? {conn-10005, pstmt-20003} clearParameters. 2017-12-05 13:03:34,604 [DEBUG] [XNIO-2 task-2] d.s.Connection:? {conn-10005} commited 2017-12-05 13:03:34,604 [DEBUG] [XNIO-2 task-2] d.s.Connection:? {conn-10005} setAutoCommit true 2017-12-05 13:03:34,607 [DEBUG] [XNIO-2 task-2] d.s.Connection:? {conn-10005} pool-recycle 2017-12-05 13:06:00,780 [DEBUG] [Thread-80] d.s.Connection:? {conn-10001} closed 2017-12-05 13:06:00,781 [DEBUG] [Thread-80] d.s.Connection:? {conn-10002} closed 2017-12-05 13:06:00,781 [DEBUG] [Thread-80] d.s.Connection:? {conn-10003} closed 2017-12-05 13:06:00,782 [DEBUG] [Thread-80] d.s.Connection:? {conn-10004} closed 2017-12-05 13:06:00,782 [DEBUG] [Thread-80] d.sql.Statement:? {conn-10005, pstmt-20002} closed 2017-12-05 13:06:00,782 [DEBUG] [Thread-80] d.sql.Statement:? {conn-10005, pstmt-20003} closed 2017-12-05 13:06:00,782 [DEBUG] [Thread-80] d.s.Connection:? {conn-10005} closed 复制代码