排序居然比不排序還快，結果是 tcmalloc 出問題了
咋了？
昨天寫了個 C++ 小程式測一下字串排序的快慢，程式碼非常簡單。
#include <algorithm>
#include <random>
#include <string>
#include <vector>
int main()
{
std::vector<std::string> vec;
std::mt19937_64 gen(43);
for (int count = 0; count < 3; ++count)
{
for (int i = 0; i < 10 * 1000 * 1000; ++i)
{
char buf[64];
snprintf(buf, sizeof buf, "%016lx", gen());
vec.push_back(buf);
}
std::sort(vec.begin(), vec.end());// 如果用 tcmalloc 2.5，這行註釋掉反而會變慢！
vec.clear();
}
}
然後在家裡的 Ubuntu 18.04 / Kernel 4.15 / g++ 7.3 上簡單測試，一開始還符合預期。
$ g++ -O2 -Wall -g sort_string.cc $ time ./a.out real0m29.717s user0m29.484s sys0m0.232s # 程式碼有比較多的小塊記憶體分配與釋放，換成 tcmalloc 後效能略有提升 $ g++ -O2 -Wall -g sort_string.cc -ltcmalloc_and_profiler $ time ./a.out real0m25.345s user0m25.097s sys0m0.248s
為了測試 std::sort() 的效能，我把排序那一行註釋掉，然後再執行一遍，就得到了“本底噪音”。
# 把 std::sort 註釋掉 $ g++ -O2 -Wall -g sort_string.cc $ time ./a.out real0m5.232s user0m4.968s sys0m0.264s
可以估算出排序本身大概用了 25.345-5.232 = 20.113s，也就是說排序 10,000,000 個隨機短字串用大約 6.7s，與預期差別不大。
但是，這版只生成隨機字串而不排序的程式碼換成 tcmalloc 就出問題了。
$ g++ -O2 -Wall -g sort_string.cc -ltcmalloc_and_profiler $ time ./a.out real0m24.616s user0m4.508s sys0m20.107s<===== 系統 CPU 開銷劇增
怎麼回事？
既然已經連結了 profiler，順手開啟看一看情況。
$ CPUPROFILE=prof.out ./a.out PROFILE: interrupts/evictions/bytes = 2490/225/17992 $ pprof -http :8000 prof.out
在瀏覽器開啟 http://localhost:8000，選火焰圖。
易見大量 CPU 時間消耗在了 madvise(2) 這個系統呼叫中，那就換成 perf(1) 這個工具進一步看一看。
可以看出時間主要花在核心中的 madvise_free_pte_range() 和 mark_page_lazyfree() 這兩個函式上。一定是哪裡出 bug 了？是 Kernel 的鍋還是 tcmalloc 的鍋？
為什麼？
為什麼不排序反而比排序慢很多倍？從火焰圖上看，是記憶體釋放 cfree() 一路呼叫到了 madvise(2) 上。這應該很容易復現，以下這段程式碼就能復現 bug。
#include <memory>
#include <vector>
int main()
{
std::vector<std::unique_ptr<char[]>> vec;
for (int count = 0; count < 3; ++count)
{
for (int i = 0; i < 10 * 1000 * 1000; ++i)
{
vec.emplace_back(new char[32]);
}
vec.clear();
}
}
我猜，估計是順序分配與釋放小物件，觸發了 tcmalloc 或者 Kernel 裡某處 O(N^2) 複雜度的 code path，否則不會這麼慢。
例如下面這段程式碼就是 C 語言初學者容易犯的錯誤，看上去是 O(N)，實際上往往是 O(N^2)。
for (int i = 0; i < strlen(str); ++i)
{
// do something
}
而對隨機字串排序之後，釋放的順序也隨機化了，反而避開了這個 bug。
怎麼辦？
接下來怎麼辦？是 Kernel 的 bug 還是 tcmalloc 的 bug？怎麼解決？
我查了一下 tcmalloc 的 GitHub ，發現應該是已經有人發現並修復了 issue 839 ，從 gperftools 2.6 開始就沒有問題了。
commit cbb312fbe8022378c4635b3075a80a7827555170 Author: Aliaksey Kandratsenka <[email protected]> Date:Sun Dec 18 11:08:54 2016 -0800 aggressive decommit: only free necessary regions and fix O(N²) We used to decommit (with MADV_FREE or MADV_DONTNEED) whole combined span when freeing span in aggressive decommit mode. The issue with that is preceding or following span with which we combined span we're freeing could be freed already and fairly large. By passing all of that memory to decommit, we force kernel to scan all of those pages. When mass-freeing many objects old behavior led to O(N^2) behavior since freeing single span could lead to MADV_{FREE,DONTNEED}-ing of most of the heap. New implementation just does decommit of individual bits as needed. While there, I'm also adding locking to calls of PageHeap::{Get,Set}AggressiveDecommit. This partially (or mostly) fixes issue #839.
我在 Debian 10 是驗證過，沒有這個 bug，它帶的 gperftools 是 2.7 版。
但是 Debian 9 和 Ubuntu 18.04 還在用有問題的 2.4 ~ 2.5 版，而且 Ubuntu 19.04 估計還會繼續用 2.5 版，一樣有坑。從版本上推測，Ubunru 16.04 也有這個 bug，誰有空驗證一下？
如果不能升級 tcmalloc，那該怎麼解決？
我發現把環境變數 TCMALLOC_AGGRESSIVE_DECOMMIT 設成 0，就能繞過這個問題。
$ ldd a.out linux-vdso.so.1 (0x00007ffc0c3ee000) libtcmalloc_and_profiler.so.4 => /usr/lib/x86_64-linux-gnu/libtcmalloc_and_profiler.so.4 (0x00007f8cd36e6000) libstdc++.so.6 => /usr/lib/x86_64-linux-gnu/libstdc++.so.6 (0x00007f8cd335d000) libgcc_s.so.1 => /lib/x86_64-linux-gnu/libgcc_s.so.1 (0x00007f8cd3145000) libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f8cd2d54000) libunwind.so.8 => /usr/lib/x86_64-linux-gnu/libunwind.so.8 (0x00007f8cd2b39000) libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007f8cd291a000) libm.so.6 => /lib/x86_64-linux-gnu/libm.so.6 (0x00007f8cd257c000) /lib64/ld-linux-x86-64.so.2 (0x00007f8cd3b5e000) liblzma.so.5 => /lib/x86_64-linux-gnu/liblzma.so.5 (0x00007f8cd2356000) libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007f8cd2152000) $ time ./a.out real0m14.906s user0m0.912s sys0m13.993s $ export TCMALLOC_AGGRESSIVE_DECOMMIT=0 $ time ./a.out real0m0.949s user0m0.849s sys0m0.100s
Hope it helps.
ps. 我估計 Raspberry Pi 上也有這個問題，有誰有興趣驗證一下？