如何阅读火焰图

这篇文章是火焰图阅读的简明教程。

火焰图是我们用来分析性能的可视化工具。很多 profile 工具输出的信息都非常多,是一个巨大的文本,在这个文本中,找到性能瓶颈,会比较困难。但是如果画出来一张图,可以一下就看到问题所在。

火焰图是 Brendan Gregg 发明的。使用官方的工具 FlameGraph,可以将文本渲染成 svg。如下。

官方的 FlameGraph 渲染出来的 svg 截图

现在也会有其他的工具能渲染出来类似的图了,比如 golang 的 pprof 现在内置了一个新版的火焰图预览工具,在线的 speedscope 也可以渲染。我最喜欢的是 Flameshow,一个终端工具,可以直接在终端用字符渲染出来火焰图,设计的非常精妙。(其实就是我自己写的)。由于是我自己写的,那么下文我就以 Flameshow 来做展示的例子了。

Flameshow

阅读方法

火焰图作为一个可视化的工具,着重表达的信息是:父子之间的关系,每一个块的占比。

火焰图有从下向上的和从上向下的,本质是相同的,只是方块之间的关系方向不同。从上向下:下面的方块是上面的子块;从下向上:上面的方块是下面的子块。

主要信息有(以从上到下为例子):

  • 每一个方块,都是一个函数,方块的宽度,就表示函数消耗的时间占比。(如果是内存火焰图,那就表示的这个函数申请的内存占比。)所以我们看火焰图,主要去找最宽的一个方块。
  • 上下堆叠在一起的是表示函数调用。Y 轴表示调用的深度。

火焰图一般是支持交互式的,svg 和 flameshow 都支持点击其中一个 function,来放大。如下例子:

点击放大其中一个 function

标记的是,最开始调用的函数是 collector.NodeCollector.Collect.func1,然后这个函数的所有时间都在调用 collector.execute,以此类推。到下下面的 os.(*File).readdir,其中有一大部分是在调用函数 os.Lstat,然后其余的时间花在了 os.direntReclen

很多人对火焰图容易有一些误解,这里着重说明一下:

  • Y 轴的深度一般不是问题。我们用火焰图主要是排查性能问题,是要找消耗时间长的地方。调用深度很深,但是没花多久时间,一般不要紧;
  • 颜色(几乎)没有意义。不是说颜色越深时间越久。颜色只是为了区分出来不同的块而已。一般会将相同名字的函数都使用同一个颜色,这样,即使它们分散在不同的 stack 中,也能清晰看出总时间比较高。从 FlameGraph 的源代码也可以看出,颜色是根据 function 名字随机生成的。但是有一种优化:比如对于 Java 的 JVM 来说,可以用不同的红色表示 Java 代码消耗的时间,可以用黄色表示 Kernel 消耗的时间,用蓝色表示 JIT 时间。但是不同的红色,红色深浅,还是没有什么意义的。
  • 方块之间的顺序没有意义。因为火焰图的生成方式(后文介绍),和渲染方式(一般会将同名字的方块 merge 在一起,方便阅读),导致火焰图方块之间的顺序是没有意义的。不代表函数调用的顺序

火焰图的本质是旭日图(Sunburst Graph)

你有没有发现,主要表示占比,又能表示占比之间的关系,是不是跟某一种图很像?

使用 tokei-pie 渲染出来的旭日图

是的,其实火焰图的本质就是拉平了的旭日图。上图是我用 tokei-pie 渲染出来的代码仓库中不同文件夹、文件的行数占比。打开一个新的项目的时候可以轻松找到核心代码。

火焰图的生成和格式

火焰图的生成主要依赖 profile 工具,目前很多工具都支持了,比如 py-spy, golang 的 pprof.

生成的原理大致是去扫描程序的内存,主要是内存的 stack 部分,对 stack 做一个快照。如果扫描了 10 次,其中 function1 出现了 3 次,function2 出现了 6 次。那么它们的宽度占比就是 1:2. 很多 profile 工具就是如此工作的,不是 100% 精确的,但足以让我们分析性能问题了。

生成的格式一般是 stackcollapse 格式,这是官方的一种定义。比如如下的文本:

