redisson記憶體洩漏問題排查

jtea發表於2024-09-24
Redis記憶體

問題描述

最近生產有個服務突然出現頻繁告警，介面P99響應時間變長，運維同學觀察到相應的pod cpu飆升，記憶體佔用很高。
cpu升高問題排查是老生常談的話題了，一般可以使用top -p pid -H檢視是哪個執行緒佔用cpu高，再結合jstack找到對應的java執行緒程式碼。
不過經驗告訴我們，cpu升高還有另外一個更常見的原因，記憶體不足導致頻繁gc。垃圾收集器回收記憶體後又很快不足，繼續回收，迴圈這個過程，而gc期間涉及到STW，使用者執行緒會被掛起，響應時間自然會增加。這裡的記憶體不足可能是正常的服務本身記憶體就不夠用，也可以是異常的程式bug導致記憶體溢位。
果不其然，當時節點的full gc時間陡增，透過jstat -gcutil pid 500 30也可以看到fc非常頻繁。如圖：

這個問題實際月初也出現過，當時研發同學和運維同學透過重啟暫時解決，今天又出現了，看來不是簡單透過“重啟大法”能解決的，這次我們需要分析解決它。

排查過程

這次我們透過heap dump將堆匯出分析，命令：

jmap -dump:format=b,file=./pid.hprof pid

用jdk自帶的virsualvm或idea virsualvm launcher外掛開啟堆檔案可以看到

很明顯，跟redisson相關，我們使用的版本是3.17.1！查詢服務涉及到redisson的地方並不多，呼叫量高且可疑的只有一處，簡化後的程式碼如下：

RLock lock = this.redissonClient.getLock("mytest");
lock.tryLock(50, 100, TimeUnit.MILLISECONDS);
        
//業務程式碼...

RLock lock2 = this.redissonClient.getLock("mytest");
if (lock2.isLocked() && lock2.isHeldByCurrentThread()) {
  lock2.unlock();
}

首先我們先簡單分析下RedissonLock tryLock和unlock的原始碼，主要地方新增了備註。

    @Override
    public boolean tryLock(long waitTime, long leaseTime, TimeUnit unit) throws InterruptedException {
        long time = unit.toMillis(waitTime);
        long current = System.currentTimeMillis();
        long threadId = Thread.currentThread().getId();
        Long ttl = tryAcquire(waitTime, leaseTime, unit, threadId);
        // 獲取到鎖，返回成功
        if (ttl == null) {
            return true;
        }
        
        time -= System.currentTimeMillis() - current;
        if (time <= 0) {
            //或取不到鎖，且超過等待時間，返回失敗
            acquireFailed(waitTime, unit, threadId);
            return false;
        }
        
        current = System.currentTimeMillis();
        //訂閱鎖釋放訊息，subscribe是本次的核心!!!
        CompletableFuture<RedissonLockEntry> subscribeFuture = subscribe(threadId);
        try {
            subscribeFuture.get(time, TimeUnit.MILLISECONDS);
        } catch (ExecutionException | TimeoutException e) {
            //超時，獲取鎖失敗
            if (!subscribeFuture.cancel(false)) {
                subscribeFuture.whenComplete((res, ex) -> {
                    if (ex == null) {
                        unsubscribe(res, threadId);
                    }
                });
            }
            acquireFailed(waitTime, unit, threadId);
            return false;
        }

        try {
            time -= System.currentTimeMillis() - current;
            if (time <= 0) {
                acquireFailed(waitTime, unit, threadId);
                return false;
            }
        
            //鎖釋放了，還未超時，自旋嘗試獲取
            while (true) {
                long currentTime = System.currentTimeMillis();
                ttl = tryAcquire(waitTime, leaseTime, unit, threadId);
                // 獲取到鎖，返回成功
                if (ttl == null) {
                    return true;
                }

                time -= System.currentTimeMillis() - currentTime;
                if (time <= 0) {
                    //或取不到鎖，且超過等待時間，返回失敗
                    acquireFailed(waitTime, unit, threadId);
                    return false;
                }

                // 等待鎖釋放
                currentTime = System.currentTimeMillis();
                if (ttl >= 0 && ttl < time) {
                    commandExecutor.getNow(subscribeFuture).getLatch().tryAcquire(ttl, TimeUnit.MILLISECONDS);
                } else {
                    commandExecutor.getNow(subscribeFuture).getLatch().tryAcquire(time, TimeUnit.MILLISECONDS);
                }

                time -= System.currentTimeMillis() - currentTime;
                if (time <= 0) {
                    //或取不到鎖，且超過等待時間，返回失敗
                    acquireFailed(waitTime, unit, threadId);
                    return false;
                }
            }
        } finally {
            //取消訂閱
            unsubscribe(commandExecutor.getNow(subscribeFuture), threadId);
        }
    }

    @Override
    public RFuture<Void> unlockAsync(long threadId) {
        RFuture<Boolean> future = unlockInnerAsync(threadId);

        CompletionStage<Void> f = future.handle((opStatus, e) -> {
            //取消鎖續期
            cancelExpirationRenewal(threadId);
            //...
        });

        return new CompletableFutureWrapper<>(f);
    }

    protected RFuture<Boolean> unlockInnerAsync(long threadId) {
        return evalWriteAsync(getRawName(), LongCodec.INSTANCE, RedisCommands.EVAL_BOOLEAN,
                "if (redis.call('hexists', KEYS[1], ARGV[3]) == 0) then " +
                        "return nil;" +
                        "end; " +
                        "local counter = redis.call('hincrby', KEYS[1], ARGV[3], -1); " +
                        "if (counter > 0) then " +
                        "redis.call('pexpire', KEYS[1], ARGV[2]); " +
                        "return 0; " +
                        "else " +
                        "redis.call('del', KEYS[1]); " +
                        "redis.call('publish', KEYS[2], ARGV[1]); " +
                        "return 1; " +
                        "end; " +
                        "return nil;",
                Arrays.asList(getRawName(), getChannelName()), LockPubSub.UNLOCK_MESSAGE, internalLockLeaseTime, getLockName(threadId));
    }

