Kubernetes用了,延迟高了10倍,问题在哪?

没想到文章受到这么多关注,也有不少朋友反映标题具有误导性。我能理解大家的想法,所以在这里澄清下本文的写作意图。当我们团队将业务迁移至Kubernetes之后,一旦出现问题,总有人觉得“这是迁移之后的阵痛”,并把矛头指向Kubernetes。我相信很多朋友肯定听人说过标题里这句话,但最终事实证明犯错的并不是Kubernetes。虽然文章并不涉及关于Kubernetes的突破性启示,但我认为内容仍值得各位管理复杂系统的朋友借鉴。

近期,我所在的团队将一项微服务迁移到中央平台。这套中央平台捆绑有CI/CD,基于Kubernetes的运行时以及其他功能。这项演习也将作为先头试点,用于指导未来几个月内另外150多项微服务的进一步迁移。而这一切,都是为了给西班牙的多个主要在线平台(包括Infojobs、Fotocasa等)提供支持。

在将应用程序部署到Kubernetes并路由一部分生产流量过去后,情况开始发生变化。Kubernetes部署中的请求延迟要比EC2上的高出10倍。如果不找到解决办法,不光是后续微服务迁移无法正常进行,整个项目都有遭到废弃的风险。

为什么Kubernetes中的延迟要远高于EC2?

为了查明瓶颈,我们收集了整个请求路径中的指标。这套架构非常简单,首先是一个API网关(Zuul),负责将请求代理至运行在EC2或者Kubernetes中的微服务实例。在Kubernetes中,我们仅代表和NGINX Ingress控制器,后端则为运行有基于Spring的JVM应用程序的Deployment对象。

                          EC2
                          +---------------+
                        |  +---------+  |
                        |  |         |  |
                     +-------> BACKEND |  |
                    |    |  |         |  |
                    |    |  +---------+  |                   
                   |    +---------------+
         +------+  |
Public       |      |  |
      -------> ZUUL +--+
traffic      |      |  |              Kubernetes
             +------+  |    +-----------------------------+
                       |    |  +-------+      +---------+ |
                       |    |  |       |  xx  |         | |
                       +-------> NGINX +------> BACKEND | |
                            |  |       |  xx  |         | |
                            |  +-------+      +---------+ |
                            +-----------------------------+

问题似乎来自后端的上游延迟(我在图中以「xx」进行标记)。将应用程序部署至EC2中之后,系统大约需要20毫秒就能做出响应。但在Kubernetes中,整个过程却需要100到200毫秒。

我们很快排除了随运行时间变化而可能出现的可疑对象。JVM版本完全相同,而且由于应用程序已经运行在EC2容器当中,所以问题也不会源自容器化机制。另外,负载强度也是无辜的,因为即使每秒只发出1项请求,延迟同样居高不下。另外,GC暂停时长几乎可以忽略不计。

我们的一位Kubernetes管理员询问这款应用程序是否具有外部依赖项,因为DNS解析之前就曾引起过类似的问题,这也是我们目前找到的可能性最高的假设。

假设一:DNS解析

在每一次请求时,我们的应用程序都像域中的某个AWS ElasticSearch实例(例如elastic.spain.adevinta.com)发出1到3条查询。我们在容器中添加了一个shell,用于验证该域名的DNS解析时间是否过长。

来自容器的DNS查询结果:

[root@be-851c76f696-alf8z /]# while true; do dig "elastic.spain.adevinta.com" | grep time; sleep 2; done
;; Query time: 22 msec
;; Query time: 22 msec
;; Query time: 29 msec
;; Query time: 21 msec
;; Query time: 28 msec
;; Query time: 43 msec
;; Query time: 39 msec

来自运行这款应用程序的EC2实例的相同查询结果:

bash-4.4# while true; do dig "elastic.spain.adevinta.com" | grep time; sleep 2; done
;; Query time: 77 msec
;; Query time: 0 msec
;; Query time: 0 msec
;; Query time: 0 msec
;; Query time: 0 msec

