我的线程池怎么没了?

事情的背景是这样的:我们有一个系统 A,通过 HTTP 请求到系统 B,系统 B 处理这个请求需要很长时间,并且请求频率也不同,有时候请求多,有时候请求少,所以会先返回给 A “HTTP 200 OK”, 然后再在一个线程池中继续处理这个请求。B 是一个 uWSGI app,线程池也是在 uWSGI 中开的线程池。

我们发现有一些请求处理到一般就没了,没有处理完成。但是即没有返回值,也没有 Exception 在日志里面。有问题的任务日志大体是这样子的(日志的格式是时间、module 名称、进程 ID、线程ID):

这个问题蛋疼的地方在于,没有 Exception 日志,线程就这么罢工了,转而去处理下一个任务了。而且出现的频率大约是 5 分钟一次,我们有一个 staging 环境,一天大约四五次。俗话说如果一个 BUG 能重现,那么就约等于解决了。而这个问题,是我想了好几天都不知道该怎么复现的。出现的时候转瞬即逝,没有留下一丝痕迹……

我们先后尝试了加上更多的 log(但是没有什么用,task 停止的地方很随意,几乎没有什么规律),试图找出这些有问题的 task 的规律(也没有什么规律)。之前听一哥们讲过用 settrace 打印出来所有的调用和执行日志,我写好了 settrace 的代码,打算要用这个东西了,但是试了一下打出来这个日志是在是太慢了,3s 处理完成的任务,开了 settrace 要 40s 才能完成。所以就暂时没有尝试这个方法,打算实在没什么办法了再考虑开这个日志。

今天看 log 的时候,发现线程 ID 虽然一样,但是进程 ID 已经变了。这个进程是 uWSGI 的进程,于是我怀疑是 uWSGI 销毁了这个进程,并且一并销毁了进程里面的线程池。我的理由是:因为 uWSGI 是一个 HTTP 服务器,它只关心我的所有的 HTTP 请求是否处理完了。我们的模型是先返回 HTTP Response,然后再在线程池处理。对于 uWSGI 来说,它看到已经返回 Response 了,就认为这个请求已经处理完了,我就可以关闭这个进程了。

那么 uWSGI 什么情况下会销毁并重启进程呢?我去翻了文档,发现有几个让 uWSGI respawn 的参数,其中有一个是:

max-requests
argument: required_argument

shortcut: -R

parser: uwsgi_opt_set_64bit

help: reload workers after the specified amount of managed requests

uWSGI 在一个 process 处理的请求书达到了 max-reqeusts 就会 respawn 这个 process。

我在本地尝试了一个,开一个 uWSGI 设置 –max-requests=10,发现确实请求数在 10 左右(不是精确的10,比如说下面的日志就是 14)的时候,这个进程会被 respawn,日志如下:

这个时候也确实留下了没有处理完的任务。

OK,这个问题找到了,那么之前的现象也都解释通了,线程不是自己退出的,是父进程被杀掉了,所以没有留下 traceback。

解决的办法

虽然文档和 uWSGI 代码中将 max-reqeusts 作为了一个 required arg,但是从代码的实现上看,如果设置为 0 的话,这一行 if 是永远不会执行的,也就是说 worker process 就不会被重启。于是我在 uWSGI 的配置文件中将 max-requests 选项给删掉了。临时解决了这个问题。

其实这并不是最好的方案,uWSGI 作为一个 HTTP 服务器,应该只用来处理 HTTP 请求。文档里这样说:

During the life-cycle of your webapp you will reload it hundreds of times.

You need reloading for code updates, you need reloading for changes in the uWSGI configuration, you need reloading to reset the state of your app.

Basically, reloading is one of the most simple, frequent and dangerous operation you do every time.

禁用 max-requests 虽然能保证正常情况下 process 不会被 respawn ,但是在不正常的情况,还是有可能出现的。

像是这种耗时的任务,应该通过中间件发往一个专门的 worker 来处理的,通过任务执行的框架来保证每一个任务都被执行到了。

即使不用消息,也可以用 uWSGI 的 spooler 来处理耗时的任务。

被浪费掉的时间