redisson加解鎖主要利用了lua指令碼和redis的釋出訂閱機制，使用到的資料結構是hash。
lua指令碼保證了多個命令執行的原子性，不會有併發問題。
在java程式碼中使用synchroized/lock加鎖失敗時，可以將執行緒放到連結串列中等待喚醒重新獲取鎖。在使用redis的分散式系統中，使用的是釋出訂閱機制，透過訂閱channel，當鎖釋放時重新獲取鎖。redis的釋出訂閱跟我們使用kafka等mq中介軟體是一樣的原理，實際也可以用redis的釋出訂閱機制來實現mq功能，如下channel相當於是mq中的topic。相關命令是：

  • PUBLISH channel message，釋出一個訊息到channel。
  • SUBSCRIBE channel [channel ...]，訂閱channel，當channel有訊息時，客戶端會收到通知。
  • UNSUBSCRIBE [channel [channel ...]]，取消訂閱
  • PSUBSCRIBE pattern [pattern ...]，訂閱匹配模式的channel
  • PUNSUBSCRIBE [pattern [pattern ...]]，取消訂閱匹配模式的channel

接下來是我們的排查過程：

懷疑寫法問題

回到我們的程式碼，首先映入眼簾值得懷疑的是，加鎖和解鎖使用不是同個物件，如果redisson加解鎖是與物件狀態相關的，那就會有問題。
但從原始碼分析可以看到，解鎖邏輯非常簡單，主要使用到的是執行緒id，這個是不會變的。當然這種寫法還是要修正，除了會給人誤導，也沒必要多建立一個鎖物件。此外持有鎖的時間設定為100ms也太短了，儘管業務邏輯處理很快，但如果持有鎖期間發生full gc，鎖就會過期，其它執行緒就可以獲取到鎖，出現併發執行。

懷疑網路問題

由於不是頻繁出現問題，一個月就出現一兩次，所以懷疑是不是某些特殊條件才觸發，例如當時出現過網路抖動，主從切換等異常情況。聯絡dba同學得知前一天redis網路確實出現過抖動，結合生產日誌發現8月份出現兩次問題的前一天都有redis異常，redisson github上也有一些相關討論，這更堅定了我的推測，在網路異常情況下可能觸發某個bug，導致記憶體溢位，驗證這一點也浪費了我們不少時間。

網路問題主要有兩種，連線直接斷開和讀取超時。連線直接斷開我們連開發環境的redis很好模擬，直接將內網斷開即可。讀取超時可以使用redis-cli登入redis server，然後使用client pause命令阻塞客戶端，如下會阻塞所有客戶端請求10s，這個命令在我平時一些模擬測試也經常用到。

client pause 10000

接著寫程式碼迴圈測試，使用jvirsualvm觀察記憶體物件，發現並沒有問題，redisson相關物件佔比都很低，且能被gc回收。

for (int i = 0; i < 10000000; i++) {
  //貼入前面的程式碼
}

原始碼分析

