plantegg

java tcp mysql performance network docker Linux

发表于 更新于 分类于

为什么你的连接不均衡了？

场景

假如你有两个Redis 服务，挂载在一个LVS 下，然后客户端使用的Jedis，Jedis 配置的最大连接池是200个连接，最小是100个(也就是超过100个，当闲置一段时间后就释放掉)。然后过一阵假设来了一个访问高峰，把连接数打到200，过一会高峰过去连接就会释放到100，客户端每次取连接然后随便 get 以下就归还连接

场景构造小提示：

  1. 用Jedis；
  2. 构造流量一波一波，就是有流量高峰(触发新建连接)、有流量低峰(触发连接释放)，如此反复
  3. 不需要太大流量把Redis 节点打到出现瓶颈

如下图：

image-20240618202012463

期待场景：在这个过程中，Jedis 每次取一个连接随便get 一个key 就行了，无论怎么折腾两个Redis Service 的连接数基本是均衡的，实际也确实是这样

比如可以这样设置Jedis 参数(你也可以随便改)，也可以用你们生产环境

1
2
3
4
5
6
7
8
9
JedisPoolConfig config = new JedisPoolConfig();
config.setMaxIdle(100);
config.setMaxTotal(200);
config.setMinEvictableIdleTimeMillis(3000);
config.setTimeBetweenEvictionRunsMillis(1000);
config.setTestOnBorrow(false);
config.setTestOnReturn(false);
config.setTestWhileIdle(false);
config.setTestOnCreate(false);

验证代码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
import com.taobao.eagleeye.redis.clients.jedis.Jedis;
import com.taobao.eagleeye.redis.clients.jedis.JedisPool;
import com.taobao.eagleeye.redis.clients.jedis.JedisPoolConfig;

public class JedisPoolTest {
    // 初始化连接超时时间
    private static final int DEFAULT_CONNECTION_TIMEOUT = 5000;
    // 查询超时时间
    private static final int DEFAULT_SO_TIMEOUT = 2000;
    private static final JedisPoolConfig config = new JedisPoolConfig();
    private static JedisPool jedisPool = null;

    public static void main(String args[]) {
        // 代理连接地址，用控制台上的"代理地址"。
        String host = "redis";
        int port = 6379;
        //String password = "1234";

        // 设置参考上面
        config.setMaxTotal(xx);
        config.setMaxIdle(xx);
        config.setMinIdle(xx);
        

        // 只需要初始化一次
        try {
            jedisPool = new JedisPool(config, host, port, 
            DEFAULT_CONNECTION_TIMEOUT, DEFAULT_SO_TIMEOUT, password, 0, null);
            try (Jedis jedis = jedisPool.getResource()) {
                if (!"PONG".equals(jedis.ping())) {
                    throw new RuntimeException("Init Failed");
                }
            }
        } catch (Exception e) {
            // 如果有exception，说明初始化失败。
            e.printStackTrace();
        }

        // 每次 API 查询都像下面这么写
        Jedis jedis = null;
        try {
            jedis = jedisPool.getResource(); // 查询前获取一个连接
            String ret = jedis.set("key", "value");
            if ("OK".equals(ret)) {
                System.out.println(ret);
                // SET success
            }
        } catch (Exception e) {
            e.printStackTrace();
            // 连接错误，超时等情况
        } finally {
            if (jedis != null) {
                // 查询结束后还回连接池，不是销毁连接
                // 必须尽快还回，否则会导致连接池资源不够
                jedis.close(); 
            }
        }

        // 只需要最后程序退出时调用一次，不需要每次查询完之后都调用
        jedisPool.close();
    }
}

运行如上代码，应该看到一个负载均衡正常环境——符合预期

不均衡重现

背景里描述的是完全符合预期的，假设实际使用中两个 Redis中的一个节点的CPU有一个降频了/争抢/温度高 等种种原因，导致这个节点处理更慢了

如何模拟其中一个节点突然慢了(这些手段在之前的星球案例重现里都反复使用过了)

  1. 你可以把Redis 进程绑到一个核上，然后在这这个核上跑一个死循环故意让；
  2. 或者，也可以在这个节点上给网络延迟加200ms 进去

这个时候你再重新跑背景描述里的代码，一段时间后你会看到下图中红线对应的 Redis 节点上的连接数越来越高，QPS 越来越高(别用太大的压力，导致这个节点的访问超时哈)

image-20240618203121532

到这里就算是问题重现出来了

重现确认注意：

如果只是看到瞬间连接数不均衡这应该没有重现出来，因为节点慢了所以 active 要变高才会维系住同样的QPS，这是符合预期的。

期望的是长期运行后慢的节点上统计意义上的连接数越来越多、QPS 越来越大

比如下图是重现过程中的连接数监控，可以看到橙色线对应的Redis 节点上的连接越来越多：

img

下图是对应的QPS 监控，问题Redis 节点(黄色线)的QPS 比另外一个节点大很多，长期下去会导致问题节点成为瓶颈：

img

重现脚本和代码

以下涉及的脚本、代码提交到 github，这些脚本、手段在我们之前的实验、案例都反复出现过了，我就不给了

参考星球里扒老师的操作(不含客户端Java代码)：https://malleable-elbow-b9f.notion.site/redis-f7dfcecb7f7441e1ba96f4da3ca8aee8?pvs=4

星球里橘橘球用python 3.8 实现了一个python 版本的：https://github.com/gongyisheng/playground/blob/dev/network/lvs_case/readme.md

好奇同学用Java/Jedis 和Go两个版本(Go 版本是没有Jedis，也能重现问题)的实现代码：https://github.com/haoqixu/case-reproduction-240618

docker

用 docker起两个Redis 节点

1
2
//这里提供Redis docker run脚本

ipvsadm

1
//创建一个 LVS，将上面的两个Redis 加入到负载均衡里面

Java 客户端代码

完整代码应该很简单，就是一个Java + Jedis 的HelloWorld 上传到 github，别人下载代码后，自己配置一个 LVS + Redis 的负载均衡环境就能重现以上问题

tc qdisc

1
//给其中的一个 节点构造 200ms 的延时

也可以跑死循环抢 CPU

分析

原因：Jedis 连接池使用的是 apache commons-pool 这个组件，默认从连接池取连接使用的是 LIFO(last in first out) ，如果两个节点负载正常两个节点上的连接基本能保持在队列里交叉均衡；如果连接闲置久了释放的时候就是均衡释放的

但如果有一个节点处理慢了，那么这个节点的连接被取出来使用的时候必然需要更多的时间在连接池外面处理请求，用完归还的时候就会更高概率出现在队列的顶部，导致下次首先被取出来使用，长期下去就会出现快的节点上的连接慢慢被释放，慢的节点的连接越来越多，进而慢的节点的QPS 越来越高，最后这个节点崩了

泛化问题

针对这个问题就一定是Jedis 和 Redis 才有吗？本质是我们没法期望所有节点一样快，导致连接归还一定有慢的，进而只要是取连接用 LIFO(last in first out) 就会有这个问题，Jedis/Lettuce/MySQL dbcp 都用了 apache commons-pool 这个组件来实现连接池功能，而 apache commons-pool 默认就是 LIFO ，所以这些组件全部中枪。应该是用的 LinkedBlockingDeque 队列，它有有 FIFO 和 FILO 两种策略

那么没有用 apache-commons-pools 的就安全吗？也不一定，得看取连接的逻辑，一般都是 LIFO，比如 Druid 连接池的实现用的 stack ，也就是 stack 顶部的几个连接被反复使用，可能底部连接完全用不到的情况。 且Druid 还不提供接口去设置是不是 stack/queue（LIFO/FIFO)

你们的微服务只要是用连接池大概率也会有同样的问题

那么有什么好办法来解决类似的问题吗？Druid 有个设置 phyTimeoutMillis 和 phyMaxUseCount (就是一个长连接用多久、或者执行了多少次SQL ) 来将长连接主动断开，这就有概率修复这个问题；

另外如果LVS 用的 WLC 均衡算法也可以fix 这个问题，见参考资料。

php听说有个功能，进程跑一段时间后自行销毁重建；担心内存泄漏啥的 —— 是不是很像遇到问题就重启，又不是不work，不优雅但是管用，有点像通信基站半夜重启

内核 epoll 的线程也是 FILO

参考：Why does one NGINX worker take all the load? (链接里提供完整的最简测试重现代码)

唤醒时容易最是唤醒最后几个线程(一般一个线程对应一个核)，在并发压力不大时某几个线程总是被唤醒->归还->唤醒(再次取出分配执行任务)

epoll的accept模型为LIFO，倾向于唤醒最活跃的进程。多进程场景下：默认的accept是FIFO，进程加入到监听socket等待队列的尾部，唤醒时从头部开始唤醒；epoll的accept是LIFO，在epoll_wait时把进程加入到监听socket等待队列的头部，唤醒时从头部开始唤醒。

影响：当并发数较小时，只有最后几个进程会被唤醒，它们使用的CPU时间会远高于其它进程。当并发数较大时，所有的进程都有机会被唤醒，各个进程之间的差距不大。内核社区中关于epoll accept是使用LIFO还是RR有过讨论，在4.9内核和最新版本中使用的都是LIFO。

image.png

你看虽然是一次 Jedis 客户端在某些条件下导致的问题，只要你去通用化问题的本质就可以发现很容易地跳出来看到各个不同场景下同样会引起的问题，无招胜有招啊

参考资料

https://plantegg.github.io/categories/LVS/ 强调下这次的不均衡和我这个链接里的两篇文章描述的毫无关系，只是接着这个机会可以重温一下导致不均衡的其它原因，做个汇总

发表于 更新于 分类于

一次抓包分析过程——Wireshark 新手上车

问题

网友尝试做星球第一个必做实验的时候，什么内核参数都没改，发现请求经常会停滞 100ms，这种要怎么判断是局域网的网络问题还是应用问题呢？ 服务是 python3 -m http.server 启动的，看上去没有出现什么重传、窗口也没看到什么问题

因为不能提供环境给我，我尝试对这个抓包进行了分析，因为只有客户端抓包，所以分析结果是没有结论的，但分析过程比较适合入门 Wireshark，适合刚加入星球的、没分析过网络包的同学可以参考，熟手请忽略

分析

整个抓包 28MB，跨度 600 毫秒，看得出带宽很大、RTT 极小(到Wireshark 里看看前几个包的交互 RT 就知道了)

image-20240715093847359

详细分析

看第一次卡 100ms 之前的抓包，在100ms 以前客户端ack 了所有Server 发出来的的tcp包(红框)，也就是说每一个发给客户端的包客户端都ack 完毕，证明客户端处理足够快，但是 8089端口不继续发包而是等了100ms再继续发，如下图：

image-20240715094218182

到这里的结论：

不是因为发送buffer、接收buffer太小导致的卡；也不是因为拥塞窗口导致的，就是Server 端没有发包。大概率是Server 进程卡了，或者Server 进程读取物理文件往OS buffer 写这些环节卡了（可以在服务端通过 strace -tt 看看进程在这 100 毫秒有没有往内核怼数据）

所以要继续在 Server 端来分析这个问题

怎么快速定位到红框、红线这里的包？

到 Time Sequence 图上点平台两边的点都可以自动跳转到这里，每个点代表一个网络包，横坐标代表时间

其它分析

将如下 Time Sequence 图使劲放大，从第一个包开始看，可以观察到教科书所说的慢启动

image-20240715095134352

整体看的话，慢启动几乎可以忽略，毕竟这个抓包是下载一个巨大的文件，如果是一个小文件这个慢启动还是影响很大的，如下图，红框部分看起来微不足道

image-20240715095506381

把时间范围放大，继续看，在卡之前红色箭头很长的，代表带宽、buffer有能力一次发送很多网络包，但是后面每次只发一点点网络包(绿色箭头长度)就卡了

image-20240715095647702

重现

我用 python3 当服务端未能重现这个卡100ms 的现象，拉取都很丝滑

image-20240715101505977

非常细节地去分析的话，也是能看到一些小问题的，比如1.9ms的卡顿、比如zero_window

image-20240715103928266

重现的时候，有1.9ms 这样的卡顿，但是不算有规律，因为这么小在整个传输过程中影响不大

image-20240715103708750

我重现的时候正好抓到了 seq 回绕，seq 是个 32位的无符号整数，到了最大值就从0又开始：

image-20240715115500312

此时的 Time Sequence:

image-20240715115655516

建议

可以用实验1里面的一些手段debug 一下Server 为什么卡了，除了 strace -tt 还可以用 ebpf 试试看看 Server 的调度上哪里顿了 100ms

新手如何通过Wireshark 来看抓包？

首先不要纯粹为了学习去看，而是要问你的问题是什么？如果网络传输速度慢，我们就看 Time Sequence(斜率越陡速度越快)，去看为什么发送端不发包了

  • 如正文里的卡顿平台，在250ms内差不多要卡240ms 不发包，速度自然不行
  • 我重现抓包中的zero Windows
  • 达到网络BDP 瓶颈了，去看拥塞窗口在最大值的时候会丢包，触发降速

里面可以看、要看的东西太多，所以我也说不上要看什么，而是要问你的问题是什么

发表于 更新于 分类于

一次故障的诊断过程–Sysbench

背景

我们的数据库需要做在线升级丝滑的验证，所以构造了一个测试环境，客户端Sysbench 用长连接一直打压力，Server 端的数据库做在线升级，这个在线升级会让 MySQL Server进程重启，毫无疑问连接会断开重连，所以期望升级的时候 Sysbench端 QPS 跌0几秒钟然后快速恢复

但是每次升级都是 Sysbench端 QPS 永久跌0，再也不能恢复，所以需要分析为什么，问题出在哪里？有人说是服务端的问题因为只有服务端做了变更

整个测试过程中 Sysbench 是配置的1-2个连接去压 MySQL Server

Sysbench 介绍

以下介绍来自 ChatGPT-4，用过Sysbench的同学可以跳过这节：

Sysbench 是一个适用于多个系统的多线程基准测试工具，被广泛用于评估不同系统服务的性能，包括数据库系统（如 MySQL、PostgreSQL）、文件I/O、CPU性能以及线程调度。

对于MySQL数据库，Sysbench 可以执行包括但不限于以下类型的测试：

  • OLTP (Online Transaction Processing) 测试: 这是最常见的数据库基准测试类型，模拟在线事务处理工作负载，包括事务性的Insert、Update、Delete和Select操作。
  • 点查找测试: 测试数据库针对特定索引的单行查找性能。
  • 简单写测试: 测试数据库进行插入操作的性能。
  • 复杂的选择查询测试: 运行复杂的Select查询，包含多个表和多个条件，测试数据库的读取性能。
  • 非事务性查询测试: 类似于事务查询测试，但不在事务框架内进行。

Sysbench使用Lua脚本语言进行测试案例的开发，它预置了一些标准的测试模板如oltp_read_only、oltp_read_write、oltp_write_only等，这些可以针对数据库执行标准的过程以及自定义的工作负载。

进行Sysbench压力测试的基本步骤包括：

  1. 安装Sysbench。
  2. 准备测试数据集，这通常涉及Sysbench创建数据库及表，然后填充数据。
  3. 执行测试，Sysbench以定义的并发线程数向数据库发送请求。
  4. 收集并分析结果，例如吞吐量（每秒事务数）、延迟以及一致性。

一个简单的Sysbench测试命令可以是这样：

1
2
3
4
5
/usr/local/bin/sysbench --debug=on --mysql-user='root' --mysql-password='123' --mysql-db='test' --mysql-host='127.0.0.1' --mysql-port='3307' --tables='16'  --table-size='10000' --range-size='5' --db-ps-mode='disable' --skip-trx='on' --mysql-ignore-errors='all' --time='11080' --report-interval='1' --histogram='on' --threads=2 oltp_read_write prepare

/usr/local/bin/sysbench --debug=on --mysql-user='root' --mysql-password='123' --mysql-db='test' --mysql-host='127.0.0.1' --mysql-port='3307' --tables='16'  --table-size='10000' --range-size='5' --db-ps-mode='disable' --skip-trx='on' --mysql-ignore-errors='all' --time='11080' --report-interval='1' --histogram='on' --threads=2 oltp_read_write run

sysbench oltp_read_write --table-size=100000 --mysql-db=testdb --mysql-user=root --mysql-password=password cleanup

这个命令序列分别准备数据、运行测试和清理环境。运行测试部分变量--threads=4表示使用4个线程，--time=60表示测试持续时间60秒。

使用Sysbench时，请确保执行的测试与你的用例相关，并考虑到可能的性能差异。例如，如果目标是测试Web应用程序的数据库后端，确保测试的查询和事务能够反映真实的使用案例。

Sysbench的使用可以参考这个链接

Sysbench 编译

从 github 下载源代码

以5.10(ALinux3/CentOS8) 为例

1
2
3
4
5
6
7
8
yum install libtool -y //configure.ac:61: error: possibly undefined macro: AC_PROG_LIBTOOL
yum install mysql-devel -y 

然后：
./autogen.sh ; ./configure ; make ; make install 

起压力重现命令：
sysbench --mysql-user='root' --mysql-password='123' --mysql-db='test' --mysql-host='127.0.0.1' --mysql-port='3306' --tables='16'  --table-size='10000' --range-size='5' --db-ps-mode='disable' --skip-trx='on' --mysql-ignore-errors='all' --time='1180' --report-interval='1' --histogram='on' --threads=1 oltp_read_only run --verbosity=5

分析

研发人员第一反应重启了Sysbench 所在的ECS 然后恢复了，但是也没有了现场，我告诉他们等有了现场通知我，不要重启。今天终于再次重现了，我连上ECS 速度看了几个指标，通过 top 看到Sysbench 进程占用CPU 400%(整个 ECS 是4核)，如图：

image-20240320173723799

再进一步看看 sys 都在干什么，用 perf top -p 16329 可以看到：

img

确实是内核态在网络里面有网络方面的函数占比很高，且 spin_lock 严重，所以速度用 ss -s 和 netstat -anto 看看网络连接情况：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
# ss -s
Total: 41682
TCP:   41498 (estab 5241, closed 1, orphaned 0, timewait 0)

Transport Total     IP        IPv6
RAW	  0         0         0
UDP	  8         5         3
TCP	  41497     41495     2     //用了几万个连接了，这不正常
INET	  41505     41500     5
FRAG	  0         0         0

# netstat -anto | head -30 //确实可以看到几万个连接，几乎都是 CLOSE_WAIT 状态
Active Internet connections (servers and established)
     注意第二列一直都是——79，Recv-Q的意思是3306端发给Sysbench的内容79字节，但这79自己还在 OS 的tcp buffer 中，等待Sysbench 读走