其实如果我早一点去看一下 uWSGI 的日志,应该是可以发现规律的,每 5000 个请求进程被杀一次,而这也正好是未处理完的任务出现的时间。但是我觉得 uWSGI 日志没有什么有用的信息,有 Nginx + django 日志就够了,所以不久前将 uWSGI 的日志 disable 了。现在看来这部分日志还是有用的,毕竟运行的 Nginx 和 uWSGI,这两个进程的运行状态很重要。至于 Django 的日志,属于业务的日志。

另外从日志可以看到,任务被中断之后,Process ID 已经不一样了,但是 Thread ID 一样,我误以为是线程一直存在,只不过线程自己出了问题。试图在线下重现的时候,我也一直用的 Django 的 runserver 模式,而忽略了服务器上跑的进程其实是 uWSGI 的事实。两个进程都不一样,根本不可能重现。

但是这个 BUG 的根本原因,我归咎于我没有仔细看 uWSGI 的文档。文档和外面的 example 几乎都带上了 max-requests 这个参数,于是我也在自己的配置文件里面写上了。但是我误以为它的意思是:uWSGI 等待队列的最大长度,而不是处理过这么多 requests 就重启。

mrluanma 说:

抄东西过来不看是很不好的习惯。我是会把每个选项是否需要都想清楚的。

uWSGI 文档中的 The Art of Graceful Reloading 说:

Finally: Do not blindly copy & paste!

Please, turn on your brain and try to adapt shown configs to your needs, or invent new ones.

Each app and system is different from the others.

Experiment before making a choice.

记住了。

 

证书换至 Let’s Encrypt(手动模式)

今天小伙伴告诉我博客的证书过期了(我隐约想起来 Kaybase 发给过我一封邮件告诉我网站所有权验证失败,被我给忽略掉了)。早上开始 renew 证书。这个过程太乌龙了,记一下吧,顺便推广一下 Let’s Encrypt。

之前的证书是腾讯云的免费 1 年的 TrustAsia 证书,用了应该两年了,这次第一反应也是打开腾讯云续命。后来万万没有想到被腾讯云的这个登陆搞了半天。

没想到腾讯云登陆不上了…… 需要我提供手机验证码,但是我现在的手机号试了十几次都收不到腾讯云的验证码。打联通的客服,客服让我发短信到一个号码,那个号码一直说“系统繁忙,请稍后再试”,网上的诸如 “发送 11111 到 106xxx 的号码” 也不好使,还有网友说让朋友尝试登陆一下他的账号,然后你往朋友收到验证码的那个号码发送 11111,我试过了也不好使。

我决定换成 Let’s Encrypt 的证书。

Let’s Encrypt 的证书一般是由 Certbot 自动签发的。但是像我这种用古老的 PHP 空间提供商的,就只好使用手动模式了。

以下教程是使用 Mac 系统手动申请网站证书的教程。

首先在 Mac 上安装 Certbot:

然后用手动模式开始申请证书(默认的 log 位置需要 root 权限,我直接用 sudo 跑了)。

然后根据提示输入域名,这里可以输入多个。

同意记录申请机器的 IP。

接下来会出现 ACME 挑战,这个挑战的意义是让你证明的域名是你的(否则的话别人就可以申请一个你的域名的证书,用来做中间人攻击了)。ACME 挑战有两种: http 和 dns,http ACME 挑战就是在你网站的 .well-known/ 下面放一个文件,显示特定的文本。dns ACME 挑战是添加一条 TXT DNS 记录到你的 DNS 解析中。默认使用的是 http,如果要使用 dns 的话,最开始的命令要添加一个选项,如下:

这里准备好证明(http 的话就放好那个文件,dns 的话就准备好解析记录),然后自己试一下(一定要试一下,不然失败了要重来),再按下回车,Cerbot 会去验证。

验证过后证书就颁发好了,Certbot 会打印出证书和 key 的路径。有效期只有三个月,所以手动模式的话还是挺麻烦的。

 

推荐 Vim 进阶书籍:《Vim 实用技巧》

最近读了《Vim 实用技巧》这本书,也是读的第一本有关 Vim 的书。此书是一种 Cookbook 的形式,每一个章节给出一个 Vim 的技巧。但是又不同一般的 Cookbook 书籍那样草草的给出解决方案,然后告诉你为什么。这本书会告诉你如何以一种“Vim 的思想”来做事情,如何将操作变成肌肉记忆,对已经能够使用 Vim 的同学来说,是居家旅行良品。

