nginx debug

4 月份的時候看到一道面試題，據說是騰訊校招面試官提的：在多線程和高并發環境下，如果有一個平均運作一百萬次才出現一次的 bug，你如何調試這個 bug？知乎原貼位址如下：騰訊實習生面試，這兩道題目該怎麼回答？ – 程式設計 .

遺憾的是知乎很多答案在抨擊這道題本身的正确性，雖然我不是這次的面試官，但我認為這是一道非常好的面試題。當然，隻是道加分題，答不上，不扣分。答得不錯，說明解決問題的思路和能力要超過應屆生平均水準。

之是以寫上面這段，是因為我覺得大部分背景服務端開發都有可能遇到這樣的 BUG，即使沒有遇到，這樣的題目也能夠激發大家不斷思考和總結。非常湊巧的是，我在 4 月份也遇到了一個類似的而且要更加嚴重的 BUG，這是我自己挖的一個很深的坑，不填好，整個項目就無法上線。現在已經過去了一個多月，趁着有時間，自己好好總結一下，希望裡面提到的一些經驗和工具能夠帶給大家一點幫助。

項目背景

我們針對 nginx 事件架構和 openssl 協定棧進行了一些深度改造，以提升 nginx 的 HTTPS 完全握手計算性能。

由于原生 nginx 使用本地 CPU 做 RSA 計算，ECDHE_RSA 算法的單核處理能力隻有 400 qps 左右。前期測試時的并發性能很低，就算開了 24 核，性能也無法超過 1 萬。

核心功能在去年底就完成了開發，線下測試也沒有發現問題。經過優化後的性能提升幾倍，為了測試最大性能，使用了很多用戶端并發測試 https 性能。很快就遇到了一些問題：

1. 第一個問題是 nginx 有極低機率（億分之一）在不同地方 core dump。白天線下壓力測試 2W qps 一般都要兩三個小時才出一次 core。每次晚上睡覺之前都會将最新的調試代碼編譯好并啟動測試，到早上醒來第一眼就會去檢視機器并祈禱不要出 core，不幸的是，一般都會有幾個到幾十個 core，并且會發現經常是在一個時間點集中 core dump。線上灰階測試運作了 6 天，在第 6 天的早上才集中 core dump 了幾十次。這樣算來，這個 core dump 的機率至少是億分之一了。 不過和面試題目中多線程不同的是，nginx 采用的是多程序 + 全異步事件驅動的程式設計模式（目前也支援了多線程，但隻是針對 IO 的優化，核心機制還是多程序加異步）。在 webserver 的實作背景下，多程序異步相比多線程的優點是性能高，沒有太多線程間的切換，而且記憶體空間獨立，省去線程間鎖的競争。當然也有缺點，就是異步模式程式設計非常複雜，将一些邏輯上連續的事件從空間和時間切割，不符合人的正常思考習慣，出了問題後比較難追查。另外異步事件對網絡和作業系統的底層知識要求較高，稍不小心就容易挖坑。
2. 第二個問題是高并發時 nginx 存在記憶體洩漏。在流量低的時候沒有問題，加大測試流量就會出現記憶體洩漏。
3. 第三個問題，因為我們對 nginx 和 openssl 的關鍵代碼都做了一些改造，希望提升它的性能。那麼如何找到性能熱點和瓶頸并持續優化呢？

其中第一和第二個問題的背景都是，隻有并發上萬 qps 以上時才有可能出現，幾百或者一兩千 QPS 時，程式沒有任何問題。

core dump 的調試

首先說一下 core 的解決思路，主要是如下幾點：

1. gdb 及 debug log 定位，發現作用不大。
2. 如何重制 bug？
3. 構造高并發壓力測試系統。
4. 構造穩定的異常請求。

gdb 及 debug log 效率太低

因為有 core dump ，是以這個問題初看很容易定位。gdb 找到 core dump 點，btrace 就能知道基本的原因和上下文了。 core 的直接原因非常簡單和常見，全部都是 NULL 指針引用導緻的。不過從函數上下文想不通為什麼會出現 NULL 值，因為這些指針在原生 nginx 的事件和子產品中都是這麼使用的，不應該在這些地方變成 NULL。

由于暫時找不到根本原因，還是先解決 CORE dump 吧，修複辦法也非常簡單，直接判斷指針是否 NULL，如果是 NULL 就直接傳回，不引用不就完事了，這個地方以後肯定不會出 CORE 了。