Proto Recv-Q Send-Q Local Address           Foreign Address         State       Timer
tcp       79      0 192.168.0.1:48743       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:32747       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:40838       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:40190       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:58337       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:23976       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:41687       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:57214       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:30464       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:2015        192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:16032       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:47188       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:3054        192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)
tcp       79      0 192.168.0.1:46344       192.168.20.220:3306     CLOSE_WAIT  off (0.00/0/0)

延伸：Recv-Q 和 netstat 定位性能案例可以看这篇

内核代码

前文通过 perf top 可以看到 __inet_check_established 这个函数占用非常高

不符合正常逻辑，github 内核源码地址(我只加了注释)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
//connect()时进行随机端口四元组可用性的判断
//如果本地地址和目标地址组成的元组之前已经存在了，则返回错误码EADDRNOTAVAIL: Cannot assign requested address
//这个时候即使设置了REUSEADDR也要报错
/* called with local bh disabled */
static int __inet_check_established(struct inet_timewait_death_row *death_row,
				    struct sock *sk, __u16 lport,
				    struct inet_timewait_sock **twp)
{
	struct inet_hashinfo *hinfo = death_row->hashinfo;
	struct inet_sock *inet = inet_sk(sk);
	__be32 daddr = inet->inet_rcv_saddr;
	__be32 saddr = inet->inet_daddr;
	int dif = sk->sk_bound_dev_if;
	struct net *net = sock_net(sk);
	int sdif = l3mdev_master_ifindex_by_index(net, dif);
	INET_ADDR_COOKIE(acookie, saddr, daddr);
	const __portpair ports = INET_COMBINED_PORTS(inet->inet_dport, lport);
	unsigned int hash = inet_ehashfn(net, daddr, lport,
					 saddr, inet->inet_dport);
	//inet_ehash_bucket存放ESTABLISHED状态的socket 哈希表
	struct inet_ehash_bucket *head = inet_ehash_bucket(hinfo, hash);
	spinlock_t *lock = inet_ehash_lockp(hinfo, hash);
	struct sock *sk2;
	const struct hlist_nulls_node *node;
	struct inet_timewait_sock *tw = NULL;

	spin_lock(lock);
	//遍历检查四元组是否冲突
	sk_nulls_for_each(sk2, node, &head->chain) {
		if (sk2->sk_hash != hash)
			continue;
		//INET_MATCH 执行四元组比较
		if (likely(INET_MATCH(sk2, net, acookie,
					 saddr, daddr, ports, dif, sdif))) {
			if (sk2->sk_state == TCP_TIME_WAIT) {
				tw = inet_twsk(sk2);
				if (twsk_unique(sk, sk2, twp))
					break;
			}
			goto not_unique;
		}
	}
	
	……
   
not_unique:
	spin_unlock(lock);
	return -EADDRNOTAVAIL;   //Cannot assign requested address错误，在510行看到了下一节 telnet/strace 中的错误信息


// #define	EADDRNOTAVAIL	227	/* Cannot assign requested address */

到这里可以很清楚说明问题在客户端而不是服务端，但是要回答：

  1. 为什么CPU这么高，CPU都在忙什么
  2. 什么原因会导致 CLOSE_WAIT 状态
  3. 为什么Sysbench 要疯狂创建4万多个连接；

所以接下来我们就来分别回答这三个问题

为什么CPU这么高，CPU都在忙什么

首先用 strace -p Sysbench-pid 看看 Sysbench 进程都在忙什么，下图最上面是 Sysbench 在疯狂不断地 connect：

image-20240320174806093

从上图最上面的Strace 来看 Sysbench在疯狂创建连接，但是在Connect 的时候报错：无法指定被请求的地址

那接下来我就要ping 一下 192.168.20.220 这个IP 是OK的，再然后telnet 192.168.20.220 22 发现没报错但是也没有 SSH 让我输密码，于是看了下 cat /proc/sys/net/ipv4/ip_local_port_range 是4万个Local Port 可用，这个时候可以去看看我这篇关于可用端口的经典文章

于是我改了下Port Range范围多加了1万Port 上去，然后很快看到如图 ss -s 就有5万连接了，说明你给多少Port 都不够用

同时我也用 telnet 192.168.20.220 3306 报错是：Cannot assign requested address —— 这个报错和 无法指定被请求的地址 很像了，到这里可以看到做一个基本结论：

  1. 之所以内核 sys CPU 跑高到 100%，是因为当Local Port 用完，又要新建连接的时候内核会用死循环去找可用端口，导致CPU 跑高（这也是为什么telnet 22端口不会报错，也不会正常出来SSH login——因为抢不到CPU 资源去走选端口的流程）
  2. Cannot assign requested address 和 无法指定被请求的地址 报错是找不到可用端口导致的，还没有走到三次握手，也就是和服务端无关

继续验证：

image-20240320180024067

上图是先把local port 增多，然后立即 telnet 3306 发现成功了！这更是证明了上面的结论2

到这里分析清楚了为什么CPU 高—— Sysbench疯狂建连接导致端口用完，内核要用死循环不断去找可用端口导致了CPU使用率高，因为是内核态的行为所以表现出来就是 sys CPU 100%

而telnet 22端口不报这个错，是因为 22端口的可用端口几万个没有被使用掉，但是22端口也没让我输密码，这里应该是telnet 22时抢不到CPU 造成TCP 三次握手缓慢，但绝对不会报 Cannot assign requested address 错误

什么原因会导致 CLOSE_WAIT 状态

在将这个问题前还是请先去看看 CLOSE_WAIT 代表了什么含义： 为什么这么多CLOSE_WAIT

当同事们看到几万个连接的时候第一反应就是能不能改改这两 Linux 的系统参数：tcp_tw_reuse, tcp_tw_recycle 让端口/连接快速回收？

有没有你们都是这种同事，看到一个现象条件反射得出这个结论，这都是略知皮毛的经验太多了导致的

我在 《为什么这么多CLOSE_WAIT》一文中反复提到这张图，以及学霸是怎么从这张图推断原因的：

image.png

看完上面这个图和我的 《为什么这么多CLOSE_WAIT》就应该知道 CLOSE_WAIT 就是 Sysbench 没有调 Socket.close 导致的 和内核没有关系，所以改啥内核参数也没有用，因为在这次问题中很多研发同学看到 CLOSE_WAIT 第一反应是去改这些参数：

1
2
net.ipv4.tcp_tw_recycle = 0
net.ipv4.tcp_tw_reuse = 0

如何进一步证明是Sysbench的问题呢？可以抓包看看：

image-20240320181258965上图是在 Sysbench 所在ECS 上抓包可以看到所有连接都是这样，注意第四个包是 Server端在3次握手成功后发了 Server Greeting 给客户端 Sysbench，此时Sysbench 应该发自己的账号密码来 Login但是抓包永远卡在这里，也就是Sysbench 建立完连接后跑了，不搭理服务端发了什么，这也是为什么最前面的 netstat -anto 看到 Recv-Q 这列总是79，这79长度的内容就是 Server 发给Sysbench 的 Server Greeting 内容，本该Sysbench 去读走 Server Greeting 然后按照MySQL 协议发账号密码，但是不，此时Sysbench 颠了，不管这个连接了，又去创建新连接于是重复上面的过程；直到本地端口用完，sys CPU 干到 100%

其实上面这个抓包的连接状态是 ESTABLISHED 状态，为什么最终看到的是 CLOSE_WAIT 呢，因为 Server发了 Server Greeting 后有一个超时时间，迟迟等不到Sysbench Client的账号密码就会发 FIN 给Client 端请求断开这个连接，导致Client断的连接状态从 ESTABLISHED 进入 CLOSE_WAIT ，这从上面的 TCP 状态图完全可以推导出来，扩大抓包时间的话会抓到 Server 发过来的 FIN 包

你要看不懂这个抓包，可以找个正常的MySQL-client 连 Server抓一次包，有个正常的对比会很幸福，我丢一个正常的给大家对比参考，上面错在 Sysbench 没有发如下红框的包：

img

Server 一重启就去看 netstat 的话确实都是 ESTABLISHED：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
# netstat -anto | head -30 |grep -E "State|:3306 "
Proto Recv-Q Send-Q Local Address           Foreign Address         State       Timer
tcp       78      0 192.168.0.1:46344       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:44592       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:45908       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:44166       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:59484       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:60720       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:53436       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:58690       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:35932       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:53944       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:59758       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:53676       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:59304       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:41848       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:44312       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:56654       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:3516        192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:39316       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:55074       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:59476       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)
tcp       78      0 192.168.0.1:48854       192.168.20.220:3306     ESTABLISHED off (0.00/0/0)

此时端口还够的时候去 strace 看到Sysbench 确实在疯狂 connect 建连接，也不像端口不够的时候会报错：

image-20240320184307103

到这里就可以回答：什么原因会导致 CLOSE_WAIT 状态？因为Sysbench 没有去正常 Login MySQL，MySQL-Server 等了 10 秒也没等到 Sysbenche login 就主动 close 了，而 Sysbench client 一直没有调 Socket.close 来关闭这个连接导致这个连接在 Sysbench 端一直是CLOSE_WAIT 且永久残留为 CLOSE_WAIT

为什么Sysbench 要疯狂创建4万多个连接

为什么Sysbench 要疯狂创建4万多个连接，且还在不停地创建，这就要涉及到 Sysbench 具体代码逻辑(这个版本的 Sysbench 被我厂同事魔改过) ，在一猛子扎进去看代码逻辑前，我换了个开源的 Sysbench 版本(Update 20240325 其实是换了个压测环境，用了不同的Sysbench而已)，问题就消失了 —— 有时候猛干不如取巧

到此可以说明问题的原因就是：这个 Sysbench 版本在连接异常断开(Server升级主动断开连接)后，新建连接逻辑错误，疯狂建连接引起的

Update 20240327

后来经过网友 扒皮哥和 haoqixu的耐心分析，发现这个问题不完是 Sysbench 本身代码的问题，Sysbench 依赖 libmysqlclient.so 包去连MySQL-Server 和处理MySQL 协议等，而这个 Bug 存在 libmysqlclient.so 中，准确来说是MariaDB的 libmysqlclient 中(和版本没关系，最新版还有这个问题)，如果换成MySQL Community的 libmysqlclient 就不存在这个问题了。划重点：无论你怎么更换 Sysbench 版本这个问题也无法解决

另外 MySQL 社区和 MariaDB 的 libmysqlclient 只是接口一样，实现完全可以不同，MariaDB 要求连接重连的时候先 close 再init 后才能使用，而MySQL 社区版本没有这个要求，所以改 Sysbench 重连的代码也可以 fix 这个问题

这个问题也有人怀疑过OS 的问题，比如换个OS 就好了，但我始终坚持是 Sysbench的问题，因为建连接后不读走TCP buffer里的内容都是业务层面的逻辑(相对于OS Sysbench和libmysqlclient 都是业务层)，所以这个错误肯定不在OS

但是很多人换了 OS 就正常了，其实这里不是你只换了 OS，而是换 OS 的时候你顺便把 libmysqlclient 也换了你自己都不知道，这就是我们常说的瞎蒙蒙对了，但是这种经验却是错误的

更换 libmysqlclient 来验证：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
yum remove  mariadb-devel -y //删掉 mariadb-devel 所带的 libmysqlclient 18
rpm -i https://dev.mysql.com/get/mysql80-community-release-el8-9.noarch.rpm
yum install mysql-community-devel -y //安装 mysql-community-deve ,会带上 libmysqlclient 21
./configure
make install

# 查看依赖
objdump -x /usr/local/bin/sysbench |grep libmysqlclient

  NEEDED               libmysqlclient.so.21
  required from libmysqlclient.so.21:
    0x03532d60 0x00 08 libmysqlclient_21.0
0000000000000000       F *UND*  0000000000000000              mysql_stmt_next_result@@libmysqlclient_21.0
0000000000000000       F *UND*  0000000000000000              mysql_errno@@libmysqlclient_21.0
... 省略若干
0000000000000000       F *UND*  0000000000000000              mysql_server_end@@libmysqlclient_21.0

自己编译 libmariadb.so

通过下载 mariadb-connector-c-3.3 源码，自己独立编译，新生成的 so 包不再导致CPU飙高，但是TPS 永远跌零，而通过yum 安装的是mariadb-connector-c-3.2.6

此时抓包，可以看到3.3 收到Server Greeting 后也不发送账号密码，但是直接 RST 了连接，这样使得连接被释放，占用端口被释放，CPU不会飙高，但是连接永远无法创建成功，TPS 永远跌零

1
2
3
4
5
6
7
mariadb-connector-c-3.3 抓包：
15100	Mar 27, 2024 17:07:53.422009421 CST	0.001052729	49548	3306	0	49548 → 3306 [SYN] Seq=0 Win=65495 Len=0 MSS=65495 SACK_PERM=1 TSval=1021766452 TSecr=0 WS=128
15101	Mar 27, 2024 17:07:53.422013946 CST	0.000004525	3306	49548	0	3306 → 49548 [SYN, ACK] Seq=0 Ack=1 Win=65483 Len=0 MSS=65495 SACK_PERM=1 TSval=1021766452 TSecr=1021766452 WS=128
15102	Mar 27, 2024 17:07:53.422018506 CST	0.000004560	49548	3306	0	49548 → 3306 [ACK] Seq=1 Ack=1 Win=65536 Len=0 TSval=1021766452 TSecr=1021766452
15103	Mar 27, 2024 17:07:53.422116125 CST	0.000097619	49548	3306	0	49548 → 3306 [FIN, ACK] Seq=1 Ack=1 Win=65536 Len=0 TSval=1021766452 TSecr=1021766452
15104	Mar 27, 2024 17:07:53.422146191 CST	0.000030066	3306	49548	77	Server Greeting proto=10 version=8.2.0 //Server Greeting
15105	Mar 27, 2024 17:07:53.422155229 CST	0.000009038	49548	3306	0	49548 → 3306 [RST] Seq=2 Win=0 Len=0

image-20240327171929387

此时：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
#ldd /usr/local/bin/sysbench
	linux-vdso.so.1 (0x00007ffc3a736000)
	libmariadb.so.3 => /lib64/libmariadb.so.3 (0x00007f3ce6352000)  
	libdl.so.2 => /lib64/libdl.so.2 (0x00007f3ce634b000)
	libm.so.6 => /lib64/libm.so.6 (0x00007f3ce6205000)
	libgcc_s.so.1 => /lib64/libgcc_s.so.1 (0x00007f3ce61ea000)
	libpthread.so.0 => /lib64/libpthread.so.0 (0x00007f3ce61c8000)
	libc.so.6 => /lib64/libc.so.6 (0x00007f3ce5fec000)
	libssl.so.1.1 => /lib64/libssl.so.1.1 (0x00007f3ce5f53000)
	libcrypto.so.1.1 => /lib64/libcrypto.so.1.1 (0x00007f3ce5c58000)
	/lib64/ld-linux-x86-64.so.2 (0x00007f3ce63f1000)
	libz.so.1 => /lib64/libz.so.1 (0x00007f3ce5c3e000)

#objdump -x /usr/local/bin/sysbench |grep libmysqlclient
    0x0f735338 0x00 04 libmysqlclient_18  
    
#rpm -q --whatprovides /lib64/libmariadb.so.3
mariadb-connector-c-3.2.6-1.al8.x86_64

#yum info mariadb-connector-c-3.2.6-1.al8.x86_64
上次元数据过期检查：0:23:09 前，执行于 2024年03月27日 星期三 16时53分17秒。
已安装的软件包
名称         : mariadb-connector-c
版本         : 3.2.6
发布         : 1.al8
架构         : x86_64
大小         : 545 k
源           : mariadb-connector-c-3.2.6-1.al8.src.rpm
仓库         : @System
来自仓库     : alinux3-updates
概况         : The MariaDB Native Client library (C driver)
URL          : http://mariadb.org/
协议         : LGPLv2+
描述         : The MariaDB Native Client library (C driver) is used to connect
             : applications developed in C/C++ to MariaDB and MySQL databases.

Sysbench 建连接堆栈，当端口不够的时候很容易抓到 connect 函数，因为connect 需要lookup 可用端口：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
#pstack 1448113
Thread 3 (Thread 0x7f9a0b23c640 (LWP 1448115)):
#0  0x00007f9a0b9722bb in connect () from /lib64/libpthread.so.0
#1  0x00007f9a0bb02b00 in pvio_socket_internal_connect (pvio=0x7f99fa5db270, name=0x7f99fc0247c0, namelen=16) at /root/mariadb-connector-c-3.2.6/plugins/pvio/pvio_socket.c:642
#2  0x00007f9a0bb02d76 in pvio_socket_connect_sync_or_async (pvio=0x7f99fa5db270, name=0x7f99fc0247c0, namelen=16) at /root/mariadb-connector-c-3.2.6/plugins/pvio/pvio_socket.c:750
#3  0x00007f9a0bb03499 in pvio_socket_connect (pvio=0x7f99fa5db270, cinfo=0x7f9a0b23b3d0) at /root/mariadb-connector-c-3.2.6/plugins/pvio/pvio_socket.c:919
#4  0x00007f9a0bb15277 in ma_pvio_connect (pvio=0x7f99fa5db270, cinfo=0x7f9a0b23b3d0) at /root/mariadb-connector-c-3.2.6/libmariadb/ma_pvio.c:484
#5  0x00007f9a0bb0b59c in mthd_my_real_connect (mysql=0x7f99fc01ff50, host=0x14e4110 "127.0.0.1", user=0x14e27c0 "root", passwd=0x14e40c0 "123", db=0x14e28f0 "test", port=3306, unix_socket=0x0, client_flag=65536) at /root/mariadb-connector-c-3.2.6/libmariadb/mariadb_lib.c:1462
#6  0x00007f9a0bb0affb in mysql_real_connect (mysql=0x7f99fc01ff50, host=0x14e4110 "127.0.0.1", user=0x14e27c0 "root", passwd=0x14e40c0 "123", db=0x14e28f0 "test", port=3306, unix_socket=0x0, client_flag=65536) at /root/mariadb-connector-c-3.2.6/libmariadb/mariadb_lib.c:1301
#7  0x000000000041b5d0 in mysql_drv_real_connect (db_mysql_con=0x7f99fc01fbf0) at drv_mysql.c:405
#8  0x000000000041cc6c in mysql_drv_reconnect (sb_con=0x0) at drv_mysql.c:815
#9  check_error (sb_con=sb_con@entry=0x7f99fc0210a0, func=func@entry=0x486637 "mysql_drv_query()", query=query@entry=0x7f99fc0207f0 "SELECT c FROM sbtest16 WHERE id=5031", counter=counter@entry=0x7f99fc0210c8) at drv_mysql.c:894
#10 0x000000000041d1d1 in mysql_drv_query (rs=0x7f99fc0210c8, len=<optimized out>, query=0x7f99fc0207f0 "SELECT c FROM sbtest16 WHERE id=5031", sb_conn=<optimized out>) at drv_mysql.c:1071
#11 mysql_drv_query (rs=0x7f99fc0210c8, len=<optimized out>, query=0x7f99fc0207f0 "SELECT c FROM sbtest16 WHERE id=5031", sb_conn=<optimized out>) at drv_mysql.c:1051
#12 mysql_drv_execute (stmt=<optimized out>, rs=<optimized out>) at drv_mysql.c:1040
#13 0x000000000040f32a in db_execute (stmt=0x7f99fc021270) at db_driver.c:517