前者的平均解析时间约为30毫秒,很明显,我们的应用程序在其ElasticSearch上造成了额外的DNS解析延迟。

但这种情况非常奇怪,原因有二:

  • Kubernetes当中已经包含大量与AWS资源进行通信的应用程序,而且都没有出现延迟过高的情况。因此,我们必须弄清引发当前问题的具体原因。
  • 我们知道JVM采用了内存内的DNS缓存。从配置中可以看到,TTL在$JAVA_HOME/jre/lib/security/java.security位置进行配置,并被设置为networkaddress.cache.ttl = 10。JVM应该能够以10秒为周期缓存所有DNS查询。

为了确认DNS假设,我们决定剥离DNS解析步骤,并查看问题是否可以消失。我们的第一项尝试是让应用程序直接与ELasticSearch IP通信,从而绕过域名机制。这需要变更代码并进行新的部署,即需要在/etc.hosts中添加一行代码以将域名映射至其实际IP:

34.55.5.111 elastic.spain.adevinta.com

通过这种方式,容器能够以近即时方式进行IP解析。我们发现延迟确实有所改进,但距离目标等待时间仍然相去甚远。尽管DNS解析时长有问题,但真正的原因还没有被找到。

网络管道

我们决定在容器中进行tcpdump,以便准确观察网络的运行状况。

[root@be-851c76f696-alf8z /]# tcpdump -leni any -w capture.pcap

我们随后发送了多项请求并下载了捕捉结果(kubectl cp my-service:/capture.pcap capture.pcap),而后利用Wireshark进行检查。

DNS查询部分一切正常(少部分值得讨论的细节,我将在后文提到)。但是,我们的服务处理各项请求的方式有些奇怪。以下是捕捉结果的截图,显示出在响应开始之前的请求接收情况。

数据包编号显示在第一列当中。为了清楚起见,我对不同的TCP流填充了不同的颜色。

从数据包328开始的绿色部分显示,客户端(172.17.22.150)打开了容器(172.17.36.147)间的TCP连接。在最初的握手(328至330)之后,数据包331将HTTP GET /v1/…(传入请求)引向我们的服务,整个过程耗时约1毫秒。

来自数据包339的灰色部分表明,我们的服务向ElasticSearch实例发送了HTTP请求(这里没有显示TCP握手,是因为其使用原有TCP连接),整个过程耗费了18毫秒。

到这里,一切看起来还算正常,而且时间也基本符合整体响应延迟预期(在客户端一侧测量为20到30毫秒)。

但在两次交换之间,蓝色部分占用了86毫秒。这到底是怎么回事?在数据包333,我们的服务向/latest/meta-data/iam/security-credentials发送了一项HTTP GET请求,而后在同一TCP连接上,又向/latest/meta-data/iam/security-credentials/arn:…发送了另一项GET请求。

我们进行了验证,发现整个流程中的每项单一请求都发生了这种情况。在容器内,DNS解析确实有点慢(理由同样非常有趣,有机会的话我会另起一文详加讨论)。但是,导致高延迟的真正原因,在于针对每项单独请求的AWS Instance Metadata Service查询。

假设二:指向AWS的流氓调用

两个端点都是AWS Instance Metadata API的组成部分。我们的微服务会在从ElasticSearch中读取信息时使用该服务。这两条调用属于授权工作的基本流程,端点通过第一项请求产生与实例相关的IAM角色。

/ # curl http://169.254.169.254/latest/meta-data/iam/security-credentials/
arn:aws:iam::<account_id>:role/some_role

第二条请求则向第二个端点查询实例的临时凭证:

/ # curl http://169.254.169.254/latest/meta-data/iam/security-credentials/arn:aws:iam::<account_id>:role/some_role`
{
    "Code" : "Success",
    "LastUpdated" : "2012-04-26T16:39:16Z",
    "Type" : "AWS-HMAC",
    "AccessKeyId" : "ASIAIOSFODNN7EXAMPLE",
    "SecretAccessKey" : "wJalrXUtnFEMI/K7MDENG/bPxRfiCYEXAMPLEKEY",
    "Token" : "token",
    "Expiration" : "2017-05-17T15:09:54Z"
}