這樣的防守式程式設計并不提倡，指針 NULL 引用如果不 core dump，而是直接傳回，那麼這個錯誤很有可能會影響使用者的通路，同時這樣的 BUG 還不知道什麼時候能暴露。是以 CORE DUMP 在 NULL 處，其實是非常負責任和有效的做法。

在 NULL 處傳回，确實避免了在這個地方的 CORE，但是過幾個小時又 core 在了另外一個 NULL 指針引用上。于是我又繼續加個判斷并避免 NULL 指針的引用。悲劇的是，過了幾個小時，又 CORE 在了其他地方，就這樣過了幾天，我一直在想為什麼會出現一些指針為 NULL 的情況？為什麼會 CORE 在不同地方？為什麼我用浏覽器和 curl 這樣的指令工具通路卻沒有任何問題？

熟悉 nginx 代碼的同學應該很清楚，nginx 極少在函數入口及其他地方判斷指針是否為 NULL 值。特别是一些關鍵資料結構，比如‘ngx_connection_t’及 SSL_CTX 等，在請求接收的時候就完成了初始化，是以不可能在後續正常處理過程中出現 NULL 的情況。

于是我更加迷惑，顯然 NULL 值導緻出 CORE 隻是表象，真正的問題是，這些關鍵指針為什麼會被指派成 NULL？這個時候異步事件程式設計的缺點和複雜性就暴露了，好好的一個用戶端的請求，從邏輯上應該是連續的，但是被讀寫及時間事件拆成了多個片斷。雖然 GDB 能準确地記錄 core dump 時的函數調用棧，但是卻無法準确記錄一條請求完整的事件處理棧。根本就不知道上次是哪個事件的哪些函數将這個指針指派為 NULL 的, 甚至都不知道這些資料結構上次被哪個事件使用了。

舉個例子：用戶端發送一個正常的 get 請求，由于網絡或者用戶端行為，需要發送兩次才完成。服務端第一次 read 沒有讀取完全部資料，這次讀事件中調用了 A，B 函數，然後事件傳回。第二次資料來臨時，再次觸發 read 事件，調用了 A，C 函數。并且 core dump 在了 C 函數中。這個時候，btrace 的 stack frame 已經沒有 B 函數調用的資訊了。

是以通過 GDB 無法準确定位 core 的真正原因

這時候強大的 GDB 已經派不上用場了。怎麼辦？列印 nginx 調試日志。但是列印日志也很郁悶，隻要将 nginx 的日志級别調整DEBUG，CORE 就無法重制。為什麼？因為 DEBUG 的日志資訊量非常大，頻繁地寫磁盤嚴重影響了 NGINX 的性能，打開 DEBUG 後性能由幾十萬直線下降到幾百 qps。

調整到其他級别比如 INFO, 性能雖然好了，但是日志資訊量太少，沒有幫助。盡管如此，日志卻是個很好的工具，于是又嘗試過以下辦法：

1. 針對特定用戶端 IP 開啟 debug 日志，比如 IP 是 10.1.1.1 就列印 DEBUG，其他 IP 就列印最進階别的日志，nginx 本身就支援這樣的配置。
2. 關閉 DEBUG 日志，自己在一些關鍵路徑添加進階别的調試日志，将調試資訊通過 EMERG 級别列印出來。
3. nginx 隻開啟一個程序和少量的 connection 數。抽樣列印連接配接編号（比如尾号是 1）的調試日志。

總體思路依然是在不明顯降低性能的前提下列印盡量詳細的調試日志，遺憾的是，上述辦法還是不能幫助問題定位，當然了，在不斷的日志調試中，對代碼和邏輯越來越熟悉。

bug 如何重制？

這時候的調試效率已經很低了，幾萬 QPS 連續壓力測試，幾個小時才出一次 CORE，然後修改代碼，添加調試日志。幾天過去了，毫無進展。是以必須要線上下構造出穩定的 core dump 環境，這樣才能加快 debug 效率。雖然還沒有發現根本原因，但是發現了一個很可疑的地方：出 CORE 比較集中，經常是在淩晨 4,5 點，早上 7,8 點的時候 dump 幾十個 CORE。

弱網絡環境的構造 traffic control

聯想到夜間有很多的網絡硬體調整及故障，我猜測這些 core dump 可能跟網絡品質相關。特别是網絡瞬時不穩定，很容易觸發 BUG 導緻大量的 CORE DUMP。最開始我考慮過使用 TC(traffic control) 工具來構造弱網絡環境，但是轉念一想，弱網絡環境導緻的結果是什麼？顯然是網絡請求的各種異常啊, 是以還不如直接構造各種異常請求來複現問題。于是準備構造測試工具和環境，需要滿足兩個條件：