修复

改下Sysbench 代码 ./src/drivers/mysql/drv_mysql.c 加一行就可以解决这个问题：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
static int mysql_drv_reconnect(db_conn_t *sb_con)
{
  db_mysql_conn_t *db_mysql_con = (db_mysql_conn_t *) sb_con->ptr;
  MYSQL *con = db_mysql_con->mysql;

  log_text(LOG_DEBUG, "Reconnecting zhejian");

  DEBUG("mysql_close(%p)", con);
  mysql_close(con);
  mysql_init(con); //add by ren

//这个死循环在反复创建新连接用光 port range
  while (mysql_drv_real_connect(db_mysql_con))
  {
    if (sb_globals.error)
      return DB_ERROR_FATAL;

    usleep(1000); 
  }

  log_text(LOG_DEBUG, "Reconnected");

  return DB_ERROR_IGNORABLE;
}

重现

只有sysbench 编译时依赖 libmariadb.so 才会有问题

1
2
3
4
5
#ldd /usr/local/bin/sysbench
	linux-vdso.so.1 (0x00007ffee0f93000)
	libmariadb.so.3 => /lib64/libmariadb.so.3 (0x00007fecb3f9d000)
	
yum install  mariadb-devel

卸载掉 mysql-devel 重新安装 mariadb-devel, 再编译 sysbench

sysbench 源码下载：https://github.com/akopytov/sysbench

总结

问题结论：mariadb 的 connect lib库对 libmysql 接口实现得有问题，当连接异常断开后会进入死循环疯狂创建连接导致了这个问题

这里涉及很多技巧：top/ss -s/strace/netstat/telnet 以及很多基础知识 local port range/ CLOSE_WAIT ，会折腾很重要，折腾的前提是会解锁各种姿势

难的是如何恰到好处地应用这些技巧和正确应用这些知识，剩下的分析推进就很符合逻辑了

另外我之前强调的在一个错误面前反复折腾不断缩小范围的能力也很重要，比如换个版本确认总比你看代码快吧

从这篇文章可以看出我真是个好教练，一次故障诊断涉及2-3个知识点，3-5个小命令，2-4次逻辑推断，最后完美定位问题，把各个知识的解读、各种命令的灵活使用展现的淋漓尽致。

接下来就是如何在我们的统一实验 ECS 上重现这个问题并保证让大家跟着实际操作

其实开始的时候问题没有这么清晰，每次升级才能稳定重现，后来想要定位问题就必须降低重现难度，考虑到重启客户端ECS 就能恢复，于是：

  • 不再重启ECS，只重启 Sysbench —— 能恢复
  • 不真正升级只重启Server —— 问题能稳定重现，重现容易很多了
  • 不重启 Server，只是kill掉Sysbench 的一条连接 —— 能重现
  • 将Sysbench 连接数从最开始100个，改成2个压 Server，然后 kill 掉 Sysbench 的一条连接 —— 能重现

到最后稳定重现方案就是 Sysbench 用两个连接压 Server，然后到 Server 上随便kill 掉其中一条连接，这个问题能稳定重现；重现后重启Sysbench 就能稳定恢复

参考资料

一个类似的bug 和 https://bugs.mysql.com/bug.php?id=88428

内核笔记

分人分析得再好也是别人的，自己积累的一点点终究是自己的；端口不够的时候CPU 拉高我之前碰到过，所以在内核的代码里写了点笔记，这次Sysbench 问题又碰到了，所以正好看到我上次的笔记：https://github.com/plantegg/linux/blob/3157b476f8216d2655c1c85bad53c975190689ba/net/ipv4/inet_hashtables.c#L447

我的意思是可以拉个Linux 内核较新的代码分支，自己随便哪天学到点啥在上面注释一下，commit，时间久了慢慢就串起来了，如下图错误码和strace 看到的错误信息就是一致的

直播总结：

关于可用端口一文，搞懂这个概念(到底有多少可用端口)只是开始；还需要借助案例去理解；天杀的Google 把端口分为奇偶数两部分，简直是神助攻，给了我们无穷Case 来加深端口不够时候系统什么表现的映像；今天直播的案例是端口全不够了，这种非常明显的异常更好发现；如果端口还够只是偶数用完了，但每次都要扫描一遍偶数，发现偶数没有可用端口再去扫描奇数就能找到可用端口，这导致的是每次可能有点卡顿，但是又不报错，因为过于隐晦这在业务层面带来的危害更加大

同样是学TCP状态流转(ESTABLISHED TIME_WAIT CLOSE_WAIT )，有人看一次就能推理，但大多数都是普通人，看过了还瞎猜，不管啥都想的是 tcp_reuse/tcp_recycle，还处在使劲蒙的状态

ping/telnet/strace/tcpdump 几乎都会用，但是如何恰到好处地去用，报错是什么状态、没任何输出是什么状态

然后就是过程分析中的一些推理。先从最根本的现象QPS 跌0开始撸

三个版本：

不同的 libmysqlclient 版本 现象
yum install mariadb-devel (libmariadb.so 3.2.6) 永远跌零，耗尽端口、CPU高
手工编译 mariadb-connector-c-3.3(libmariadb.so 3.3) 永远跌零，但是不费端口、不耗CPU
yum install MySQL-devel（libmysqlclient 哪个版本都行） 正常

手工编译 libmariadb.so 后 CPU 不飙高，但是TPS 一直跌0，也会疯狂重建连接(每1ms 去建一次连接), 还是没处理对，不过会reset 连接释放端口

如果一个分析推理要求很高的逻辑能力(or 智商)，那复制性就不强，没有太大的学习价值(主要是学不会)，我们尽量多去学1+1=2这样的逻辑推理，时间久了你就会了1+2=3

真正的高手肯定不只是流于表象：

  1. 啊，连不上了
  2. 啊，服务器有问题
  3. 啊，CPU高
  4. 啊，too many Connection

天翼云老哥一年前也发现了这个问题并给了解决办法，但是阅读量只有55 https://www.ctyun.cn/developer/article/405333884604485 ——文章过于简单，如果去学习的话只能看到一个结论

进一步总结

如果3306 端口被防火墙drop，那么：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
[root@plantegg 11:25 /root]
#mysql -h127.0.0.1 --ssl-mode=DISABLED -uroot -p123 test
mysql: [Warning] Using a password on the command line interface can be insecure.

…… 卡着，不报错


strace 看到是这样：
futex(0x55b99f129518, FUTEX_WAKE_PRIVATE, 2147483647) = 0
getpid()                                = 1511313
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(3306), sin_addr=inet_addr("127.0.0.1")}, 16

一直卡在这里

Too many connections

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
getpid()                                = 1515762
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(3306), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
setsockopt(3, SOL_TCP, TCP_NODELAY, [1], 4) = 0
setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
recvfrom(3, "\27\0\0\0\377\20\4Too many connections", 16384, 0, NULL, NULL) = 27
shutdown(3, SHUT_RDWR)                  = 0
close(3)                                = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0), ...}) = 0
write(2, "ERROR 1040 (HY000): ", 20ERROR 1040 (HY000): )    = 20
write(2, "Too many connections", 20Too many connections)    = 20

#mysql -h127.0.0.1 --ssl-mode=DISABLED -uroot -p123 test
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1040 (HY000): Too many connections

用完端口后：
getpid()                                = 1515928
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(3306), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EADDRNOTAVAIL (Cannot assign requested address)
shutdown(3, SHUT_RDWR)                  = -1 ENOTCONN (Transport endpoint is not connected)
close(3)                                = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0), ...}) = 0
write(2, "ERROR 2003 (HY000): ", 20ERROR 2003 (HY000): )    = 20
write(2, "Can't connect to MySQL server on"..., 54Can't connect to MySQL server on '127.0.0.1:3306' (99)) = 54
write(2, "\n", 1
)                       = 1
write(1, "\7", 1)                       = 1
#mysql -h127.0.0.1 --ssl-mode=DISABLED -uroot -p123 test
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 2003 (HY000): Can't connect to MySQL server on '127.0.0.1:3306' (99)

如果是服务端3306 没起：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(3306), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 ECONNREFUSED (Connection refused)
shutdown(3, SHUT_RDWR)                  = -1 ENOTCONN (Transport endpoint is not connected)
close(3)                                = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0), ...}) = 0
write(2, "ERROR 2003 (HY000): ", 20ERROR 2003 (HY000): )    = 20
write(2, "Can't connect to MySQL server on"..., 55Can't connect to MySQL server on '127.0.0.1:3306' (111)) = 55
write(2, "\n", 1
)                       = 1
write(1, "\7", 1)                       = 1
rt_sigaction(SIGQUIT, {sa_handler=SIG_IGN, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f20ab9f0a60}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_IGN, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f20ab9f0a60}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGHUP, {sa_handler=SIG_IGN, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f20ab9f0a60}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
exit_group(1)                           = ?
+++ exited with 1 +++

[root@plantegg 11:54 /root]
#mysql --show-warnings=FALSE -h127.0.0.1 --ssl-mode=DISABLED -uroot -p123 test
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 2003 (HY000): Can't connect to MySQL server on '127.0.0.1:3306' (111)

账号密码权限错误

1
2
#mysql --show-warnings=FALSE -h127.0.0.1 --ssl-mode=DISABLED -uroot -p1234 test
ERROR 1045 (28000): Access denied for user 'root'@'127.0.0.1' (using password: YES)

telnet

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
//正常telnet ，能看到 Greeting以及输密码信息
#telnet 127.0.0.1 3306
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
I
8.2.0�#[6Y
          @+5=,mi?%#caching_sha2_password^]

//当MySQL-Server 的连接数不够了时
#telnet 127.0.0.1 3306
Trying 127.0.0.1...
Connected to 127.0.0.1.
Escape character is '^]'.
Too many connectionsConnection closed by foreign host.

//当客户端本地可用端口不够，三次握手还没开始
#telnet 127.0.0.1 3306
Trying 127.0.0.1...
telnet: connect to address 127.0.0.1: Cannot assign requested address

99 VS 111

在MySQL错误信息中，ERROR 2003 (HY000)是一个通用的连接失败错误。错误之后的括号中的数字代表的是系统级别的错误码，与MySQL本身的错误代码不同，它们来自于操作系统，表示尝试建立网络连接时遇到了错误。错误码99 和 111 具体代表以下含义：

  • (99)：这个错误码通常与网络配置相关。在大多数情况下，这个错误产生于Linux系统，并对应于EADDRNOTAVAIL错误，意义是”Cannot assign requested address”。当尝试绑定到无法分配的本地地址时，就会遇到这个错误。在尝试连接到MySQL服务器时，如果客户端使用了一个不存在的网络接口，例如，错误配置的TCP端口或地址，就有可能产生这个错误。
  • (111)：这个错误码同样在Linux系统中更常见，对应于ECONNREFUSED错误，意义是”Connection refused”。当连接请求被远程主机或中间网络设施（如防火墙）明确拒绝时，就会遇到这个错误。在MySQL的上下文中，(111)错误可能表明MySQL服务没有在指定地址或端口上运行，或是防火墙设置阻止了连接。这也可能表明MySQL配置中的bind-address参数错误，设置为了仅允许本地连接。

解决错误99通常需要确保客户端是在向正确配置的地址发起连接，而解决错误111则可能需要检查MySQL服务是否运行、防火墙的设置以及my.cnf或my.ini中bind-address参数的配置。

image-20240328122311991

抓包解读

服务端主动断开

如下图是出问题的其中一次抓包，我们可以通过这个抓包来详细解析问题出在哪里。这是Sysbench(38692端口) 主动连MySQL Server(3306 端口)，3次TCP 握手正常后Server 发送了 Server Greeting(截图中第四个包)，然后Sysbench所在的Linux OS 38692端口回复了ack(这个ack 动作不需要Sysbench参与，完全由OS 来处理)，这个时候 Sysbench应该读走这个 Server Greeting包并按MySQL 协议发送客户端账号密码，但是没有，过了10秒钟后(图中绿框) Server 再次发送了 1159 错误也就是图中红框，1159表示 Server等了10秒钟也没等到Client的账号密码，于是超时报错

image-20240407103809182

客户端非正常主动断开

如下图，Server 端回复了 Greeting，本该JDBC Client 发起 login 流程，但是因为这里Server 是 8.0，但是 JDBC Driver 用的5.7 导致兼容性问题，Client 主动断开了

image-20240704084229482

这是 Server 认为通信异常，于是返回：Error message: Got an error reading communication packets 即1158 报错

延伸

类似的分析手段，解决其他问题

体验抓包分析，的确……很快就找到了问题点。local_infile=0 时，libmariadb 会在 login 包中设置标志位为 0，但是 libmysqlclient 仍然是 1，这是诡异点1。Server DB产品 在标志位为 0 时会报登录信息错误，这是诡异点2。

image-20240403144037002

这条研发人员根据重现的抓包很快定位到了是Server DB产品的Bug，简单来说 Server DB产品对MySQL 协议实现得不好，如图的flag设置为0的话就会被当成 MySQL ping 协议来处理，感叹下还是抓包好使，要不还得去看账号权限啥的

换个MySQL Client 就糊弄过去了；

但是如果去分析就能发现就那一个bit的差异，一定是Server 导致了问题，Server研发在铁的证据面前快速定位是产品bug，但是你如果不会抓包分析，一看报错是账号、权限错误就寄了——程序员对别人说的一个字都不要信，只信自己看到的

再回想想我们平时放弃的那些问题、那些撕逼撕不清楚的锅等等

参考资料

sysbench benchmark MySQL 时候，为什么 kill 连接后，sysbench 没有重连 https://exfly.github.io/why-sysbench-dont-reconnect-after-kill/

LittleFatz：https://www.wolai.com/3cXBGNzWkW7oqKJQ5VKM3X

WindSoilde*：https://articles.zsxq.com/id_9a8b4f87zv6l.html

@邹扒皮.com：https://articles.zsxq.com/id_d27pgzmhuq08.html 最佳作业

最终问题的修复也有星球成员提交给社区并被合并了：https://github.com/akopytov/sysbench/pull/528/files

如果你觉得看完对你很有帮助可以通过如下方式找到我

find me on twitter: @plantegg

知识星球：https://t.zsxq.com/0cSFEUh2J

开了一个星球，在里面讲解一些案例、知识、学习方法，肯定没法让大家称为顶尖程序员(我自己都不是)，只是希望用我的方法、知识、经验、案例作为你的垫脚石，帮助你快速、早日成为一个基本合格的程序员。

争取在星球内：

  • 养成基本动手能力
  • 拥有起码的分析推理能力–按我接触的程序员，大多都是没有逻辑的
  • 知识上教会你几个关键的知识点
image-20240324161113874

发表于 更新于 分类于

历时5年的net_write_timeout 报错分析

全网关于 JDBC 报错：net_write_timeout 的最好/最全总结

前言

上一次为了讲如何分析几百万个抓包，所以把这个问题中的一部分简化写了这篇抓包篇：https://articles.zsxq.com/id_lznw3w4zieuc.html 建议你先去看看把场景简化下，然后本篇中的分析涉及抓包部分就不再啰嗦讲解，请看抓包篇

问题描述

用户为了做数据分析需要把160个DB中的数据迁移到另外一个只读库中，有专门的迁移工具，但是这个迁移工具跑一阵后总是报错，报错堆栈显示是Tomcat 到DB之间的连接出了异常：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Application was streaming results when the connection failed. Consider raising value of 'net_write_timeout' on the server.
    at sun.reflect.GeneratedConstructorAccessor150.newInstance(Unknown Source)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:989)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3749)
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3649)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4090)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:972)
    at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:2123)
    at com.mysql.jdbc.RowDataDynamic.nextRecord(RowDataDynamic.java:374)
    at com.mysql.jdbc.RowDataDynamic.next(RowDataDynamic.java:354)
    at com.mysql.jdbc.RowDataDynamic.close(RowDataDynamic.java:155)
    at com.mysql.jdbc.ResultSetImpl.realClose(ResultSetImpl.java:6726)
    at com.mysql.jdbc.ResultSetImpl.close(ResultSetImpl.java:865)
    at com.alibaba.druid.pool.DruidPooledResultSet.close(DruidPooledResultSet.java:86)

这个异常堆栈告诉我们Tomcat 到Database之间的连接异常了，似乎是 net_write_timeout 超时导致的

对应业务结构：

image-20230706210452742

net_write_timeout 原理简介

先看下 net_write_timeout的解释：

The number of seconds to wait for a block to be written to a connection before aborting the write. 只针对执行查询中的等待超时，网络不好，tcp buffer满了（应用迟迟不读走数据）等容易导致mysql server端报net_write_timeout错误，指的是mysql server hang在那里长时间无法发送查询结果。

报这个错就是DB 等了net_write_timeout这么久没写数据，可能是Tomcat 端卡死没有读走数据。

但是根据我多年来和这个报错打交道的经验告诉我：这个报错不只是因为net_write_timeout 超时导致的，任何Tomcat 到 DB间的连接断开了，都报这个错误，原因是JDBC 驱动搞不清楚断开的具体原因，统统当 net_write_timeout 了

一定要记住这个原理。如果这里不理解可以进一步阅读：https://wx.zsxq.com/dweb2/index/topic_detail/412251415855228

分析

首先把Tomcat 集群从负载均衡上摘一个下来，这样没有业务流量干扰更利于测试和分析日志

然后让迁移数据工具直接连这个没有流量的节点，问题仍然稳定重现。

进一步提取迁移工具的SQL，然后走API手工提交给Tomcat 执行，问题仍然稳定重现，现在重现越来越简单了，效率高多了。

Tomcat 上抓包

因为没有业务流量干扰，抓包很干净，但是因为DB 节点太多，所以量还是很大的，分析如抓包篇：https://articles.zsxq.com/id_lznw3w4zieuc.html

如下图红框所示的地方可以看到MySQL Server 传着传着居然带了个 fin 包在里面，表示MySQL Server要断开连接了，无奈Client只能也发送quit 断开连接。红框告诉我们一个无比有力的证据MySQL Server 在不应该断开的地方断开了连接，问题在 MySQL Server 端