每一行就代表一个 stack,数字代表整个 stack 的占比。我们要把所有的 stack 相同层级相同名字的 merge 起来,最后就变成下面这样:

简单的 stackcollapse

另一种常见的格式是 pprof 的格式。虽然是 golang 最先开始用的,但是设计的(我个人认为)比较好,也是开源的,protobuf 定义,所以很多工具也支持输出这种格式了。

Continuous Profiling

持续 Profiling 也是我比较感兴趣的一个领域,很多 APM 工具都已经支持了。比如 DatadogGrafana。简单来说,就是不断地对线上部分实例进行 Profile,然后对结果不是简单的展示,而是收集起来。将它们的 stack 都合并起来,做成一个由多个实例的 stack 组成的 Flame Graph,就可以找到集群层面的性能热点了。

另外一个用处是,在发布新版本的时候,可以在灰度的时候,检查新版本的 Flame Graph 和之前的,看有没有引入新的性能热点。

相关链接

  1. https://www.brendangregg.com/flamegraphs.html
  2. https://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html
  3. https://queue.acm.org/detail.cfm?id=2927301
  4. https://youtu.be/6uKZXIwd6M0
  5. https://youtu.be/6uKZXIwd6M0
  6. https://www.webperf.tips/tip/understanding-flamegraphs/
  7. https://github.com/jlfwong/speedscope/wiki
  8. https://www.speedscope.app/
 

再多来点 TCP 吧:Delay ACK 和 Nagle 算法

教科书介绍的 TCP 内容通常比较基础:包括三次握手,四次挥手,数据发送通过收到 ACK 来保证可靠传输等等。当时我以为已经学会了 TCP,但是后来在工作中,随着接触 TCP 越来越多,我发现很多内容和书上的不一样——现实世界的 TCP 要复杂一些。

我们从一个简单的 HTTP 请求开始。发送一个简单的 HTTP 请求,tcpdump 抓包如下:

第一个和书上不一样的地方是,TCP 结束连接不是要 4 次挥手吗?为什么这里只出现了 3 次?

回顾 TCP 的包结构,FIN 和 ACK 其实是不同的 flags,也就是说,理论上我可以在同一个 Segment 中,即可以设置 FIN 也可以同时设置 ACK。

TCP segment,图来源

所以如果在结束连接的时候,客户端发送 FIN,这时候服务端一看:“正好我也没有东西要发送了。”于是,除了要 ACK 自己收到的 FIN 之外,也要发送一个 FIN 回去。那不如我一石二鸟,直接用一个包好了。

TCP FIN 教科书的图,和实际的图

这个例子在 TCP可以使用两次握手建立连接吗? 中详细介绍过。

既然 FIN 可以附带去 ACK 自己收到的 FIN,那么数据是否也可以附带 ACK?也是可以的。

Delay ACK

TCP 是全双工的,意味着两端都可以同时向对方发送数据,而两端又需要分别去 ACK 自己收到的数据。

TCP 的一端在收到数据之后,反正马上也要发送数据回去,与其发送两个包:一个 ACK 和一个数据包,不如不立即发送 ACK 回去,而是等待一段时间——我反正一会要发送数据给你,等到那时候,我再带上 ACK 就好啦。这就是 Delay ACK

数据 + ACK

Delay ACK 可以显著降低网络中纯 ACK 包的数量,大概 1/3. 纯 ACK 包(即 payload length 是 0 ),有 20 bytes IP header 和 20 bytes TCP header。

Delay ACK 的假设是:如果我收到一个包,那么应用层会需要对这个包做出回应,所以我等到应用的回应之后再发出去 ACK。这个假设是有问题的。而且现实是,Delay ACK 所造成的问题比它要解决的问题要多。(下文详解)

Nagle’s Algorithm

现在再考虑这样一个问题:像 ncssh 这样的交互式程序,你按下一个字符,就发出去一个字符给 Server 端。每通过 TCP 发送一个字符都需要额外包装 20 bytes IP header 和 20 bytes TCP header,发送 1 bytes 带来额外的 40 bytes 的流量,不是很不划算吗?