1. 并發性能強，能夠同時發送數萬甚至數十萬級以上 qps。
2. 請求需要一定機率的異常。特别是 TCP 握手及 SSL 握手階段，需要異常中止。

traffic control 是一個很好的構造弱網絡環境的工具，我之前用過測試 SPDY 協定性能。能夠控制網絡速率、丢包率、延時等網絡環境，作為 iproute 工具集中的一個工具，由 linux 系統自帶。但比較麻煩的是 TC 的配置規則很複雜，facebook 在 tc 的基礎上封裝成了一個開源工具 apc，有興趣的可以試試。

WRK 壓力測試工具

由于高并發流量時才可能出 core，是以首先就需要找一個性能強大的壓測工具。WRK是一款非常優秀的開源 HTTP 壓力測試工具，采用多線程 + 異步事件驅動的架構，其中事件機制使用了 redis 的 ae 事件架構，協定解析使用了 nginx 的相關代碼。相比 ab（apache bench）等傳統壓力測試工具的優點就是性能好，基本上單台機器發送幾百萬 pqs, 打滿網卡都沒有問題。wrk 的缺點就是隻支援 HTTP 類協定，不支援其他協定類測試，比如 protobuf，另外資料顯示也不是很友善。

nginx 的測試用法： wrk -t500 -c2000 -d30s https://127.0.0.1:8443/index.html

分布式自動測試系統的建構

由于是 HTTPS 請求，使用 ECDHE_RSA 密鑰交換算法時，用戶端的計算消耗也比較大，單機也就 10000 多 qps。也就是說如果 server 的性能有 3W qps，那麼一台用戶端是無法發送這麼大的壓力的，是以需要建構一個多機的分布式測試系統，即通過中控機同時控制多台測試機用戶端啟動和停止測試。

之前也提到了，調試效率太低，整個測試過程需要能夠自動化運作，比如晚上睡覺前，可以控制多台機器在不同的協定，不同的端口，不同的 cipher suite 運作整個晚上。白天因為一直在盯着，運作幾分鐘就需要檢視結果。 這個系統有如下功能：

1. 并發控制多台測試用戶端的啟停，最後彙總輸出總的測試結果。

2. 支援 https，http 協定測試，支援 webserver 及 revers proxy 性能測試。

3. 支援配置不同的測試時間、端口、URL。

4. 根據端口選擇不同的 SSL 協定版本，不同的 cipher suite。

5. 根據 URL 選擇 webserver、revers proxy 模式。

異常測試請求的構造

壓力測試工具和系統都準備好了，還是不能準确複現 core dump 的環境。接下來還要完成異常請求的構造。構造哪些異常請求呢？由于新增的功能代碼主要是和 SSL 握手相關，這個過程是緊接着 TCP 握手發生的，是以異常也主要發生在這個階段。于是我考慮構造了如下三種異常情形：

1. 異常的 tcp 連接配接。即在用戶端 tcp connent 系統調用時，10% 機率直接 close 這個 socket。
2. 異常的 ssl 連接配接。考慮兩種情況，full handshake 第一階段時，即發送 client hello 時，用戶端 10% 機率直接 close 連接配接。full handshake 第二階段時，即發送 clientKeyExchange 時，用戶端 10% 機率直接直接關閉 TCP 連接配接。
3. 異常的 HTTPS 請求，用戶端 10% 的請求使用錯誤的公鑰加密資料，這樣 nginx 解密時肯定會失敗。

core bug fix 小結

構造好了上述高并發壓力異常測試系統，果然，幾秒鐘之内必然出 CORE。有了穩定的測試環境，那 bug fix 的效率自然就會快很多。雖然此時通過 gdb 還是不友善定位根本原因，但是測試請求已經滿足了觸發 CORE 的條件，打開 debug 調試日志也能觸發 core dump。于是可以不斷地修改代碼，不斷地 GDB 調試，不斷地增加日志，一步步地追蹤根源，一步步地接近真相。最終通過不斷地重複上述步驟找到了 core dump 的根本原因。

其實在寫總結文檔的時候，core dump 的根本原因是什麼已經不太重要，最重要的還是解決問題的思路和過程，這才是值得分享和總結的。很多情況下，千辛萬苦排查出來的，其實是一個非常明顯甚至愚蠢的錯誤。比如這次 core dump 的主要原因是：由于沒有正确地設定 non-reusable，并發量太大時，用于異步代理計算的 connection 結構體被 nginx 回收并進行了初始化，進而導緻不同的事件中出現 NULL 指針并出 CORE。

