mysql排序快还是list排序快_排序居然比不排序还快，原来是 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
real    0m29.717s
user    0m29.484s
sys     0m0.232s

# 代码有比较多的小块内存分配与释放，换成 tcmalloc 后性能略有提升

$ g++ -O2 -Wall -g sort_string.cc -ltcmalloc_and_profiler
$ time ./a.out
real    0m25.345s
user    0m25.097s
sys     0m0.248s

为了测试 std::sort() 的性能，我把排序那一行注释掉，然后再运行一遍，就得到了“本底噪音”。

# 把 std::sort 注释掉
$ g++ -O2 -Wall -g sort_string.cc
$ time ./a.out

real    0m5.232s
user    0m4.968s
sys     0m0.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
real    0m24.616s
user    0m4.508s
sys     0m20.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) 这个工具进一步看一看。

$ sudo perf record -g ./a.out
$ sudo perf report

可以看出时间主要花在内核中的 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。从 commit message 猜测，应该是 tcmalloc 让 kernel 做了类似 for (char ch : input) strcat(str, ch); 的操作，这当然是 O(N^2) 的。从 gperftools 2.6 开始就没有问题了。

commit cbb312fbe8022378c4635b3075a80a7827555170
Author: Aliaksey Kandratsenka <alkondratenko@gmail.com>
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.

我是怎么找到这个 commit 的呢？用 strace 发现大量 madvise(MADV_FREE) 的系统调用，然后在 git log 里搜 MADV_FREE 就很快找到它了。

我在 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  # 这是上面的第 2 个程序，分配释放 vector<unique_ptr<char[]>>
        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
real    0m14.906s
user    0m0.912s
sys     0m13.993s

$ export TCMALLOC_AGGRESSIVE_DECOMMIT=0

$ time ./a.out
real    0m0.949s
user    0m0.849s
sys     0m0.100s

Hope it helps.

ps. 我估计 Raspberry Pi 上也有这个问题，有谁有兴趣验证一下？（根据我试验，Raspbian Stretch 一样有这个 bug，它是基于 Debian 9。）