问题:
线上riskProvision定时任务,计算出的金额不对
定位问题:
查看日志
4.13 riskProvision 2017-04-13 01:10:00.009 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] from current transaction 2017-04-13 01:10:00.010 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] for iBATIS operation 2017-04-13 01:10:00.010 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] 2017-04-13 01:10:00.011 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] from current transaction 2017-04-13 01:10:00.011 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] for iBATIS operation 2017-04-13 01:10:00.011 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] 2017-04-13 01:10:00.012 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Creating SqlSession with JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@43c10cbc] 2017-04-13 01:10:00.012 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.Connection] DEBUG ooo Connection Opened 2017-04-13 01:10:00.012 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SpringManagedTransaction] DEBUG JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@43c10cbc] will be managed by Spring 2017-04-13 01:10:00.012 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1159e5ac] 2017-04-13 01:10:00.012 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1159e5ac] for iBATIS operation 2017-04-13 01:10:00.012 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.PreparedStatement] DEBUG ==> Executing: select sum(a.TRAN_AMT) from FIN_FUND_TRAN a join outcome_flow b on a.pt_no = b.pt_no and a.ser_no = b.bus_ser where '1' = a.TRAN_ACC and a.TRAN_REA = '1' and (b.RECO_STATE = 'U'or b.RECO_STATE = '0' or b.RECO_STATE = '5') and a.pt_no = ? 2017-04-13 01:10:00.012 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.PreparedStatement] DEBUG ==> Parameters: 002(String) 2017-04-13 01:10:00.014 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.ResultSet] DEBUG <== Columns: 1
好像也执行了,但是金额为什么和数据库的表里的不一致,再查整个的定时任务日志
4.13 cron2017-04-13 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] from current transaction2017-04-13 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] for iBATIS operation2017-04-13 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28]2017-04-13 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [net.tangdi.gxseas.service.AutoRecon] INFO === 日切日期:2017-04-072017-04-13 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [net.tangdi.gxseas.service.AutoRecon] INFO 任务号:A,任务执行步骤:A01,日切日期:20170407
4月13日应该执行4.12日的,为什么执行了4.07日的了?
查下数据库定时任务日期控制表也是4,12,诡异啊?不对,日志为什么没有执行的sql记录呢?异常的话也不应该执行下去啊,莫名其妙,陷入了无头绪的状态.因为mybatis的调用时用的第三方小厂家封装框架,出于对于它的不信任,看起了源码,在BaseExecutor发现看玄机public List query(MappedStatement ms, Object parameter, RowBounds rowBounds, ResultHandler resultHandler) throws SQLException { ErrorContext.instance().resource(ms.getResource()).activity("executing a query").object(ms.getId()); if (closed) throw new ExecutorException("Executor was closed."); // Flush the internal cache is force is true if (ms.isFlushCacheRequired()) { clearLocalCache(); } List list; try { queryStack++; CacheKey key = createCacheKey(ms, parameter, rowBounds); list = resultHandler == null ? (List) localCache.getObject(key) : null; if (list != null) { handleLocallyCachedOutputParameters(ms, key, parameter); } else { list = queryFromDatabase(ms, parameter, rowBounds, resultHandler, key); } } finally { queryStack--; } if (queryStack == 0) { for (DeferredLoad deferredLoad : deferredLoads) { deferredLoad.load(); } } return list;}
调用方resultHandler传入的默认全是null,说明它会缓存拿.
因为上面的sql都没有参数,key是一定的,所以第二次之后会查缓存,但是数据时会变的,造成缓存和数据库的数据不一致.继续看mybatis源码,发现localCache是SqlSession的成员变量.那么就可以断定如果相同的sql在同一个SqlSession执行,就会命中缓存,为了证实我的猜想,继续翻日志4.10 rishProvision2017-04-10 01:10:00.011 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] from current transaction2017-04-10 01:10:00.011 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] for iBATIS operation2017-04-10 01:10:00.011 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.PreparedStatement] DEBUG ==> Executing: SELECT PT_NO, ACC_AMT, BOON_AMT, CUST_AMT, PRO_AMT, FEE_AMT, MX_AMT, LT_AMT, FXJT_AMT, PT_DEP_AMT, PRO_DEP_AMT, PROCOUNT, FINCOUNT, INVCOUNT, BOUNS_RATIO, LOANSUM_AMT, REPAY_RAT, LEVER_RAT, OVERDUE_RAT, OVERDUE_PRO_RAT, UPDATE_DATE, CORE_MANA_AMT, CORE_WAIT_AMT, PT_WAIT_AMT, CORE_RESULT, CORE_GUARA_AMT, CORE_BOND_WAIT_AMT, PT_BOND_WAIT_AMT, BOND_RESULT FROM PALTFORMACCOUNT2017-04-10 01:10:00.011 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.PreparedStatement] DEBUG ==> Parameters:2017-04-10 01:10:00.013 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.ResultSet] DEBUG <== Columns: PT_NO, ACC_AMT, BOON_AMT, CUST_AMT, PRO_AMT, FEE_AMT, MX_AMT, LT_AMT, FXJT_AMT, PT_DEP_AMT, PRO_DEP_AMT, PROCOUNT, FINCOUNT, INVCOUNT, BOUNS_RATIO, LOANSUM_AMT, REPAY_RAT, LEVER_RAT, OVERDUE_RAT, OVERDUE_PRO_RAT, UPDATE_DATE, CORE_MANA_AMT, CORE_WAIT_AMT, PT_WAIT_AMT, CORE_RESULT, CORE_GUARA_AMT, CORE_BOND_WAIT_AMT, PT_BOND_WAIT_AMT, BOND_RESULT2017-04-10 01:10:00.014 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.ResultSet] DEBUG <== Row: 006, 17115160.20, 1316359.13, 12149570.66, 3057572.01, 1638003.75, 61413.78, 0.00, 208600.00, 1316359.13, 0.00, 61841, 61841, 5, 0.00, 453419406.77, 0.68, 0.070, 0.020, 0.000, 2015-09-07 10:07:26.292735, 19534686.720, null, null, 0, 851068.580, null, null, 02017-04-10 01:10:00.015 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28]
4.10 cron2017-04-10 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28]2017-04-10 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [net.tangdi.gxseas.service.AutoRecon] INFO 数据迁移到历史表,当前主机域名:znq1332017-04-10 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] from current transaction2017-04-10 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28] for iBATIS operation2017-04-10 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.PreparedStatement] DEBUG ==> Executing: SELECT TO_CHAR(MAX(DT),'YYYY-MM-DD') FROM WORK_HOLIDAY WHERE TRASTATUS = '1'2017-04-10 01:10:00.004 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.PreparedStatement] DEBUG ==> Parameters:2017-04-10 01:10:00.005 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.ResultSet] DEBUG <== Columns: 12017-04-10 01:10:00.005 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [java.sql.ResultSet] DEBUG <== Row: 2017-04-072017-04-10 01:10:00.005 [org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-6] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@12af9e28]
可以看出这几个SQLSession都是@12af9e28,且错误执行的数据就是这几天日志查处的,证实了我的想法
解决问题
了解下mybatis 的一级缓存,select语句默认开启,由MappedStatement的flushCache属性控制.
那么怎么把mybatis的一级缓存关闭呢?官网说
1.sql级别
2.全局FlushCache
mybatis->configuration.xml->setting标签添加
单条关闭不适合现在的存量项目,sql太多了,排查不方便,全局吧,一运行发现mybatis3.0.6版本不支持此属性
3.mybatis插件
全局拦截MappedStatement使flushCache=true
import org.apache.ibatis.executor.Executor;import org.apache.ibatis.mapping.MappedStatement;import org.apache.ibatis.plugin.Interceptor;import org.apache.ibatis.plugin.Intercepts;import org.apache.ibatis.plugin.Invocation;import org.apache.ibatis.plugin.Plugin;import org.apache.ibatis.plugin.Signature;import org.apache.ibatis.session.ResultHandler;import org.apache.ibatis.session.RowBounds; import java.util.Properties; /** * 关掉Mybatis所有查询的一级缓存 * Created by mumubin 2017/4/13. */@Intercepts(@Signature(method = "query", type = Executor.class, args = {MappedStatement.class, Object.class, RowBounds.class, ResultHandler.class}))public class FlushCacheInterceptor implements Interceptor { @Override public Object intercept(Invocation invocation) throws Throwable { MappedStatement mappedStatement = (MappedStatement) invocation.getArgs()[0]; MappedStatement copy = copyMappedStatementFlushCache(mappedStatement); invocation.getArgs()[0] = copy; return invocation.proceed(); } /** * 复制MappedStatement 并设置FlushCache=true * @param mappedStatement * @return */ private MappedStatement copyMappedStatementFlushCache(MappedStatement mappedStatement) { MappedStatement.Builder builder = new MappedStatement.Builder(mappedStatement.getConfiguration(), mappedStatement.getId(), mappedStatement.getSqlSource(), mappedStatement.getSqlCommandType()); builder.resource(mappedStatement.getResource()); builder.fetchSize(mappedStatement.getFetchSize()); builder.statementType(mappedStatement.getStatementType()); builder.keyGenerator(mappedStatement.getKeyGenerator()); builder.keyProperty(mappedStatement.getKeyProperty()); builder.timeout(mappedStatement.getTimeout()); builder.resultMaps(mappedStatement.getResultMaps()); builder.resultSetType(mappedStatement.getResultSetType()); builder.cache(mappedStatement.getCache()); builder.useCache(mappedStatement.isUseCache()); builder.parameterMap(mappedStatement.getParameterMap()); builder.flushCacheRequired(true); return builder.build(); } @Override public Object plugin(Object o) { return Plugin.wrap(o, this); } @Override public void setProperties(Properties properties) { }}
单元测试测试下吧,查缓存的日志
2017-04-14 09:00:21.495 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Creating SqlSession with JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@3541d281]2017-04-14 09:00:21.496 [main] [java.sql.Connection] DEBUG ooo Connection Opened2017-04-14 09:00:21.500 [main] [com.tangdi.jump.bp.service.sqlmap.support.SpringManagedTransaction] DEBUG JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@3541d281] will be managed by Spring2017-04-14 09:00:27.437 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@53372fcf]2017-04-14 09:00:27.442 [main] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@53372fcf] for iBATIS operation2017-04-14 09:00:37.826 [main] [java.sql.PreparedStatement] DEBUG ==> Executing: SELECT TO_CHAR(MAX(DT),'YYYY-MM-DD') FROM WORK_HOLIDAY WHERE TRASTATUS = '1' 2017-04-14 09:00:37.826 [main] [java.sql.PreparedStatement] DEBUG ==> Parameters: 2017-04-14 09:00:37.842 [main] [java.sql.ResultSet] DEBUG <== Columns: 12017-04-14 09:00:37.842 [main] [java.sql.ResultSet] DEBUG <== Row: 2017-04-052017-04-14 09:00:37.846 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@53372fcf]aa:2017-04-052017-04-14 09:00:59.856 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@53372fcf] from current transaction2017-04-14 09:00:59.856 [main] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@53372fcf] for iBATIS operation2017-04-14 09:00:59.857 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@53372fcf]bb:2017-04-052017-04-14 09:00:59.857 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@53372fcf]2017-04-14 09:00:59.858 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@53372fcf]
加入插件,FlushCache后的日志
2017-04-14 09:51:04.864 [main] [java.sql.Connection] DEBUG ooo Connection Opened2017-04-14 09:51:04.867 [main] [com.tangdi.jump.bp.service.sqlmap.support.SpringManagedTransaction] DEBUG JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@7722306c] will be managed by Spring2017-04-14 09:51:04.879 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1011dc21]2017-04-14 09:51:04.880 [main] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1011dc21] for iBATIS operation2017-04-14 09:51:07.890 [main] [java.sql.PreparedStatement] DEBUG ==> Executing: SELECT TO_CHAR(MAX(DT),'YYYY-MM-DD') FROM WORK_HOLIDAY WHERE TRASTATUS = '1' 2017-04-14 09:51:07.890 [main] [java.sql.PreparedStatement] DEBUG ==> Parameters: 2017-04-14 09:51:07.905 [main] [java.sql.ResultSet] DEBUG <== Columns: 12017-04-14 09:51:07.905 [main] [java.sql.ResultSet] DEBUG <== Row: 2017-04-142017-04-14 09:51:07.909 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1011dc21]aa:2017-04-142017-04-14 09:51:09.837 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1011dc21] from current transaction2017-04-14 09:51:09.838 [main] [com.tangdi.jump.bp.service.sqlmap.impl.SqlMapImpl] DEBUG Opened SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1011dc21] for iBATIS operation2017-04-14 09:51:09.839 [main] [java.sql.PreparedStatement] DEBUG ==> Executing: SELECT TO_CHAR(MAX(DT),'YYYY-MM-DD') FROM WORK_HOLIDAY WHERE TRASTATUS = '1' 2017-04-14 09:51:09.840 [main] [java.sql.PreparedStatement] DEBUG ==> Parameters: 2017-04-14 09:51:09.844 [main] [java.sql.ResultSet] DEBUG <== Columns: 12017-04-14 09:51:09.844 [main] [java.sql.ResultSet] DEBUG <== Row: 2017-04-142017-04-14 09:51:09.845 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1011dc21]bb:2017-04-142017-04-14 09:51:09.846 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1011dc21]2017-04-14 09:51:09.848 [main] [com.tangdi.jump.bp.service.sqlmap.support.SqlSessionUtils] DEBUG Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@1011dc21]
ok,大功告成,bug完美解决,所以sql查询都必须查询数据库了
总结
吐槽下mybatis的设计问题,ORM好好做数据库的事情,关于缓存的事情不要做,交给redis好了,功能做就做了,但是默认开启就不对了!!! 不管是什么开源项目,都需在保证正确性的下再考虑提示性能.在提示性能有可能引入数据错误的功能应默认关闭!!!!