http 客户端常见的三种 timeout

微服务的开发部署方式已经在业界广泛被采用, 许多微小的服务共同组成一个完整的软件系统, 对外提供有价值的商业服务. 一个完整的系统组合起来, 离不开内部各个微服务之间的依赖调用, 于是微服务之间形成了一个密集的调用网. 因此我们在微服务的代码中看到许多的 http 客户端到服务端的调用, 而且当应用出问题时候, 我们经常看到各种 http client 相关的各种问题. 这些问题当中, 尤其与 timeout 相关的问题特别多, 本系列的几篇文章将以典型的 Liunx 上 Java 的 http client 为例, 来详细讨论常见的 http 客户端的3种timeout 问题.

connect timeout 和 read timeout

首先, 我们看一个最简单的服务间的调用过程:

  1. 客户端发起 tcp 连接, 服务端应答, tcp 连接建立;
  2. 客户端发出 http request;
  3. 服务端收到请求, 处理请求, 发回 http response;
  4. 客户端收到应答, 关闭 tcp 连接(open issue)

在上面的过程中, 客户端可能会面临2种timeout.

  1. 在上面的第(1)步建立 tcp 连接的过程中, 如果客户端发出 syn, 迟迟收不到服务端的应答, 会产生 connect timeout;
  2. 在上面的过程中, 如果客户端发出了请求, 迟迟收不到 http response, 或收不到完整的response, 则可能产生 read timeout;

从连接池租借连接 timeout

如果某个服务调用的频率非常高, 那么按照上面的流程, 每次都新建一个 tcp 连接就显得非常消耗系统资源和时间. 于是一个可以优化的选项就是在客户端建立连接池, 每次需要发送请求的时候, 从连接池租借出一个连接. 若连接池有现成的连接, 则可以立即借来用. 若没有, 才去新建. 当连接用完之后, 不是关闭连接, 而是返还给连接池以备下次使用. 一般情况下, 连接池不可能有无限的连接, 通常设置一个最大值, 当被借出的连接达到最大值之后, 后续的请求通常要等待空闲的连接可用 (这里介绍的连接池是一个比较简单的模型, 查看专门的书籍去查看更多关于连接的模型和策略).
所以, 从连接池去租借一个可用的连接, 并不一定每次都能立即拿到, 所以有可能迟迟拿不到连接, 所以这里会出现从连接池租借连接的等待 timeout.

所以, 一个客户端的请求会出现3种可能的timeout. 如下图:
timeouts.png

针对上面的3种timeout, 在我们常见的代码中, 它们的默认值是什么呢? 我们应该如何设置这些值呢? 如果设置不合理, 又可能出现那些问题呢?

docker container 的生命周期

当我们创建一个 container 的时候, 它的生命过程中都会经历哪几个阶段呢? 有时候明明一个 container 已经死了, 我们去创建一个同名 container 的时候, 它竟然说有一个同名的 container 存在? 明白了 container 的生命周期, 就能理解了.

container 的生命阶段

一个 docker container 从创建到彻底消亡, 可能会经过的阶段:
docker_container_lifecycle.png

  1. created: container 被创建, 但是没有被启动
  2. running: container 被启动, 里面的进程在运行
  3. paused: container 里的所有进程被挂起, 暂停运行
  4. stopped: container 里面的进程被杀死, container 还存在
  5. deleted: container 被彻底删除

下面我们就以 nginx 做container 为例来说明这个过程.

create 创建 container

下面创建一个 nginx container, 并使用 ps -l (--latest) 来查看, 状态是 Created.

supra@suprabox:~$ docker create --name nginxServer nginx
ac301e1f4f3f3ba5631ff5d7f3276d1544610229a9e3727dac6d5f66181bfe05

supra@suprabox:~$ docker ps -l
CONTAINER ID   IMAGE     COMMAND                  CREATED          STATUS    PORTS     NAMES
ac301e1f4f3f   nginx     "/docker-entrypoint.…"   1 minutes ago   Created             nginxServer

