【编者按】新婚现场给服务器扩容,下班路上修Bug……对于程序员来说,这样的日常并不陌生。在新年第一天,国外一名叫Ali Josie 的软件工程师、信息安全爱好者就经历了找Bug、复现、修复这样的事情,并且还发表了一篇《This Is Why Our 3000 Apache Servers Went Down On The First Day of 2022》,具体是怎么一回事呢?
新年第一天,又恰逢周六,早上醒来却看到一堆整个基础设施挂掉的警报!我的一位同事就遭遇了这样的真实,他当时的心情可想而知。
首先,最重要的是恢复服务,把服务宕机的影响降到最低,我们重启了所有Apache服务器,还好没有任何问题。接下来就要找出宕机的原因了。为什么所有服务器都在新年第一天宕机?这肯定不是偶然吧?
我们看到每台服务器上都记录了如下日志:
AH00171: Graceful restart requested, doing restart
libgomp: 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
看来,新版都没有使用多线程,因此完全没有创建键。
终于解决了,但是为什么这么长时间都没有重启过?我们决定不再在这个问题上浪费时间了,因为“如果排除一切不可能的选项,那么剩下来的那个无论多么不可思议,都是真相。”
解决这个问题后感觉挺奇怪。虽然解决问题感觉挺自豪,但世界上还有很多长时间运行的服务器不知道在什么时候就会遇到这个问题。
原文链接:
https://alijosie.medium.com/this-is-why-our-3000-apache-servers-went-down-on-the-first-day-of-2022-3cc5e9639587
本文为 CSDN 翻译,转载请注明来源出处。
《新程序员003》正式上市,50余位技术专家共同创作,云原生和数字化的开发者们的一本技术精选图书。内容既有发展趋势及方法论结构,华为、阿里、字节跳动、网易、快手、微软、亚马逊、英特尔、西门子、施耐德等30多家知名公司云原生和数字化一手实战经验!