之前一段時(shí)間，為我們發(fā)現(xiàn)的一個(gè)SaaS應(yīng)用程序會(huì)間歇性地卡頓、變慢，因?yàn)楹荛L(zhǎng)時(shí)間都沒(méi)有定位到原因，所以解決的辦法就只能是重啟。

這個(gè)現(xiàn)象和之前我們遇到的程序變得卡頓不太一樣，因?yàn)槲覀儼l(fā)現(xiàn)這個(gè)應(yīng)用程序不僅在高流量期間時(shí)會(huì)變慢，有時(shí)在低流量時(shí)期也會(huì)變慢。所以這令大家都很奇怪。

這類應(yīng)用程序的變慢，重新啟動(dòng)之后就可以維持一段時(shí)間，但是過(guò)段時(shí)間又有可能會(huì)再次出現(xiàn)。

故障排除

當(dāng)我們準(zhǔn)備排查這個(gè)問(wèn)題的時(shí)候，我們?cè)趹?yīng)用程序速度很慢的時(shí)候，嘗試著捕獲了這個(gè)應(yīng)用程序的線程Dump。有很多種方式來(lái)捕獲線程轉(zhuǎn)Dump，我們選擇了“jstack”工具來(lái)獲取。

在問(wèn)題發(fā)生時(shí)獲得線程Dump是非常關(guān)鍵的!

然后我們將捕獲的線程Dump上傳到一個(gè)線上線程Dump分析工具(https://fastthread.io/)。該工具立即幫我們生成了一份報(bào)告。

報(bào)告立即找出了問(wèn)題的根本原因。分析工具上顯示“http-nio-8080-exec-121”線程阻塞了100多個(gè)線程。下面是傳遞依賴圖，展示了阻塞線程:

從圖中可以看到100多個(gè)線程被“http-nio-8080-exec-121”線程阻塞。當(dāng)我們點(diǎn)擊圖中的“http-nio-8080-exec-121”超鏈接時(shí)，它會(huì)打印出線程的堆棧軌跡:

仔細(xì)觀察圖中被框出來(lái)的部分，你可以看到該線程已經(jīng)獲取到org.apache.log4j.Logger的鎖，正在進(jìn)行其他的操作。

接下來(lái)，我們隨便找一個(gè)被"http-nio-8080-exec-121"阻塞的線程，看一下他的堆棧信息：

看一下上面堆棧跟蹤中被框出來(lái)的部分。我們可以看到“http-nio-8080-exec-56”當(dāng)前正處于阻塞(BLOCKED)狀態(tài)，而阻塞的原因是它正在等待獲取org.apache.log4j.Logger的鎖。

前面我們剛剛分析過(guò)，“http-nio-8080-exec-121”獲得了org.apache.log4j.Logger的鎖，正在進(jìn)行其他操作，而鎖并沒(méi)有被釋放，所以其他線程想要獲得鎖就只能被阻塞。

其余的所有被阻塞的線程也在等待獲取org.apache.log4j.Logger的鎖。因此，每當(dāng)任何應(yīng)用程序線程試圖記錄日志時(shí)，它都會(huì)因?yàn)闊o(wú)法獲取到鎖而進(jìn)入阻塞狀態(tài)。

剛開(kāi)始我們也沒(méi)有太多的頭緒，后來(lái)我們嘗試借助Google的力量，然后我們用谷歌搜索了"org.apache.log4j.Logger 阻塞 線程"這樣的關(guān)鍵字。

我們?cè)贏pache Log4j bug數(shù)據(jù)庫(kù)中偶然發(fā)現(xiàn)了這個(gè)有趣的Bug，而且這個(gè)Bug早在2015年就被發(fā)現(xiàn)了。(https://bz.apache.org/bugzilla/show_bug.cgi?id=57714 )。

這是Log4J框架中已知的bug之一，也是開(kāi)發(fā)新的Log4j2框架的主要原因之一。

由于這個(gè)bug，任何試圖打印日志的線程都進(jìn)入了阻塞狀態(tài)。它導(dǎo)致整個(gè)應(yīng)用程序嘎然而止。一旦應(yīng)用程序從Log4j遷移到Log4j2框架，問(wèn)題就解決了。

結(jié)論

Log4j已經(jīng)在2015年8月開(kāi)始就不再被維護(hù)了。如果您的應(yīng)用程序仍在使用Log4J框架，強(qiáng)烈建議升級(jí)到Log4j2框架。Log4j2不僅僅是Log4j框架的下一個(gè)版本，它是一個(gè)從零開(kāi)始編寫(xiě)的新框架，它有很多性能改進(jìn)。

最后，如果網(wǎng)站遇到程序被拖慢的問(wèn)題，那么也可以考慮一下這個(gè)因素。

關(guān)于作者：漫話編程，是一個(gè)通過(guò)漫畫(huà)+音頻的形式講解枯燥的編程知識(shí)的公眾號(hào)。致力于讓編程變得更有樂(lè)趣。

本文轉(zhuǎn)載自微信公眾號(hào)「漫話編程」，可以通過(guò)以下二維碼關(guān)注。轉(zhuǎn)載本文請(qǐng)聯(lián)系漫話編程公眾號(hào)。