image-20230620141017987

看起来是Database 主动端开了连接，因为这个过程Tomcat 不需要发任何东西给 Database。这个现象5年前在其它用户场景下就抓到过了，最后问题也不了了之，这次希望搞清楚

Database 分析

打开 DB 日志，捞取全量日志可以看到 DB 断开的原因是收到了kill Query！

有这个结果记住上面抓包图，以后类似这样莫名起来 DB 主动断开大概率就是 kill Query 导致的(经验攒得不容易！)

Database 抓包

确实能抓到kill，而且从用户账号来看就是从 Tomcat 发过去的！

继续分析Tomcat 抓包

从 DB 分析来看还是有人主动 kill 导致的，所以继续分析Tomcat的抓包看是不是因为代码bug导致Tomcat 发了kill 给DB

大海捞针，搜 kill，找Tomcat 发给DB的tcp length 长度是16-20的(刚好容纳kill id) 总的来说就是找不到，很神奇

由于 DB上记录的 Tomcat IP、port 都被中间链路转换过几次了，根本没办法一一对应搞清楚是哪个Tomcat 节点发出来的

继续尝试重现

分析完Tomcat 业务代码后感觉业务不会去kill，于是灵机一动在没有流量的Tomcat上跑了一个Sleep 600秒，不用任何数据，神奇的问题也稳定重现了，这下大概知道什么原因了，肯定是客户自己加了慢查询监控逻辑，一旦发现慢查询就 kill

于是问客户是不是有这种监控，果然有，停掉后反复重试不再有问题！

测试环境手工触发kill，然后能抓到下发的kill Query 给Database

image-20230707150658392

未解谜题

为什么没在Tomcat 抓到发给Database的 kill ？

我反复去重现了，如果是我手工触发Tomcat kill是可以清晰地抓到Tomcat 会发160个kill 给Database，但是我任其自然等待用户监控来杀就一定抓不到kill 下发给DB

我猜和 Tomcat 集群有关，首先用户监控是走的LVS，通过其中一个Tomcat 可以查询到所有 Tomcat 上的请求，然后发起 kill

但因为节点太多无法证实！当然业务监控也可以监控DB 然后直接发kill，但是和抓包看到的发起kill的用户不对，发起 kill 的用户是Tomcat独一无二的。

JDBC驱动报错 net_write_timeout 结论

Application was streaming results when the connection failed. Consider raising value of ‘net_write_timeout’ on the server. - com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Application was streaming results when the connection failed. Consider raising value of ‘net_write_timeout’ on the server.

这个报错不一定是 net_write_timeout 设置过小导致的，JDBC 在 streaming 流模式下只要连接异常就会报如上错误，比如：

  • 连接被 TCP reset
  • RDS 前端自带的Proxy 主动断开连接
  • 连接因为某种原因(比如 QueryTimeOut) 触发 kill Query导致连接中断
  • RDS 端因为kill 主动断开连接 //比如用户监控RDS、DRDS脚本杀掉慢查询

net_write_timeout：表示这么长时间RDS/DN 无法写数据到网络层发给DRDS/CN，原因是DRDS/CN 长时间没将数据读走

总结

首先一个错误现象对应多个完全不一样的错误原因是非常头疼的，这个问题反反复复在多个场景下出现，当然原因各异，但是这个传数据途中 DB 主动 fin连接还是第一次碰到并搞清楚，同样主动 fin 不一定是kill，但是我们要依照证据推进问题，既然是DB fin就有必要先从DB 来看原因。

从这个问题你可以先从什么是JDBC 流模式出发(mysql –quick 就是流模式，你可以快速查一个大数据试试；然后去掉–quick 对比一下)，结合网络buffer 来了解流模式：https://plantegg.github.io/2020/07/03/MySQL%20JDBC%20StreamResult%20%E5%92%8C%20net_write_timeout/

然后从流模式来学习MySQL 的 net_write_timeout，假如你的代码报了 net_write_timeout 你会分析吗？

最后从连接断开去总结，比如网络不好、比如内核bug、比如DB crash、比如 kill、比如……都会导致连接断开，但这一切对业务来说只有 net_write_timeout 一个现象

这个问题分享出来是因为非常综合，我惊抱怨 socketTimeout、Communication failure等异常，这些异常也挺常见导致的原因多种，但是和 net_write_timeout 比起来还是不如 net_write_timeout 更综合，所以分享给大家，建议这几篇一起阅读效果最好！

实验模拟 Consider raising value of ‘net_write_timeout’

使用 Java MySQL JDBC Driver 的同学经常碰到如下错误堆栈，到底这个错误是 net_write_timeout 设置太小还是别的原因也会导致这个问题？需要我们用实验验证一下： 

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Application was streaming results when the connection failed. Consider raising value of 'net_write_timeout' on the server.
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:500)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:481)
	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
	at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3559)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3459)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3900)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:873)
	at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1996)
	at com.mysql.jdbc.RowDataDynamic.nextRecord(RowDataDynamic.java:374)
	at com.mysql.jdbc.RowDataDynamic.next(RowDataDynamic.java:354)
	at com.mysql.jdbc.ResultSetImpl.next(ResultSetImpl.java:6312)
	at Test.main(Test.java:38)
Caused by: java.io.EOFException: Can not read response from server. Expected to read 8 bytes, read 3 bytes before connection was unexpectedly lost.
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3011)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3519)
	... 8 more

JDBC 驱动对这个错误有如下提示(坑人)：

Application was streaming results when the connection failed. Consider raising value of ‘net_write_timeout’ on the server. - com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Application was streaming results when the connection failed. Consider raising value of ‘net_write_timeout’ on the server.

实验中的一些说明：

  1. netTimeoutForStreamingResults=1 表示设置 net_write_timeout 为 1 秒，客户端会发送 set net_write_timeout=1 给数据库
  2. conn.setAutoCommit(false); //流式读取必须要 关闭自动提交
  3. stmt.setFetchSize(Integer.MIN_VALUE);

以上 2/3是触发流式读取的必要条件，第一条不设置默认是 600 秒，比较难等 :)

如果确实是 net_write_timeout 太小超时了, RDS 直接发 fin（但是 fin 前面还有一堆 response 包也在排队），然后 RDS 日志先报错：

1
2024-11-28T14:33:03.447397Z 12 [Note] Aborted connection 12 to db: 'test' user: 'root' host: '172.26.137.130' (Got timeout writing communication packets)

此时客户端还慢悠悠地读，RDS 没有回任何错误信息给客户端，客户端读完所有 Response 然后直接读到连接断开就报 Consider raising value of ‘net_write_timeout’ on the server 了，如果客户端读的慢，比如要 10 分钟实际连接在 RDS 上 10 分钟前就进入 fin 了，但是 10 分钟后客户端才报错

1
2
3
4
5
6
7
8
9
10
#netstat -anto | grep "3307"
tcp6       0      0 :::3307                 :::*                    LISTEN      off (0.00/0/0)
tcp6       0 140192 172.26.137.120:3307     172.26.137.130:51216    ESTABLISHED probe (0.04/0/0)
2024年 11月 28日 星期四 15:01:43 CST

//1秒中后此时 数据库感知到超时于是调用 close 断开连接，触发发送 fin给客户端，但是 fin 也需要排队，所以 140192增加了 1 变成140193
tcp6       0      0 :::3307                 :::*                    LISTEN      off (0.00/0/0)
tcp6       0 140193 172.26.137.120:3307     172.26.137.130:51216    FIN_WAIT1   probe (0.58/0/1)
2024年 11月 28日 星期四 15:01:44 CST

重现代码，数据库上构造一个大表，比如 10万行就行，能堆满默认的 tcp buffer size：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.sql.Statement;
import java.sql.PreparedStatement;

/*
 * 编译：
 *  javac -cp /root/java/*:. Test.java
 *  运行：
 *   java -cp .:./mysql-connector-java-5.1.45.jar Test "jdbc:mysql://gf1:3307/test?useSSL=false&useServerPrepStmts=true&cachePrepStmts=true&connectTimeout=500&socketTimeout=1700&netTimeoutForStreamingResults=1" root 123 "select *, id from streaming " 3000
 * netTimeoutForStreamingResults=1 表示RDS 等超过 1 秒都因为 tcp buffer 满无法继续发送数据就断开连接
 *   */
public class Test {
    private static String url;
    private Str name;

    public static void main(String args[]) throws NumberFormatException, InterruptedException, ClassNotFoundException {
        Class.forName("com.mysql.jdbc.Driver");
        url = args[0];
        String user = args[1];
        String pass = args[2];
        String sql = args[3];
        String interval = args[4];
        try {
            Connection conn = DriverManager.getConnection(url, user, pass);
            while (true) {

								conn.setAutoCommit(false);
								Statement stmt = conn.createStatement();
								stmt.setFetchSize(Integer.MIN_VALUE);

                long start = System.currentTimeMillis();
                ResultSet rs = stmt.executeQuery(sql);
                int count=0;
                while (rs.next()) {
                  System.out.println("id:"+rs.getInt("id")+" count:"+count);
                  count++;
                  if(count<3) //1 秒后数据库端连接就已经关闭了，但是因为客户端读得慢，需要不 sleep 后才能读到 fin 然后报错，所以报错可以比实际晚很久
                		Thread.sleep(1500);
								}
                rs.close();
                stmt.close();
                Thread.sleep(Long.valueOf(interval));
									break;
            }
	    			conn.close();
        } catch (SQLException e) {
            e.printStackTrace();
        }
    }
}

Consider raising value of ‘net_write_timeout’ 这个报错数据库端不会返回任何错误码给客户端，只是发 fin 断开连接，对客户端来说这条连接是 net_write_timeout 超时了 还是 被kill(或者其他原因) 是没法区分的，所以不管什么原因，只要连接异常 MySQL JDBC Driver 就抛 net_write_timeout 错误

如图，3 秒钟后 fin 包混在数据库 response 就被发到了客户端，实际2 秒前数据库已经报错了，也就是客户端和数据库端报错时间会差 2 秒(具体差几秒取决于重现代码里 sleep 多久然后-1)

image-20241128151324385

实验总结

这个报错不一定是 net_write_timeout 设置过小导致的，JDBC 在 streaming 流模式下只要连接异常就会报如上错误，比如：

  • 连接被 TCP reset
  • RDS 前端自带的Proxy 主动断开连接
  • 连接因为某种原因(比如 QueryTimeOut) 触发 kill Query导致连接中断
  • RDS 端因为kill 主动断开连接 //比如用户监控RDS 脚本杀掉慢查询
  • 开启流式读取后，只要客户端在读取查询结果没有结束就读到了 fin 包就会报这个错误

可以将 netTimeoutForStreamingResults 设为 0 或者 100，然后在中途 kill 掉 MySQL 上的 SQL，你也会在客户端看到同样的错误, kill SQL 是在 MySQL 的报错日志中都是同样的：

1
2024-11-28T07:33:12.967012Z 23 [Note] Aborted connection 23 to db: 'test' user: 'root' host: '172.26.137.130' (Got an error writing communication packets)

所以你看一旦客户端出现这个异常堆栈，除了抓包似乎没什么好办法，其实抓包也只能抓到数据库主动发了 fin 什么原因还是不知道，我恨这个没有错误码一统江湖的报错

net_write_timeout 后 RDS 直接发 fin（有时 fin 前面还有一堆 response 包也在排队），然后 rds 日志先报错：2024-11-28T06:33:03.447397Z 12 [Note] Aborted connection 12 to db: ‘test’ user: ‘root’ host: ‘172.26.137.130’ (Got timeout writing communication packets)

客户端慢悠悠地读，RDS 没有传任何错误信息给客户端，客户端读完所有 response 然后直接读到连接断开就报 Consider raising value of ‘net_write_timeout’ on the server 了，如果客户端读的慢，比如要 10 分钟实际连接在 RDS 上 10 分钟前就进入 fin 了，但是 10 分钟后客户端才报错

进阶阅读：https://plantegg.github.io/2024/09/25/%E4%B8%80%E4%B8%AA%E5%8E%86%E6%97%B65%E5%B9%B4%E7%9A%84%E9%97%AE%E9%A2%98%E5%88%86%E6%9E%90/ 和 https://x.com/plantegg/status/1867535551337050153

发表于 更新于 分类于

长连接黑洞重现和分析

这是一个存在多年，遍及各个不同的业务又反反复复地在集团内部出现的一个问题，本文先通过重现展示这个问题，然后从业务、数据库、OS等不同的角度来分析如何解决它，这个问题值得每一位研发同学重视起来，避免再次踩到

背景

为了高效率应对故障，本文尝试回答如下一些问题：

  • 为什么数据库crash 重启恢复后，业务还长时间不能恢复？
  • 我依赖的业务做了高可用切换，但是我的业务长时间报错
  • 我依赖的服务下掉了一个节点，为什么我的业务长时间报错
  • 客户做变配，升级云服务节点规格，为什么会导致客户业务长时间报错

目的：希望通过这篇文章尽可能地减少故障时长、让业务快速从故障中恢复

重现

空说无凭，先也通过一次真实的重现来展示这个问题

LVS+MySQL 高可用切换

OS 默认配置参数

1
2
3
4
5
6
#sysctl -a |grep -E "tcp_retries|keepalive"
net.ipv4.tcp_keepalive_intvl = 30
net.ipv4.tcp_keepalive_probes = 5
net.ipv4.tcp_keepalive_time = 10
net.ipv4.tcp_retries1 = 3
net.ipv4.tcp_retries2 = 15  //主要是这个参数，默认以及alios 几乎都是15

LVS 对外服务端口是3001， 后面挂的是 3307，假设3307是当前的Master，Slave是 3306，当检测到3307异常后会从LVS 上摘掉 3307挂上 3306做高可用切换

undefined

切换前的 LVS 状态

1
2
3
4
5
6
7
8
#ipvsadm -L --timeout
Timeout (tcp tcpfin udp): 900 120 300
#ipvsadm -L -n
IP Virtual Server version 1.2.1 (size=4096)
Prot LocalAddress:Port Scheduler Flags
  -> RemoteAddress:Port           Forward Weight ActiveConn InActConn
TCP  127.0.0.1:3001 rr
  -> 127.0.0.1:3307               Masq    1      0          0

Sysbench启动压力模拟用户访问，在 31秒的时候模拟管控检测到 3307的Master无法访问，所以管控执行切主把 3306的Slave 提升为新的 Master，同时到 LVS 摘掉 3307，挂上3306，此时管控端着冰可乐、翘着二郎腿，得意地说，你就看吧我们管控牛逼不、我们的高可用牛逼不，这一套行云流水3秒钟不到全搞定

切换命令如下：

1
2
#cat del3307.sh
ipvsadm -d -t  127.0.0.1:3001 -r 127.0.0.1:3307 ; ipvsadm -a -t  127.0.0.1:3001 -r 127.0.0.1:3306 -m

此时Sysbench运行状态，在第 32秒如期跌0：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
#/usr/local/bin/sysbench --debug=on --mysql-user='root' --mysql-password='123' --mysql-db='test' --mysql-host='127.0.0.1' --mysql-port='3001' --tables='16'  --table-size='10000' --range-size='5' --db-ps-mode='disable' --skip-trx='on' --mysql-ignore-errors='all' --time='11080' --report-interval='1' --histogram='on' --threads=1 oltp_read_write run
sysbench 1.1.0 (using bundled LuaJIT 2.1.0-beta3)

Running the test with following options:
Number of threads: 1
Report intermediate results every 1 second(s)
Debug mode enabled.

Initializing random number generator from current time


Initializing worker threads...

