前言
前段时间项目有关redis分布式锁的代码经常出现锁超时的情况,经排查终于发现了个隐藏的问题,现记录下来以备忘。
问题复现
引用的jedis锁项目是
<groupId>com.github.jedis-lock</groupId><artifactId>jedis-lock</artifactId><version>1.0.0</version>
项目很简单,就一个java类,为描述清楚,我把它简要改造(不影响原义)
public class JedisLock {Jedis jedis;String lockKey;int expireMsecs = 60 * 1000;int timeoutMsecs = 10 * 1000;boolean locked = false;public JedisLock(Jedis jedis, String lockKey) {this.jedis = jedis;this.lockKey = lockKey;}pblic String getLockKey() {return lockKey;}public synchronized boolean acquire() throws InterruptedException {int timeout = timeoutMsecs;while (timeout >= 0) {long expires = System.currentTimeMillis() + expireMsecs + 1;String expiresStr = String.valueOf(expires);if (jedis.setnx(lockKey, expiresStr) == 1) {// lock acquiredlocked = true;return true;}String currentValueStr = jedis.get(lockKey);if (currentValueStr != null && Long.parseLong(currentValueStr) < System.currentTimeMillis()) {// lock is expiredString oldValueStr = jedis.getSet(lockKey, expiresStr);if (oldValueStr != null && oldValueStr.equals(currentValueStr)) {// lock acquiredlocked = true;return true;}}timeout -= 100;Thread.sleep(100);}return false;}public synchronized void release(Jedis jedis) {if (locked) {jedis.del(lockKey);locked = false;}}}
项目里依赖的一个子项目引用了这个锁实现,并对这个类简单进行了封装。当时的问题是,据此实现的redis锁时不时就会有超时情况,查看日志发现,如有2个线程同时去获取锁,第2个线程会报超时,第1个线程直到第2个线程超时才继续执行。
下面是简化业务后的测试用例
@Testpublic void testLock() {Jedis jedis = new Jedis("127.0.0.1", 6379);String accessTokenKey = "accessTokenKey";jedisLock = new JedisLock(jedis, accessTokenKey);int threadCount = 2;CountDownLatch countDownLatch = new CountDownLatch(threadCount);Runnable runnable = () -> {boolean locked = false;try {locked = jedisLock.acquire();if (locked) {log.info("{}已获取到锁", Thread.currentThread().getName());// 模拟业务操作TimeUnit.SECONDS.sleep(2);} else {log.info("{}没有获取到锁", Thread.currentThread().getName());} catch (InterruptedException e) {log.error("{}获取锁失败", Thread.currentThread().getName(), e);} finally {if (locked) {log.info("{}释放锁", Thread.currentThread().getName());jedisLock.release();log.info("{}释放锁完成", Thread.currentThread().getName());}}countDownLatch.countDown();};for (int i = 0; i < threadCount; i++) {Thread t = new Thread(runnable);t.start();}try {countDownLatch.await();} catch (InterruptedException e) {e.printStackTrace();}}
打印结果为
10:36:51.023 - Thread-1已获取到锁10:36:53.028 - Thread-1释放锁10:37:01.485 - Thread-2没有获取到锁10:37:01.485 - Thread-1释放锁完成
根据打印结果我们能清楚看到,线程1获取到了锁,并在完成业务操作后去释放锁。可却一直没释放成功,直到线程2锁等待超时后,线程1才释放掉了锁。这个现象,倒是和日志描述的一致。
分析与解释
当时刚开始排查时,把重点放在业务代码的检查和加锁和解锁的代码上去了,后来通过简单复现才注意到,为什么线程1锁释放会阻塞住呢?这里也没什么操作啊,就是删除redis key值。debug发现线程1根本没进到release方法里面去。啊?这咋回事。考虑cpu满了也太牵强了,咋这么巧偏线程2超时退出了线程1就好了呢
后来才注意到居然这里有个synchronized。再前后梳理下就全明白了。由于acquire和release都有synchronized修饰,在同一个对象(jedisLock)下,它们会有同一把对象锁。
初始,线程1首先执行,进入acquire方法获取redis锁(这里线程1也会获取对象锁,不过执行完acquire方法h后对象锁就释放了)执行业务逻辑。
此时线程2也进入acquire方法,获取到了对象锁,由于线程1此时在实现业务逻辑,所以线程2拿不到redis锁。它会一直在acquire方法中,不会释放对象锁
此时线程1执行完业务逻辑,准备去释放redis锁,但是由于线程2占据了对象锁,所以它进不到release中,就此发生死锁,直到线程2获取redis锁超时退出acquire方法。
怎么解决?最简单的就是线程的redisLock对象不是一个即可。也就是在线程里创建redislock对象。
Runnable runnable = () -> {JedisLock jedisLock = new JedisLock(jedis, accessTokenKey);// 其他代码....jedisLock.acquire();// 其他代码....jedisLock.release();};