前面的原始碼分析是最外層，最簡單的部分，還不足以幫忙我們發現問題。從前面subscribe方法進入，內部還有大量邏輯做併發控制和釋出訂閱相關邏輯。
進入subscribe，會呼叫PublishScribe的subscribe方法，接著會呼叫AsyncSemaphore的acquire方法獲取訊號量。jdk的Semaphore我們都很熟悉，AsyncSemaphore是非同步的形式，使用訊號量最關鍵的就是申請到許可使用完後，要呼叫release方法歸還，否則其它申請者就無法再次申請到許可。

    public CompletableFuture<E> subscribe(String entryName, String channelName) {
        AsyncSemaphore semaphore = service.getSemaphore(new ChannelName(channelName));
        CompletableFuture<E> newPromise = new CompletableFuture<>();

        semaphore.acquire(() -> {
            if (newPromise.isDone()) {
                semaphore.release();
                return;
            }

            E entry = entries.get(entryName);
            if (entry != null) {
                entry.acquire();
                //1.釋放許可
                semaphore.release();
                //...
                return;
            }

            E oldValue = entries.putIfAbsent(entryName, value);
            if (oldValue != null) {
                //2.釋放許可
                semaphore.release();
                //...
                return;
            }

            RedisPubSubListener<Object> listener = createListener(channelName, value);
            CompletableFuture<PubSubConnectionEntry> s = service.subscribeNoTimeout(LongCodec.INSTANCE, channelName, semaphore, listener);            
            //...
        });

        return newPromise;
    }

AsyncSemaphore主要程式碼如下，permits是1，listeners是一個無界佇列。在我們dump出來的異常例項中有一個AsyncSemaphore lambda物件，也有CompletableFuture lambda物件，看起來和這裡高度匹配，這裡大機率就是問題所在了，應該是在某種情況下，acquire後沒有呼叫release，導致其它執行緒呼叫decrementAndGet的時候是<=0，進而沒法執行listeners.poll()移除元素，最終listeners佇列元素越來越多，直到記憶體溢位。

public class AsyncSemaphore {
    private final AtomicInteger counter;
    private final Queue<CompletableFuture<Void>> listeners = new ConcurrentLinkedQueue<>();

    public AsyncSemaphore(int permits) {
        counter = new AtomicInteger(permits);
    }

    public CompletableFuture<Void> acquire() {
        CompletableFuture<Void> future = new CompletableFuture<>();
        listeners.add(future);
        tryRun();
        return future;
    }

    public void acquire(Runnable listener) {
        acquire().thenAccept(r -> listener.run());
    }

    private void tryRun() {
        while (true) {
            if (counter.decrementAndGet() >= 0) {
                CompletableFuture<Void> future = listeners.poll();
                if (future == null) {
                    counter.incrementAndGet();
                    return;
                }

                if (future.complete(null)) {
                    return;
                }
            }

            if (counter.incrementAndGet() <= 0) {
                return;
            }
        }
    }

    public void release() {
        counter.incrementAndGet();
        tryRun();
    }
}

關於Semaphore還有話說，如果一次acquire，但程式異常多次呼叫release，將導致許可超發，後續的acquire可以申請到許可執行。解決方案可以參考rocketmq SemaphoreReleaseOnlyOnce，它封裝了Semaphore，並維護一個AtomicBoolean，保證只能釋放一次。

回到上面subscribe方法，有兩處正常呼叫了release，還有一處進入了PublishSubscribeServie的subscribeNoTimeout(LongCodec.INSTANCE, channelName, semaphore, listener)方法，重點這裡傳的topicType型別是PubSubType.SUBSCRIBE。

    public CompletableFuture<PubSubConnectionEntry> subscribeNoTimeout(Codec codec, String channelName,
                                                              AsyncSemaphore semaphore, RedisPubSubListener<?>... listeners) {
        CompletableFuture<PubSubConnectionEntry> promise = new CompletableFuture<>();
        //重點：PubSubType.SUBSCRIBE
        subscribeNoTimeout(codec, new ChannelName(channelName), getEntry(new ChannelName(channelName)), promise,
                        PubSubType.SUBSCRIBE, semaphore, new AtomicInteger(), listeners);
        return promise;
    }