start 启动 container

通过start子命令启动 container, 然后通过ps子命令查看状态. 通过exec子命令写一句话到/text.txt文件, 并且查看写入内容.

supra@suprabox:~$ docker start nginxServer
nginxServer

supra@suprabox:~$ docker ps -l
CONTAINER ID   IMAGE     COMMAND                  CREATED          STATUS         PORTS     NAMES
ac301e1f4f3f   nginx     "/docker-entrypoint.…"   25 minutes ago   Up 5 seconds   80/tcp    nginxServer

supra@suprabox:~$ docker exec nginxServer bash -c 'echo "this is a test" > /test.txt'
supra@suprabox:~$ docker exec nginxServer cat  /test.txt
this is a test

pause 暂停 container

可以看到经过 pause 之后, 状态变为 Paused. 如果尝试进入这个 container exec, 这个时候会报错.

supra@suprabox:~$ docker pause nginxServer
nginxServer

supra@suprabox:~$ docker ps -l
CONTAINER ID   IMAGE     COMMAND                  CREATED          STATUS                  PORTS     NAMES
ac301e1f4f3f   nginx     "/docker-entrypoint.…"   29 minutes ago   Up 4 minutes (Paused)   80/tcp    nginxServer

supra@suprabox:~$ docker exec -it nginxServer bash
Error response from daemon: Container nginxServer is paused, unpause the container before exec

unpause 继续 container

supra@suprabox:~$ docker unpause nginxServer
nginxServer

supra@suprabox:~$ docker ps -l
CONTAINER ID   IMAGE     COMMAND                  CREATED             STATUS          PORTS     NAMES
ac301e1f4f3f   nginx     "/docker-entrypoint.…"   About an hour ago   Up 44 minutes   80/tcp    nginxServer

stop 停止 container

stop 之后, 通过docker ps -l 可以看到状态变为 Exited, 这个时候通过docker logs 仍旧能看到之前的log, 并且可以看到主进程被杀死的日志. 但是通过docker exec 已经无法进入 container.

supra@suprabox:~$ docker stop nginxServer
nginxServer

supra@suprabox:~$ docker ps -l
CONTAINER ID   IMAGE     COMMAND                  CREATED             STATUS                     PORTS     NAMES
ac301e1f4f3f   nginx     "/docker-entrypoint.…"   About an hour ago   Exited (0) 8 seconds ago             nginxServer

supra@suprabox:~$ docker logs -f nginxServer
/docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
/docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/
...
2023/01/27 13:35:52 [notice] 1#1: signal 17 (SIGCHLD) received from 32
2023/01/27 13:35:52 [notice] 1#1: worker process 32 exited with code 0
2023/01/27 13:35:52 [notice] 1#1: worker process 37 exited with code 0
2023/01/27 13:35:52 [notice] 1#1: exit

supra@suprabox:~$ docker exec -it nginxServer bash
Error response from daemon: Container ac301e1f4f3f3ba5631ff5d7f3276d1544610229a9e3727dac6d5f66181bfe05 is not running

start 重新启动 stop 的 container

通过 start 子命令, 可以重新启动 stop 的container, 通过docker ps -l 可以看到它的状态是刚起来4秒. 这时候去查看之前写入的 /test.txt 文件, 内容还在. 但是这时候里面的进程都是新启动的, 不说 stop 之前的那个(批)进程了.

supra@suprabox:~$ docker start nginxServer
nginxServer

supra@suprabox:~$ docker ps -l
CONTAINER ID   IMAGE     COMMAND                  CREATED             STATUS         PORTS     NAMES
ac301e1f4f3f   nginx     "/docker-entrypoint.…"   About an hour ago   Up 4 seconds   80/tcp    nginxServer

supra@suprabox:~$ docker exec nginxServer cat  /test.txt
this is a test