客户可以在短时间内使用这些凭证,且端点会定期(在Expiration过期之前)检索新凭证。这套模型非常简单:出于安全原因,AWS经常轮换临时密钥,但客户端可以将密钥缓存几分钟,从而抵消检索新凭证所带来的性能损失。

照理来说,整个过程应该由AWS Java SDK为我们处理。但不知道为什么,实际情况并非如此。搜索了一遍GitHub问题,我们从 #1921 当中找到了需要的线索。

AWS SDK会在满足以下两项条件之一时刷新凭证:

  • Expiration 已经达到 EXPIRATION_THRESHOLD之内,硬编码为15分钟。
  • 最后一次刷新凭证的尝试大于REFRESH_THRESHOLD,硬编码为60分钟。

我们希望查看所获取凭证的实际到期时间,因此我们针对容器API运行了cURL命令——分别指向EC2实例与容器。但容器给出的响应要短得多:正好15分钟。现在的问题很明显了:我们的服务将为第一项请求获取临时凭证。由于有效时间仅为15分钟,因此在下一条请求中,AWS SDK会首先进行凭证刷新,每一项请求中都会发生同样的情况。

为什么凭证的过期时间这么短?

AWS Instance Metadata Service在设计上主要代EC2实例使用,而不太适合Kubernetes。但是,其为应用程序保留相同接口的机制确实很方便,所以我们转而使用KIAM,一款能够运行在各个Kubernetes节点上的工具,允许用户(即负责将应用程序部署至集群内的工程师)将IAM角色关联至Pod容器,或者说将后者视为EC2实例的同等对象。其工作原理是拦截指向AWS Instance Metadata Service的调用,并利用自己的缓存(预提取自AWS)及时接上。从应用程序的角度来看,整个流程与EC2运行环境没有区别。

KIAM恰好为Pod提供了周期更短的临时凭证,因此可以合理做出假设,Pod的平均存在周期应该短于EC2实例——默认值为15分钟。如果将两种默认值放在一起,就会引发问题。提供给应用程序的每一份证书都会在15分钟之后到期,但AWS Java SDK会对一切剩余时间不足15分钟的凭证做出强制性刷新。

结果就是,每项请求都将被迫进行凭证刷新,这使每项请求的延迟提升。接下来,我们又在AWS Java SDK中发现了一项功能请求,其中也提到了相同的问题。

相比之下,修复工作非常简单。我们对KIAM重新配置以延长凭证的有效期。在应用了此项变更之后,我们就能够在不涉及AWS Instance Metadata Service的情况下开始处理请求,同时返回比EC2更低的延迟水平。

总结

根据我们的实际迁移经验,最常见的问题并非源自Kubernetes或者该平台其他组件,与我们正在迁移的微服务本身也基本无关。事实上,大多数问题源自我们急于把某些组件粗暴地整合在一起。

我们之前从来没有复杂系统的整合经验,所以这一次我们的处理方式比较粗糙,未能充分考虑到更多活动部件、更大的故障面以及更高熵值带来的实际影响。

在这种情况下,导致延迟升高的并不是Kubernetes、KIAM、AWS Java SDK或者微服务层面的错误决策。相反,问题源自KIAM与AWS Java SDK当中两项看似完全正常的默认值。单独来看,这两个默认值都很合理:AWS Java SDK希望更频繁地刷新凭证,而KIAM设定了较低的默认过期时间。但在二者结合之后,却产生了病态的结果。是的,各个组件能够正常独立运行,并不代表它们就能顺利协作并构成更庞大的系统。

原文链接:

https://srvaroa.github.io/kubernetes/migration/latency/dns/java/aws/microservices/2019/10/22/kubernetes-added-a-0-to-my-latency.html

  • 发表于:
  • 本文为 InfoQ 中文站特供稿件
  • 首发地址https://www.infoq.cn/article/GocOUcRfST2fWgCUUM1C

扫码关注云+社区

领取腾讯云代金券