Debug 一个在 uWSGI 下使用 subprocess 卡住的问题

今天花了很长的时间在排查一个诡异的问题,值得记录一下。

本来是想写一个 HTTP 的服务,你告诉这个 HTTP 服务一个 IP 地址和端口,这个 HTTP 服务就可以返回通过 TCP 访问这个 IP 端口的延迟。因为我们每次做 chaos 注入的时候都要测试一下注入延迟成功了没有,有了这个服务,这个测试就可以自动化。

其实很简单,收到请求之后用 TCP ping 几次拿到延迟,然后返回就可以了。

之前测量 TCP 的延迟使用的都是 hping3,Redis 的作者 antirez 写的。然后就想到用这个工具来做测试好了。

搜索了一下发现没有 Python 的 binding,所以打算粗暴一些,直接在 HTTP 服务里面 fork 出来一个进程做测试,然后去处理 stdout,grep 出来延迟的数据。很快就写好了,代码大体如下:

很简单的一段代码,收到请求,调用命令,返回结果。框架使用的是 Django,在本地测试一切正常,然后发布到 staging, 噩梦开始了……

在 staging 环境中,测试的时候发现,HTTP 请求发过去永远收不到回应,最后会得到一个 504 Gateway Timeout 的结果。去容器(应用运行在一个容器里面)看,发现 hping3 进程一直没有结束,像是卡住了。

一开始有很多错误的怀疑,比如怀疑 hping3 需要 TTY 才能执行,以为 hping3 需要使用绝对路径等…… 但是想想同样的代码在本地可以运行正常,就应该不是这些原因。一个验证就是,我去应用运行的环境中开一个 Python 的 REPL 执行这段代码,是能正常得到结果的。在应用运行的环境直接运行 hping3 命令,也是没有问题的。

然后怀疑 hping3 没有足够的权限来运行,因为 hping3 发送的是 raw TCP/IP 包,需要 CAP_NET_RAW 才能执行。去容器里面检查了一下,发现这个 capability 也是有的。

到这里,其实已经花费了很多时间了,得到的事实有:

  1. 容器里面执行 hping3 是完全没有问题的,权限是足够的
  2. 直接使用 Python3 的 REPL 执行这段代码也是没有问题,代码逻辑是对的

到这里你能猜到问题出在哪里了吗?

其实还有一个运行环境没有提到,就是 uWSGI. 这个 Python 写的服务是作为 WSGI 应用跑在 uWSGI 里面的。不知道和 uWSGI 有没有关系(直觉告诉我是有的,比直觉更厉害的同事也告诉是有关系的)。于是我打算直接使用 python manage.py runserver 在容器里面跑起来试试……

一切正常了。

所以 python 直接跑应用没问题,用 uWSGI 运行就有问题。现在问题锁定在 uWSGI 上面了。为了复现这个问题,我写了一个最小的测试用例。

首先需要一个文件,叫做 pingapp.py

然后使用 uWSGI 运行这个程序:uwsgi --http-socket :9090 --wsgi-file pingapp.py --threads=4.

uWSGI 的版本是 2.0.20,Python 的版本是 3.7.5, 但其实这不重要。

最后,访问这个程序,即 curl localhost:9090.

如果是 uWSGI 的问题的话,我们期望这里已经可以复现问题了,即 curl 命令会卡在这里,然后进程( ps -ef )里面出现一个 hping3 的进程,结束不了。

如同……下面这样:

图1 – 卡住的 hping3

但现实是……这个程序一点问题没有,运行地丝般顺滑。

这就见鬼了,直接没了思路。我的应用和这个最小的复现代码根本没什么(太大的)区别啊!我又没有用一些奇奇怪怪的 lib。

后面我实在解决不了了,找了(大佬)同事帮忙,花了很多时间,找到以下事实:

  1. hping3 卡住了,发现 SIGTERM 结束不了它,只能 kill -9
  2. 然后发现 uwsgi 进程也有一样的行为了,只能 kill -9 去杀它
  3. hping3 程序被 uwsgi 正常起起来是没问题的,起来之后运行不了
  4. …… 以及中间奇奇怪怪的现象,就不细说了,其实都不重要

最后虽然也找到了根因,但是走得路太弯了。本文从这里开始,就以事后诸葛亮的视角,看看有了上面的信息,我们怎么从正确的思路一步一步找到问题。

首先,同样的环境,在 shell 里面可以正常执行 hping3 但是 uWSGI 里面却不可以,既然 uWSGI 能正常开 hping3 进程,我们就可以看看这个进程到底卡在了哪里?

通过 strace 可以发现它一直在 poll 4 这个 fd,然后查看这个 fd,发现它是一个正常的 socket,应该就是 ping tcp 端口使用的那个 socket.

然后,我们应该去看一下,正常的 hping3 的 trace 是什么样子的。

strace hping3 104.244.42.1 -p 80 --syn -c 1

可以看到 poll 附近很神奇,下面突然就开始 write 到 stdout 内容了。不知道怎么结束的。

但是往上看,有一段代码获取了当前的 pid,然后给自己发送了 SIGALRM。再往前,发现注册了 SIGALRM 的 handler.

SIGALRM 是什么呢?

SIGALRM is an asynchronous signal. The SIGALRM signal is raised when a time interval specified in a call to the alarm or alarmd function expires.

看起来是用来做异步的。

搜索了一下 hping3代码。发现代码里确实是用这个信号的。

 

