在需求實現裏,我需要把持久化在數據庫中的對象一直往kafka裏發送,然後由flink進行消費,把當前的對象和存儲的用户軌跡記錄等等信息進行比對,如果比對成功則觸發
最開始我是通過單線程發送,發現發送速度有點慢,這裏面我需要把對象做一些處理(比如split,flat,fitler)後才發送到kafka,大概30w+的對象需要十多分鐘那邊才能預警到,於是開始進行性能優化,使用並行流進行處理,改變之後同樣30w的數據這次只需要8秒左右就能發送完成,然而跑了一陣之後程序開始出現報錯
Received invalid metadata error in produce request on partition xxxTopic due to org.apache.kafka.common.errors.NetworkException: The server disconnected before a response was received.. Going to request metadata update now
第一眼看到這個錯,我以為是kafka或者網絡出問題了,也去看了broker的日誌,發現是有一些關於當前topic被刪除的錯誤,但是日誌級別只是一個info,我以為是topic出現錯誤,又嘗試了使用kakfa的消費命令,發現是能夠正常消費的,説明這個topic和metadata應該是沒有問題的。
我也在網上搜索着,發現很少有這個問題的説明,但是我發現了一些特徵,經過我重啓後程序又是可以繼續發送的,而且速度還是很快,但是跑了一會兒,開始又有這個報錯了,開始是一個報錯,其他的都成功,後來是慢慢的,報錯越來越多,成功的越來越少。接着過了很久竟然還發生了nacos的心跳超時導致服務不可用的情況。
我這時想到了之前看過的一些文章,説頻繁fullgc可能會導致心跳請求失敗的問題,最開始的時候看了cpu使用率,發現非常高,600%左右,我以為是因為我的程序裏面因為是有定時任務去循環發送消息所有有點佔用是正常的,沒有當回事,後來我用起了arthas和gc命令,先使用dashboard,看了下cpu線程,發現gc線程佔用以及那個並行流forkjoinpool的線程佔用非常大的cpu利用率,然後full gc次數非常多,又使用
jstat -gcutil $pid 1000
命令進行確認,開始我就發現了old區的佔用比非常高,且fullgc的頻率非常高,幾乎是幾秒鐘就有一次,最重要的是,最開始是能回收一些內存,隨着時間的推移,old區佔用比基線一直在增長,最後到了100,在這個過程中我也發現了,出現報錯的頻率和old區佔用比之間是存在關係的,報錯越來越多的時候,old區被佔用的越多,fullgc越頻繁。
這裏我才意識到這是出現內存泄漏的問題了吧,可能是我寫的代碼有點問題,於是我繼續開始排查,通過
jmap dump:format=b,file=xx.hprof $pid
然後導出文件到本地,用java visualvm打開(也可以用mat或者idea的profiler進行解析,我這裏用visualvm解析類實例的還報了堆內存不足,要改一下/lib/visualvm/etc/visualvm.conf,把-xms改大點)
查看了一下佔用最大的幾個對象ObjectiveVO(這個是我推送到kafka的封裝對象)、LogUtil.$$(這個是我發送消息的工具類)、java.util.concurrent.LinkedBlockingDeque$NODE,還有char[]、String這幾個佔用是比較大的,看到這裏我逐漸清晰了,在logUtil裏面的代碼我是從其他需要發送日誌的地方拷過來的,在這裏我加了一個異步executor的操作,主要就是為了隔離業務和日誌的發送或者發生異常的情況,然而,我把這個executor的線程池隊列設置為了new LinkedBlockingDeque<>(),這個的隊列的默認長度值為Integer.MAX,因為我們的系統屬於to G系統,所以操作日誌是比較少的,一直沒有發現這個問題,而在這個發送Kafka的場景中,數據量非常大,8秒鐘左右差不多就是30w的數據,為了快速實現布控我甚至在外層又加了一個並行流,然後這裏logUtil裏面又有一個異步把ObjectiveVO加入到隊列,所以才導致的內存溢出了....
後面我把這個異步executor去掉了,就沒有發生內存溢出的問題,也就沒有發生上面報的NetworkException,或者如果要使用線程池異步的話,一定要設計一下隊列的長度,以及拒絕策略!!!