除了像这种程序,还有一种情况是应用代码写的不好。TCP 实际上是由 Kernel 封装然后通过网卡发送出去的,用户程序通过调用 write syscall 将要发送的内容送给 Kernel。有些程序的代码写的不好,每次调用 write 都只写一个字符(发送端糊涂窗口综合症)。如果 Kernel 每收到一个字符就发送出去,那么有用数据和 overhead 占比就是 1/41.

为了解决这个问题,Nagle 设计了一个巧妙的算法 (Nagle’s Algorithm),其本质就是:发送端不要立即发送数据,攒多了再发。但是也不能一直攒,否则就会造成程序的延迟上升。

算法的伪代码如下:

简单来说,就是如果要发送的内容足够一个 MSS 了,就立即发送。否则,每次收到对方的 ACK 才发送下一次数据。

Delay ACK 和 Nagle 算法

这两个方法看似都能解决一些问题。但是如果一起用就很糟糕了。

假设客户端打开了 Nagle’s Algorithm,服务端打开了 Delay ACK。这时候客户端要发送一个 HTTP 请求给服务端,这个 HTTP 请求大于 1 MSS,要用 2 个 IP 包发送。于是情况就变成了:

  • Client: 这是第一个包
  • Server:… (不会发送 ACK,直到 Server 想发送数据给 Client,但是这里因为 Server 没有收到整个 HTTP 请求内容,所以 Server 不会发送数据给 Client)
  • Client: … (因为 Nagle 算法,Client 在等待对方的 ACK,然后再发送第二个包的数据)
  • Server: 好吧,我等够了,这是 ACK
  • Client: 这是第二个包
Nagle’s Algorithm 和 Delay ACK 在一起使用的时候的问题

这里有一个类似死锁的情况发生。会导致某些情况下,HTTP 请求有不合理的延迟

再多说一点有关的历史,我曾经多次在 hackernews 上看到 Nagle 的评论(Nagle 亲自解释 Nagle 算法!12)。大约 1980s,Nagle 和 Berkeley 为了解决几乎相同的问题,发明了二者。Berkeley 的问题是,很多用户通过终端共享主机,网络会被 ssh 或者 telnet 这样的字符拥塞。于是用 Delay ACK,确实可以解决 Berkeley 的问题。但是 Nagle 觉得,他们根本不懂问题的根源。如果他当时还在网络领域的话,就不会让这种情况发生。可惜,他当时改行去了一家创业公司,叫 Autodesk

解决方法是关闭 Delay ACK 或者 Nagle’s Algorithm。

配置方法

关闭 Nagle’s Algorithm 的方法:可以给 socket 设置 TCP_NODELAY. 这样程序在 write 的时候就可以 bypass Nagle’s Algorithm,直接发送。

关闭 Delay ACK 的方法:可以给 socket 设置 TCP_QUICKACK,这样自己(作为 server 端)在收到 TCP segment 的时候会立即 ACK。实际上,在现在的 Linux 系统默认就是关闭的。

前面这篇文章提到:

如果在收到对方的第二次包SYN+ACK之后很快要发送数据,那么第三次包ACK可以带着数据一起发回去。这在Windows和Linux中都是比较流行的一种实现。但是数据的大小在不同实现中有区别。

如果我们关闭 TCP_QUICKACK ,就可以看到几乎每一次 TCP 握手,第三个 ACK 都是携带了数据的。

 

肯特岗

肯特岗,一定是我在新加坡度过时间最多的地方,因为我在这里上班。

这里地形很奇特,坐了三次电梯上楼,可以从另一个门出来,居然还是一楼,对得起“岗”这个名字了。

去吃午饭的路上,可以望到山岗脚下的一些楼,有希捷,Grab,得意洋洋地把招牌挂在大楼最高的地方。还有一个没有窗户的奇怪建筑,是一个数据中心。

公司每个月都会搞一次大型促销,时间定在 1月1日,2月2日,3月3日,以此类推,非常有创意。像我们这种工作就要苦哈哈地值班,以免系统出现异常。

有一天,凌晨2点下班,打车回家。司机是一个老安哥。

安哥问我,“怎么才能在你们公司的网站上买东西呢?需要到什么地方填表格吗?”

我震惊,好像从没有听说过报纸是何物的 00 后一样。我说,“不需要填表,只要下载一个 app 就可以了,很简单的。”

