書圈 - 新年第一天，3000台Apache服務器宕機－鑽石舞台

點擊上圖，查看教學大綱

【編者按】新婚現場給服務器擴容，下班路上修Bug……對於程序員來說，這樣的日常並不陌生。在新年第一天，國外一名叫Ali Josie 的軟件工程師、信息安全愛好者就經歷了找Bug、復現、修復這樣的事情，並且還發表了一篇《This Is Why Our 3000 Apache Servers Went Down On The First Day of 2022》，具體是怎麼一回事呢？

作者 |Ali Josie 譯者|彎月

出品 | CSDN（ID：CSDNnews）

新年第一天，又恰逢周六，早上醒來卻看到一堆整個基礎設施掛掉的警報！我的一位同事就遭遇了這樣的真實，他當時的心情可想而知。

大清早

首先，最重要的是恢復服務，把服務宕機的影響降到最低，我們重啟了所有Apache服務器，還好沒有任何問題。接下來就要找出宕機的原因了。為什麼所有服務器都在新年第一天宕機？這肯定不是偶然吧？

我們看到每台服務器上都記錄了如下日誌：

AH00171:Gracefulrestartrequested,doingrestartlibgomp: could not create thread pool destructor.

libgomp是什麼？我們先上網查了一下這個錯誤。ServerFault上有人問過這個問題，但沒人回答，至少沒有我們能用的東西。不過這個問題有點奇怪，因為提問者說他的服務器每隔24～36小時就會發生一次。

思考

回到錯誤本身。我們每天早上都會做一次日誌輪轉，這樣每天都用新的日誌。因此要重啟服務器。似乎Apache已經成功重啟，但由於libgomp錯誤又宕機了。

在網上搜索到的大量結果中尋找答案無異於大海撈針，於是我們開始閱讀libgomp的源代碼，看看究竟發生了什麼。首先，libgomp是什麼？根據其主頁的描述：

「GOMP項目是C、C++和Fortran編譯器OpenMP的一個實現……GOMP能簡化所有GNU系統上的並行編程。」

所以它是OpenMP的實現。它怎麼會出問題？

搜索了一下源代碼，我們發現錯誤消息的唯一出處是這裡：

所以顯然，它在試圖創建一個線程鍵，但出錯了。檢查pthread_key_create的手冊：

「pthread_key_create會創建用於線程專有的數據鍵，可在進程的所有線程中使用。pthread_key_create()提供的鍵值是不透明的對象，用於定位線程專有的數據。雖然不同線程可以使用相同的鍵名稱，通過pthread_setspecific()綁定到鍵的值是按照線程維護的，在線程的整個生命周期都有效。」

有意思！那返回值是什麼？

「pthread_key_create()函數會在下述情況失敗：

系統資源不足，無法創建另一個線程特定數據鍵，或每個進程的鍵總數達到了 PTHREAD_KEYS_MAX 上限。

內存不足，無法創建鍵。」

然後檢查了代碼，看看發生了什麼，以及PTHREAD_KEYS_MAX最大值是多少：

所以說，key只是一個0~1024之間（不含1024）的數字，賦給pthread_key_create的調用者。這些鍵由一個簡單的CAS負責賦值，因此肯定有某個地方釋放這些鍵。似乎我們找到了問題。我們只需要增大PTHREAD_KEYS_MAX。但是，這個值是常量。我們甚至找到了一個帖子，要求增加PTHREAD_KEYS_MAX：

「pthread_key_create()會拒絕超過 PTHREAD_KEYS_MAX pthread_key_t的創建請求。我遇到的問題是在NetBSD上Apache無法與多種模塊一起工作，因為這個值太低了。時間長了，服務器就會陷入無法提供服務的狀態。」

這篇帖子描述的問題域我們相似，因此我們的假設可能是正確的。但是我們依然沒辦法增大這個值。

我們開始調查為何重新加載Apache會進入libgomp的這段代碼。所以顯然，重載Apache會導致mod_php調用一個名為Imagick的模塊。Imagick是什麼？它是一個使用ImageMagick庫來創建和修改圖片的PHP擴展。