但是此书不太适合刚刚接触 Vim 或者想要开始使用 Vim 的同学,Vim 的学习曲线是比价陡峭的,这本书适合急速上升的那个阶段。对于刚刚入门的人来说,我觉得最好的方法还是删掉电脑上的 IDE 和其他编辑器,强迫自己使用 Vim,大约一个星期,基本上就能够习惯 Vim 的几种模式和 hjkl 移动了。然后你可以翻看这本书,去了解一些 Vim 里面的概念和思想,甚至还能学编辑器历史。

这篇文章记一下我从这本书学到的东西。

:help 是一个好东西。这本书也在极力像你推荐这个工具。很多地方都是一句话带过,然后后面跟上一个括号鼓励你自己去看:help 文档。其实我也知道看到文档,尴尬的问题是,我经常遇到的问题不知道是啥,在 Vim 里面叫啥,该去查什么 help,甚至我连怎么 Google 都不知道。这就是因为不知道 Vim 里面的一些概念。比如我之前经常不小心进入命令行编辑界面(按 q: 跳进去的那个)不知所措,我是谁,我在哪……看了这本书我知道了这是可以用上 Vim 基本所有的 feature 来编辑命令的一个界面,用于编辑长命令或者查看历史。是命令模式的一个升级版。这样的东西还有很多,所以我对这本书是相见恨晚啊!

从这本书中,我觉得最有用的一个思想是:编辑、重复、撤销。这个技巧的一个核心思想是:不要思考。比如要删掉 7 个单词,你可以选择 d7w ,一下子删掉 7 个,也可以选择 dw 然后按 . 重复 7 次。第一个选择你需要在心里算一下一共有多少个单词,需要按几下,这样就会打断你的思路。但是如果无脑的按 7 下就不需要思考了。那万一按错了怎么办?另一个重要的技巧是:所有的操作都成对出现。比如重复操作 . 对应 u 撤销操作;向前搜索 ; 对应退回 , ;回到上一个位置 Ctrl-o 对应 Ctrl-i。重复的时候无脑按就可以,发现按多了的话立即按撤销操作,可以形成肌肉记忆。另外一半“重复”操作都是使用的 . ,. 表示重复上一次的修改,这个“一次”很重要。需要注意一下尽量将操作合成一次,如果一次修改是由两次操作构成的,就不可重复了。

另一个我觉得比较好的思想是“重做比修复更快”,虽然这本书很少提,我忘记在哪看到的。举个例子,比如你打了 “bsah”,想改成“bash”,那么最快、最不用动脑的做法就是 ciw 然后重新打一次。无论对 vim 再熟练,这个做法一定是最快的(虽然可能别的路子可以让你少按几个键,但是不用思考才是王道,将脑子用在你要写的程序上面)。书中技巧 62 提到的是将 “fish and chips” 替换成 “chips and fish”,最少的替换方法也要按将近 20 个键,不如重新打一次呢。

Vim 的技巧很多,比如自动设置的标记,各种 text object 组合,快速移动等。而这些技巧的来源除了权威的文档,还有各种论坛,各种书籍,偷窥你同事的屏幕等等可以学习。这些都是比较零散的,还比较难记。但是 Vim 的学习就是这样的,各种各样的技巧,学的越多,用的就越熟练。对于这种零散的技巧,我的一个方法是:将平时学到的技巧用便利贴记下来,写代码的时候不时瞄一眼,渐渐就学会了。不必死记硬背,多用几次,感受到它的存在,渐渐的就记住了。建议你在读本书的时候就这样做。

另外很多概念、命令记起来非常复杂。比如 w 是快速移动一个单词,W 是快速移动一个“字”,那什么才是字呢? 空格隔开的算啥? "';: 这些符号隔开的算啥?我的经验是,这些都不必去记,如果一个操作你需要思考的话,速度就已经慢下来了,还影响你的思路。你的脑子应该用在考虑代码逻辑上,而不是用在怎么把代码打出来。拿刚刚这个例子来说吧,就简单的理解成“W 是更快的 w ”就好啦!如果移动多了怎么办?再用 w 或者 h 移动回来就好了呗。无脑的重复、撤销要比思考快的多。但是注意,无脑的重复也有高效的和低效的,如果你连 w 和 W 都不知道,那么就只能用 l 来移动了,这是无论你思考还是不思考都快不起来的。