DEBUG: Worker thread (#0) started
DEBUG: Reporting thread started
DEBUG: Worker thread (#0) initialized
Threads started!

[ 1s ] thds: 1 tps: 51.89 qps: 947.00 (r/w/o: 739.44/207.56/0.00) lat (ms,95%): 35.59 err/s 0.00 reconn/s: 0.00
[ 2s ] thds: 1 tps: 60.03 qps: 1084.54 (r/w/o: 841.42/243.12/0.00) lat (ms,95%): 22.28 err/s 0.00 reconn/s: 0.00
…………
[ 29s ] thds: 1 tps: 68.00 qps: 1223.01 (r/w/o: 952.00/271.00/0.00) lat (ms,95%): 16.12 err/s 0.00 reconn/s: 0.00
[ 30s ] thds: 1 tps: 66.00 qps: 1188.00 (r/w/o: 924.00/264.00/0.00) lat (ms,95%): 16.71 err/s 0.00 reconn/s: 0.00
[ 31s ] thds: 1 tps: 67.00 qps: 1203.96 (r/w/o: 937.97/265.99/0.00) lat (ms,95%): 17.95 err/s 0.00 reconn/s: 0.00
[ 32s ] thds: 1 tps: 22.99 qps: 416.85 (r/w/o: 321.88/94.96/0.00) lat (ms,95%): 15.55 err/s 0.00 reconn/s: 0.00
[ 33s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 34s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 35s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00

5分钟后故障报告大批量涌进来，客户：怎么回事，我们的业务挂掉10分钟了，报错都是访问MySQL 超时，赶紧给我看看，从监控确实看到10分钟后客户业务还没恢复：

1
2
3
4
[ 601s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 602s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 603s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 604s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00

这时 oncall 都被从被窝里拎了起来，不知谁说了一句赶紧恢复吧，先试试把应用重启，5秒钟后应用重启完毕，业务恢复，大家开心地笑了，又成功防御住一次故障升级，还是重启大法好！

在业务/Sysbench QPS跌0 期间可以看到 3307被摘掉，3306 成功挂上去了，但是没有新连接建向 3306，业务/Sysbench 使劲薅着 3307

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
#ipvsadm -L -n --stats -t 127.0.0.1:3001
Prot LocalAddress:Port               Conns   InPkts  OutPkts  InBytes OutBytes
  -> RemoteAddress:Port
TCP  127.0.0.1:3001                      2   660294   661999 78202968  184940K
  -> 127.0.0.1:3306                      0        0        0        0        0
  
#ipvsadm -Lcn | head -10
IPVS connection entries
pro expire state       source             virtual            destination
TCP 13:11  ESTABLISHED 127.0.0.1:33864    127.0.0.1:3001     127.0.0.1:3307

#netstat -anto |grep -E "Recv|33864|3001|33077"
Proto Recv-Q Send-Q Local Address           Foreign Address         State       Timer
tcp        0    248 127.0.0.1:33864         127.0.0.1:3001          ESTABLISHED probe (33.48/0/8)
tcp6       0     11 127.0.0.1:3307          127.0.0.1:33864         ESTABLISHED on (49.03/13/0)

直到 900多秒后 OS 重试了15次发现都失败，于是向业务/Sysbench 返回连接异常，触发业务/Sysbench 释放异常连接重建新连接，新连接指向了新的 Master 3306，业务恢复正常

1
2
3
4
5
6
7
[ 957s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
DEBUG: Ignoring error 2013 Lost connection to MySQL server during query,
DEBUG: Reconnecting 
DEBUG: Reconnected
[ 958s ] thds: 1 tps: 53.00 qps: 950.97 (r/w/o: 741.98/208.99/0.00) lat (ms,95%): 30.26 err/s 0.00 reconn/s: 1.00
[ 959s ] thds: 1 tps: 64.00 qps: 1154.03 (r/w/o: 896.02/258.01/0.00) lat (ms,95%): 22.69 err/s 0.00 reconn/s: 0.00
[ 960s ] thds: 1 tps: 66.00 qps: 1184.93 (r/w/o: 923.94/260.98/0.00) lat (ms,95%): 25.28 err/s 0.00 reconn/s: 0.00

到这里重现了故障中经常碰到的业务需要900多秒才能慢慢恢复，这个问题也就是 TCP 长连接流量黑洞

如果我们把 net.ipv4.tcp_retries2 改成5 再来做这个实验，就会发现业务/Sysbench 只需要20秒就能恢复了，也就是这个流量黑洞从900多秒变成了20秒，这回 oncall 不用再被从被窝里拎出来了吧：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
[ 62s ] thds: 1 tps: 66.00 qps: 1191.00 (r/w/o: 924.00/267.00/0.00) lat (ms,95%): 17.63 err/s 0.00 reconn/s: 0.00
[ 63s ] thds: 1 tps: 63.00 qps: 1123.01 (r/w/o: 874.00/249.00/0.00) lat (ms,95%): 17.63 err/s 0.00 reconn/s: 0.00
[ 64s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 65s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 66s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 67s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 68s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 69s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 70s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 71s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 72s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 73s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 74s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 75s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 76s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 77s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 78s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 79s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 80s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 81s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
[ 82s ] thds: 1 tps: 0.00 qps: 0.00 (r/w/o: 0.00/0.00/0.00) lat (ms,95%): 0.00 err/s 0.00 reconn/s: 0.00
DEBUG: Ignoring error 2013 Lost connection to MySQL server during query,
DEBUG: Reconnecting 
DEBUG: Reconnected
[ 83s ] thds: 1 tps: 26.00 qps: 457.01 (r/w/o: 357.01/100.00/0.00) lat (ms,95%): 16.41 err/s 0.00 reconn/s: 1.00
[ 84s ] thds: 1 tps: 60.00 qps: 1086.94 (r/w/o: 846.96/239.99/0.00) lat (ms,95%): 26.68 err/s 0.00 reconn/s: 0.00
[ 85s ] thds: 1 tps: 63.00 qps: 1134.02 (r/w/o: 882.01/252.00/0.00) lat (ms,95%): 23.10 err/s 0.00 reconn/s: 0.00

LVS + Nginx 上重现

NGINX上重现这个问题：https://asciinema.org/a/649890 3分钟的录屏，这个视频构造了一个LVS 的HA切换过程，LVS后有两个Nginx，模拟一个Nginx(Master) 断网后，将第二个Nginx(Slave) 加入到LVS 并将第一个Nginx(Master) 从LVS 摘除，期望业务能立即恢复，但实际上可以看到之前的所有长连接都没有办法恢复，进入一个流量黑洞

TCP 长连接流量黑洞原理总结

TCP 长连接在发送包的时候，如果没收到ack 默认会进行15次重传(net.ipv4.tcp_retries2=15, 这个不要较真，会根据RTO 时间大致是15次)，累加起来大概是924秒，所以我们经常看到业务需要15分钟左右才恢复。这个问题存在所有TCP长连接中(几乎没有业务还在用短连接吧？)，问题的本质和 LVS/k8s Service 都没关系

我这里重现带上 LVS 只是为了场景演示方便

这个问题的本质就是如果Server突然消失(宕机、断网，来不及发 RST )客户端如果正在发东西给Server就会遵循TCP 重传逻辑不断地TCP retran , 如果一直收不到Server 的ack，大约重传15次，900秒左右。所以不是因为有 LVS 导致了这个问题，而是在某些场景下 LVS 有能力处理得更优雅，比如删除 RealServer的时候 LVS 完全可以感知这个动作并 reset 掉其上所有长连接

为什么在K8S 上这个问题更明显呢，K8S 讲究的就是服务不可靠，随时干掉POD(切断网络），如果干POD 之前能kill -9(触发reset)、或者close 业务触发断开连接那还好，但是大多时候啥都没干，有强摘POD、有直接隔离等等，这些操作都会导致对端只能TCP retran

怎么解决

业务方

业务方要对自己的请求超时时间有控制和兜底，不能任由一个请求长时间 Hang 在那里

比如JDBC URL 支持设置 SocketTimeout、ConnectTimeout，我相信其他产品也有类似的参数，业务方要设置这些值，不设置就是如上重现里演示的900多秒后才恢复

SocketTimeout

只要是连接有机会设置 SocketTimeout 就一定要设置，具体值可以根据你们能接受的慢查询来设置；分析、AP类的请求可以设置大一点

最重要的：任何业务只要你用到了TCP 长连接一定要配置一个恰当的SocketTimeout，比如 Jedis 是连接池模式，底层超时之后，会销毁当前连接，下一次重新建连，就会连接到新的切换节点上去并恢复

RFC 5482 TCP_USER_TIMEOUT

RFC 5482 中增加了TCP_USER_TIMEOUT这个配置，通常用于定制当 TCP 网络连接中出现数据传输问题时，可以等待多长时间前释放网络资源，对应Linux 这个 commit

TCP_USER_TIMEOUT 是一个整数值，它指定了当 TCP 连接的数据包在发送后多长时间内未被确认（即没有收到 ACK），TCP 连接会考虑释放这个连接。

打个比方，设置 TCP_USER_TIMEOUT 后，应用程序就可以指定说：“如果在 30 秒内我发送的数据没有得到确认，那我就认定网络连接出了问题，不再尝试继续发送，而是直接断开连接。”这对于确保连接质量和维护用户体验是非常有帮助的。

在 Linux 中，可以使用 setsockopt 函数来设置某个特定 socket 的 TCP_USER_TIMEOUT 值：

1
2
int timeout = 30000; // 30 seconds
setsockopt(sock, IPPROTO_TCP, TCP_USER_TIMEOUT, (char *)&timeout, sizeof(timeout));

在这行代码中，sock 是已经 established 的 TCP socket，我们将该 socket 的 TCP_USER_TIMEOUT 设置为 30000 毫秒，也就是 30 秒。如果设置成功，这个 TCP 连接在发送数据包后 30 秒内如果没有收到 ACK 确认，将开始进行 TCP 连接的释放流程。

TCP_USER_TIMEOUT 相较 SocketTimeout 可以做到更精确(不影响慢查询)，SocketTimeout 超时是不区分ACK 还是请求响应时间的，但是 TCP_USER_TIMEOUT 要求下层的API、OS 都支持。比如 JDK 不支持 TCP_USER_TIMEOUT，但是 Netty 框架自己搞了Native 来实现对 TCP_USER_TIMEOUT 以及其它OS 参数的设置，在这些基础上Redis 的Java 客户端 lettuce 依赖了 Netty ，所以也可以设置 TCP_USER_TIMEOUT

原本我是想在Druid 上提个feature 来支持 TCP_USER_TIMEOUT，这样集团绝大部分业务都可以无感知解决掉这个问题，但查下来发现 JDK 不支持设置这个值，想要在Druid 里面实现设置 TCP_USER_TIMEOUT 的话，得像 Netty 一样走Native 绕过JDK 来设置，这对 Druid 而言有点重了

ConnectTimeout

这个值是针对新连接创建超时时间设置，一般设置3-5秒就够长了

连接池

建议参考这篇 《数据库连接池配置推荐》 这篇里的很多建议也适合业务、应用等，你把数据库看成一个普通服务就好理解了

补充下如果用的是Druid 数据库连接池不要用它来设置你的 SocketTimeout 参数，因为他有bug 导致你觉得设置了但实际没设置上，2024-03-16号的1.2.22这个Release 才fix，所以强烈建议你讲 SocketTimeout 写死在JDBC URL 中简单明了

OS 兜底

假如业务是一个AP查询/一次慢请求，一次查询/请求就是需要半个小时，将 SocketTimeout 设置太小影响正常的查询，那么可以将如下 OS参数改小，从 OS 层面进行兜底

1
2
net.ipv4.tcp_retries2 = 8
net.ipv4.tcp_syn_retries = 4

keepalive

keepalive 默认 7200秒太长了，建议改成20秒，可以在OS 镜像层面固化，然后各个业务可以 patch 自己的值；

如果一条连接限制超过 900 秒 LVS就会Reset 这条连接，但是我们将keepalive 设置小于900秒的话，即使业务上一直闲置，因为有 keepalive 触发心跳包，让 LVS 不至于 Reset，这也就避免了当业务取连接使用的时候才发现连接已经不可用被断开了，往往这个时候业务抛错误的时间很和真正 Reset 时间还差了很多，不好排查

在触发 TCP retransmission 后会停止 keepalive 探测

LVS

如果你们试用了aliyun的SLB，当摘除节点的时候支持你设置一个时间，过了这个时间 aliyun的SLB 就会向这些连接的客户端发 Reset 干掉这些流量，让客户端触发新建连接，从故障中快速恢复，这是一个实例维度的参数，建议云上所有产品都支持起来，管控可以在购买 aliyun的SLB 的时候设置一个默认值：

connection_drain_timeout

其它

神奇的900秒

上面阐述的长连接流量黑洞一般是900+秒就恢复了，有时候我们经常在日志中看到 CommunicationsException: Communications link failure 900秒之类的错误，恰好 LVS 也是设置的 900秒闲置 Reset

1
2
#ipvsadm -L --timeout
Timeout (tcp tcpfin udp): 900 120 300

为什么这个问题这几年才明显暴露

  • 工程师们混沌了几十年
  • 之前因为出现频率低重启业务就糊弄过去了
  • 对新连接不存在这个问题
  • 有些连接池配置了Check 机制(Check机制一般几秒钟超时 fail)
  • 微服务多了
  • 云上 LVS 普及了
  • k8s service 大行其道

我用的 7层是不是就没有这个问题了？

幼稚，你4层都挂了7层还能蹦跶，再说一遍只要是 TCP 长连接就有这个问题

极端情况

A 长连接 访问B 服务，B服务到A网络不通，假如B发生HA，一般会先Reset/断开B上所有连接(比如 MySQL 会去kill 所有processlist；比如重启MySQL——假如这里的B是MySQL)，但是因为网络不通这里的reset、fin网络包都无法到达A，所以B是无法兜底这个异常场景， A无法感知B不可用了，会使用旧连接大约15分钟

最可怕的是 B 服务不响应，B所在的OS 还在响应，那么在A的视角 网络是正常的，这时只能A自己来通过超时兜底

总结

这种问题在 LVS 场景下暴露更明显了，但是又和LVS 没啥关系，任何业务长连接都会导致这个 900秒左右的流量黑洞，首先要在业务层面重视这个问题，要不以后数据库一挂掉还得重启业务才能从故障中将恢复，所以业务层面处理好了可以避免900秒黑洞和重启业务，达到快速从故障中恢复

再强调下这个问题如果去掉LVS/k8s Service/软负载等让两个服务直连，然后拔网线也会同样出现

最佳实践总结：

  • 如果你的业务支持设置 SocketTimeout 那么请一定要设置，但不一定适合分析类就是需要长时间返回的请求
  • 最好的方式是设置 OS 层面的 TCP_USER_TIMEOUT 参数，只要长时间没有 ack 就报错返回，但 JDK 不支持直接设置
  • 如果用了 ALB/SLB 就一定要配置 connection_drain_timeout 这个参数
  • OS 镜像层面也可以将 tcp_retries2 设置为5-10次做一个兜底
  • 对你的超时时间做到可控、可预期

假如你的业务不是 Java，而是 Python 的话，请参考Java/Python超时参数对照表：

功能 JDBC (Java) mysql-connector-python PyMySQL
连接建立超时 connectTimeout connect_timeout connect_timeout
读写操作超时 socketTimeout connection_timeout read_timeout/write_timeout
连接池等待超时 poolTimeout pool_timeout 需手动实现

相关故障和资料

ALB 黑洞问题详述：https://mp.weixin.qq.com/s/BJWD2V_RM2rnU1y7LPB9aw

数据库故障引发的“血案” ：https://www.cnblogs.com/nullllun/p/15073022.html 这篇描述较细致，推荐看看

tcp_retries2 的解释：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
tcp_retries1 - INTEGER
    This value influences the time, after which TCP decides, that
    something is wrong due to unacknowledged RTO retransmissions,
    and reports this suspicion to the network layer.
    See tcp_retries2 for more details.

    RFC 1122 recommends at least 3 retransmissions, which is the
    default.

tcp_retries2 - INTEGER
    This value influences the timeout of an alive TCP connection,
    when RTO retransmissions remain unacknowledged.
    Given a value of N, a hypothetical TCP connection following
    exponential backoff with an initial RTO of TCP_RTO_MIN would
    retransmit N times before killing the connection at the (N+1)th RTO.

    The default value of 15 yields a hypothetical timeout of 924.6
    seconds and is a lower bound for the effective timeout.
    TCP will effectively time out at the first RTO which exceeds the
    hypothetical timeout.

    RFC 1122 recommends at least 100 seconds for the timeout,
    which corresponds to a value of at least 8.

tcp_retries2 默认值为15，根据RTO的值来决定，相当于13-30分钟(RFC1122规定，必须大于100秒)，但是这是很多年前的拍下来古董参数值，现在网络条件好多了，尤其是内网，个人认为改成 5-10 是比较恰当 azure 建议：https://learn.microsoft.com/en-us/azure/azure-cache-for-redis/cache-best-practices-connection ，Oracle RAC的建议值是3：https://access.redhat.com/solutions/726753

发表于 更新于 分类于

十年后数据库还是不敢拥抱NUMA-续篇

背景

十年后数据库还是不敢拥抱NUMA， 这篇经典的纠正大家对NUMA 认知的文章一晃发布快3年了，这篇文章的核心结论是：

  • 之所以有不同的NUMA Node 是不同的CPU Core 到不同的内存距离远近不一样所决定的，这是个物理距离
  • 程序跑在不同的核上要去读写内存可以让性能差异巨大，所以我们要尽量让一个程序稳定跑在一个Node 内
  • 默认打开NUMA Node 其实挺好的

写这个续篇是我收到很多解释，因为跨Node 导致性能抖动，所以集团在物理机OS 的启动参数里设置了 numa=off ，也就是不管BIOS 中如何设置，我们只要在OS 层面设置一下 numa=off 就能让程序稳定下来不再抖了！

我这几年也认为这是对的，只是让我有点不理解，既然不区分远近了，那物理上存在的远近距离(既抖动)如何能被消除掉的呢？

所以这个续篇打算通过测试来验证下这个问题

设置

BIOS 中有 numa node 设置的开关(注意这里是内存交错/交织)，不同的主板这个BIOS设置可能不一样，但是大同小异，基本都有这个参数

img

Linux 启动引导参数里也可以设置numa=on(默认值)/off ，linux 引导参数设置案例：

1
2
#cat /proc/cmdline
BOOT_IMAGE=/vmlinuz-3.10.0-327.x86_64  ro crashkernel=auto vconsole.font=latarcyrheb-sun16 vconsole.keymap=us BIOSdevname=0 console=tty0 console=ttyS0,115200 scsi_mod.scan=sync intel_idle.max_cstate=0 pci=pcie_bus_perf ipv6.disable=1 rd.driver.pre=ahci numa=on nosmt=force

注意如上的 numa=on 也可以改为 numa=off

看完全置篇要记住一条铁律：CPU到内存的距离是物理远近决定的，你软件层面做些设置是没法优化这个距离，也就是没法优化这个时延 (这是个核心知识点，你要死死记住和理解，后面的一切实验数据都回过头来看这个核心知识点并揣摩)

实验

测试机器CPU，如下是BIOS numa=on、cmdline numa=off所看到的，一个node

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
#lscpu
Architecture:          x86_64
CPU op-mode(s):        32-bit, 64-bit
Byte Order:            Little Endian
CPU(s):                96
On-line CPU(s) list:   0-95
Thread(s) per core:    2
Core(s) per socket:    24
Socket(s):             2
NUMA node(s):          1
Vendor ID:             GenuineIntel
CPU family:            6
Model:                 85
Model name:            Intel(R) Xeon(R) Platinum 8163 CPU @ 2.50GHz
Stepping:              4
CPU MHz:               2500.000
CPU max MHz:           3100.0000
CPU min MHz:           1000.0000
BogoMIPS:              4998.89
Virtualization:        VT-x
L1d cache:             32K
L1i cache:             32K
L2 cache:              1024K
L3 cache:              33792K
NUMA node0 CPU(s):     0-95

测试工具是lmbench，测试命令：

1
for i in $(seq 0 6 95); do echo core:$i; numactl -C $i -m 0 ./bin/lat_mem_rd -W 5 -N 5 -t 64M; done >lat.log 2>&1

上述测试命令始终将内存绑定在 node0 上，然后用不同的物理core来读写这块内存，按照前一篇 这个时延肯定有快慢之分

BIOS和引导参数各有两种设置方式，组合起来就是四种，我们分别设置并跑一下内存时延，测试结果：

BIOS ON BIOS OFF
cmdline numa=on（默认值） NUMA 开启，内存在Node内做交织，就近有快慢之分 bios 关闭后numa后，OS层面完全不知道下层的结构，默认全局内存做交织，时延是个平均值
cmdline numa=off 交织关闭，效果同上 同上

测试原始数据如下(测试结果文件名 lat.log.BIOSON.cmdlineOff 表示BIOS ON，cmdline OFF )：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
//从下面两组测试来看，BIOS层面 on后，不管OS 层面是否on，都不会跨node 做交织，抖动存在
//BIOS on 即使在OS层面关闭numa也不跨node做内存交织，抖动存在
//默认从内存高地址开始分配空间，所以0核要慢
#grep -E "core|64.00000" lat.log.BIOSON.cmdlineOff 
core:0 //第0号核
64.00000 100.717 //64.0000为64MB， 100.717 是平均时延100.717ns 即0号核访问node0 下的内存64MB的平均延时是100纳秒
core:24
64.00000 68.484
core:48
64.00000 101.070
core:72
64.00000 68.483
#grep -E "core|64.00000" lat.log.BIOSON.cmdlineON
core:0
64.00000 67.094
core:24
64.00000 100.237
core:48
64.00000 67.614
core:72
64.00000 101.096

//从下面两组测试来看只要BIOS off了内存就会跨 node 交织，大规模测试下内存 latency 是个平均值
#grep -E "core|64.00000" lat.log.BIOSOff.cmdlineOff //BIOS off 做内存交织，latency就是平均值
core:0
64.00000 85.657  //85 恰好是最大100，最小68的平均值
core:24
64.00000 85.741
core:48
64.00000 85.977
core:72
64.00000 86.671

//BIOS 关闭后numa后，OS层面完全不知道下层的结构，默认一定是做交织
#grep -E "core|64.00000" lat.log.BIOSOff.cmdlineON
core:0
64.00000 89.123
core:24
64.00000 87.137
core:48
64.00000 87.239
core:72
64.00000 87.323

从数据可以看到在BIOS 设置ON后，无论 OS cmdline 启动参数里是否设置了 ON 还是 OFF，内存延时都是抖动且一致的(这个有点诧异，说好的消除抖动的呢？)。如果BIOS 设置OFF后内存延时是个稳定的平均值(这个比较好理解)

疑问

  • 内存交错时为什么 lmbench 测试得到的时延是平均值，而不是短板效应的最慢值？

测试软件只能通过大规模数据的读写来测试获取一个平均值，所以当一大块内存读取时，虽然通过交织大块内存被切分到了快慢物理内存上，但是因为规模大慢的被平均掉了。(欢迎内核大佬指正)

  • 什么是内存交织？

我的理解假如你有8块物理内存条，如果你有一个int 那么只能在其中一块上，如果你有1MB的数据那么会按cacheline 拆成多个块然后分别放到8块物理内存条上(有快有慢)这样带宽更大，最后测试得到一个平均值

如果你开启numa那么只会就近交织，比如0-3号内存条在0号core所在的node，OS 做内存交织的时候只会拆分到这0-3号内存条上，那么时延总是最小的那个，如上测试中的60多纳秒。

这个问题一直困扰了我几年，所以我最近再次测试验证了一下，主要是对 BIOS=on 且 cmdline=off 时有点困扰

Intel 的 mlc 验证

测试参数: BIOS=on 同时 cmdline off

用Intel 的 mlc 验证下，这个结果有点意思，latency稳定在 145 而不是81 和 145两个值随机出现，应该是mlc默认选到了0核，对应lmbench的这组测试数据(为什么不是100.717， 因为测试方法不一样)：

1
2
3
4
5
6
7
8
9
10
11
12
//如下是
//从下面两种测试来看，BIOS层面 on后，不管OS 层面是否on，都不会跨node 做交织，抖动存在
//BIOS on 即使在OS层面关闭numa也不跨node做内存交织，抖动存在
#grep -E "core|64.00000" lat.log.BIOSON.cmdlineOff 
core:0
64.00000 100.717
core:24
64.00000 68.484
core:48
64.00000 101.070
core:72
64.00000 68.483

此时对应的mlc

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
#./mlc
Intel(R) Memory Latency Checker - v3.9
Measuring idle latencies (in ns)...
    Numa node
Numa node    0
    0   145.8  //多次测试稳定都是145纳秒

Measuring Peak Injection Memory Bandwidths for the system
Bandwidths are in MB/sec (1 MB/sec = 1,000,000 Bytes/sec)
Using all the threads from each core if Hyper-threading is enabled
Using traffic with the following read-write ratios
ALL Reads     :  110598.7
3:1 Reads-Writes :  93408.5
2:1 Reads-Writes :  89249.5
1:1 Reads-Writes :  64137.3
Stream-triad like:  77310.4

Measuring Memory Bandwidths between nodes within system
Bandwidths are in MB/sec (1 MB/sec = 1,000,000 Bytes/sec)
Using all the threads from each core if Hyper-threading is enabled
Using Read-only traffic type
    Numa node
Numa node    0
    0  110598.4

Measuring Loaded Latencies for the system
Using all the threads from each core if Hyper-threading is enabled
Using Read-only traffic type
Inject  Latency Bandwidth
Delay (ns)  MB/sec
==========================
 00000  506.00   111483.5
 00002  505.74   112576.9
 00008  505.87   112644.3
 00015  508.96   112643.6
 00050  574.36   112701.5

当两个参数都为 on 时的mlc 测试结果：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
#./mlc
Intel(R) Memory Latency Checker - v3.9
Measuring idle latencies (in ns)...
    Numa node
Numa node    0     1
    0    81.6   145.9
    1   144.9    81.2

Measuring Peak Injection Memory Bandwidths for the system
Bandwidths are in MB/sec (1 MB/sec = 1,000,000 Bytes/sec)
Using all the threads from each core if Hyper-threading is enabled
Using traffic with the following read-write ratios
ALL Reads     :  227204.2
3:1 Reads-Writes :  212432.5
2:1 Reads-Writes :  210423.3
1:1 Reads-Writes :  196677.2
Stream-triad like:  189691.4

说明：mlc和 lmbench 测试结果不一样，mlc 时81和145，lmbench测试是68和100，这是两种测试方法的差异而已，但是快慢差距基本是一致的

结论

在OS 启动引导参数里设置 numa=off 完全没有必要、也不能解决抖动的问题，反而设置了 numa=off 只能是掩耳盗铃，让用户看不到 NUMA 结构

发表于 更新于 分类于

流量一样但为什么CPU使用率差别很大

这是我翻到2013年的一篇文章，当时惊动所有公司高人，最后分析得知原因后所有人都跪拜，你要知道那是2013年，正好10年过去了，如果是现在用我们星球的理论去套的话，简直不要太容易

问题描述

同样大小内存、同样的CPU、同样数量的请求、几乎可以忽略的io，两个机器的load却差异挺大。一个机器的load是12左右，另外一个机器却是30左右

你可以理解这是两台一摸一样的物理机挂在一个LVS 下，LVS 分发流量绝对均衡

所以要找出为什么？

分析

两台机器的资源使用率：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
//load低、CPU使用率低 的物理机，省略一部分核
Cpu0  : 67.1%us,  1.6%sy,  0.0%ni, 30.6%id,  0.0%wa,  0.0%hi,  0.7%si,  0.0%st
Cpu1  : 64.1%us,  1.6%sy,  0.0%ni, 34.3%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu2  : 63.0%us,  1.6%sy,  0.0%ni, 35.4%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu3  : 60.0%us,  1.3%sy,  0.0%ni, 38.4%id,  0.0%wa,  0.0%hi,  0.3%si,  0.0%st
Cpu4  : 59.8%us,  1.3%sy,  0.0%ni, 37.9%id,  1.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu5  : 56.7%us,  1.0%sy,  0.0%ni, 42.3%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu6  : 63.4%us,  1.3%sy,  0.0%ni, 34.6%id,  0.0%wa,  0.0%hi,  0.7%si,  0.0%st
Cpu7  : 62.5%us,  2.0%sy,  0.0%ni, 35.5%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu8  : 58.5%us,  1.3%sy,  0.0%ni, 39.5%id,  0.0%wa,  0.0%hi,  0.7%si,  0.0%st
Cpu9  : 55.8%us,  1.6%sy,  0.0%ni, 42.2%id,  0.3%wa,  0.0%hi,  0.0%si,  0.0%st

//load高、CPU使用率高 的物理机，省略一部分核
Cpu0  : 90.1%us,  1.9%sy,  0.0%ni,  7.1%id,  0.0%wa,  0.0%hi,  1.0%si,  0.0%st
Cpu1  : 88.5%us,  2.9%sy,  0.0%ni,  8.0%id,  0.0%wa,  0.0%hi,  0.6%si,  0.0%st
Cpu2  : 90.4%us,  1.9%sy,  0.0%ni,  7.7%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Cpu3  : 86.9%us,  2.6%sy,  0.0%ni, 10.2%id,  0.0%wa,  0.0%hi,  0.3%si,  0.0%st
Cpu4  : 87.5%us,  1.9%sy,  0.0%ni, 10.2%id,  0.0%wa,  0.0%hi,  0.3%si,  0.0%st
Cpu5  : 87.3%us,  1.9%sy,  0.0%ni, 10.5%id,  0.0%wa,  0.0%hi,  0.3%si,  0.0%st
Cpu6  : 90.4%us,  2.9%sy,  0.0%ni,  6.4%id,  0.0%wa,  0.0%hi,  0.3%si,  0.0%st
Cpu7  : 90.1%us,  1.9%sy,  0.0%ni,  7.6%id,  0.0%wa,  0.0%hi,  0.3%si,  0.0%st
Cpu8  : 89.5%us,  2.6%sy,  0.0%ni,  6.7%id,  0.0%wa,  0.0%hi,  1.3%si,  0.0%st
Cpu9  : 90.7%us,  1.9%sy,  0.0%ni,  7.4%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st

可以分析产出为什么低，检查CPU是否降频、内存频率是否有差异——检查结果一致

10年前经过一阵 perf top 看热点后终于醒悟过来知道得去看 IPC，也就是相同CPU使用率下，其中慢的机器产出低了一半，那么继续通过perf看IPC：

img

可以看到两台机器的IPC是 0.3 VS 0.55，和CPU使用率差异基本一致，instructions几乎一样(意味着流量一样，LVS 不背锅)，但是处理同样的instructions 用掉的cpu-clock 几乎差了一倍，这应该是典型的内存时延大了一倍导致的。IPC 大致等于 instrunctions/cpu-clock （IPC：instrunctions per cycles）

经检查这两台物理机都是两路，虽然CPU型号/内存频率一致，但是主板间跨Socket的 QPI带宽差了一倍(主板是两个不同的服务商提供)。可以通过绑核测试不同Socket/Node 下内存时延来确认这个问题

这是同一台机器下两个Socket 的内存带宽，所以如果跨Socket 内存访问多了就会导致时延更高、CPU使用率更高

img

总结

在今天我们看到这种问题就很容易了，但我还是要感叹一下在入门前简直太神奇，入门后也不过尔尔，希望你也早点入门。

第一：向CPU要产出，同样的使用率产出得一样，不一样的话肯定是偷懒了，偷懒的直接证据就是 IPC 低了，导致IPC 低最常见的是内存时延高(内存频率、跨Node/Socket 等，或者内存碎片)；延伸阅读：性能的本质 IPC ，也是本星球唯二的必读实验

第二：测试工具很完善了，lmbench , 怎么用lmbench 可以看这篇 ; 怎么使用perf Perf IPC以及CPU性能

，学成后装逼可以看 听风扇声音来定位性能瓶颈

我以前说过每个领域都有一些核心知识点，IPC 就是CPU领域的核心知识点，和tcp的rmem/wmem 一样很容易引导你入门

计算机专业里非要挑几个必学的知识点肯定得有计算机组成原理，但计算机组成原理内容太多，都去看也不现实，况且很多过时的东西，那么我只希望你能记住计算机组成原理里有个最核心的麻烦：内存墙——CPU 访问内存太慢导致了内存墙是我们碰到众多性能问题的最主要、最核心的一个，结合今天这个案例掌握IPC后再来学内存墙，再到理解计算机组成原理就对了，从一个实用的小点入手。

计算机专业里除掉组成原理(有点高大上，没那么接地气)，另外一个我觉得最有用的是网络——看着low但是接地气，问题多，很实用

2011年的文章：

详解服务器内存带宽计算和使用情况测量

更好的工具来发现类似问题：https://github.com/intel/numatop

img

如果你觉得看完对你很有帮助可以通过如下方式找到我

find me on twitter: @plantegg

知识星球：https://t.zsxq.com/0cSFEUh2J

开了一个星球，在里面讲解一些案例、知识、学习方法，肯定没法让大家称为顶尖程序员(我自己都不是)，只是希望用我的方法、知识、经验、案例作为你的垫脚石，帮助你快速、早日成为一个基本合格的程序员。

争取在星球内：

  • 养成基本动手能力
  • 拥有起码的分析推理能力–按我接触的程序员，大多都是没有逻辑的
  • 知识上教会你几个关键的知识点
image-20240324161113874

发表于 更新于 分类于

SocketTimeout 后客户端怎么做和服务端怎么做

背景

希望通过一个极简，几乎是人人都可以上手验证的实验来触及到一些深度的内容，然后再看看是否会激发你进一步自己设计类似实验和验证过程等

关于这种简单类型的实验欢迎给我提意见：比如你会不会做；太难、太容易？能学到东西吗？效果如何？我要如何改进

安装JDK和MySQL

1
2
3
4
5
6
7
8
9
10
11
yum install -y java-1.8.0-openjdk.x86_64 java-1.8.0-openjdk-devel.x86_64  podman-docker.noarch wireshark 

//启动MySQL Server，root密码123
docker run -it -d --net=host -e MYSQL_ROOT_PASSWORD=123 --name=plantegg mysql

docker run --net=host -v /root/mysql/my3306.cnf:/etc/my.cnf -it -d  -e MYSQL_ROOT_PASSWORD=123 --name=mysql3306 mysql:8.0

//可能需要的MySQL 账号命令
//8.0密码问题，可以设置配置：
ALTER USER 'test'@'localhost' IDENTIFIED WITH mysql_native_password BY '123';
ALTER USER 'root'@'%' IDENTIFIED WITH mysql_native_password BY '123';

测试环境机器是99块一年购买的aliyun ECS，OS版本选ALinux3，对应内核版本：

1
5.10.134-15.al8.x86_64

测试使用的MySQL 版本：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
mysql> \s
--------------
mysql  Ver 8.0.32 for Linux on x86_64 (Source distribution)

Connection id:		9
Current database:	test
Current user:		root@127.0.0.1
SSL:			Not in use
Current pager:		stdout
Using outfile:		''
Using delimiter:	;
Server version:		8.2.0 MySQL Community Server - GPL
Protocol version:	10
Connection:		127.1 via TCP/IP
Server characterset:	utf8mb4
Db     characterset:	utf8mb4
Client characterset:	utf8mb4
Conn.  characterset:	utf8mb4
TCP port:		3306
Binary data as:		Hexadecimal
Uptime:			15 hours 46 min 24 sec

Threads: 2  Questions: 34  Slow queries: 0  Opens: 176  Flush tables: 3  Open tables: 95  Queries per second avg: 0.000

客户端

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
测试代码(复制粘贴就可以编译运行了，运行时需要下载jdbc mysql driver，链接见附录)：
import java.sql.Connection;
import java.sql.DriverManager;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.sql.Statement;
import java.sql.PreparedStatement;
public class Test { //不要琢磨代码规范、为什么要这么写，就是为了方便改吧改吧做很多不同的验证试验
    public static void main(String args[]) throws NumberFormatException, InterruptedException, ClassNotFoundException {
        Class.forName("com.mysql.jdbc.Driver");
        String url = args[0];
        String user = args[1];
        String pass = args[2];
        String sql = args[3];
        String interval = args[4];
        try {
            Connection conn = DriverManager.getConnection(url, user, pass);
            while (true) {
                PreparedStatement stmt = conn.prepareStatement(sql);
                //stmt.setFetchSize(Integer.MIN_VALUE); //这句是表示开流式读取，但是每条SQL 都会先发set net_write_timeout=600 给Server
                stmt.setString(1, interval);
                ResultSet rs = stmt.executeQuery();
                rs.close();
                stmt.close();

                PreparedStatement stmt2 = conn.prepareStatement(sql);
                stmt2.setString(1, interval);
                rs = stmt2.executeQuery();
								while (rs.next()) {
								    System.out.println("fine");
								}
                rs.close();
                stmt2.close();

                Thread.sleep(Long.valueOf(interval));
								break;
            }
						conn.close();
        } catch (SQLException e) {
            e.printStackTrace();
        }
    }
}

#javac Test.java //编译，需要提前安装JDK
//执行，需要下载jdbc jar驱动，见附录，还需要有一个数据库，随便建个表，或者查里面自带的库都可以
#java -cp .:./mysql-connector-java-5.1.45.jar Test "jdbc:mysql://127.0.0.1:3306/test?useSSL=false&useServerPrepStmts=true&cachePrepStmts=true&connectTimeout=500&socketTimeout=1700" root 123 "select sleep(10), id from sbtest1 where id= ?" 100 //设置了1.7秒超时查询还不返回的话业务代码报错，堆栈如下：
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure //连接异常

The last packet successfully received from the server was 1,701(1700ms) milliseconds ago.  The last packet sent successfully to the server was 1,701 milliseconds ago.
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:500)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:481)
	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
	at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3559)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3459)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3900)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2527)
	at com.mysql.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1283)
	at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:783)
	at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1966)
	at Test.main(Test.java:30)