懷疑

似乎關閉Imagick就可以避免使用libgomp，這樣就不會遇到最大線程數的問題了。而且只需要設置一個環境變量即可。似乎這個方案非常安全，但我們依然有一個最大的疑問：

為什麼會在1月1日發生？而且這麼大的範圍，真的是偶然嗎？

為什麼用了這麼多年都沒事兒？會不會因為是某個更新的原因？

這樣解決問題顯然不能讓我們滿意。還有好多未解之謎。我們開始進一步閱讀Apache HTTP的和libgomp的代碼，但似乎一切都很正常，至少我們沒發現任何問題。問題也無法重現，很快這個問題就會變成未解之謎。我們搜索了許多無關的關鍵字，甚至找到了一些關於「2038年問題」的帖子。

但這些都沒有任何幫助。我們甚至懷疑過Apache的最大uptime。

最後我們檢查了Imagick的更新日誌，發現了這個：

「多個修改來減少GOMP段錯誤的發生，包括：

在關閉過程中，如果可能，則調用omp_pause_resource_all

增加了 `imagick.shutdown_sleep_count` （默認10）和`imagick.set_single_thread`（默認On）。兩者都可以減少關閉時的段錯誤。」

這符合我們的猜測：將Imagick的最大線程數設置為1就能解決問題。但並沒有解答有關時間的最大疑問。

靈光乍現

在搜索了更多奇怪的東西後，我們想看看一月份有沒有人遇到這個問題。

第一篇文章正是解開這一切的鑰匙！

突然想到……要是線程鍵從來沒有被釋放，會怎樣？有可能嗎？因為從部署依賴就從來沒有發生過這個問題……所以我們重新計算了一下，1024個鍵，如果每天早上重新加載，就需要兩年零10個月才會超過1024次重新加載。如果過去1024天內每天早上都分配一個線程鍵，而這個鍵從未被釋放的話……

終於看到了一絲曙光。我們終於找到了重現該問題的方法。我們做了一個測試環境，用同樣的服務器配置，然後簡單地運行這個腳本。

for i in seq{1..1100}; do sudo systemctl reload apache2;done

重新加載apache2 1100次（多了76次作為冗餘）。然後果然問題出現了！

Apache在重新加載了1024次以後，libgomp就報錯了。現在所有問題都得到了解答。

來看看能否通過增加環境變量MAGICK_THREAD_LIMIT（新版Imagick是OMP_THREAD_LIMIT）。很不幸，問題依舊。所以下一步就是更新Imagick版本到一個修正了該問題的版本（v3.5.0+）。很幸運，更新之後重新加載數千次都不會出問題。

檢查

還有個未解決的問題：新版Imagick有沒有刪除這個鍵？為了解答這個疑問，我們使用了一個工具：ltrace這個工具可以截獲並記錄程序運行的特定命令。我們首先在舊版本的Imagick（v.3.4.4）的服務器上運行ltrace：

ltrace -xpthread_key_*@libpthread.so.0 -L -c /usr/sbin/apache2 -k graceful

-x是特定庫中的函數的搜索字符串，此處為 libpthrad.so.0中的 pthrad_key_create 和 pthread_key_delete。

-L告訴ltrace忽略默認的過濾器，以降低噪聲。

-c會在末尾匯總所有結果。而 /usr/sbin/apache2 -k graceful相當於systemctlreload apache。

結果並沒有出乎意料：

% time seconds usecs/call calls function------ ----------- ----------- -----------------------------100.00 0.000157 157 1 pthread_key_create------ ----------- ----------- -----------------------------100.00 0.000157 1total

3.4.4版只調用了pthread_key_create而沒有刪除！

然後在新版（v3.6.0）上運行同樣的命令：

% time seconds usecs/call calls function------ ----------- ----------- ------------------------------------ ----------- ----------- ------------------------------100.00 0.000000 0 total

看來，新版都沒有使用多線程，因此完全沒有創建鍵。