rm 彻底删除container

可以通过rm子命令删除任何状态的container. 如果一个container 是 stopped 或 created 状态的, 可以直接rm, 否则就必须通过 -f 强制删除.

docker rm nginxServer
docker rm -f nginxServer

run 创建同时启动container

可以通过 run 子命令, 在创建container的同时, 启动container, 相当于同时执行了create和start.

supra@suprabox:~$ docker run --name nginxServer1 --rm  nginx
/docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
/docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/

kill 杀掉一个运行的container

通过kill 杀掉一个运行的container 之后, container 进入 stopped 的状态.

supra@suprabox:~$ docker kill nginxServer
nginxServer

supra@suprabox:~$ docker ps -l
CONTAINER ID   IMAGE     COMMAND                  CREATED       STATUS                        PORTS     NAMES
ac301e1f4f3f   nginx     "/docker-entrypoint.…"   2 hours ago   Exited (137) 18 seconds ago             nginxServer

虚拟以太网卡 veth

这是一块真实的台式机网卡, 左边是一个插网线的接口, 右边是电路板, 电路板上哪些金色的地方就插入主板的接口. 于是外部流量就通过网线, 进入网卡, 然后流入计算机, 计算机内部数据则通过相反的方向流出到外部.
网卡.png

虚拟以太网卡, 就是一个通过软件模拟的网卡设备, 它能模拟网卡的功能把数据传出去, 接收进来的数据, 在操作系统看来, 它就是一块功能完备的网卡. 这个虚拟的网卡一头连着操作系统的kernel, 另外一头呢? 它有没有网线可以插拔, 所以它只能连向另外一个网卡, 所以虚拟出来的网卡都是成对出现的, 它们不能插网线, 所以只能2个网卡之间相互通信, 就好比2个机器之间通过一条直连的网线连在了一起. 就好比下图这样:
vethPair.png

但是这个 veth0 和 veth1 对必然在同一台机器上, 不可能跨域两台机器还能连着. 不过 veth0 和 veth1 可以属于同一台机器上的不同VM, container 或者不同的 netns.

下面演示如何创建虚拟网卡:

# 新建之前查看已有的
$ ip link show

$ sudo ip link add  name veth1 type veth #新建link

$ ip link show # 再次查看
1994: veth0@veth1: <BROADCAST,MULTICAST,M-DOWN> mtu 1500 qdisc noop state DOWN mode DEFAULT group default qlen 1000
    link/ether fe:99:a3:6e:f7:b0 brd ff:ff:ff:ff:ff:ff
1995: veth1@veth0: <BROADCAST,MULTICAST,M-DOWN> mtu 1500 qdisc noop state DOWN mode DEFAULT group default qlen 1000
    link/ether 56:64:02:ac:de:26 brd ff:ff:ff:ff:ff:ff

可以看到新加出来的 veth0 和 veth1 这对. 我们给的veth 的名字是 veth1, 而系统默认给出了配对的名字是 veth0. 最前面的数字 1994 和 1995 是系统的一个索引值, 称之为 IDX. @后面的名字是成对的另外一边点名字. <> 里面是支持的一些功能, 后边是一些相关参数, 这些参数可以在新建时设置, 也可以使用默认值. 下面一行代表 link 类型: ether(以太网), link 层地址(MAC 地址) 和 广播地址.

当然, 我们可以新建的时候, 直接给出这一对的名字, 比如:

$ sudo ip link add  name veth2 type veth peer name veth3

$ ip link show
1996: veth3@veth2: <BROADCAST,MULTICAST,M-DOWN> mtu 1500 qdisc noop state DOWN mode DEFAULT group default qlen 1000
    link/ether 12:39:5b:12:84:49 brd ff:ff:ff:ff:ff:ff