那么我们的 uWSGI 下的异常 hping3 是否是因为没有收到这个 SIGALRM 而一直在傻 poll 呢?

在上面的 图1 中,卡住的 hping3 pid 是 4285,我们看下这个进程能否处理信号:

这里可以发现 SigBlk 不是全 0 的,说明有 signal 被 block 了。SigBlk 是个 64 个 bit 组成的 bitmask,每一位代表一个 signal 是否被 block,1 是 block,0 是没有 block。从右到左分别表示 1-64 号信号。

举例:

可以使用下面这段脚本去 parse 到底哪些信号被 block 了:

可以看到,hping3 需要的 14 号信号正好被 block 了。

manual 中得知:

A child created via fork(2) inherits a copy of its parent’s signal mask; the signal mask is preserved across execve(2).

所以说,我们正常的 hping3 可以收到 signal,但是 uWSGI 里面 fork 出来的进程就不可以,可能是 hping3 从 uWSGI 里面继承了 signal mask,导致它也去 block 14 这个 signal 了。

我们可以去看下 uWSGI 里面是否也是 block 了这个 signal 的:

果然是的。

代码中发现,里面只有 core_id = 0 的 thread 是处理信号的,其余的 thread block 了所有的信号。

这段代码是 core_id 如果大于0,那么 block 所有的信号,如果不大于 0,就处理信号。

所以到现在也就明白我写的那个最小的 case 为什么不能复现了:我使用了默认配置,只有一个 thread,core_id =0,它永远可以处理信号。而生产环境开了 64 个 thread,只有 1/64 的几率能够处理信号从而让应用正确返回。

我们可以重新验证一下,开 2 个 thread,预期是它会有 50% 的几率卡住:

uwsgi --http-socket :9090 --wsgi-file pingapp.py --threads=2

果然是,50% 能得到结果,50% 会卡住。

 

到这里就真相大白了。至于修改呢,我打算直接用 socket.connect 来测量 tcp 的连接时间。因为 TCP 是 3 次握手的,但是对于客户端来说基本上只花费了一个 RTT 的时间。测试下来,这样得到的时间和 hping3 也是一致的。

 

另外这个故事告诉我们,uWSGI 下 fork 出来的子进程最好都默认信号不工作,虽然 core_id =0 是可以处理信号的,但是这个作为 uWSGI 本身回应信号的设计就可以。发现 uWSGI 的代码中还有很多别的地方调用了 sigprocmask(2),可能还有其他屏蔽信号的地方。

 

有一位智者同事曾经跟我说过这么一句话:

Learn some eBPF, xintao!

看来是时候认认真真学一学 eBPF 啦。

 

 

TTY 到底是什么?

先来回答一道面试题:我们知道在终端中有一些常用的快捷键,Ctrl+E 可以移动到行尾,Ctrl+W 可以删除一个单词,Ctrl+B 可以向前移动一个字母,按上键可以出现上一个使用过的 shell 命令。在这 4 种快捷键中,有一个是和其他的实现不一样的,请问是哪一个?

答案是 Ctrl+W。因为 Ctrl+W 是一个叫 TTY 的东西提供的,其余的三个是 shell 提供的。好吧,我承认问别人这样的题目会被打死,这里只是为了吸引读者的兴趣而已。

再看另外一个比较有意思的问题:假如你现在在 host1 上面使用 ssh 命令登录了 host2,然后执行了 sleep 9999 命令。这个时候按下 Ctrl+C,请问会发生什么情况?

  1. host1 上面的 ssh 会被停止
  2. host2 上面的 sleep 命令会被停止,ssh 会话将继续保持

用过 ssh 命令的人都应该知道现象是(2),我们可以在 ssh 提供的 shell 里面随便 Ctrl+C 而不会对 ssh 造成任何影响。

那么这是怎么实现的呢?

我们知道 Ctrl+C 是发送一个 signal,int值是2,名字叫做 SIGINT. 所以我们可以猜想:是否是 ssh 进程收到了 SIGINT,然后将其转发到了 ssh 远程那边的程序,而自己不会处理这个信号呢?

我们可以使用 killsnoop 程序验证这个猜想,这个程序可以将进程间的信号打印出来。

首先我们启动 killsnoop 程序:

然后新开一个 shell,按下 Ctrl+C,会发现所在的 shell (pid=1549)收到了 signal=2 的信号,即 SIGINT.

然后我们 ssh 到本机,在 ssh 内部按下 Ctrl+C:

如果我们猜想正确的话,现在应该是 shell (pid=1549) 依然收到 SIGINT,然后将其转发到 ssh 进程。

但是 killsnoop 显示只有 ssh 打开的那个 shell 收到了 SIGINT,ssh 进程本身和原来的 pid=1549 的 shell 并没有收到任何的信号。

显然,我们的猜想是不成立的。那么,是如何实现 Ctrl+C 不影响 ssh 本身而是会影响 ssh 内部的程序的呢?相信看完本文你就会有一个答案了。

希望已经吸引到了你足够的兴趣,这些问题都要从 TTY 开始讲起,我们现在开始考古。

TTY 是一个历史产物

首先要明确一点的是,TTY 是一个历史产物。就像现在的 Unix 系统有那么多的 /bin。是因为很多程序都默认这种存在了,老的程序需要它们才能运行,新的程序也会默认去兼容它们。如果不考虑历史原因和兼容,完全写一个从头设计的 Terminal 或者目录组织的话,是可以不需要那么多 /bin,不需要 TTY 的。