裡面的邏輯比較複雜，有興趣的同學可以自己分析分析，但我們關注的是每個分支最終都需要呼叫semaphore.release。
按照這個思路，最終筆者在此處發現一處可能沒有呼叫release的方法：org.redisson.pubsub.PublishSubscribeService#unsubscribe。
unsubscribe方法在complete的時候會執行lock.release()，它的complete是在BaseRedisPubSubListener回撥中呼叫的，只有if條件成立才會執行。前面我們說傳記錄的topicType是subscribe，而這裡BaseRedisPubSubListener處理的是unsubscribe和punsubscribe型別，對應不上了，這就導致whenComplete不會執行，lock.release()不會執行。

 private CompletableFuture<Void> addListeners(ChannelName channelName, CompletableFuture<PubSubConnectionEntry> promise,
            PubSubType type, AsyncSemaphore lock, PubSubConnectionEntry connEntry,
            RedisPubSubListener<?>... listeners) {

        //...
        subscribeFuture.whenComplete((res, e) -> {
            if (e != null) {
                lock.release();
                return;
            }

            if (!promise.complete(connEntry)) {
                if (!connEntry.hasListeners(channelName)) {
                    unsubscribe(type, channelName)
                        .whenComplete((r, ex) -> {
                            //這裡不會被執行，AsyncSemaphore release沒有執行！
                            lock.release();
                        });
                } else {
                    lock.release();
                }
            } else {
                lock.release();
            }
        });
        return subscribeFuture;
}

 public CompletableFuture<Void> unsubscribe(PubSubType topicType, ChannelName channelName) {
        //...
        BaseRedisPubSubListener listener = new BaseRedisPubSubListener() {

            @Override
            public boolean onStatus(PubSubType type, CharSequence channel) {
                //這個if不會進入...
                if (type == topicType && channel.equals(channelName)) {
                    executed.set(true);

                    if (entry.release() == 1) {
                        MasterSlaveEntry msEntry = getEntry(channelName);
                        msEntry.returnPubSubConnection(entry.getConnection());
                    }

                    //觸發外面whenComplete的執行
                    result.complete(null);
                    return true;
                }
                return false;
            }

        };

        ChannelFuture future;
        //這裡是unsubscribe和punsubscribe，而前面傳進來的topicType是subscribe，對不上了
        if (topicType == PubSubType.UNSUBSCRIBE) {
            future = entry.unsubscribe(channelName, listener);
        } else {
            future = entry.punsubscribe(channelName, listener);
        }
        return result;
}

問題復現

前面分析得頭頭是道，我們還得透過實踐證明一下，有理有據才行。
我的復現程式碼如下，透過併發呼叫加鎖，開始執行加個斷點在org.redisson.pubsub.PublishSubscribeService#unsubscribe裡的BaseRedisPubSubListener的onStatus方法，發現正如前面所說，topicType確實對不上。接著執行一段時間後，打一個斷點在AsyncSemaphore.acquire方法，觀察到listener屬性的size不斷增長，透過jmap pid GC.run觸發gc後也不會回收，問題得以復現。

public void test() {
  for (int i = 0; i < 20000000; i++) {
    executor.submit(() -> {
      //貼入前面的程式碼，提交到執行緒池
    });
  }
}

問題解決

在開始排查問題的時候，筆者就在github提issue諮詢是什麼原因，如何解決。他們的回覆是跟這個相關，並推薦升級到3.21.2版本，不過裡面提到的描述跟我的不太一樣，所以按照版本選擇的經驗，我決定將版本升級到3.17最後一個小版本3.17.7試一下，重新跑上面的測試程式碼，跑一段時間後，發現問題沒有出現了。

檢視org.redisson.pubsub.PublishSubscribeService#unsubscribe原始碼，發現出問題那段邏輯已經被修復了。

經驗總結

遇到難啃問題幾乎是每個開發不可避免的事情，解決問題的過程，方法和事後覆盤，經驗總結非常重要，對個人的學習和能力提升有很大的幫助。
以下幾點是我本次的總結：

  • 及時止損
    當生產出現問題，很多開發同學首先會想如何找到原因，解決根本問題，但實際情況應該是評估影響，及時止損，避免問題發散，擴大影響。
    例如不能在短時間內解決的，還要下來慢慢看日誌，分析程式碼的，能回滾的先回滾，能重啟的先重啟，爭取在出現資損前解決問題，減少對業務產生影響。

  • 向上彙報
    遇到棘手問題不要悶聲自己想辦法解決，正確做法是先向你的leader彙報問題和風險。如果問題比較棘手和嚴重，可以請求協助，避免因為個人能力不足遲遲不能解決問題，小問題拖成大問題。

  • 保留現場
    有時候問題是難以復現的，像我們本次的情況一個月可能就出現一次，如果直接重啟服務，那麼等下次問題出現就非常久了。所以正確的做法是保留現場，同時要不影響業務，可以保留一個節點，將其流量摘除，透過jstack/jmap dump出程式堆疊，其它節點重啟。

  • 保持耐心
    有些問題不是一時半會就能解決的，有的以天為單位，有的可能要一個月才解決。所以保持耐心很重要，多看看官方文件，github issue，分析原始碼，嘗試各種方式，排除各種可能，相信總會找到解決方法。

  • 版本選擇
    我們選擇的redisson版本是3.17.1，實際這個選擇不是很好。按照x.y.z的版本規範，x表示大版本，通常是有重大更新，y表示小版本，通常是一些功能迭代，z表示修復版本，通常是修bug用的。例如springboot從2.x升級到3.0，jdk版本要求最低17，是一個非常重大的更新。
    上面我為什麼選擇3.17.7來測試，是因為3.17.7是3.17的最後一個小版本，看到這個版本的release報告你就知道是為什麼了，它全部都是在修bug。
    當然本次的問題修復不一定在.7這個版本，可能是在1-7之間的某個版本，有興趣的可以再細看下。

更多分享，歡迎關注我的github：https://github.com/jmilktea/jtea

相關文章