記憶體洩漏

雖然解決了 core dump，但是另外一個問題又浮出了水面，就是 ** 高并發測試時，會出現記憶體洩漏，大概一個小時 500M 的樣子。

valgrind 的缺點

出現記憶體洩漏或者記憶體問題，大家第一時間都會想到 valgrind。valgrind 是一款非常優秀的軟體，不需要重新編譯程式就能夠直接測試。功能也非常強大，能夠檢測常見的記憶體錯誤包括記憶體初始化、越界通路、記憶體溢出、free 錯誤等都能夠檢測出來。推薦大家使用。

valgrind 運作的基本原理是：待測程式運作在 valgrind 提供的模拟 CPU 上，valgrind 會紀錄記憶體通路及計算值，最後進行比較和錯誤輸出。我通過 valgrind 測試 nginx 也發現了一些記憶體方面的錯誤，簡單分享下 valgrind 測試 nginx 的經驗：

1. nginx 通常都是使用 master fork 子程序的方式運作，使用–trace-children=yes 來追蹤子程序的資訊
2. 測試 nginx + openssl 時，在使用 rand 函數的地方會提示很多記憶體錯誤。比如 Conditional jump or move depends on uninitialised value，Uninitialised value was created by a heap allocation 等。這是由于 rand 資料需要一些熵，未初始化是正常的。如果需要去掉 valgrind 提示錯誤，編譯時需要加一個選項：-DPURIFY
3. 如果 nginx 程序較多，比如超過 4 個時，會導緻 valgrind 的錯誤日志列印混亂，盡量減小 nginx 工作程序, 保持為 1 個。因為一般的記憶體錯誤其實和程序數目都是沒有關系的。

上面說了 valgrind 的功能和使用經驗，但是 valgrind 也有一個非常大的缺點，就是它會顯著降低程式的性能，官方文檔說使用 memcheck 工具時，降低 10-50 倍。也就是說，如果 nginx 完全握手性能是 20000 qps, 那麼使用 valgrind 測試，性能就隻有 400 qps 左右。對于一般的記憶體問題，降低性能沒啥影響，但是我這次的記憶體洩漏是在大壓力測試時才可能遇到的，如果性能降低這麼明顯，記憶體洩漏的錯誤根本檢測不出來。

AddressSanitizer 的優點

address sanitizer（簡稱 asan）是一個用來檢測 c/c++ 程式的快速記憶體檢測工具。相比 valgrind 的優點就是速度快，官方文檔介紹對程式性能的降低隻有 2 倍。對 Asan 原理有興趣的同學可以參考 asan 的算法這篇文章，它的實作原理就是在程式代碼中插入一些自定義代碼，如下：

1 2 3 4 5 6 7

編譯前：    * address = . . . ;    //   or: ... = *address; 編譯後：    if ( IsPoisoned ( address ) ) {      ReportError ( address , kAccessSize , kIsWrite ) ;    } * address = . . . ;    // or: ... = *address;`

和 valgrind 明顯不同的是，asan 需要添加編譯開關重新編譯程式，好在不需要自己修改代碼。而 valgrind 不需要程式設計程式就能直接運作。

address sanitizer 內建在了 clang 編譯器中，GCC 4.8 版本以上才支援。我們線上程式預設都是使用 gcc4.3 編譯，于是我測試時直接使用 clang 重新編譯 nginx：

1 2 3

-- with - cc = "clang" \ -- with - cc - opt = "-g -fPIC -fsanitize=address -fno-omit-frame-pointer" 其中 with - cc是指定編譯器， with - cc - opt指定編譯選項， - fsanitize = address就是開啟 AddressSanitizer功能。

由于 AddressSanitizer 對 nginx 的影響較小，是以大壓力測試時也能達到上萬的并發，記憶體洩漏的問題很容易就定位了。這裡就不詳細介紹記憶體洩漏的原因了，因為跟 openssl 的錯誤處理邏輯有關，是我自己實作的，沒有普遍的參考意義。最重要的是，知道 valgrind 和 asan 的使用場景和方法，遇到記憶體方面的問題能夠快速修複。

性能熱點分析

到此，經過改造的 nginx 程式沒有 core dump 和記憶體洩漏方面的風險了。但這顯然不是我們最關心的結果（因為代碼本該如此），我們最關心的問題是：

1. 代碼優化前，程式的瓶頸在哪裡？能夠優化到什麼程度？

2. 代碼優化後，優化是否徹底？會出現哪些新的性能熱點和瓶頸？