安哥说,“安哥老了,跟不上时代了,搞不懂了。”

我决定继续解释一下,“只需要下载一个 App,然后填上你的手机号码,收到验证码,填上验证码,然后将商品加入购物车,选择 checkout,然后填上你的银行卡,银行可能会给你发验证码,完成付款,就可以等待收货了。”说完这些,我发现这个过程对一个老人来说可能不简单,也不好意思重复再说很简单的话了。

安哥继续抱怨说,出租车公司发过来一个要上网完成的东西,自己按照说明却操作不好。让我想起来我的母亲,虽然我的工作就是天天跟这些电脑打交道,但是却不擅长教会别人用手机。在诺基亚流行的时代,我教我的母亲怎么把别人的手机号记到手机里,怎么打开新的通讯录,什么键是确认,怎么退出。我的母亲总是喜欢记:按这个键,再按这个键,最后按这个,就能打开通讯录。全不管屏幕在显示什么。

安哥询问我家乡,得知我是中国北方人,又开始兴致勃勃地跟我聊起来北方的冬天,跟我确认他听说的有关冬天的寒冷是不是真的。然后又不知怎的,开始跟我确认一些北方的习俗是不是真的,真相是,他的信息,我大部分都是第一次听说。

生活小技巧

在肯特岗地铁站下车,从唯一的扶梯上楼,右拐进入到一个小商区,在右手边扫码支付 1.7 元,阿姨问你,你就说,要一个 Plain Waffle. 当当,就会收获一个世界上最好吃的华夫饼。

 

真实世界中的 PMTUD

上回书说到被 MTU 问题小小坑了一下,问题最后解决了,但是留了一个疑问点没有证实:为什么在 MSS 协商失败的情况下,curl https://x.com 可以,但是 curl https://accounts.google.com 不可以?

本文的实验代码都是在虚拟机中做的,所以没有隐藏 IP,直接粘贴的 tcpdump 结果。代码太宽,可以通过代码块右上角的工具栏配合阅读,比如点击 <-> 按钮来展开,或者在新窗口浏览。读本文之前,最好先读一下这篇介绍 MTU 介绍的比较好的博客:有关 MTU 和 MSS 的一切 (即本博客)。

上文中的猜想是这些网站实现了 PMTUD,这一点比较容易证明。

PMTUD 测试

TCP 握手的时候双方协商 MSS,是根据本地的网卡信息协商的。比如网卡的 MTU 是 1500,那么 MS S 就会是 1460,如果网卡 MTU 是 1450,那么 MSS 就是 1410. 这个过程,TCP 的双方都对中间网络设备的 MTU 没有概念,中间设备能转发的 MTU 很可能比两边都小(尤其是在有 VPN 或者有隧道的情况)。PMTUD 就是处理这种情况的:它的原理很简单,当有丢包的时候,我尝试发送小包,看能不能收到 ACK,如果能,说明链路 path 的 MTU 比我想的要小,等用小一点的包发送。PMTUD 的全称是 Path MTU Discovery。

验证方法很简单,我们只要创造一个环境,假设这个环境能接受的 MTU 最大是 800,超过 800 bytes 的都会直接丢包,并且不会发回去 ICMP 消息。

我们用 iptables 直接 DROP 掉超过 800 bytes 的包。实验环境我习惯将 DROP 打印出来。

然后,我们还要将 Generic Receive Offload 关闭(以及其他的 offload 也一起关了吧,方便查看)。如果不关的话,即使对方发过来小包,网卡也会帮我们合并成大包,导致被 iptables 丢弃。

最后,我们打开 tcpump,并且发送请求:curl -v https://accounts.google.com。抓包结果如下:

果然,对方一直尝试发给我们大小是 1400 的包,不断被我们丢弃,不断重发,非常锲而不舍,可惜是无用功。

还记得我们当时 MTU 设置错误,还是可以访问通 x.com,我们再拿它来试一下。

以下是 curl https://x.com 的抓包结果:

可以看到,在 server 端发送了 4 个长度为 1448 的包之后,就开始发送了一个长度为 512 的包,发现能够收到 ACK,就加大到 936 尝试扩大 MTU 发送,然后失败了,就退回到 512,可以看到后面还有大包的尝试,同样也失败了。不过最终的结果是发送成功的。