下面就简单地介绍一下需要 TTY 的那段历史,以及为什么在当时的情况下,TTY 和各个子组件是不可缺少的。

TTY 的全程是 Teletype,什么是 Teletype 呢?

By ArnoldReinhold – Own work, CC BY-SA 3.0, Link

这,就是 Teletype——远程(tele),打字机(type)。

这个视频展示了它是怎么工作的。

还有一个叫做 Teletype Model 33 的 Twitter 账号会发布一些相关的内容,比如这个 git pushTeletype 上的视频

简单的来说,在很久之前,很多人一起使用一台计算机(你一定听说过 Unix 是多用户多任务的操作系统吧?)。每个人都有这么一个“终端”(Terminal, TTY, 在这种语境下可以认为是一个意思啦)。在这里敲下自己要运行的命令,然后发送给系统执行,从系统拿到结果,在纸上打印出结果。

所以,在当时,TTY 是一个硬件,作为一个硬件,是怎么连接到计算机的呢?

首先要有线,但是这根线连到的其实并不直接是计算机,而是一个叫做 Universal Asynchronous Receiver and Transmitter (UART) 的硬件。UART Driver 可以从硬件中读出信息,然后将其发送到 TTY Driver. TTY 从中读出来发送给程序。(事实上,UART 到今天也还在使用,如果你玩过 Arduino 或者树莓派的话,可能接触过。)

类似于这样:

图片来自 The TTY demystified

到这里,其实对于我们“现代人”来说,也都比较直接。来自硬件的输入通过 Driver 层层复制最终到了应用程序而已。

等等,上面还有一个叫做 “Line discipline” 的东西。这是什么鬼?

如它的名字所说,用来“管教” line 的。命令在输入之后,在按下 Enter 键之前,其实是存储在 TTY 里面的。存在 TTY 的 line 就可以被 Line discipline 所“管教”。比如它提供的功能有:通过 Ctrl+U 删除,也就是说,你按下 Ctrl+U 之后,TTY 并不会发送字符给后面的程序,而是会将当前缓存的 line 整个删掉。同理,Ctrl+W 删除一个字符也是 Line discipline 所提供的功能。(哇!你现在能通过我的面试了!)我会在后面证明这是 TTY 提供的功能。

这个功能在我们“现代人”看来简直太无聊了!不能直接交给 bash 来处理吗?有必要作为一个 Kernel 的子系统处理这种事情吗?

每当你想要批评别人时,你要记住,这个世界上所有的人,并不是个个都有过你拥有的那些优越条件。

是的,当年的 Unix 就没有这样的条件。

在很久之前,将每一个字符读进来然后立即发送给后面的程序的话,对计算机来说太累了。因为 Unix 的 RAM 很小,只有 64K words. 如果 20 个人用每分钟 60 个单词的速度打字的话,大概每秒会需要 100 次 context switches 和 disk swap,那么计算机将会花费 100% 的时间来处理这些人的按键上,根本没有时间干别的了。(PS 这段内容其实是我从 dev.to 一个评论能看到的,实在太精彩了,看到这个评论之前我看了很多文章都没想明白到底为什么需要 Line discipline.)

Line discipline 最大的用处,其实是一个可编程的中间人。它可以 buffer 20 个 TTYs 的内容,直到有一个人按下 Enter 的时候,才会真正将内容发送给后端的程序。一个 Line discipline 模块可以 cache 20 个 TTYs,假设我们需要 30s 输入一个命令的话,那么每一个用户差不多有 1.5s 的执行时间。几乎快了 100 倍。

Line discipline 的工作方式有点像 Emacs,有一个 size=127 的 function table,每一个 key 都有一个绑定的功能。比如说:进入 buffer; 将命令发送出去等等。

你可以将 TTY 设置为 raw mode,这样 Line discipline 将不会对收到的字符作任何解释,会直接发送给后面的程序(准确说,应该是前台的进程组,session,会收到)(实际上,这就是 ssh 不会收到 SIGINT 而是 ssh 内部的程序收到 SIGINT 的原因,我会在后文给你证明)。现在很多程序使用的 TTY 都是 raw mode 了,比如 ssh 和 Vim. 但是在很久之前,Vim 是运行在 cooked mode(即 Line discipline 会起作用)。当你在一行的中间输入一些文字,比如 asdffwefs,屏幕会乱掉,这些文字会覆盖后面的内容,直到你按下 Esc 退出编辑才会正常。

今天的电脑已经比当时的硬件性能搞了千万倍,所以 Line discipline 没有什么意义了。但是在当时,如果人们想要对当前输入的命令进行删除在编辑,这个功能在哪里实现最合适呢?显然是 buffer 的地方了!

这里的性能问题已经成为历史,但是 TTY 和 Line discipline 却存在了下来(不然我们现在怎么能用 Ctrl+W 呢?),因为(我猜的)很多程序在写的时候,比如 bash,会默认有 TTY 的存在;TTY 也继续保留着 Line discipline 的功能,而用户对此并没有任何体感(之前我们不知道 TTY 这个玩意,终端和 ssh 不也用的好好的吗?)所以我看来,这是一个向后兼容的“文物”。

那么在今天,TTY 到底是什么呢?本质上,它不再是一个硬件,而只是一个软件(内核子系统)。从系统的用户层面来说,他是——一个文件。当然了,Unix 里面什么不是文件呢?

通过 tty 命令可以查看当前的 shell 使用的哪一个 TTY。