這個時候我們就需要一些工具來檢測程式的性能熱點。

perf，oprofile，gprof，systemtap

linux 世界有許多非常好用的性能分析工具，我挑選幾款最常用的簡單介紹下：

1. [perf](Perf Wiki) 應該是最全面最友善的一個性能檢測工具。由 linux 核心攜帶并且同步更新，基本能滿足日常使用。** 推薦大家使用 **。

2. oprofile，我覺得是一個較過時的性能檢測工具了，基本被 perf 取代，指令使用起來也不太友善。比如 opcontrol –no-vmlinux , opcontrol –init 等指令啟動，然後是 opcontrol –start， opcontrol –dump， opcontrol -h 停止，opreport 檢視結果等，一大串指令和參數。有時候使用還容易忘記初始化，資料就是空的。

3. gprof主要是針對應用層程式的性能分析工具，缺點是需要重新編譯程式，而且對程式性能有一些影響。不支援核心層面的一些統計，優點就是應用層的函數性能統計比較精細，接近我們對日常性能的了解，比如各個函數時間的運作時間，，函數的調用次數等，很人性易讀。

4. systemtap 其實是一個運作時程式或者系統資訊采集架構，主要用于動态追蹤，當然也能用做性能分析，功能最強大，同時使用也相對複雜。不是一個簡單的工具，可以說是一門動态追蹤語言。如果程式出現非常麻煩的性能問題時，推薦使用 systemtap。

這裡再多介紹一下 perf 指令，tlinux 系統上預設都有安裝，比如通過 perf top 就能列舉出目前系統或者程序的熱點事件，函數的排序。

perf record 能夠紀錄和儲存系統或者程序的性能事件，用于後面的分析，比如接下去要介紹的火焰圖。

火焰圖 flame graph

perf 有一個缺點就是不直覺。火焰圖就是為了解決這個問題。它能夠以矢量圖形化的方式顯示事件熱點及函數調用關系。比如我通過如下幾條指令就能繪制出原生 nginx 在 ecdhe_rsa cipher suite 下的性能熱點：

1. perf record -F 99 -p PID -g — sleep 10
2. perf script | ./stackcollapse-perf.pl > out.perf-folded
3. ./flamegraph.pl out.perf-folded>ou.svg

   

直接通過火焰圖就能看到各個函數占用的百分比，比如上圖就能清楚地知道 rsaz_1024_mul_avx2 和 rsaz_1024_sqr_avx2 函數占用了 75% 的采樣比例。那我們要優化的對象也就非常清楚了，能不能避免這兩個函數的計算？或者使用非本地 CPU 方案實作它們的計算？

當然是可以的，我們的異步代理計算方案正是為了解決這個問題，

心态

為了解決上面提到的 core dump 和記憶體洩漏問題，花了大概三周左右時間。壓力很大，精神高度緊張， 說實話有些狼狽，看似幾個很簡單的問題，搞了這麼長時間。心裡當然不是很爽，會有些着急，特别是項目的關鍵上線期。但即使這樣，整個過程我還是非常自信并且鬥志昂揚。我一直在告訴自己：

1.調試 BUG 是一次非常難得的學習機會，不要把它看成是負擔。不管是線上還是線下，能夠主動地，高效地追查 BUG 特别是有難度的 BUG，對自己來說一次非常寶貴的學習機會。面對這麼好的學習機會，自然要充滿熱情，要如饑似渴，回首一看，如果不是因為這個 BUG，我也不會對一些工具有更深入地了解和使用，也就不會有這篇文檔的産生。

2.不管什麼樣的 BUG，随着時間的推移，肯定是能夠解決的。這樣想想，其實會輕松很多，特别是接手新項目，改造複雜工程時，由于對代碼，對業務一開始并不是很熟悉，需要一個過渡期。但關鍵是，你要把這些問題放在心上。白天上班有很多事情幹擾，上下班路上，晚上睡覺前，大腦反而會更加清醒，思路也會更加清晰。特别是白天上班時容易思維定勢，陷入一個長時間的誤區，在那裡調試了半天，結果大腦一片混沌。睡覺前或者上下班路上一個人時，反而能想出一些新的思路和辦法。

3.開放地讨論。遇到問題不要不好意思，不管多簡單，多低級，隻要這個問題不是你 google 一下就能得到的結論，大膽地，認真地群組内同僚讨論。這次 BUG 調試，有幾次關鍵的讨論給了我很大的啟發，特别是最後 reusable 的問題，也是組内同僚的讨論才激發了我的靈感。謝謝大家的幫助。