你是否在MacOS的PostgreSQL Docker容器中遇到过这样神奇的情况：用EXPLAIN ANALYZE查看一个查询实际的执行计划，竟然比正常执行查询慢60倍？！今天让我们一起来研究一下PostgreSQL和Linux的内部实现，看看到底发生了什么！

clock_gettime系统调用

首先，我们需要对EXPLAIN ANALYZE是如何工作的有一定的理解。让我们一起来看看PostgreSQL的代码，我们发现EXPLAIN ANALYZE的代码可以大致归结为如下伪代码：

start = clock_gettime()
row = node.nextRow()
node.time += clock_gettime() - start
return row

由于generate_series(1, 10000)会产生10000行结果，而对于每一行，PostgreSQL会在开始和结束的时候各调用一次clock_gettime syscall，那么这样不难发现PostgreSQL一共调用了20000个clock_gettime的syscall，并且这个clock_gettime的调用不知道为什么在Docker for Mac上很慢。那到底为什么慢呢，让我们再深挖一下。

pg_test_timing

让我们先来确保一下我们关于clock_gettime是罪魁祸首的猜想方向是正确的，那用pg_test_timing来试试吧。pg_test_timing是一个用来测量PostgreSQL计时到底需要多少开销的工具，它是PostgreSQL Docker Image自带的一个工具。查看pg_test_timing代码，我们可以知道它也调用了clock_gettime syscall。

pg_test_timing的官方文档里说到：大多数（超过90%）的计时本身消耗的时间应该小于1微秒，循环计时的平均消耗会更低，低于100纳秒。

good results will show most (>90%) individual timing calls take less than one microsecond. Average per loop overhead will be even lower, below 100 nanoseconds.

在MacOS上PostgreSQL Docker容器里跑pg_test_timing，我们得到的结果是每次计时需要6853纳秒！那么我们最初的查询调用了20000次计时，那就需要20000*6853ns=137ms，这就能解释我们为什么在EXPLAIN ANALYZE里看到的总用时是157.140ms了。

同样的pg_test_timing，在部署在MacOS主机上的PostgreSQL上运行的话，只要65纳秒，比Docker里快100多倍。

到这里，我突然意识到Docker for Mac的运行机制是在后台启动了一个Linux虚拟机，那会不会是由于多出来的这层虚拟机带来了多余的开销呢？那可能不仅是Docker的问题，如果在MacOS上启动一个Linux虚拟机，并在虚拟机内运行PostgreSQL，也许应该可以看到同样的计时高延迟问题。

那让我们来比较一下Linux虚拟机和Docker的虚拟机开销区别吧。我在VirtualBox上运行了Ubuntu 18.04，运行了同样的查询EXPLAIN ANALYZE SELECT count(*) FROM generate_series(1, 10000);，这次运行时长只有3毫秒（Docker的运行时长是157毫秒）。pg_test_timing在Ubuntu 18.04上的结果是单次计时开销为33纳秒(Docker的单次计时开销是6853纳秒，MacOS主机的单次计时开销是65纳秒)。那“虚拟机这层带来了多余开销”这个理论根本说不通😮！

数数clock_gettime调用

到这里，我们需要做一个合理性检查了。之前我们是根据静态分析（查看代码）的结论提出clock_gettime是罪魁祸首的假设，那clock_gettime是不是真的如我们所料，在我们的查询期间被调用了20000次呢？

那现在让我们用perf这个工具来查查clock_gettime这个系统接口到底被调用了多少次吧。顺便说一句，perf的功能很强大，是一个值得学习的好工具。

我们用下面这个命令来查看clock_gettime在我们的查询运行时，到底被系统调用了多少次：

sudo perf stat -e 'syscalls:sys_enter_clock_*' -p <backend_pid>

我们首先通过SELECT pg_backend_pid();来看我们PostgreSQL运行的pid是什么，之后在perf命令运行开始后，运行我们的查询：

这个结果告诉我们clock_gettime syscall没有被调用过。什么？！那pg_test_timing总该调用clock_gettime syscall了吧，试一下：

sudo perf stat -e 'syscalls:sys_enter_clock_*' $(which pg_test_timing)

没有，竟然还是没有clock_gettime syscall被调用。计算机太难了😩

好吧，是时候拿出秘密武器了。查看EXPLAIN ANALYZE的代码，我们知道InstrStartNode是计时开始时调用的方法，我们用gdb来反汇编一下，看看我们是不是真的调用了clock_gettime syscall：