具体 PMTUD 的行为不太一样,比如 facebook.com 的第一次尝试是 1024,然后退到 512.

ICMP type 3 code 4 测试

ICMP 专门有一种消息是处理这种不可达的错误的。ICMP 的 type 3 意思是 Destination Unreachable,但是 Destination Unreachable 的原因有很多,对于每一种原因都有一种 Code,Code 4 意思就是 Fragmentation Needed and Don’t Fragment was Set。(即,包太大,需要拆成多个 IP 包,但是你有设置了不要拆包,所以我只能丢弃,并且用此 ICMP 来告知你。)

在上面的测试中,我们并没有发送任何的 ICMP 消息,而只是丢包。现在,我们添加一步,在丢包的时候,发回去一个 ICMP 消息。我们用 scapy 来做这个。代码非常简单,它抓所有超过 800 bytes 的包,对这些包的来源都发送一个 ICMP。还是 iptables 负责丢包,scapy 脚本只负责发 ICMP。

为什么 filter 是 greater 815 呢?因为 libpcapgreater 是 Ethernet 层的大小,Ethernet 的 header 是 14 bytes,所以我们要的条件是 >= 815 bytesgreater 是大于等于。(是,我也觉得很奇怪)

保存上文件为 a.py。运行方式是 python3 a.py

然后使用这台服务器进行测试。发现…… 结果和上文完全一样,我都告诉他们 next hop mtu 是 800 了,但是他们有自己的想法,从 512 开始尝试之类的。仿佛 ICMP 从来没发送到他们的服务器上。不知道是我构造包的问题,还是他们的服务器没有处理好 ICMP 的问题。比如之前看过 cloudflare 的这篇文章,就是说因为 ECMP 的问题,ICMP 消息会被路由到错误的负载均衡器上去,导致 PMTUD 失败。解决办法是将 ICMP type 3 code 4 广播到所有的负载均衡器上去。

ICMP type 3 code 4 虚拟机测试

为了试试看是不是我的脚本有问题,我在本地搭建了一个非常简单的网络环境。

抓包结构如下,可以看到,8000 端口尝试发送 1448 bytes 的包一直被忽略。当收到 ICMP 消息,server 端就立即改用 800 bytes (MSS 是 748 bytes)来发送了。所以,感觉还是公网发送 ICMP 黑洞的问题。

而且这个 path MTU 信息会在 route 的 cache 中,后续的发送会默认这个 path 的 MTU 就是 800,不会使用更高的尝试。

相关链接:

  1. nmap 有 Path MTU 探测功能:https://nmap.org/nsedoc/scripts/path-mtu.html
  2. Path MTU discovery in practice
  3. Iptables Tutorial 1.2.2 by Oskar Andreasson 一份不错的 iptables 教程
  4. RFC 5508 NAT Behavioral Requirements for ICMP
  5. Resolve IPv4 Fragmentation, MTU, MSS, and PMTUD Issues with GRE and IPsec
 

一次网络问题排查

故事起因

我们需要在一个新的环境搭建 Jenkins (一个 Java 程序)。因为我们不想自己维护 Java 运行环境,所以是将 Jenkins 运行在 Docker 里面的。

需要我去申请了 VM,然后在 VM 里面安装好 Docker,用 Jenkins 官方的 Docker 镜像启动 Docker 容器,一切正常。然后回到浏览器登录,发现这时候 Jenkins 报错了。

Jenkins 打开报错

查看 Jenkins 的日志,错误是:java.net.SocketTimeoutException: Read timed out。但是不知道具体是要访问什么服务报错的。

收集信息

首先,我们先找到具体是访问哪一个服务不通。在 Jenkins 启动的过程中进行 tcpdump 可以发现,确实是访问一个 IP 的 443 端口会卡住。但是这个 IP 是可以 ping 通的,说明 3 层没问题,问题是出在 4 层及以上。tcpdump 发现对这个 IP 的 443 端口建立 TCP 连接是没有问题的,但是在数据交换的过程中会卡住。那很可能是应用层的问题。