Caused by: java.net.SocketTimeoutException: Read timed out // 异常，JDBC Driver 会调 Socket.setSoTimeout 来设置超时时间给 timeRead使用
	at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:284) //timedRead 函数可以设置读取超时（timeout）
	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:310)
	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:351)
	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:802)
	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:919)
	at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101)
	at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144)
	at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174)
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3008)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3469)
	... 7 more

源码参考：https://sourcegraph.com/github.com/openjdk/jdk/-/blob/src/java.base/share/classes/sun/nio/ch/NioSocketImpl.java?L291:18-291:26

客户端读到一半的时候 MySQL Hang 了，也会触发 SocketTimeoutException 异常，同时客户端还会看到 Consider raising value of ‘net_write_timeout’ on the server(测试代码开启了流式读取)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
java -cp .:./mysql-connector-java-5.1.45.jar Test "jdbc:mysql://gf1:3307/test?useSSL=false&useServerPrepStmts=true&cachePrepStmts=true&connectTimeout=500&socketTimeout=1500&netTimeoutForStreamingResults=0" root 123 "select *, id from streaming " 5000

timestamp:1734084150084 id:1 count:60798
timestamp:1734084150084 id:2 count:60799
timestamp:1734084151594  //读到 60799行后，MySQL 卡了，读卡了 1500ms 后报错
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Application was streaming results when the connection failed. Consider raising value of 'net_write_timeout' on the server.
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:500)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:481)
	at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
	at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:990)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3559)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3459)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3900)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:873)
	at com.mysql.jdbc.MysqlIO.nextRow(MysqlIO.java:1996)
	at com.mysql.jdbc.RowDataDynamic.nextRecord(RowDataDynamic.java:374)
	at com.mysql.jdbc.RowDataDynamic.next(RowDataDynamic.java:354)
	at com.mysql.jdbc.ResultSetImpl.next(ResultSetImpl.java:6312)
	at Test.main(Test.java:38)
Caused by: java.net.SocketTimeoutException: Read timed out
	at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:288)
	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:314)
	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:355)
	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:808)
	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966)
	at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101)
	at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144)
	at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174)
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3008)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3469)
	... 8 more

服务端对应的抓包

如果OS 比较老，安装的tshark 也较老，那么命令参数略微不一样，主要是 col.Info 这个列，没有 _ws 前缀：