我们看到了callq 0xafc10 <clock_gettime@plt>，这里的@plt表示Procedure Linkage Table，这代表我们调用了libc的接口！我们再快速用perf工具的动态追踪功能确认一下，确认了有20016次clock_gettime libc调用：

sudo perf probe -x /lib/x86_64-linux-gnu/libc.so.6 'clock_gettime'
sudo perf stat -e 'probe_libc:clock_gettime' -p <backend_pid>

vDSO优化

接下来，我又继续尝试用gdb了解更多，并且阅读了一些libc的源代码，我终于发现了vDSO这个东西。简而言之vDSO是避免调用syscall的一个优化。而对于clock_gettime的优化更是写在了文档中：

译：一个会被经常调用到的syscall是gettimeofday()。这个syscall既被用户空间的应用所直接调用，也间接地被一些C库所调用。比如时间戳，循环计时，或者轮询，都需要准确地得到当前时间。时间信息并不是秘密，任何应用，任何有无权限的人都会得到相同的时间答案。所以内核把回答时间问题所需要的信息都放在用户进程可以读到的地方。从而gettimeofday()本来是一个系统调用，现在变成了一个正常的函数调用，并且只需访问内存即可得到时间。

罪魁祸首：clock_gettime系统调用没有使用vDSO优化

现在让我们回到我们最初的问题，为什么clock_gettime在Docker for Mac上很慢？当我到处google这个问题的时候，我在这篇博客中发现“时间偏移”问题会改变时钟脉冲源(clocksource)。运行如下命令，你会发现一开始的TSC时钟脉冲源由于被认为不稳定而自动切换到了hpet时钟脉冲源：

docker run --privileged -it postgres dmesg | egrep '(tsc|hpet)'

根据Linux vDSO的维护者所述，hpet这个时钟脉冲源太差了，所以他决定在vDSO中完全禁用对hpet的支持。

至此，我们终于找到了根源问题：

在MacOS主机和Docker虚拟机的时间偏移太大时，Docker后台的虚拟机决定把时钟脉冲源从TSC切换至hpet。原本TSC的gettimeofday调用非常快，因为gettimeofday调用的并不是syscall，而是通过vDSO发生在用户空间。在vDSO中，当系统当前的时钟脉冲源不支持通过vDSO调用时，gettimeofday就会退而求其次调用syscall，其中包括发生内核调用和各种其他开销。而hpet不支持通过vDSO调用，所以每个gettimeofday都是一个syscall，最终20000个syscall的多余开销使得性能差强人意。

主机和Docker之间的时间偏移问题，曾经在Docker 18.05的版本中被尝试修复过。这个修复本应该解决时间偏移问题，所以理论上没有时间偏移就不会有切换时钟脉冲源的事情发生。然而，他们的修复看上去仍然是有缺陷的，尤其是在虚拟机sleep的时候仍会发生时间偏移问题。可惜的是，尽管这个问题对很多应用产生了影响，用户在github上提出的问题却并没有得到太多的关注，这里是一个用户说PHP请求由于Docker时间偏移的问题响应慢了3倍。当我在google上到处浏览的时候，发现vDSO不支持某些时钟脉冲源的问题过去严重影响了如AWS的一些云厂商。

解决方案

重启Docker for Mac是一个变通的方法，但是时钟脉冲源自动切换的问题再次发生只是时间问题。在我工作的团队里，同事们一致同意在做性能测试方面的工作时，直接在MacOS主机上使用PostgreSQL，而不用Docker。

收获

无论如何，这次重要的收获是，现代的技术栈既复杂又脆弱，作为一个应用开发者，你也许不能完全掌握这些难点，但是你会经常需要解释为什么你的应用性能不好。所以，增强你的调试技能吧。学习足够的C语言让自己有能力阅读源代码，使用足够的gdb去设置断点，掌握足够的perf功能去追踪系统调用和方法调用。这样的话，不久那些最令人生畏的PostgreSQL性能谜题将得到解答。

如果你读到了这里，并且你对PostgreSQL、Golang或者DevOps相关职位很有兴趣，欢迎与我们联系。

原文链接：

https://twitter.com/felixge/status/1221512507690496001

译者邮箱：stoneapple0920@163.com

创作场景

为什么 Docker for Mac 中运行 EXPLAIN ANALYZE 比正常查询慢 60 倍？