1997: veth2@veth3: <BROADCAST,MULTICAST,M-DOWN> mtu 1500 qdisc noop state DOWN mode DEFAULT group default qlen 1000
    link/ether 8a:f0:21:23:20:52 brd ff:ff:ff:ff:ff:ff

因为它们是默认一对出现的, 如果一方下线(down) 则另外一方默认就下线了:

$ sudo ip link set veth3  down

$ ip link
1996: veth3@veth2: <BROADCAST,MULTICAST,M-DOWN> mtu 1500 qdisc noop state DOWN mode DEFAULT group default qlen 1000
    link/ether 12:39:5b:12:84:49 brd ff:ff:ff:ff:ff:ff
1997: veth2@veth3: <BROADCAST,MULTICAST,M-DOWN> mtu 1500 qdisc noop state DOWN mode DEFAULT group default qlen 1000
    link/ether 8a:f0:21:23:20:52 brd ff:ff:ff:ff:ff:ff

可以看到, 我们这里新建的 veth 都只有link 层地址, 没有 IP 地址, 我们可以给它们赋予IP 地址.

$ ip addr show #设置 IP 地址之前先查看一下

$ sudo ip address add 192.168.88.1/16 dev veth3
$ sudo ip address add 192.168.88.2/16 dev veth2

$ ip addr show #设置完再次查看 
1996: veth3@veth2: <BROADCAST,MULTICAST,M-DOWN> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 12:39:5b:12:84:49 brd ff:ff:ff:ff:ff:ff
    inet 192.168.88.1/16 scope global veth3
       valid_lft forever preferred_lft forever
1997: veth2@veth3: <BROADCAST,MULTICAST,M-DOWN> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 8a:f0:21:23:20:52 brd ff:ff:ff:ff:ff:ff
    inet 192.168.88.2/16 scope global veth2
       valid_lft forever preferred_lft forever

$ sudo ip link set veth3 up #up

tcpdump 里面的数据只有特定方向的

最近在诊断一个问题的时候, 当时有件奇怪的事情: 所有的流量都是流向一个IP的, 再也没有其它流量.
为了查出为什么会连接timeout, 于是去抓包, 因为知道连接肯定是443 或 80, 于是使用下面的命令:

$ tcpdump port 80 or port 443 -w /tmp/tcpdump.pcap

可是抓到的结果却全是流向这个IP 的, 并且没有返回traffic:
tcpdump.png

最后发现, 这个机器上有2个接口: tunl0 和 eth0, 抓包时候, tcpdump 默认使用了 tunl0 接口:

$ ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: tunl0@NONE: <NOARP,UP,LOWER_UP> mtu 1480 qdisc noqueue state UNKNOWN group default qlen 1000
    link/ipip 0.0.0.0 brd 0.0.0.0
    inet 10.147.64.197/32 scope global tunl0
       valid_lft forever preferred_lft forever
22: eth0@if23: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
    link/ether e2:99:0b:96:46:a0 brd ff:ff:ff:ff:ff:ff link-netnsid 0
    inet 10.147.166.192/32 scope global eth0
       valid_lft forever preferred_lft forever
    inet6 fe80::e099:bff:fe96:46a0/64 scope link
       valid_lft forever preferred_lft forever

$ tcpdump port 80 or 443 -w /tmp/tcpdump.pcap
tcpdump: listening on tunl0, link-type RAW (Raw IP), capture size 262144 bytes
^C2 packets captured
16 packets received by filter
0 packets dropped by kernel

从上面ip a 的结果看, 除了 lo 之外, 它存在一个隧道接口和一个eth 端口, 可是使用 tcpdump 时候, 它默认使用了 tunl0 接口.

如果要抓取所有接口的流量, 可以使用

$ tcpdump -i any port 80 or port 443 -w /tmp/tcpdump.pcap
tcpdump: listening on any, link-type LINUX_SLL (Linux cooked), capture size 262144 bytes

记录在生产环境k8s安装 janusgraph 的艰难过程