这本书的第六部分和前面一些章节介绍了一些 Vim 插件,有一些已经过时了。比如现在文件浏览大家一般都用 NerdTree,还有好用的 CtrlP 这种模糊匹配的工具等。但是也建议看一下吧,了解一下各种插件的角色,看看他们的设计思想。说不定哪一天你也要写一个插件才能解决自己的问题呢。

 

最后再推荐几个我觉得可以快速提升 Vim 的技巧:

  1. 不要觉得修改自己已经熟悉的快捷键是多困难的事情,记住快捷键是很快的。一开始设置的快捷键可能不是很合理的,勇敢地去修改吧!合理的快捷键更加好记!
  2. 将自己平时操作觉得很烦的地方都记下来,有时间相办法去优化,写命令,或者找插件。解决自己的痛点。不要就这么忍着,你忍一次就会忍无数次。你怎么度过今天,就会怎么度过这一生。
  3. 去观摩其他 Vim 用户写代码(当然要在人家允许的情况下),从其他人的屏幕上能学到的技巧更多,因为你看到的都是人家日常用的,如果不好用人家也不会用。有时候还能发掘出跟多好用的软件呢。
  4. 逛逛 Github 的 Vim 插件,Follow 一些 Vim 插件的作者,有时候会发现一些有用的插件(虽然大多数时候发现并不是自己需要的)。
 

记一个 Python logging 多进程 rotate 问题

线下环境的日志轮转一直工作的很奇怪,今天必须要解决一下了。

我们 Django 的 settings 里面 LOGGING 配置了日志轮转,满了 100M 就开新的文件。奇怪的是我每次去看日志,发现都有很多 log 才几 M,根本没到 100M 就“轮转”了。实际的配置简化如下。

这个配置基本上是没有问题的。我把 maxBytes 改成 30M,然后观察文件的大小。发现刚开始是正常的,/var/log/django.log 一直在打,逐渐到了 30M。这个时候神奇的事情发生了,到了轮转的时刻,旧日志被 rename 成了 django.log.1 ,然后又被 rename 成了 django.log.2 ,突然,十几个文件都开始写入了,这些文件 last_modify 时间一直在更新,也一直在变大。

思考片刻,我觉得问题出在 Python 的 logging 模块并没有去处理多进程的问题。我的 Django 应用是用 uwsgi 跑的,开了 16 个进程。当日志快要超过 maxBytes 的时候,第一个进程执行了 rename、新开文件 A 的操作(这个具体的流程,看一下文档里对 rotate 的流程描述就明白了),开始朝新开的文件 A 写入;这时候第二个进程将第一个进程打开的新文件给 rename 了,然后自己又新开一个文件 B 写入。但是第一个进程依然持有文件 A 的句柄的,所以依然可以往 A 里面写入。以此类推,就导致 16 个进程大家都持有了一个文件句柄,大家同时向不同的文件写入。(这段流程是我根据现象推测的,如果不正确请指正)。

Python 自身的 logging 模块不关心多进程写文件的问题,我觉得是可以接受的。一个 Python 程序就是一个进程实例,无须关心所在的环境是什么样子。我考虑开始通过其他的方案解决这个问题。

尝试了 uwsgi 的 daemonize,遇到了两个问题:1)uwsgi 的日志和 django 的日志混在一起了 2)原本 uwsgi 的 log 是可以 rotate 的,结果我加上 daemonize 之后,日志里面出现一下错误提示,竟然直接不转了。

考虑到引入 syslog 这种第三方 log 进程或者 rotate,会增加运维的复杂度。而且得重新考虑 rotate、删除、写入不同文件等的方案,所以也没有去考虑用第三方进程的方式。

这个问题实际上是 rotate 操作执行的时候,导致了竞争条件,被执行了多次的问题。所以自然而然就想到,如果在执行这个操作的时候,能加一个锁就好了。只有一次 rotate 会被执行。找到了一个实现了这个功能 mrfh 的库。代码只有几百行,里面继承了 BaseRotatingHandler 实现了自己的一个 Handler,做的事情很简单,就是在 rotate 的时候增加一个基于文件的锁(基于 fcntl),保证 rotate 能只做一次就好了。