作为一个“文件”,你可以直接往里面写。内容写进 TTY 之后将会被输出设备读出去。(下图表现为在下面的 shell 写入,出现在上面的 shell 中)

当然,也可以读。但当你从 TTY 读的时候,你就和输出设备形成了竞争关系,因为你们都在从这个 TTY 中尝试读,原来这个 TTY 只有一个读者,现在有了两个。我在上面的 shell 中按下了 1-9 这几个数字,每一次输入不一定会被哪边读到:

一旦被 cat 读到了,那么你按下的键将不会显示在当前的 shell 中。

是不是有了坏坏的想法?是的,我们可以通过 w 命令看看有哪些人登录在机器上,然后去 cat 他们的 TTY,他们一定会以为自己的键盘坏了!(小提示,当用户登录的时候,使用的 TTY 文件权限将设置为仅自己读写,owner 设置为自己,所以这个恶作剧必须要 root 才行!)

了解了 TTY 是什么,那么它在今天有什么用呢?

我们可以反向思考这个问题,没有 TTY 行不行?

答案是可以的。

我可以演示一下没有 TTY 一样可以使用终端。

设想一种场景,假如你攻破了别人的一台机器,比如 kawabangga.com 所在的服务器,你发现了一种可以在里面执行 python 代码的方法,但是,你只能将代码注入进去执行,看不到输出,这怎么办呢?

有一种叫做 reverse shell 的东西。通俗来讲,我们 ssh 一般是我们跑去远程的电脑上做控制,reverse,顾名思义就是反向的 shell。其实就是我在远程的机器上打开一个 shell,然后将它拱手送给你,交给你控制。

下面演示,我在下面的终端使用 nc 打开了一个 tcp 端口,然后在上面的终端执行了如下命令:

可以看到这段 python 代码实际上打开了一个sh 程序,然后将 stdin/stdout/stderr 全部和 tcp 的 socket 连接了起来。对于 nc 的这一端来说,nc 的 stdin/stdout/stderr 就发送进入了 socket,所以,我的 nc 变成了能控制对方的一个shell!

这样,我就可以在对方的主机上随意执行命令了,非常方便!

使用其他语言也可以打开 reverse shell

通过上面的图片也可以看出,这是一个没有 TTY 的 shell。它有什么问题呢?我们来跑一下 TUI 程序,比如 htop

注意看左上角的问题,其实是按下 q 之后尝试敲下 hostname 这几个字,而 sh 已经丧失理智了,连我敲下的字符都不能正常显示出来。除此之外,这个没有 TTY 的 shell 还有以下缺点:

  1. 无法正常使用 TUI 的程序,比如 Vim,htop
  2. 无法使用 tab 补全
  3. 无法使用上箭头看 history 命令
  4. 没有 job control
  5. ……