最近有个功能的某些数据特别适合图数据库, 一开始使用的是 MySQL 数据库, 但是在业务开发的过程中, 愈发觉得图数据库才是它的最终归宿, 于是先期先用 MySQL 做了一版, 顺利上线, 然后第二步准备迁移到图数据库.

之前小组内部有人用过 Neo4j, 用的还挺不错, 准备使用, 但是后来听说这个对于大企业要收费, 并且公司有个部门已经做好了一个基于 Janusgraph 的数据库, 统一管理, 保证稳定运行, 所以最后放弃 Neo4j, 转而准备上公司已经搭好并且有部门维护的这个图数据库. 但是一番打听下来, 要使用这个数据库, 有个复杂的流程, 关键的关键是: 如果你改任何一个图的schema(顶点, 边及其任何属性, 都要提ticket, 然后走review流程. 对于我们这种一开始还不确定到底有多少类型的顶点, 多少边, 时不时随时可以加边的实验性的项目, 这种流程简直就是灾难.

所以, 最可行的方案是: 我们先自己在开发, 测试, 生产环境搭一套基于 Janusgraph 的图数据库, 等我们的 schema 都稳定之后, 再考虑迁移到有稳定保障的, 有部门支持的图数据库.

首先, 在开发环境基于 Janusgraph 的 docker image 做了一个server, 并且搭了一个 graphexp 的 UI server. 脚本如下:

mkdir -p /home/supra/work/data/janusgraph/{data,index}
sudo chown -R 999:999 /home/supra/work/data/janusgraph
docker run --name janusgraph -p 8182:8182 --restart always -d --platform linux/amd64 -v /home/supra/work/data/janusgraph/data:/var/lib/janusgraph/data -v /home/supra/work/data/janusgraph/index:/var/lib/janusgraph/index janusgraph/janusgraph
docker run --name graphexp  -p 8183:80 --restart always -d --platform linux/amd64 ghcr.io/armandleopold/graphexp:0.8.3

大家注意到, 这里我们给 Janusgraph 的server 挂载了一个 volume, 还把这个挂载的文件夹的owner 改成了用户和组都是999的用户, 这里确实是偷懒. 这一切都是因为 Janusgraph 的 docker 文件里面新起了一个 janusgraph 的用户, 它的uid和gid都是 999. 在 Janusgraph server 里面, 都是以这个用户运行的. 都是因为这个用户和组, 导致我最后必须写下这篇记录.

本地环境这么起起来, 往里面灌入数据, 在用 graphexp 的UI 去访问, 一切顺利. 于是准备轰轰烈烈的去搞一个prod Janusgraph server 集群, 目标是1个小时搞定.

首先, prod 环境不能访问外网的 docker image, 于是拉下最新的外网image, 然后重新打一个 tag, 搞成内网的 image, 然后在生产环境的 k8s 环境做一个新的app, 然后一番乱搞, docker image 开始启动了.

但是呢, 总是启动不起来, 为啥, 因为:

chown: changing ownership of '/var/lib/janusgraph': Operation not permitted
chown: changing ownership of '/etc/opt/janusgraph': Operation not permitted
chmod: changing permissions of '/var/lib/janusgraph': Operation not permitted
chmod: changing permissions of '/etc/opt/janusgraph': Operation not permitted

仔细分析下来, 主要是:

  1. 生产环境都是 rootless 的, 所以运行 container 的 uid 都不是 root, 是一个根据 namespace 预先定义好的用户.
  2. 生产环境默认所有image 里面的文件都是read only, 所以对于日志, 数据文件必须通过 volume 挂载使用.
  3. 给 Janusgraph server 用的 data 和 index 文件夹都是挂载的 volume, 而这些 volume 的owner 都是上面预先定义好的 rootless 用户;
  4. 而一旦进入 Janusgraph, 它却以 Dockerfile 中自己新加的 janusgraph(999:999) 这个用户运行.

所以, 就造成了这种困境: 因为 image 里面的文件都是 read only, 和必须保存这些数据, 数据必须以 volume 的方式挂载, 然而挂载的文件夹的主人是预先定义好的非 root 账号, Janusgraph 的启动脚步里面却要改变这些数据文件夹的属主, 但是它使用的自己创建的账号janusgraph(999:999), 而这个账号有没有权限更改owner. 于是死了.

想解决这个问题, 有2种可能的方案:

  1. 生产环境其实可以改变这个预先定义好的非root 账号, 我们的生产环境可以针对某个namespace 创建一个新的用户, 而这个用户必须绑定生产环境的 LDAP. 所以, 要先定义一个生产环境的 LDAP 账号, 规定它的uid/gid, 然后绑定某个 k8s 下面的namespace, 然后在运行这个 container 的 spec 里面的 SecurityContext 里面设置 fsgroup, runAsUser 等.
  2. hack Janusgraph 的 Docker 文件, 去掉这个自己创建的用户, 像其它 image 一样, 用默认用户不香吗?

首先想去试试第一种方案. 去找了公司内部k8s的文档, 说是有这么一个创建posixuser 的流程, 可能是因为很少有人用, 搜了半个多小时, 没有找一个完整的文档, 能教会我怎么去做的. 更多的文档是说查看有了这么一个账号, 然后就可以以它运行container 了. 再加上更改任何生产环境的东西, 要走审批流程, 1个小时后, 我彻底放弃了.

第二种方案, 就是要大改看懂 Janusgraph 的Dockerfile 和 docker-entrypoint.sh 两个文件. 花了半个小时, 大改看到它就是想以一个service acount (janusgraph) 来运行这个服务, 然后启动前, 把相关的文件都给这个用户设置好, 然后就启动. 于是改了上述2个文件里面的关于这个用户的行, 然后加了一些日志, 然后本地做一个新的image, 然后push 到内部 image 仓库, 然后启动等好消息.

然而, 有没起来, 还以为是关于这个用户的错误, 又加调试代码, 做新image, 发布的流程再走一遍, 仍然起不来. 后来竟然发现是 刚起来, 就被 OOM kill 了. 哎, 命运多舛. 为啥 OOM 呢, 本地好好的. 因为 OOM 很快被 kill, 所以只有很短的时间, 能进入 container 去查看日志, 但是进入发现, 日志文件都是空.

于是进入本地启动好的 container 里面, 去查看它的启动参数(container 里面啥工具都没有, cat /proc/1/cmdline 才看到), 发现它启动的时候, 竟然就要求 heap 是4G, 那么再加点其它的 metaspace , 还有些辅助进程等, 岂不是5G打不住? 然而一开始我觉的它需要的内存很小, 只给了它1G的空间, 所以 OOM 也就很好理解了. 于是我就想问了, 为啥官方文档不告诉你最少需要5G呢???, 另外启动日志不能把这么重要的参数打印出来吗?

虽然心有不忿, 还是立马改了内存限制, 立马给他8个G, 然后再启动, 发现起来了, 可是有错:

Disk usage is not within je.maxDisk or je.freeDisk limits and write operations are prohibited

对了, 就是这个还在 open 的issue, 必将以后还要open: https://github.com/internetarchive/heritrix3/issues/340. 因为他们改变不了. 原来这个内存数据库, 需要至少5个G的磁盘空间, 否则, 它就生气. 而我给所有的 volume 的大小总共才2个G, 所以出这个错, 也就不难理解了.

于是, 我有给 volume 加到12个G. 于是重新部署, 大家都开心了, 你好, 我也好. 终于成功了. 至此, 本来打算要1个小时完成的工作, 终于通过12个小时(早上9点到晚上9点, 当然中间包括2顿饭的时间和1个多小时的开会)的努力, 画上句号了.