引入也很简单,只是安装好依赖,然后将 logging 配置的 handler 改成此库里面的 handler 就好了。

现在打出来的日志都是整整齐齐的 100M 了,另外他会在日志目录下生成一个 .filename.log.lock 作为锁,无伤大雅。

 

时区问题“最佳实践”

时区这个问题太头疼了,如果你编程,几乎会一定遇到这个问题。对一些时区没有学好的同学,每每碰到心里都会害怕的……其实这个问题很简单,你只知道自己在做什么就好了。

简单的介绍一下时区。中央时间是 UTC 时间,其他时区都是根据这个时间偏移的。中国的时间叫做“北京时间”,时区在“东八区”,记做是 UTC+8. 意思就是我们比中央时间快 8 个小时。我们过着早上9点,中央时间地区的人们过着早上1点(凌晨1点)。为了在程序中方便表达和理解,每个地区会用“区域/位置”格式来表达时区。比如中国的时区可以使用 Asia/Shanghai,纽约用 America/New_York 表示。

如果你在美国租一台 VPS,那么你将会得到 3 个时间:你在中国写程序,你的电脑上显示的“北京时间”,服务器跑着的是美国时间,然后很多程序会用 UTC 时间来表示。

如果不事先想清楚,你之后肯定会经历很多痛苦来琢磨一个时间到底是 UTC 时间还是美国时间。时间变量传来传去还经常弄丢时区信息,或者转换两次时区,都是很头疼的。我们之前做爬虫,保存数据的抓取时间、更新时间是很重要的,但是数据经过多次存储和处理,忘记了到底在哪里转换过时区,这个时间到底是什么时区的时间。后来开发了一个专门的组件用来处理,这个组件的逻辑又很不清晰,最后此组件的作者离职了,交给我来维护,所以……想象一下我的痛苦吧。

关于时区的最佳实践,和 Python 的 “Unicode” 最佳实践是一样的:三明治模型

拿到的时间处理成正确的时区,比如抓取了一个中国的网页,时区是北京时间,那么就生成一个北京时间。当数据开始保存的时候,只保存 UTC,这样你就知道,只要是内部系统,保存的时间全都是 UTC 时间。然后时间要进行展示的时候,再进行本地化。这个可以有些框架可以自动完成,比如 django。对于前后端分离的项目,可以考虑用 moment.js 这种框架实现。

另一个关键的点是:知道你的框架是怎么处理时间的

比如 Django,文档就说的很明白:当开启 USE_TIMEZONE 的时候,Django 会在数据库中存储 UTC 时间,对于 template 和 form Django 会自己在内部进行本地化。

When support for time zones is enabled, Django stores datetime information in UTC in the database, uses time-zone-aware datetime objects internally, and translates them to the end user’s time zone in templates and forms.

有关系统的时间,其实内部是用一个时间戳来计时的。Unix Timestamp 是不带时区信息的,因为这个数字代表的是从1970年(UTC)开始过去了多少秒。所以理论上讲,世界上所有的电脑在内部的计时是一样的,只是显示出来的时间是不同的。如果担心时区混乱,在系统中存储时间戳也是一个不错的方法。

但是需要注意的是,并不是所有的 Timestamp 都是不带时区信息的。我写这篇文章主要是因为今天因为 Celery 的一个时间问题调试了半天。最后发现 Celery 用的时间戳竟然不是 UTC 的,还带时区的信息!具体的代码可以看这里。我实在搞不懂他们在搞毛,为啥不用一个标准的时间戳。

另外 Python 有一个处理时间的库叫 arrow ,这个库因为一个 get() 函数就能处理各种各样的时间格式而受欢迎,之前我们要从网站的文本中提取时间,用了很多这个库。但是我的建议是:千万不要用!这个库的 API 太混乱了,比如 get() 当不写第二个可选参数的时候回忽略第三个参数 tz_info 而导致时区无法识别,写上第二个可选参数第三个参数才可以被识别(后来貌似已经修复了)。

推荐使用 Pendulum 。

另外时间有一个标准的格式,可能你已经见过了,形如这样:2019-01-13T16:27:26+00:00。这是 ISO 8601 规定的格式。大多数库都能处理这种格式。