在使用aop实现分布式锁,发现锁释放后另外的线程查询到的数据依然是历史数据,导致数据不一致。日志如下
[Thread-8]|DEBUG|o.m.s.t.SpringManagedTransaction[debug,49]|JDBC Connection [com.mysql.cj.jdbc.ConnectionImpl@74c9ec9] will be managed by Spring
[Thread-8]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Preparing: SELECT id,order_id,purchase_odd,status,remark,create_time FROM o_erp_log WHERE (order_id = ?)
[Thread-8]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Parameters: -1(Long)
[Thread-8]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|<== Total: 1
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@7ca31702]
[Thread-8]|INFO |c.c.o.e.s.i.ErpLogServiceImpl[crud,92]|查询到数据[-1]:[ErpLog(id=1418, orderId=-1, purchaseOdd=abcd, status=2, remark=Thread-9, createTime=Tue Aug 23 11:00:13 CST 2022)]
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@7ca31702] from current transaction
[Thread-8]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Preparing: UPDATE o_erp_log SET order_id=?, purchase_odd=?, status=?, remark=?, create_time=? WHERE id=?
[Thread-8]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Parameters: -1(Long), abcd(String), 2(Integer), Thread-8(String), 2022-08-23 11:00:13.0(Timestamp), 1418(Long)
[Thread-8]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|<== Updates: 1
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@7ca31702]
[Thread-8]|DEBUG|c.c.x.XLockInterceptor[afterReturning,92]|[分布式锁] - 处理完:锁释放。返回值:Thread-8
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@7ca31702]
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@7ca31702]
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@7ca31702]
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Creating a new SqlSession
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@78492fa1]
[Thread-9]|DEBUG|o.m.s.t.SpringManagedTransaction[debug,49]|JDBC Connection [com.mysql.cj.jdbc.ConnectionImpl@7f02c3ed] will be managed by Spring
[Thread-9]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Preparing: SELECT id,order_id,purchase_odd,status,remark,create_time FROM o_erp_log WHERE (order_id = ?)
[Thread-9]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Parameters: -1(Long)
[Thread-9]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|<== Total: 1
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@78492fa1]
[Thread-9]|INFO |c.c.o.e.s.i.ErpLogServiceImpl[crud,92]|查询到数据[-1]:[ErpLog(id=1418, orderId=-1, purchaseOdd=abcd, status=2, remark=Thread-8, createTime=Tue Aug 23 11:00:13 CST 2022)]
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@78492fa1] from current transaction
[Thread-9]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Preparing: UPDATE o_erp_log SET order_id=?, purchase_odd=?, status=?, remark=?, create_time=? WHERE id=?
[Thread-9]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Parameters: -1(Long), abcd(String), 2(Integer), Thread-9(String), 2022-08-23 11:00:13.0(Timestamp), 1418(Long)
[Thread-9]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|<== Updates: 1
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@78492fa1]
[Thread-9]|DEBUG|c.c.x.XLockInterceptor[afterReturning,92]|[分布式锁] - 处理完:锁释放。返回值:Thread-9
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@78492fa1]
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@78492fa1]
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@78492fa1]
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Creating a new SqlSession
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@62c85647]
[Thread-7]|DEBUG|o.m.s.t.SpringManagedTransaction[debug,49]|JDBC Connection [com.mysql.cj.jdbc.ConnectionImpl@7093f13b] will be managed by Spring
[Thread-7]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Preparing: SELECT id,order_id,purchase_odd,status,remark,create_time FROM o_erp_log WHERE (order_id = ?)
[Thread-7]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Parameters: -1(Long)
[Thread-7]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|<== Total: 1
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@62c85647]
[Thread-7]|INFO |c.c.o.e.s.i.ErpLogServiceImpl[crud,92]|查询到数据[-1]:[ErpLog(id=1418, orderId=-1, purchaseOdd=abcd, status=2, remark=Thread-9, createTime=Tue Aug 23 11:00:13 CST 2022)]
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@62c85647] from current transaction
[Thread-7]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Preparing: UPDATE o_erp_log SET order_id=?, purchase_odd=?, status=?, remark=?, create_time=? WHERE id=?
[Thread-7]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Parameters: -1(Long), abcd(String), 2(Integer), Thread-7(String), 2022-08-23 11:00:13.0(Timestamp), 1418(Long)
[Thread-7]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|<== Updates: 1
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@62c85647]
[Thread-7]|DEBUG|c.c.x.XLockInterceptor[afterReturning,92]|[分布式锁] - 处理完:锁释放。返回值:Thread-7
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@62c85647]
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@62c85647]
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@62c85647]
经过日志分析后发现,分布式锁释放后, @Transactional 事务才进行提交,导致其他线程读取的是之前的数据,这是由于@Transactional也是使用AOP实现的。
调整了分布式锁的优先级后日志如下,可以看到事务提交后分布式锁才释放
[Thread-8]|DEBUG|o.m.s.t.SpringManagedTransaction[debug,49]|JDBC Connection [com.mysql.cj.jdbc.ConnectionImpl@51554eba] will be managed by Spring
[Thread-8]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Preparing: SELECT id,order_id,purchase_odd,status,remark,create_time FROM o_erp_log WHERE (order_id = ?)
[Thread-8]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Parameters: -1(Long)
[Thread-8]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|<== Total: 1
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3cceabbe]
[Thread-8]|INFO |c.c.o.e.s.i.ErpLogServiceImpl[crud,92]|查询到数据[-1]:[ErpLog(id=1418, orderId=-1, purchaseOdd=abcd, status=2, remark=Thread-7, createTime=Tue Aug 23 11:00:13 CST 2022)]
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3cceabbe] from current transaction
[Thread-8]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Preparing: UPDATE o_erp_log SET order_id=?, purchase_odd=?, status=?, remark=?, create_time=? WHERE id=?
[Thread-8]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Parameters: -1(Long), abcd(String), 2(Integer), Thread-8(String), 2022-08-23 11:00:13.0(Timestamp), 1418(Long)
[Thread-8]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|<== Updates: 1
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3cceabbe]
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3cceabbe]
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3cceabbe]
[Thread-8]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@3cceabbe]
[Thread-8]|DEBUG|c.c.x.XLockInterceptor[afterReturning,92]|[分布式锁] - 处理完:锁释放。返回值:Thread-8
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Creating a new SqlSession
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@d2d1364]
[Thread-7]|DEBUG|o.m.s.t.SpringManagedTransaction[debug,49]|JDBC Connection [com.mysql.cj.jdbc.ConnectionImpl@51554eba] will be managed by Spring
[Thread-7]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Preparing: SELECT id,order_id,purchase_odd,status,remark,create_time FROM o_erp_log WHERE (order_id = ?)
[Thread-7]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Parameters: -1(Long)
[Thread-7]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|<== Total: 1
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@d2d1364]
[Thread-7]|INFO |c.c.o.e.s.i.ErpLogServiceImpl[crud,92]|查询到数据[-1]:[ErpLog(id=1418, orderId=-1, purchaseOdd=abcd, status=2, remark=Thread-8, createTime=Tue Aug 23 11:00:13 CST 2022)]
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@d2d1364] from current transaction
[Thread-7]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Preparing: UPDATE o_erp_log SET order_id=?, purchase_odd=?, status=?, remark=?, create_time=? WHERE id=?
[Thread-7]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Parameters: -1(Long), abcd(String), 2(Integer), Thread-7(String), 2022-08-23 11:00:13.0(Timestamp), 1418(Long)
[Thread-7]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|<== Updates: 1
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@d2d1364]
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@d2d1364]
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@d2d1364]
[Thread-7]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@d2d1364]
[Thread-7]|DEBUG|c.c.x.XLockInterceptor[afterReturning,92]|[分布式锁] - 处理完:锁释放。返回值:Thread-7
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Creating a new SqlSession
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Registering transaction synchronization for SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@4a44ab5]
[Thread-9]|DEBUG|o.m.s.t.SpringManagedTransaction[debug,49]|JDBC Connection [com.mysql.cj.jdbc.ConnectionImpl@51554eba] will be managed by Spring
[Thread-9]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Preparing: SELECT id,order_id,purchase_odd,status,remark,create_time FROM o_erp_log WHERE (order_id = ?)
[Thread-9]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|==> Parameters: -1(Long)
[Thread-9]|DEBUG|c.c.o.e.m.E.selectList[debug,137]|<== Total: 1
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@4a44ab5]
[Thread-9]|INFO |c.c.o.e.s.i.ErpLogServiceImpl[crud,92]|查询到数据[-1]:[ErpLog(id=1418, orderId=-1, purchaseOdd=abcd, status=2, remark=Thread-7, createTime=Tue Aug 23 11:00:13 CST 2022)]
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Fetched SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@4a44ab5] from current transaction
[Thread-9]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Preparing: UPDATE o_erp_log SET order_id=?, purchase_odd=?, status=?, remark=?, create_time=? WHERE id=?
[Thread-9]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|==> Parameters: -1(Long), abcd(String), 2(Integer), Thread-9(String), 2022-08-23 11:00:13.0(Timestamp), 1418(Long)
[Thread-9]|DEBUG|c.c.o.e.m.E.updateById[debug,137]|<== Updates: 1
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Releasing transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@4a44ab5]
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization committing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@4a44ab5]
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization deregistering SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@4a44ab5]
[Thread-9]|DEBUG|o.m.s.SqlSessionUtils[debug,49]|Transaction synchronization closing SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@4a44ab5]
[Thread-9]|DEBUG|c.c.x.XLockInterceptor[afterReturning,92]|[分布式锁] - 处理完:锁释放。返回值:Thread-9
在分布式锁拦截器 XLockInterceptor 类上加上 @Order 注解即可。【必须加在类上面】
@Aspect
@Order(-1)
public class XLockInterceptor {
}