要知道这个服务是干啥的,我们要找到这个 IP 对应的 domain。那这个 IP 是怎么拿到的呢——对了,是 DNS,用 tcpdump 对 DNS 协议抓包,可以发现这个 IP 对应的 domain。

tcpdump port 53

可以发现这个域名是 accounts.google.com

我在容器中做了一些简单的测试:

  • 在容器里面是可以 ping 通 accounts.google.com 的。
  • 在容器里面可以正常 curl http://accounts.google.com 并且拿到 response。
  • 但是 curl https://accounts.google.com 必定会超时。
  • 问题出在 https? 容器内可以访问其他的一些 https 网站,比如 curl https://x.com,但是速度很慢
  • 我去 VM(容器所在的宿主机)curl https://accounts.google.com 发现是正常的。说明 Host 网络是 OK 的,也说明不是 Google 挂了(废话)。
在容器内访问 https://x.com 的抓包

到这里就是收集到的所有的信息了。其实答案就在本站的其他博文中,嘻嘻。读者可以推断出原因了吗?

答案

回顾 Docker (容器) 的原理 一文中网络的部分,容器发送包到 WAN 大致的路径是:容器内的 eth0 -> Host 对应的 veth 的另一头 -> docker0 bridge -> Host eth0 -> WAN。而因为在 Host 上的网络没有问题,所以最后一段 Host eth0 -> WAN 是没问题的。

通过抓包的现象可以看到,在 TCP 正常建立连接之后,如果是 HTTP 就很顺喜,如果是 HTTPS,在建立连接之后会卡住。从上图抓包可以看到(虽然 IP 部分打了码,但是可以通过 Flags 前面的字看出来是谁发回来的),从 443 端口发回来的包,只有 length = 0 的。所以猜测(只能猜吗?),从 443 端口发回来的包都因为 MTU 太大的原因被丢弃了。参考 有关 MTU 和 MSS 的一切

只能猜测吗?因为如果超过了 MTU 1500 的大小,那么丢包的可能是任何中间设备,所以我们看不到被丢弃的包的,现象就是对方的 443 端口没有发送任何东西回来导致超时。但是我们可以有以下理由这么猜:

  • 因为 HTTP 访问相同的 IP port 可以拿到正常响应,说明 4 层网络是通的,至少不是因为防火墙之类的问题;
  • HTTP 响应相对较小,HTTPS 和 HTTP 相对于 4 层来说有啥不同呢?只是中间多了一层 TLS 而已,TLS 在握手的过程中要交换很多信息,包括证书等。
  • 访问某些 HTTPS 网站是可以的,但是从抓包可以看出,中间也卡了很久,过了一段时间,对方才从 443 端口发回来数据。而且奇怪的是,明明对方要发送一连串的数据,却没有用 length 很长的 segment 发回来,而是发了几个很小的 segment。说明这些网站可能实现了 PMTUD.

证明

为什么会导致 MTU 太大,进而导致丢包呢?肯定是 TCP 的 MSS 协商出了问题。

既然 Host 上的网络没有问题,我就对比了 Docker 中的 interface 配置和 Host 上的 interface 配置。发现 Host 上的 MTU 设置为 1450,而 Docker 里面是默认的 1500. 于是就明白了:我们的 Host (即 virtual machine)运行在一个 Overlay 网络中。简单可以理解为,Host 收发的网络包,中间的网络设备要在上面添加额外的信息,添加之后,MTU 就会超过 1500,为了避免这个问题,就调小 interface 上的 MTU 值,这样,为“额外信息”预留出来空间,保证网络中的任何包大小都不超过 1500 bytes。但是我们自己搭建的 docker,没有单独去配置 interface 的 MTU,于是就会让 Docker 内的程序在建立 TCP 连接的时候,错误地认为自己的 MTU 是 1500,导致最终产生 MTU 大于 1500 bytes 的包。

Docker interface 和 Host interface MTU 对比

解决办法

我们可以用 MSS clamping 来解决这个问题:通过 iptables 将 TCP 握手的包中的 MSS 值强制修改成 1450 – 40:

然后就可以在 Docker 容器中正常访问这个 HTTPS 服务了。

另一个解决办法是,让 dockerd 启动的时候,指定 interface 的 mtu