1
#tshark -i eth0 port 3306 -d tcp.port==3306,mysql -nn -T fields -e frame.number -e frame.time_delta -e tcp.srcport -e tcp.dstport -e col.Info -e mysql.query

如果是阿里云 99 买了ECS，安装的内核版本较高比如4.19，那么配套安装的tshark也较高，就用如下命令：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
#tshark -i eth0 -Y "tcp.port==3306" -d tcp.port==3306,mysql -T fields -e frame.number -e frame.time -e frame.time_delta -e tcp.srcport -e tcp.dstport -e tcp.len -e _ws.col.Info -e mysql.query
 //第二列是时间间隔
1	0.000000000	30260	3306	kingdomsonline > mysql [SYN] Seq=0 Win=42340 Len=0 MSS=1460 SACK_PERM=1 WS=512
2	0.000024473	3306	30260	mysql > kingdomsonline [SYN, ACK] Seq=0 Ack=1 Win=29200 Len=0 MSS=1460 SACK_PERM=1 WS=128
3	0.000271938	30260	3306	kingdomsonline > mysql [ACK] Seq=1 Ack=1 Win=42496 Len=0 //3次握手
4	0.000660359	3306	30260	Server Greeting proto=10 version=8.2.0 //MySQL server主动发送版本、问候信息等
5	0.000263009	30260	3306	kingdomsonline > mysql [ACK] Seq=1 Ack=78 Win=42496 Len=0
6	0.039698745	30260	3306	Login Request user=test db=test //客户端验证账号密码
7	0.000009044	3306	30260	mysql > kingdomsonline [ACK] Seq=78 Ack=243 Win=30336 Len=0
8	0.000171281	3306	30260	Response
9	0.000260062	30260	3306	kingdomsonline > mysql [ACK] Seq=243 Ack=126 Win=42496 Len=0
10	0.000298127	30260	3306	Request Unknown (168)
11	0.000142114	3306	30260	Response OK 
12	0.000255322	30260	3306	kingdomsonline > mysql [ACK] Seq=267 Ack=137 Win=42496 Len=0
13	0.003596187	30260	3306	Request Query	/* mysql-connector-java-5.1.45 ( Revision: 9131eefa398531c7dc98776e8a3fe839e544c5b2 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@character_set_connection AS character_set_connection, @@character_set_results AS character_set_results, @@character_set_server AS character_set_server, @@collation_server AS collation_server, @@init_connect AS init_connect, @@interactive_timeout AS interactive_timeout, @@license AS license, @@lower_case_table_names AS lower_case_table_names, @@max_allowed_packet AS max_allowed_packet, @@net_buffer_length AS net_buffer_length, @@net_write_timeout AS net_write_timeout, @@have_query_cache AS have_query_cache, @@sql_mode AS sql_mode, @@system_time_zone AS system_time_zone, @@time_zone AS time_zone, @@transaction_isolation AS transaction_isolation, @@wait_timeout AS wait_timeout
14	0.000328419	3306	30260	Response
15	0.000266581	30260	3306	kingdomsonline > mysql [ACK] Seq=1164 Ack=1208 Win=42496 Len=0
16	0.022407439	30260	3306	Request Query	SHOW WARNINGS
17	0.000058143	3306	30260	Response
18	0.000267585	30260	3306	kingdomsonline > mysql [ACK] Seq=1182 Ack=1411 Win=42496 Len=0
19	0.001776177	30260	3306	Request Query	SET NAMES utf8mb4 //客户端设置charset
20	0.000052102	3306	30260	Response OK
21	0.000263257	30260	3306	kingdomsonline > mysql [ACK] Seq=1204 Ack=1422 Win=42496 Len=0
22	0.000175172	30260	3306	Request Query	SET character_set_results = NULL
23	0.000046756	3306	30260	Response OK
24	0.000258191	30260	3306	kingdomsonline > mysql [ACK] Seq=1241 Ack=1433 Win=42496 Len=0
25	0.000185322	30260	3306	Request Query	SET autocommit=1
26	0.000037833	3306	30260	Response OK
27	0.000255747	30260	3306	kingdomsonline > mysql [ACK] Seq=1262 Ack=1444 Win=42496 Len=0
28	0.011132112	30260	3306	Request Prepare Statement	select sleep(10), id from sbtest1 where id= ?  //进一步学习
29	0.000171861	3306	30260	Response //作业：Prepared Statement 后 MySQL回了啥？
30	0.000290736	30260	3306	kingdomsonline > mysql [ACK] Seq=1312 Ack=1570 Win=42496 Len=0
31	0.000613187	30260	3306	Request Execute Statement                                           //客户端发送SQL请求
32	0.039923585	3306	30260	mysql > kingdomsonline [ACK] Seq=1570 Ack=1334 Win=32128 Len=0
33	1.675682641	30260	3306	kingdomsonline > mysql [FIN, ACK] Seq=1334 Ack=1570 Win=42496 Len=0 //1.7秒后客户端发fin主动断开
34	0.039320026	3306	30260	mysql > kingdomsonline [ACK] Seq=1570 Ack=1335 Win=32128 Len=0

//MySQL 还完全不知道客户端fin了，继续发送响应结果。tcp断开在OS 层面处理，业务再使用这个已断开的连接时OS 会返回错误
35	3.245406398	3306	30260	Response
36	0.000041708	3306	30260	Server Greeting Error 1158 //MySQL 感知到OS返回的错误，发送错误码(已经没有用了)，不过客户端已经断开收不到了
37	0.000053987	3306	30260	mysql > kingdomsonline [FIN, ACK] Seq=1742 Ack=1335 Win=32128 Len=0
38	0.000165707	30260	3306	kingdomsonline > mysql [RST] Seq=1335 Win=0 Len=0 //连接都断开了，客户端已经退出，客户端的OS代发reset 
39	0.000017860	30260	3306	kingdomsonline > mysql [RST] Seq=1335 Win=0 Len=0
40	0.000082025	30260	3306	kingdomsonline > mysql [RST] Seq=1335 Win=0 Len=0

如果你的 tshark 版本较高，以上命令行可以改为：

1
tshark -i lo -Y "tcp.port==3306" -T fields -e frame.number -e frame.time_delta -e tcp.srcport -e tcp.dstport -e _ws.col.Info -e mysql.query

GPT4.0 Turbo 对上面这个 tshark 命令的解释：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
你提到的命令使用tshark捕获在端口3306（MySQL的默认端口）上的网络流量，并提取特定的字段进行显示。tshark是Wireshark的命令行版本，一个非常强大的网络协议分析工具。

这条命令的组成部分解释如下：

-i eth0: 指定tshark监听eth0接口上的流量。这是网络接口的名称，可以根据实际情况进行修改。

port 3306: 指定tshark只捕获目标或源端口为3306的TCP流量，这是MySQL服务器监听的标准端口。

-T fields: 设置tshark的输出格式为字段值（fields），意味着输出将以列的形式显示指定的字段。

-e frame.number: 添加一个字段，显示每个捕获的帧的编号。

-e frame.time_delta: 添加一个字段，显示自上一帧以来经过的时间（以秒为单位）。

-e tcp.srcport: 添加一个字段，显示TCP源端口号。

-e tcp.dstport: 添加一个字段，显示TCP目标端口号。

-e col.Info: 添加一个字段，显示捕获帧的信息列。

-e mysql.query: 添加一个字段，如果捕获的TCP流量是MySQL流量，显示MySQL查询。

这个命令的输出将是以空格分隔的列，每一列代表上述参数指定的一个字段。每一行代表一个捕获的网络帧，其中包含MySQL查询。

请注意，由于这个命令包含了mysql.query，它需要tshark能够解析MySQL协议。而且，如果MySQL流量是加密的（例如使用SSL/TLS），那么tshark将无法直接显示查询内容。

在运行这个命令前，你需要有足够的权限来捕获网络流量，通常需要root权限或者足够的权限来访问网络接口。如果你不是root用户，可以使用sudo运行tshark命令。

sudo tshark -i eth0 port 3306 -T fields -e frame.number -e frame.time_delta -e tcp.srcport -e tcp.dstport -e col.Info -e mysql.query
这个命令将实时显示MySQL查询相关的流量信息。如果你想要保存结果到一个文件，可以使用重定向或-w选项。如果只想要捕获一定数量的包，可以使用-c选项后跟要捕获的包的数量。

最后用一张大截图来演示这个实验：

image-20240111121421625

PreparedStatement 验证

测试代码，用Prepared执行三次查询：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
                PreparedStatement stmt = conn.prepareStatement(sql);
//                stmt.setFetchSize(Integer.MIN_VALUE);
                stmt.setString(1, interval);
                ResultSet rs = stmt.executeQuery();
                rs.close();
                stmt.close();

                PreparedStatement stmt2 = conn.prepareStatement(sql);
                stmt2.setString(1, interval);
                rs = stmt2.executeQuery();
                //Thread.sleep(60000);
                while (rs.next()) {
                        System.out.println("fine");
                }
                rs = stmt2.executeQuery();
                //Thread.sleep(60000);
                while (rs.next()) {
                        System.out.println("fine");
                }
                rs.close();
                stmt2.close();

如图绿色是Prepared过程不会真执行 Select 查数据，只是把这条SQL 发给Server，让Server 提前编译，可以看出来编译时间0.000146秒(绿色方框)，因为SQL 非常简单；三个红色线分别是3次真正的查询，都走了Prepared(不再传 Select了)，不过时间很不稳定，所以这个统计必须大批量。红色方框是三次通过Prepared 执行 Select 查数据的执行时间：

image-20240322103643718

结论

作为一个CRUD boy从以上实验中你可以学到哪些东西？

  • 客户端报错堆栈要熟悉，Communications link failure (很多原因可以导致这个错误哈)和 java.net.SocketTimeoutException: Read timed out
  • JDBC 连接参数要配置socketTimeout，不配置会导致很多很多故障，显得CRUD boy太业余
  • 抓包，从抓包中学到每个动作，反过来分析原因，比如这次报错就是客户端发送了查询过1.7秒主动断开，所以问题在客户端，1.7秒也要敏感
  • 最重要的是学到这个实验过程，比如再自己去试试分析 PreparedStatement 的工作原理，如何才能让 PreparedStatement 生效

进一步学习

你可以把抓包保存，然后下载到wireshark中，能看到具体每一个包的详细内容，比如加密后的密码、Prepared statement是个啥(一个唯一id)

比如明明MySQL Server感知到了连接断开错误(Message: Got an error reading communication packets) 还要挣扎着返回这个错误信息给客户端有必要吗？

java 跑着，直接kill -9 java-pid 看看服务端收到什么包？(有经验后下次看到这样的症状就知道为啥了)

参考

MySQL 1158错误信息的详细意思

mysql jdbc driver

后续 Debug

为啥我的Java 代码跑半天也不报错：

image-20240115090336526

jstack -p java-pid ，可以看到main 卡在执行SQL 后等结果的堆栈里，所以不是Java sleep了，等看对端MySQL 在干什么

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f6a5c0db000 nid=0x109d8e in Object.wait() [0x00007f6a60a75000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000f6b08d90> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:502)
        at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
        - locked <0x00000000f6b08d90> (a java.lang.ref.Reference$Lock)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=0 tid=0x00007f6a5c04b000 nid=0x109d8a runnable [0x00007f6a638e9000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:171)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101)
        at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144)
        at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174)
        - locked <0x00000000f6b71370> (a com.mysql.jdbc.util.ReadAheadInputStream)
        at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3008)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3469)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3459)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3900)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2527)
        at com.mysql.jdbc.ServerPreparedStatement.serverExecute(ServerPreparedStatement.java:1283)
        - locked <0x00000000f6b0a228> (a com.mysql.jdbc.JDBC4Connection)
        at com.mysql.jdbc.ServerPreparedStatement.executeInternal(ServerPreparedStatement.java:783)
        - locked <0x00000000f6b0a228> (a com.mysql.jdbc.JDBC4Connection)
        at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1966)
        - locked <0x00000000f6b0a228> (a com.mysql.jdbc.JDBC4Connection)
        at Test.main(Test.java:30)

"VM Thread" os_prio=0 tid=0x00007f6a5c0d1000 nid=0x109d8d runnable

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f6a5c05e000 nid=0x109d8b runnable

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f6a5c060000 nid=0x109d8c runnable

抓包

为啥抓不到任何包？

image-20240115090420370

先确认3306 端口是你的MySQL 在跑：

1
2
3
# ss -lntp |grep 3306
LISTEN 0      151                *:3306             *:*    users:(("mysqld",pid=1023638,fd=22))
LISTEN 0      70                 *:33060            *:*    users:(("mysqld",pid=1023638,fd=20))

:3306 中的‘“” 表示MySQLD 监听本机任何网卡的3306端口，查看一下网卡名字：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
# 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: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc fq_codel state UP group default qlen 1000
    link/ether 00:16:3e:39:b5:e0 brd ff:ff:ff:ff:ff:ff
    altname enp0s5
    altname ens5
    inet 172.17.151.5/20 brd 172.17.159.255 scope global dynamic noprefixroute eth0
       valid_lft 309352989sec preferred_lft 309352989sec
    inet6 fe80::216:3eff:fe39:b5e0/64 scope link
       valid_lft forever preferred_lft forever
3: cni-podman0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
    link/ether de:a8:06:82:76:00 brd ff:ff:ff:ff:ff:ff
    inet 10.88.0.1/16 brd 10.88.255.255 scope global cni-podman0
       valid_lft forever preferred_lft forever
    inet6 fe80::dca8:6ff:fe82:7600/64 scope link
       valid_lft forever preferred_lft forever
4: veth82cad224@if2: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master cni-podman0 state UP group default
    link/ether 4e:1b:4a:0d:a9:e2 brd ff:ff:ff:ff:ff:ff link-netns netns-58786150-bf63-2ae1-242f-cf221eed34fe
    inet6 fe80::4c1b:4aff:fe0d:a9e2/64 scope link
       valid_lft forever preferred_lft forever

尝试 tshark -i any – any是个什么鬼，展开学习下抓包参数

这里对select sleep 不确定的话可以Google sleep的单位、用法；也可以MySQL Client 验证一下

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
# mysql -h127.1  -uroot -p123
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> select sleep(1.4);
+------------+
| sleep(1.4) |
+------------+
|          0 |
+------------+
1 row in set (1.40 sec)

为什么不用mysql client做这个SocketTimeout的实验：mysql似乎没有SocketTimeout这个参数：
mysql --help |grep -i time
                      and reconnecting may take a longer time. Disable with
  --connect-timeout=# Number of seconds before connection timeout.
connect-timeout                           0

终于能抓到包了

image-20240115090938622

Kill Java

1
2
3
4
5
6
7
8
9
10
11
12
56	0.014671013	40102	3306	Request Prepare Statement	select sleep(60), id from sbtest1 where id= ?
57	0.000253230	3306	40102	Response
58	0.000173110	40102	3306	40102 → 3306 [ACK] Seq=1312 Ack=1570 Win=65536 Len=0 TSval=478689604 TSecr=478689604
59	0.000602784	40102	3306	Request Execute Statement
60	0.040903127	3306	40102	3306 → 40102 [ACK] Seq=1570 Ack=1334 Win=65536 Len=0 TSval=478689645 TSecr=478689604


77	0.397023820	40102	3306	40102 → 3306 [FIN, ACK] Seq=1334 Ack=1570 Win=65536 Len=0 TSval=478705206 TSecr=478689645
78	0.040424926	3306	40102	3306 → 40102 [ACK] Seq=1570 Ack=1335 Win=65536 Len=0 TSval=478705246 TSecr=478705206
83	0.793390527	3306	40102	Response
84	0.000016522	40102	3306	40102 → 3306 [RST] Seq=1335 Win=0 Len=0

mysql kill pid

1
2
3
4
5
6
7
8
# tshark -i lo -Y "tcp.port==59636" -T fields -e frame.number -e frame.time_delta -e tcp.srcport -e tcp.dstport -e _ws.col.Info -e mysql.query
Running as user "root" and group "root". This could be dangerous.
Capturing on 'Loopback'
//
85	0.000042261	3306	59636	3306 → 59636 [FIN, ACK] Seq=1 Ack=1 Win=512 Len=0 TSval=478849322 TSecr=478831136
92	0.008106470	59636	3306	59636 → 3306 [FIN, ACK] Seq=1 Ack=2 Win=512 Len=0 TSval=478849333 TSecr=478849322
93	0.000008612	3306	59636	3306 → 59636 [ACK] Seq=2 Ack=2 Win=512 Len=0 TSval=478849333 TSecr=478849333

kill mysqld pid

1
2
3
4
5
6
7
8
9
]# tcpdump -i lo port 50436
dropped privs to tcpdump
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on lo, link-type EN10MB (Ethernet), capture size 262144 bytes


09:32:50.138291 IP localhost.mysql > localhost.50436: Flags [F.], seq 206507581, ack 2788331892, win 512, options [nop,nop,TS val 479088777 ecr 479041791], length 0
09:32:50.150621 IP localhost.50436 > localhost.mysql: Flags [F.], seq 1, ack 1, win 512, options [nop,nop,TS val 479088789 ecr 479088777], length 0
09:32:50.150640 IP localhost.mysql > localhost.50436: Flags [.], ack 2, win 512, options [nop,nop,TS val 479088789 ecr 479088789], length 0

视频学习

如果你也想试试这个实验的话，可以参考我们的视频：https://meeting.tencent.com/user-center/shared-record-info?id=c0962ad4-16bc-4ac8-83ab-2e302c372e73&is-single=false&record_type=2&from=3

如果你觉得看完对你很有帮助可以通过如下方式找到我

find me on twitter: @plantegg

知识星球：https://t.zsxq.com/0cSFEUh2J

开了一个星球，在里面讲解一些案例、知识、学习方法，肯定没法让大家称为顶尖程序员(我自己都不是)，只是希望用我的方法、知识、经验、案例作为你的垫脚石，帮助你快速、早日成为一个基本合格的程序员。

争取在星球内：

  • 养成基本动手能力
  • 拥有起码的分析推理能力–按我接触的程序员，大多都是没有逻辑的
  • 知识上教会你几个关键的知识点
image-20240324161113874 
1
2
3
JDBC客户端MySQL服务器初始化阶段建立数据库连接连接成功配置参数socketTimeout=1459msnetTimeoutForStreamingResults=1s设置流式查询setAutoCommit(false)setFetchSize(Integer.MIN_VALUE)执行查询: SELECT * FROM data_table开始准备结果集返回第一批数据开始处理第一条数据Thread.sleep(1500ms)net_write_timeout计时开始(1s)等待客户端处理...1秒后超时关闭连接仍在sleep(1500ms)尝试读取下一条数据连接已关闭抛出CommunicationsExceptionJDBC客户端MySQL服务器


发表于 更新于 分类于

无招胜有招–一周年总结

大家抱着美好和雄赳赳的目标来到这个知识星球，开始的时候兴奋地以为找到了银弹(其实银弹是有的，在文章最后)，经过一段时间后大概率发现没什么变化，然后就回到了以前的老路子上，我觉得关键问题是你没获取到星球的精华，所以这篇我打算反复再唠叨一下

知识效率 工程效率

虽然我们现在通过这篇《知识效率 工程效率》知道了两者的差别， 但是还是需要记住通过积累可以将我们的学习能力从工程效率升级到知识效率(厚积薄发)，大部分时候没有做到薄发，是因为你以为理解了、积累了实际没理解

核心知识点

尽力寻找每个领域的核心知识点，核心知识点的定义就是通过一两个这样的知识点能撬动对整个领域的理解，也就是常说的纲挈目张

比如网络领域里：一个网络包是怎么流转的+抓包。假如你理解网络包的流转后再去看LVS 负载均衡的原理你就发现只需要看一次你就能很好掌握LVS各个负载均衡的本质，而在这之前你反复看反复忘。掌握了这个知识点基本就可以通关整个领域，剩下的只是无招胜有招碰到一个挨个积累的问题了。

比如CPU领域理解超线程+IPC+会用perf和内存延时，理解超线程的本质是为什么一个核能干两个核的工作(这和操作系统的分时多任务背后原理是想通的)，那是因为我们的程序没法吃满流水线(也就是没法用完一个核的计算能力，用IPC去衡量)，没吃满闲置的时候就可以虚拟给另外一个进程用，比如CPU 跑起来最高IPC都能到4，但是无论你找一个Java还是MySQL 去看他们的IPC基本都在1以内，纯计算场景的IPC会高一点，IPC 可以到4但只跑到1的话也就是只用满了25%的能力，那当然可以再虚出来一个超线程提高效率。IPC 之所以低就是因为内存延时大，这么多年CPU的处理能力一直按摩尔定律在提升但是内存延时没有怎么提升，导致基本上我们常见的业务场景(Nginx/MySQL/Redis 等)都是CPU在等从内存取数据(所以搞了L1、L2、L3一堆cache)。

发散一下或者说留个作业你去看看NUMA 的原理或者说本质就是为了让CPU知道就近分配读取内存以提升效率。

你看整本计算机组成原理+性能的本质都在这一个知识点的范围内进行延伸和突破。

如果你发现一个核心知识点也欢迎写成博客文章分享出来

读日志、错误信息

我的经验只是大概20%左右的程序员会去耐心读别人的日志、报错信息，大部分摊摊手求助、放弃了

日志是最好的学习机会，我知道别人的日志写得很烂，但是你要能耐心多琢磨一点就会比别人更专业一点

对知识的可观测性

抓包、perf的使用这些平时要多积累，这点没有捷径，一个好的工程师肯定有一堆好的锤子、瑞士军刀、工具包的。在你掌握了知识点后要转化为工作效率，就得多积累这些工具，很多次我们碰到一个好的问题没分析出来是因为我们这种没有门槛的积累不够导致放弃了

比如需要抓包确认下，不会，一看tcpdump 一堆参数头疼放弃；比如想要知道长连接还是短连接，或者自己设置的长连接有没有生效，不会用netstat -o 这个参数去确认等；比如要下载个源码自己make/install 中间报了几个错误不仔细看放弃；

反过来回到我们所说的工程效率，就是靠这些工具帮你实现可视、可以触摸，网络之所以大多数同学在大学都学过但是最后基本学懂，就是因为这些网络的东东你只看理论很难立即，但是让你抓过一次包分析下就会恍然大悟——这就是关键门槛你能跨过去

好习惯

在星球里我更希望你带走一个好的习惯而不是一个具体知识点，虽然星球里的具体知识点、案例胜过很多教材，但他们总有过时、用不上的时候，唯有好的习惯可以跟随你，帮你实现无招胜有招

记笔记

放低身段，不要高估自己的能力(认为自己是知识效率)，放低后你要怎么做呢：记笔记、记笔记、记笔记

只要是你在学习就要或者看书、看资料的时候觉得自己有点通透了，赶紧记录下来，因为大概率一个星期你就忘了，半年你就完全不记得自己以前看过一次了，我好多次看到一篇好文章就感叹自己学到了，兴奋地拉到文章最后想去评论下，结果发现居然有了自己的评论在下面 :)

动手

动手，看到后理解了，也记了笔记，其实最好还是要自己去重现，记下自己看到的现象和理解，动手又会有一堆门槛，搭环境、客观则、怎么验证等等，这个时候我前面说的可观测性里面积累的一大堆工具可以让你如有神助、重现起来效率就是比别人高

汇总输出

最后笔记记完还没完，笔记基本是零散的，你反复积累后到了一定的时机就是要把他们总结汇总成一篇完整度较高的博客文章，这里当然有自己的虚荣心在这里，但更多的是为了自己查询方便，有了新的理解或者使用姿势我经常更新补充10年前的博客文章，不会写一篇新的，这个补充知识让我的知识结构更完善，不是为了多发一篇博文，我现在解决问题、使用工具基本要靠翻自己的博客文章照着操作

慢就是快、少就是多

往往我们喜欢求快，以为自己一看就懂；求多以为自己越看的多越厉害

不要等着时间流投喂

看这篇置顶：https://t.zsxq.com/14Yel6KBg

纲举目张

对公司的业务、一个软件的运转流程都要尽量做到理解

比如学MySQL 要尽量知道从一条SQL 怎么进来，进行哪些处理后得到了查询结果；比如前面讲过的一个网络包是怎么到达对端的；比如你们公司的请求是怎么从客户端到达服务端(中间经过了LVS、Nginx吗)，服务端又是那些服务得依赖和调用，有没有Redis、MQ、Database，最后数据又是怎么返回的，我知道这在一个公司很难(屎山很复杂)，但目前没有更好的方法让你快速掌握并立足

为什么出现问题后总有一两个人很快能猜出来问题可能在哪个环节，这一部分是经验但更多的是对系统的了解，你都不知道有Redis存在一旦出错了你肯定猜不到Redis这里来

可以看看我之前说的实习生的故事，完全真实哈：

讲一个我碰到的实习生的事情

北邮毕业直接后直接到我司实习

特点：英语好、动手能力强、爱琢磨，除了程序、电脑没有其它爱好 :)

实习期间因为英语好把我司文档很快就翻烂了，对产品、业务逻辑的理解基本是顶尖的

实习期间很快成为所有老员工的红人，都离不开他，搭环境、了解业务流程

因为别人的习惯都是盯着自己眼前的这一趴，只有他对业务非常熟悉

实习后很快就转正了，又3年后transfer 去了美国总部

连女朋友都是老员工给牵线的，最后领证一起去了美国。为啥老员工这么热情，是大家真心喜欢他

再看看张一鸣自述的第一年的工作：

img

总结

我前面所说的我也没做太好，希望大家能做得更好，我第一次感受无招胜有招就是故事一里面，到故事二过去差不多10年，这10年里我一直在琢磨怎么才能无招胜有招，也有在积累，但是花了10年肯定效率不算高，所以在星球里我希望通过我的经验帮你们缩短一些时间

上面讲再多如果你只是看看那根本还是没用，买再多的课也没用，关键是看触动后能否有点改变。你可以从里面试着挑几个你认为容易操作，比如记笔记、比如不要等着时间流投喂，或者有感触的试试先改变或者遵循下看看能不能获得一些变化进而形成正向循环

或者从评论里开始说说你星球这一年真正有哪些改变、学到了啥、你的感悟，不方便的也可以微信我私聊一下

这篇就当成整个星球学习的一个总结吧

发表于 更新于 分类于

网球肘 过劳性(持续)肌腱病的治疗

因为长期打球，导致手肘部分疼痛难耐，2024年1月开始进行了长时间的休息期，中间2024的2月是春节，所以总共修了快2个月，还不见好，于是去医院，其实医院给的治疗方案也不好，但是医师告诉了我一个关键词这个病叫：网球肘

知道关键词后就开始了自我寻求治疗方案的过程，记下来供参考，到2024年3月14号，最近两周多次打球验证我的网球肘基本好了，所以说一下治疗过程

个人总结

网球肘的核心是肌肉过劳发炎了，所以关键是如何消炎

一定要用：氟比洛芬凝胶贴膏 ，而且每天两贴尽量不要断，期间通过大拇指使劲按压疼痛部分来感受验证的减轻，一般连续贴3-5天会有明显的效果，如果无效请去医院

口服消炎药也可以试试，我估计针对性不强(瞎猜的，希望你试试后来告诉我)。至于体外冲击波可以尝试尝试，我个人的经验觉得还不足以证明其有效

后面的可以不用看了

治疗

网球肘已经有几个月了，开始我没在意以为就是肌肉劳累，休息休息就会好，直到过年的时候我真正歇了一个多月，过完年偶尔一用力居然又开是疼，让我计划去医院看看，之前自己在社区医院开过几盒：氟比洛芬凝胶贴膏

image-20240305141525956

(家中请常备这个药，膏药里的神奇)

【适应症】
下列疾病及症状的镇痛、消炎：
骨关节炎、肩周炎、肌腱及腱鞘炎、腱鞘周围炎、肱骨外上髁炎 ( 网球肘 )、肌肉痛、外伤所致肿胀、疼痛

过年期间自己也偶尔贴一下，但是效果不明显(应该是没有连续贴导致的效果不好)。

这次去医院正规想看看，但是大医院挂不上号，于是去了一个小医院(社区医院推荐的，说这家别的不行，刚好看运动医学还不错)，到医院大夫一听就笑着问我知不知道有一种病叫：网球肘。这是我第一次听说这个病，大夫用大拇指按压我的伤口附近，确实非常疼，结合我经常打球基本确诊。

然后给我开了两次体外冲击波物理治疗，当场治疗了一次，过程中很痛，打完的当时再按压就不疼了，但是过几个小时还是照旧(这也在医师的预料中)，给我开了两次这个治疗，我只去了一次

体外冲击波疗法（extracorporeal shock wave therapy, ESWT）是一种非侵入性、安全、有效治疗多种疾病的方法，在临床多个学科中得到了广泛应用，但临床应用不规范、治疗关键技术不一致、治疗方案不统一、培训体系不健全等问题严重制约了ESWT的临床推广应用。

https://rs.yiigle.com/CN101658202302/1459029.htm#:~:text=%E4%BD%93%E5%A4%96%E5%86%B2%E5%87%BB%E6%B3%A2%E7%96%97%E6%B3%95%EF%BC%88extracorporeal%20shock,ESWT%E7%9A%84%E4%B8%B4%E5%BA%8A%E6%8E%A8%E5%B9%BF%E5%BA%94%E7%94%A8%E3%80%82

回到家我就开始了对“网球肘”的学习，中间找到这篇最关键的经验贴【你一定要看】，我把这里面最有价值的引用一下：

比较对症的治疗方法是，内服 洛索洛芬钠片，外贴 氟比洛芬凝胶贴膏（商标是泽普思），尤其要注意用量和时机

  • 洛索洛芬钠片——我这次没吃这个

    • 一日三次，每次两片（60mg/片）
    • 饭后服用（切记！）

  • 氟比洛芬凝胶贴膏——这点最重要，我不再像以前一样偶尔贴，而是连续一周每天两贴

    • 每次一帖，白天/晚上 各一帖
    • 除了洗澡之外，尽量连续贴

按照上面的做法，经过5天后我的网球肘真的神奇地好了，中间还阳了3天(所以第二次冲击波治疗我也没去)

经验

我的判断是网球肘消炎很重要，应该还是氟比洛芬凝胶贴膏起了关键作用，但是要注意：连续贴一周，每天两贴

至于冲击波是否有效果，我目前觉得可能有效果，但是证据还不够

知道这个病的名字很重要，这样就有了搜索关键字，看别人描述相对来说我这次不算严重

UpToDate 临床顾问

知道名字后，我在淘宝上购买了 UpToDate 临床顾问论文库的账号(收录了几乎所有的医学论文，但是只对收费会员开放)，专业点说如果你好好研究 UpToDate，再结合自身状况可以得到比很多专业医师更专业的治疗

但是这次查到的治疗方案都是普通的消炎、镇痛(对乙氨基酚)等，但是不妨碍你下次可以继续到这里查，一般买个3天的账号才几块钱

image-20240305145408804

另外也推荐大家看默沙东手册(完全免费，有网页和app版本)：

image-20240305145706453

自我检查

自己按压疼痛的地方确认在什么地方，结合平时的运动和习惯，是否恢复也可以通过按压和发力来确认

非甾体类抗炎药(NSAID)

非甾体抗炎药（non-steroidal anti-inflammatory drugs，NSAIDs）又称非类固醇抗炎药，简称非甾体类，是一类具有解热镇痛效果的药物，在施用较高剂量时也具有消炎作用。

NSAID 包括布洛芬（Advil、Motrin IB 等）、萘普生纳（Aleve、Anaprox DS 等）、双氯芬酸钠和塞来昔布（Celebrex）

非甾体抗炎药中，属阿司匹林、伊布洛芬、甲芬那酸、萘普生最为著名，在绝大多数国家都可作为非处方药销售[4]。

对乙酰氨基酚因其抗炎作用微弱，而通常不被归为非甾体抗炎药，它主要通过抑制分布在中枢神经系统的环氧合酶-2，以减少前列腺素的生成，从而缓解疼痛，但由于环氧合酶-2在周边组织中数量较少，因此作用微弱

抗炎治疗

抗炎治疗 — 尽管抗炎治疗多年来都是肘部肌腱病的主要疗法，但支持性证据仅来自成功个案和极少数研究。在医学界对肌腱病有了科学认识之后，抗炎疗法对肘部肌腱病和其他慢性退行性肌腱病的作用也出现了争议。抗炎治疗包括冰敷、NSAID、离子透入疗法和注射糖皮质激素。对于LET，冰敷联合离心力量及柔韧性训练并未优于单纯离心力量训练[51]。(参见上文[‘病理生理学’](http://www.uptodate.zd.hggfdd.top/contents/zh-Hans/elbow-tendinopathy-tennis-and-golf-elbow?search=Tennis Elbow 冲击波&source=search_result&selectedTitle=3~150&usage_type=default&display_rank=3#H4))

体外冲击波疗法（extracorporeal shock wave therapy, ESWT）

体外震波治疗和其他电物理疗法 — 声波已用于治疗慢性LET。总体而言，支持体外震波治疗(extracorporeal shock wave therapy, ESWT)和其他“电物理”疗法的证据并不令人信服，所以我们不予以推荐[82]。该操作通常会令患者不适，但有些研究显示ESWT有一定益处[83]，但也有许多研究未发现ESWT有益[84,85]。

体外冲击波疗法临床应用中国疼痛学专家共识 2023版

定义

“网球肘 ”(TenniS Elbow)又名肱骨外上髁炎 (1ateralepicondylitis)，以网球运动 员发病率高 而得名

广义 的网球肘可分 为具有不同临床特点的四个类型 :

  1. 外侧网球肘 :亦称肱骨外上髁炎 ，即经典的网 球肘 ，主要累及附于肱骨外上髁的桡侧腕短伸肌腱起 点。
  2. 内侧网球肘:亦称肱骨内上髁炎或高尔夫球肘， 主要 累及附于 肱骨 内上髁 的屈肌 和旋前 圆肌腱 起 点。
  3. 后侧网球肘 :亦称三头肌腱炎 。
  4. 混合型网球 肘 :内外侧网球肘同时发生 ，并不少见

读懂医疗发票

自付二：对有自付的药品、检查费收取自费部分；比如药品：10%或50%；检查费：8%；材料费：30%；——可以理解为医保不管的全自付

自付一：根据下图，报销比例是90%，也就是你还要出总医药费的10%；但是要注意总医药费要减掉自付二的部分 —— 医保报销之外要自付的部分，比如未满起付线；满了起付线的 30%

举例：一张发票开了一盒泰诺(酚麻美敏片) 13.47块(乙类清单 10%自付)，还有一盒没有无自付的头孢 5.17块，共18.64

最后发票显示自付二：1.35 就是13.47 的10% ——这个10%是因为该药有部分自费，自付一：1.73 是 (18.64-(13.47X10%))X10% ——这个10%就是达到起付线1800后报销90% 比如 CT 平扫收费 135，属于有自付的自付 2，自付钱是：135*8%=10.8 这 10.8 在商保里不报

如果你没有达到起付线，就是100%自付，那么不存在自付二，付款金额全部显示为自付一

image-20250211115151569

image-20250211114917084

一般商保赔付逻辑：自付 1 赔 100%；自付 2 不赔；超过 1800 起付线后剩下的自付部分 90% 赔(去掉自付 2 后)

超过起付线后：(账单-自付 2)*90%（社区 90/医院 70）= 自付 1

职工基本医疗保险门（急）诊待遇标准

痛风

痛风是由于血中尿酸含量过高（高尿酸血症）而导致尿酸盐结晶沉积在关节内的疾病。沉积的结晶导致关节内和关节周围出现疼痛性炎症的发作。通常具有家族遗传性

痛风在男性中的发病率高于女性。男性痛风患者较女性常见，通常发生在中年男性和绝经期后的女性。很少发生于年轻人，但如果小于 30 岁的人发生痛风，其病情一般较重。

食物和痛风没关系。如果发作了就吃止痛药。不疼的时候吃非布司他（找医生开，这是处方药）。定期检查尿酸是否有降下来。 然后非常容易被忽视的一点是注意别喝含糖饮料，干脆戒掉。

而止痛的药物无非是：

  • 非甾体抗炎药（NSAIDs）
  • 秋水仙碱
  • 糖皮质激素

秋水仙碱或秋水仙素，考虑到其肝肾毒性，我是肯定坚决不吃。至于糖皮质激素，也就是俗称的激素，偶尔用一次或许也可以接受，但不能持续用

风湿性多肌痛

风湿性多肌痛是关节滑膜的炎症，是一种能引起颈、肩、髋部肌肉疼痛和僵硬的疾病。

风湿性多肌痛发病年龄在 55 岁以上，原因尚不清楚。女性的患病率较男性高。风湿性多肌痛的病因尚不清楚。风湿性多肌痛可与 巨细胞（颞）动脉炎同时出现，也可在它之前或之后出现。有学者认为这两种疾病是同一种病变的不同表现。风湿性多肌痛似乎比巨细胞动脉炎更常见。

类风湿性关节炎 (RA)

类风湿性关节炎是一种炎症性关节炎，表现为关节的炎症，受累关节通常包括手脚关节，可导致关节肿胀、疼痛以及常常遭到破坏。

0%