(其实 reverse shell 也是可以有 TTY 的

所以说,在今天,没有 TTY,我们也能跑一个不完整的 shell,毕竟,我们今天的硬件已经和远程打字机没什么关系了。

但是,TTY 依然作为一个内核的模块承担着重要的功能。有了 TTY,可以给我们完成一些 Terminal 上的功能。Terminal 可以告诉 TTY,移动指针,清除屏幕,重置大小等功能。

诶?等一下,为什么我们在上面的图片中见到的 tty 命令,都是以 /dev/pts/ 开头的,而不是以 /dev/tty 开头的呢?有什么区别?

这其实是“假装的” TTY,叫做 Pseudo terminal。

不知道你有没有意识到,我们上面讨论的 TTY 有一个很重要的点是,TTY 是作为内核的一个模块(子系统,Drive)。TTY 在内核空间而不是用户空间,我们现代的 Terminal 程序,ssh 程序等,如何能和 TTY 交互呢?

答案就是 PTY。

这里会将解释进行简化,方便理解。当像 iTerm2 这样的程序需要 TTY 的时候,它会要求 Kernel 创建一个 PTY pair 给它。注意这里是 pair,也就是 PTY 总是成对出现的。一个是 master,一个是 slave。slave 那边交给程序(刚才说过了,bash 这种程序默认会认为有 TTY 的存在,在交互状态下会和 TTY 一起工作),程序并不知道这是一个 PTY slave 还是一个真正的 TTY,它只管读写。PTY master 会被返回给要求创建这个 PTY pair 的程序(一般是 ssh,终端模拟器图形软件,tmux 这种),程序拿到它(其实是一个 fd),就可以读写 master PTY 了。内核会负责将 master PTY 的内容 copy 到 slave PTY,将 slave PTY 的内容 copy 到 master PTY。上面我们看到的 /dev/pts/* 等,pts 的意思是 pseudo-terminal slave. 意思是这些交互式 shell 的 login device 是 pseudo-terminal slave.

terminal emulator - pty master <-- TTY driver( copies stuff from/to) --> pty slave - shell

所以说,我们在 GUI 下看到的程序,比如 Xterm/iTerm2(其实用的是 ttyS,这里就不细说了),比如 tmux 中打开的 shell,比如 ssh 打开的 shell,全部都是 PTY。所以,GUI 下面的这些终端,类似 konsole, Xterm,都叫做 “终端模拟器”,它们不是真正的终端,是模拟出来的。

怎么进入到一个真正的 TTY 呢?很简单,在  Ubuntu 桌面系统中,Ctrl+Alt+F1 按下去,是图形界面,但是 Ctrl+Alt+F2(其实 F2-F6都是),就是一个终端了,这个终端,就是 TTY,你在那里登录然后按下 tty 命令,它就会告诉你这是 tty device 了。

我正好有一个 virtualbox 虚拟机,只有命令行,没有 GUI,登录进去的话,可以看到这就是一个 TTY。

 

最后我们回到本文开头的第二个问题:为什么在 ssh 里面按下 Ctrl+C 并不会停止 ssh 而是会停止 ssh 内的程序呢?

我们回顾一下,当我们在本机按下 Ctrl+C 的时候,都发生了什么?

  1. kernel 的 driver 收到了 Ctrl+C 的输入,中间经过的不相关的模块我们忽略不计
  2. 然后到达 TTY,TTY 收到了这个输入之后向当前在 TTY 前台的进程组(其实是当前 TTY 被分配给了哪一个 session,就给哪里发)发送 SIGINT 信号,如果当前是 bash 在前台,bash 会收到这个信号,如果是 sleep,那么 sleep 就会收到。

由于 SIGTERM 是可以被程序自己处理的信号,所以 bash 收到之后决定忽略,sleep 收到之后会退出。

stty 程序可以让我们修改 tty 的 function table,Ctrl+C 这里涉及的是一个叫 isig 的功能:

[-] isig

enable interrupt, quit, and suspend special characters

–from man isig

这个其实是说,如果 TTY 收到的 Ctrl+C 这种输入(原始符号是 ^C ,对应的,可以使用 stty -a 命令查看,默认的 quit 是 ^\,默认的 suspend 是 ^Z),不要将它原文发给后面的程序,而是将其转换成 SIGINT 发送给当前 TTY 后面的进程组。所以我们可以用 stty -isig 来关闭这个行为。

现在,如果在 sleep 程序中按下 Ctrl+C,TTY 将会把 ^C 字符原封不动地发送给 sleep 程序,sleep 将不会收到任何的信号。我们无法使用 Ctrl+C 结束 sleep 程序了。

回到 ssh 的那个问题,我们现在合理的猜测是:ssh 在获取远程的 shell 的时候,会先将当前自己所在的 shell disable isig,这样子,Ctrl+C 这个行为将会以字符发送给 ssh,ssh 的客户端将这个字符发送给远程的 ssh server,ssh server 发送给自己的 TTY(其实是一个 PTY master 啦),最后远程的 TTY 发送给当前远程的前台进程一个 SIGINT 信号。

如何验证我们的猜想呢?

验证1

我们可以使用 stty 查看 shell 的 TTY 设置,然后使用这个 shell 通过 ssh 登录之后,再次查看 TTY 的设置。

这个图中,我们用上面的 shell 来查看下面的 shell TTY 配置。可以看到第一次查看是 ssh 登录之前 isig 是开启状态。第二次查看是在执行 ssh 登录之后,isig 变成关闭状态了。如果 ssh 退出,isig 又会变成开启的状态。

验证2

从反面证明一下,假如说我们在 ssh 登录之前,强行将 ssh 所在的 TTY 开启 isig,那么按下 Ctrl-C ,将会结束 ssh 进程本身,而不是 ssh 内部运行的程序。

因为我这里使用的 ssh 登录本机,所以为了区分是在当前的本地 shell 还是在 ssh 中,我修改了本地 shell 的命令行提示符。

这个图片是在 ssh 登录之后,在另一个 shell 中运行 stty --file /dev/pts/0 isig 对 ssh 所在的 shell 开启 isig。然后在 ssh (当前的前台程序是 sleep 9999)按下 Ctrl+C。这时候 ssh 直接退出了,我们回到了 local shell,而不是结束 ssh 中的 sleep。

验证3

我们可以直接使用 strace 程序去跟踪 ssh 的系统调用。

strace -o strace.log ssh [email protected]

可以看到在 ssh 启动的时候,会有一行:

ioctl(0, SNDCTL_TMR_STOP or TCSETSW, {B9600 -opost -isig -icanon -echo ...}) = 0

是将 TTY 的设置改成了 -isig,以及一些其他的设置。

然后在 ssh 退出的时候,会有一行:

ioctl(0, SNDCTL_TMR_STOP or TCSETSW, {B9600 opost isig icanon echo ...}) = 0

将设置修改回去。

其实如果你用 Terminal 用的足够多的话,你一定遇到过这种情况:运行了某些 TUI 程序之后,非正常退出(比如它卡了,崩溃了,或者被 SIGKILL 了),然后你会到 Terminal 发现 Terminal 都乱了,回车无法正常换行,Ctrl+W 等无法工作等情况。有可能就是因为程序在退出的时候没有执行本应该去执行的 reset tty 代码。使用 reset 命令可以重置当前的 Terminal,让它恢复理智。

那么回到第一个问题,怎么证明哪些快捷键是 TTY 提供的,哪些是 shell 提供的呢?

这就更简单了,其实 stty -a 已经将所有 stty 的配置打印出来了:

raw mode 下,甚至回车键就是 newline,不会给你将光标移动到行首。

如果取消 Ctril+W, 这个功能自然就没了。打一个 Ctrl+W 就真的是 ^W

那么 shell 的那些快捷方式呢(比如 Ctrl+E)?我们可以用 sh 程序来验证它们是 shell 提供的功能,而不是 TTY 提供的功能。sh 是一个非常傻的程序,并不会解释 Ctrl+A 或者 上键这些功能。按下左箭头会出现 ^[[D,按下 Ctrl+A 就会出现 ^A(感觉这些字符之前很多人都会见过,当 shell 卡了的时候,按下箭头就会把这些 raw 字符打在屏幕上)。但是,在正常的 TTY 下(cooked TTY, 可以使用 reset 命令复原之前被我们玩坏的 TTY),Ctrl+W 这个功能在 sh 下依然是可以使用的。

参考链接的汇总:

  1. The TTY demystified TTY 还和 sessions, jobs, flow control, 拥塞控制,signal 有关,本文在介绍这些的时候多少有些省略,如果想了解详细的内容可以阅读这个链接
  2. Linux terminals, tty, pty and shell 这篇文章是一个对 shell,terminal,TTY 大体的介绍。其中,这个评论非常精彩。我几乎将其完全翻译到本文中了
  3. Run interactive Bash with popen and a dedicated TTY Python 这是在 Python 中如何使用 PTY 的一个例子
  4. Reverse Shell Cheat Sheet 各个语言打开 reverse shell 的方法
  5. The Linux Programming Interface 书中,第 64 章 PSEUDOTERMINALS,第 62 章 TERMINALS.
  6. Terminal emulator
 

Golang 的一个动态链接依赖问题

最近在重构一个非常古老的 build 流程(太多 bash script 了,准备重构到基于 golang:latest 来构建,干掉那些陈年依赖),程序是 golang 写的,构建出来 binary 之后,扔到服务器上一跑,直接挂了。

这个太有意思了,Golang 不是把所有依赖都 static link 的吗?怎么会出来一个 dynamic link 的 Glibc 的依赖?

更有意思的问题是,为什么老的 pipeline build 出来的 binary 没有这些静态链接的依赖呢?

下载了一个之前 build 的产物:

研究了一通,发现这个 dynamic link 实际上是来自一个 kafka 的客户端 confluent-kafka-go,这个客户端是基于 c 语言写得 librdkafka 的,所以编译的时候要 CGO_ENABLED=1. 然后编译的时候就出来 dynamic link 了。

但是为什么原来的 pipeline build 的产物是静态链接的呢?

这里省略2万字的辛酸,我在这堆 bash 脚本里面一点点还原出来了 build 环境,最后竟然发现,即使是一模一样的环境,我 build 出来的产物竟然还是有动态链接的!而 pipeline build 的就没有!这真是太神奇了。

在怀疑人生的同时,我直接改了 CI,在编译之后加了两个 debug 的命令。神奇的事情又发生了,这个 CI build 出来的产物也是动态链接的!

但是我从文件服务器上下载回来的 binary 明明就不是一个 dynamic link 的 executable!

编译之后的步骤就是 upload_binary 了,之前看它的名字只是上传,觉得应该很简单。但是现在隐约觉得并不简单,这个函数里面有什么猫腻。于是就开始阅读这里的脚本。

然后就发现了一个神奇的命令,这个脚本在编译完成之后,竟然 ssh 到文件服务器,去执行了一个 upx 命令。

upx 是一个压缩二进制的工具,如上图,经过压缩之后,这些 binary 的体积都减少了 46%。

但是 upx 压缩之后,会让这个 dynamic link 的 executable 看起来是 static link 的

所谓“看起来是”,就是在执行的时候,其实还是要“解压”,然后去 dynamic link 一些 lib。可以把依赖的 .so文件给删掉测试一下。

发现就无法正常运行了:

所以,实际上新的 pipeline 构建出来的 binary 无法正常工作的根本原因是:

  • 之前的 binary 也是 dynamic link 的,只不过 upx 过后看起来像是一个 static link  的 binary 了。但是由于之前的构建环境非常老,依赖的 glibc 版本很低,所以可以直接扔到服务器上去运行。
  • 但是新的 pipeline 是基于 golang:latest 构建的,依赖的 glibc 的版本是 2.29, 服务器上没有,所以跑不了。

和 dev 沟通之后,这个 CGO 的依赖是必要的。接下来的解决方法有:

  1. 使用golang的 kafka lib:需要 dev 去修改代码,切换使用的 kafka sdk,可以作为备选方案。
  2. 降低 golang:latest 的 glibc 版本:发行版一般固定 glibc 去编译其他的工具链,替换 glibc 是不明智的。虽然也有一些工具,比如 yum downgrade glibc\* 可以辅助干这件事情。
  3. 换个更老的 glibc 版本的镜像:又避免不了陈年的一堆 bash 脚本。
  4. 将 c 语言写的依赖静态链接。

综上,还是打算使用最新版的 image 来编译,但是将依赖全部静态链接,做到一次编译,到处运行,下载下来就能跑。

静态链接 CGO 的依赖

如果使用 glibc 的是,是不能静态链接的

因为 glibc 依赖了 libnss ,libnss 支持不同的 provider,必须被 dynamic link.

所以这里只有使用 musl 替换 glibc 了。librdkafka 和 golang 的封装 confluent-kafka-go 都支持 musl 构建。只要在构建的时候指定 --tags musl 即可。alpine 是基于 musl 的发行版,这里直接使用 alpine Linux 进行构建。

然后指定使用外部 ld,指定 flags 使用 -static,编译出来的 binary 就完全是静态链接的了。编译过程如下:

静态编译 CGO 的依赖可以参考这篇教程:Using CGO bindings under Alpine, CentOS and Ubuntu  和这个例子:go-static-linking.

 

Django 优化数据库查询的一些经验

ORM 帮我们节省了很多工作,基本上不用写 SQL,就可以完成很多 CRUD 操作,而且外键的关联也会自动被 ORM 处理好,使得开发的效率非常高。我觉得 Django 的 ORM 在 ORM 里面算是非常好用的了,尤其是自带的 Django-admin,可以节省很多工作,甚至比很多公司内部开发的后台界面都要优秀。

但是 ORM 也带来了一些问题,最严重的就是,这些外键关联会去自动 Fetch,导致非常容易写出来 N + 1 查询,加上如果使用 django-rest-framework, Serializer 可以帮助你很方便地去渲染关联的外键,就更容易写出 N + 1 查询了。也是因为这个原因,之前在蚂蚁工作的时候,公司基本上是禁止(有一些小范围的内部项目还是可以使用)使用类似于 Hibernate 这种自动关联外键 ORM 的,都需要手写 SQL map,自己去 Join。但其实,我觉得这是一种非常粗暴的做法,用大量的人力换取降低错误出现的几率。这个问题是非常好解决的,我们只要对接口 Profile,看一下完成一次请求到底进行了哪些 SQL 查询即可,如果发现了 N + 1 就去解决。

这篇文章介绍 Django 中去 debug 和优化数据库查询的一些方法,其实对于其他的语言和框架,也差不多类似,也有同类的工具。

让我们从头开始思考,如何提升网站的性能。首先,最接近于用户的就是前端的代码,我们可以从前端开始 perf,看哪一个页面渲染用的时间最长,是请求 Block 住了,还是前端的组件写的性能差。如果是非常重要的面向用户的页面,可以系统性地使用一些监控工具发现性能问题。如果是对内的,其实只要自己去每一个页面点几下试试就可以发现性能问题了。如果自己没觉得卡顿,基本上就足够了。

对于内部的系统来说,如果前端不是写的出奇的差的话,性能问题一般都是由 API 慢引起的。所以本文就不过多介绍前端性能的优化了。

Slow API

发现耗时长的 API

Django 有一个 Prometheus 的 exporter 库,django-prometheus,可以使用这个库将 metrics 暴露出来,然后在 Grafana 上绘制每一个 view 的 P99/P95 等,发现耗时长的 API,然后针对性地进行优化,去 Debug 到底是慢在了哪里。

Debug

Django 的 django-debug-toolbar 是一个非常好用的工具。安装之后,设置好 debug 用的 IP,使用这个 IP 去访问的时候,它会自动对整个请求做 Profile,包括使用的 Cache,Template,Signal 等等。最有用的就是 SQL Profile 了。

它会把一个请求涉及的所有 SQL 都列出来,包括:

  • 这个 SQL 花了多少时间
  • 这个 SQL 是由哪一行代码触发的,类似于一个 traceback
  • 有多少个类似的 SQL,有多少个重复的 SQL (如果有的话,一般就是有问题了,意味着同样的 SQL 查询了多次)
  • 点击 Expl 可以很方便地看到这个 SQL 的 Explain
  • 点击 Sel 可以看到 SQL 的详情

如下所示:

然后就可以针对慢的 API 进行优化了。

解决

N + 1 Query

N + 1 查询是造成 API 慢的最常见的原因。比如这样一个需求:我们有一个列表页,对于列表中的每一个 Item,都要展示它相关的 Tag。如果使用 djagno-rest-framework 的 Nested relationships 的话,实际的查询会:

  1. 先查询出来当前列表页要展示的 item list
  2. 对于每一个 item,都去查询它的 tag

这就是 N + 1 查询。

解决的方法很简单,就是使用 Django 的 prefetch_related(),它的原理是使用 in 一次性将所有的外键关联的数据查询出来,然后在内存中使用 Python 做 “join”,这样就只会产生两个查询:

  1. 先查询出来列表页要展示的 item list
  2. 一次查询出来所有的 tag,使用 tag_id in (item_id, item2_id…)

参考一个官方文档中的例子:每一个 Pizze 都有不同的 Topping(浇头?)。

下面这个查询就是一个 N + 1,要先查出来所有的 Pizze,然后对于每一个 Pizza 去查询它的 Toppings:

如果使用 prefetch 的话,就会只有 3 次查询(因为是一个 many-to-many 关系,所以要有一次是查询中间表的):

 

注意只能使用 .all()

prefetch 其实是缓存了一个 queryset(), 如果查询条件改变了,Django 就必须重新发起查询。以下这个用法,就不会用到 prefetch 的 cache:

因为 prefetch 已经把所有的数据查询到内存里面了,所以我们应该这么用,就不会触发新的查询了:

 

Prefetch()

prefetch_related() 所接收的参数,除了可以是一个 string 外,也可以是一个 Prefetch() 对象,可以用来更精确地控制 cache 的 queryset. 比如排序:

也可以一次性 prefetch 多个外键(顺序很重要,参考文档),Prefetch()string 可以混用:

 

many-to-many 和嵌套外键

对于嵌套的外键,可以用 __ 将 Model 的属性名字联合起来,比如这样:

这样 pizzastoppings 都会被 prefetch.

 

select_related()

select_related() 也是有类似作用的一个功能,只不过他和 prefetch 的区别是:

  • prefetch_related() 是用 in 然后用代码 join
  • select_related() 是用 SQL 直接 join

显然,select_related() 触发的查询更少,一次查询就可以解决问题。但是它的功能也有限,不能支持嵌套的外键查询。

 

prefetch_related_objects()

以上的两个方法是用于 queryset 的,如果是对 object 的话,可以使用这个函数。

比如,我们要查询最近的一个订单关联的数据的话,可以这么使用:

Cached Property

Django 提供了一很实用的装饰器 @cached_property ,用这个替换 @property 的话,一个对象在读取这个 property 的时候只会计算一次,同一个对象在第一次之后来读取这个 property 都会使用缓存。

有点类似于 Python 中的 @lru_cache

 

减少不必要的展示字段

无论是 Cache 还是 prefetch 的方法,都是有一些复杂的。如果前端用户到一些字段,就没有必要一次性返回。

刚开始写 DRF 中的 Serializer 的时候,倾向于每一个 Model 都有一个 Serializer,然后这些 Serializer 都互相关联。最终,导致查询一个列表页的时候,每一个 item 相关的数据,以及这些数据相关的数据,都被一次性展示出来了。即使优化过后也难以维护。

后来总结出来一个比较好的实践,是每一个 Model 都有两个 Serializer:

  • ListSerialzer:对于所有的外键只展开一层,不展开外键的外键
    • 用于列表页 API 的显示
    • 这样查询的时候,只需要对于每一个外键查询一次 in 就可以了
  • DetailSerializer:按需求展示所有的外键
    • 用于详情页的渲染
    • 对于每一个外键关联的 row,可能都要再进行一次查询,把所有关联的外键都展开,方便展示。但是因为只有一个对象,所以也不会特别慢。但是依然要注意 N + 1,如果嵌套的太深,考虑不一次展示那么多,新提供一个 API 进行查询

这样的好处是我们可以按需进行 prefetch,List 页面的 API 只需要 prefetch 直接关联的外键就可以了,Detail 的 API 可以按需进行级联 prefetch. 总体的原则就是尽量避免多重外键的 prefetch.

值得一提的是在 django-rest-framework 中,是可以在同一个 ModelViewSet 里面,针对不同的 API,使用不同的 Serializer 的:

使用冗余字段

现在存储已经很便宜了,在合适的场景下,可以考虑直接将 fields 多存几份,节省查询。

比如我的一个场景是:一个 group 里面有个并行执行的 Execution,如果所有的 Execution 都执行完了,这个 group 就可以被认为是执行完了。

之前的实现是在 group 上定义一个 is_running 的字段,返回 group.execution_set.filter(is_running=True).exists()。这样每次都需要查询外键。

其实可以在 group 上保存一个 is_running 的字段,然后当 Execution 结束的时候顺便更新 group.is_running. (Signal 其实不太好维护,我比较喜欢显式调用)。

这样的好处是:

  1. 方便查询,业务逻辑变得简单

缺点是:

  1. 另外肯定有某个地方的逻辑变得复杂了,因为要同步更新
  2. 可能又潜在的数据不一致

Slow SQL

随着数据越来越多,即使开发的环境中发现 API 造成的请求都很少,也很快,但是线上环境跑着跑着可能就有问题了。

所以最好对线上的 SQL 也进行观测。方法很简单,只要将查询时间 >1秒(或者其他时间)的 SQL log 出来就可以了。可以通过针对 Django ORM 设置 logging 配置来完成这件事:

添加一个新的 logger,然后 filter 类似于一下设置:

就可以将 SQL 日志过滤出来,然后只 log 请求时间 >50ms 的。

 

最后,以 Django 中的一句话作为结尾:

Always profile for your use case!

 

PromQL 使用多个 label 组合过滤

继《最近的工作感悟》中提到的大部分问题都解决了之后,有一些错误还是无法避免的,就试图想办法从监控系统中忽略掉。尝试了很长时间,发现在 PromQL 中写 “exclude 特定 label 的 metrics” 这样的查询不是很方便,目前没有找到比较合适的方法,这里记录一下一些可行的,但不是特别优雅的方法。

问题可以简化成这样:有一个 metric 叫做 request_count, 有两个 label:

  • client: 客户端的名字,比如有: curl, chrome, safari, firefox, python
  • error_code: 400, 200, 403, 302 等

因为有一些错误无法避免,比如由爬虫(假设 clientpython)引起的 404 问题,在 chrome 上发生的 403 问题,我们想从监控中忽略掉。

首先 request_count{client!="python", error_code="404"} 这样的查询是不行的,因为这样会忽略来自 python 的所有的请求,以及所有的 error_code=404。这样写实际上是一个  and 的关系,metric 的 label 满足所有的条件才会展示,否则不展示。

 

其实通过 Grafana 的 Transform 设置,我们可以取消展示一些单独的 Metric。选择 Transform  tab,然后选择 “Filter by name”, 就可以勾选单独的 metric 取消展示。

这样可以解决展示的问题,但是查询结果实际还是包含这些 metric 的。如果基于这个查询来设置 alerting rules 的话,那么这些 metric 还是无法被忽略。我还是想从查询上来忽略这些 metric,这样无论展示和告警,都可以使用同一个 aggr rule.

 

通过查询来忽略的方法有些 tricky,因为涉及两个 lebel 的 and 条件查询,总体的思路是:

  1. 忽略 label A 的所有 metrics;
  2. 使用 or 添加满足 label A 和 B 两个 label 的 metrics;

以上面的例子,查询的 PromQL 就是:

因为 label 的写法只支持 and,但是我们可以使用 or 组合 metric 来实现查询。

or 也支持连续的写法,以及再需要提一下需要永远先 rate 再 sum,所以回到刚开始的例子,就需要写成:

 

参考:How to filter by two labels in prometheus?