背景

不同的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

<springProfile name="dev,local-test,re">     <appender name="sql" class="ch.qos.logback.core.rolling.RollingFileAppender">         <File>${LOG_PATH}/${myAppName}-sql.log</File>         <encoder>             <pattern>%d [%level] [%thread] %logger{15}:%line %msg%n</pattern>         </encoder>         <filter class="ch.qos.logback.classic.filter.ThresholdFilter">             <level>DEBUG</level>         </filter>         <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">             <fileNamePattern>${LOG_PATH}/${myAppName}-sql.log.%d{yyyy-MM-dd}</fileNamePattern>             <maxHistory>30</maxHistory>         </rollingPolicy>     </appender>     <appender name="sql-queue" class="ch.qos.logback.classic.AsyncAppender">         <queueSize>512</queueSize>         <appender-ref ref="sql"/>     </appender>          <!-- mybatis loggers -->     <logger name="dao" level="DEBUG" additivity="false">         <appender-ref ref="sql-queue"/>     </logger>      </springProfile>

可以看到我们在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中声明如下

<springProfile name="dev,local-test,re">     <appender name="druid" class="ch.qos.logback.core.rolling.RollingFileAppender">         <File>${LOG_PATH}/${myAppName}-druid.log</File>         <encoder>             <pattern>%d [%level] [%thread] %logger{15}:%line %msg%n</pattern>         </encoder>         <filter class="ch.qos.logback.classic.filter.ThresholdFilter">             <level>DEBUG</level>         </filter>         <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">             <fileNamePattern>${LOG_PATH}/${myAppName}-druid.log.%d{yyyy-MM-dd}</fileNamePattern>             <maxHistory>30</maxHistory>         </rollingPolicy>     </appender>     <appender name="druid-queue" class="ch.qos.logback.classic.AsyncAppender">         <queueSize>512</queueSize>         <appender-ref ref="druid"/>     </appender>     <logger name="druid.sql.DataSource" level="DEBUG" additivity="false">         <appender-ref ref="druid-queue"/>     </logger>     <logger name="druid.sql.Connection" level="DEBUG" additivity="false">         <appender-ref ref="druid-queue"/>     </logger>     <logger name="druid.sql.Statement" level="DEBUG" additivity="false">         <appender-ref ref="druid-queue"/>     </logger> </springProfile>

这样也可以完成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