Linux内核版本升级，性能到底提升多少？

背景

X 产品在公有云售卖一直使用的2.6.32的内核，有点老并且有些内核配套工具不能用，于是想升级一下内核版本。预期新内核的性能不能比2.6.32差

以下不作特殊说明的话都是在相同核数的Intel(R) Xeon(R) Platinum 8163 CPU @ 2.50GHz下得到的数据，最后还会比较相同内核下不同机型/CPU型号的性能差异。

场景都是用sysbench 100个并发跑点查。

结论

先说大家关心的数据，最终4.19内核性能比2.6.32好将近30%，建议大家升级新内核，不需要做任何改动，尤其是Java应用（不同场景会有差异）

本次比较的场景是Java应用的Proxy类服务，主要瓶颈是网络消耗，类似于MaxScale。后面有一个简单的MySQL Server场景下2.6.32和4.19的比较，性能也有33%的提升。

2.6.32性能数据

升级前先看看目前的性能数据好对比（以下各个场景都是CPU基本跑到85%）

一波N折的4.19

阿里云上默认买到的ALinux2 OS（4.19），同样配置跑起来后，tps只有16000，比2.6.32的22000差了不少，心里只能暗暗骂几句坑爹的货，看了下各项指标，看不出来什么问题，就像是CPU能力不行一样。如果这个时候直接找内核同学，估计他们心里会说 X 是个什么东西？是不是你们测试有问题，是不是你们配置的问题，不要来坑我，内核性能我们每次发布都在实验室里跑过了，肯定是你们的应用问题。

所以要找到一个公认的场景下的性能差异。幸好通过qperf发现了一些性能差异。

通过qperf来比较差异

大包的情况下性能基本差不多，小包上差别还是很明显

qperf -t 40 -oo msg_size:1  4.19 tcp_bw tcp_lat
tcp_bw:
    bw  =  2.13 MB/sec
tcp_lat:
    latency  =  224 us
tcp_bw:
    bw  =  2.15 MB/sec
tcp_lat:
    latency  =  226 us

qperf -t 40 -oo msg_size:1  2.6.32 tcp_bw tcp_lat
tcp_bw:
    bw  =  82 MB/sec
tcp_lat:
    latency  =  188 us
tcp_bw:
    bw  =  90.4 MB/sec
tcp_lat:
    latency  =  229 us

这下不用担心内核同学怼回来了，拿着这个数据直接找他们，可以稳定重现。

经过内核同学排查后，发现默认镜像做了一些安全加固，简而言之就是CPU拿出一部分资源做了其它事情，比如旁路攻击的补丁之类的，需要关掉（因为 X 的OS只给我们自己用，上面部署的代码都是X 产品自己的代码，没有客户代码，客户也不能够ssh连上X 产品节点）

去掉 melt、spec 能到20000， 去掉sonypatch能到21000 

关闭的办法在 /etc/default/grub 里 GRUB_CMDLINE_LINUX 配置中增加这些参数：

nopti nospectre_v2 nospectre_v1 l1tf=off nospec_store_bypass_disable no_stf_barrier mds=off mitigations=off

关掉之后的状态看起来是这样的：

$sudo cat /sys/devices/system/cpu/vulnerabilities/*
Mitigation: PTE Inversion
Vulnerable; SMT Host state unknown
Vulnerable
Vulnerable
Vulnerable: __user pointer sanitization and usercopy barriers only; no swapgs barriers
Vulnerable, STIBP: disabled

这块参考阿里云文档 和这个

开启漏洞补丁（性能差）：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

# uname -r
4.19.91-24.8.an8.x86_64

# cat /proc/cmdline
BOOT_IMAGE=(hd0,gpt2)/vmlinuz-4.19.91-24.8.an8.x86_64 root=UUID=ac9faf02-89c6-44d8-80b2-0f8ea1084fc3 ro console=tty0 crashkernel=auto console=ttyS0,115200 crashkernel=0M-2G:0M,2G-8G:192M,8G-:256M
[root@Anolis82 ~]# sudo cat /sys/devices/system/cpu/vulnerabilities/*
KVM: Mitigation: Split huge pages
Mitigation: PTE Inversion; VMX: conditional cache flushes, SMT vulnerable
Mitigation: Clear CPU buffers; SMT vulnerable
Mitigation: PTI
Mitigation: Speculative Store Bypass disabled via prctl and seccomp
Mitigation: usercopy/swapgs barriers and __user pointer sanitization
Mitigation: Full generic retpoline, IBPB: conditional, IBRS_FW, STIBP: conditional, RSB filling
Not affected
Mitigation: Clear CPU buffers; SMT vulnerable

关闭（性能好）：

1
2
3
4
5
6
7
8
9
10
11
12

[root@Anolis82 ~]# sudo cat /sys/devices/system/cpu/vulnerabilities/*
KVM: Vulnerable
Mitigation: PTE Inversion; VMX: vulnerable
Vulnerable; SMT vulnerable
Vulnerable
Vulnerable
Vulnerable: __user pointer sanitization and usercopy barriers only; no swapgs barriers
Vulnerable, IBPB: disabled, STIBP: disabled
Not affected
Vulnerable
[root@Anolis82 ~]# cat /proc/cmdline
BOOT_IMAGE=(hd0,gpt2)/vmlinuz-4.19.91-24.8.an8.x86_64 root=UUID=ac9faf02-89c6-44d8-80b2-0f8ea1084fc3 ro console=tty0 crashkernel=auto console=ttyS0,115200 nopti nospectre_v2 nospectre_v1 l1tf=off nospec_store_bypass_disable no_stf_barrier mds=off mitigations=off crashkernel=0M-2G:0M,2G-8G:192M,8G-:256M

4.9版本的内核性能

但是性能还是不符合预期，总是比2.6.32差点。在中间经过几个星期排查不能解决问题，陷入僵局的过程中，尝试了一下4.9内核，果然有惊喜。

下图中对4.9的内核版本验证发现，tps能到24000，明显比2.6.32要好，所以传说中的新内核版本性能要好看来是真的，这下坚定了升级的念头，同时也看到了兜底的方案–最差就升级到4.9

多队列是指网卡多队列功能，也是这次升级的一个动力。看起来在没达到单核瓶颈前，网卡多队列性能反而差点，这也符合预期

继续分析为什么4.19比4.9差了这么多

4.9和4.19这两个内核版本隔的近，比较好对比分析内核参数差异，4.19跟2.6.32差太多，比较起来很困难。

最终仔细对比了两者配置的差异，发现ALinux的4.19中 transparent_hugepage 是 madvise ,这对 Java应用来说可不是太友好：

$cat /sys/kernel/mm/transparent_hugepage/enabled
always [madvise] never

将其改到 always 后4.19的tps终于稳定在了28300

这个过程中花了两个月的一些其他折腾就不多说了，主要是内核补丁和transparent_hugepage导致了性能差异。

transparent_hugepage，在redis、mongodb、memcache等场景（很多小内存分配）是推荐关闭的，所以要根据不同的业务场景来选择开关。

透明大页打开后在内存紧张的时候会触发sys飙高对业务会导致不可预期的抖动，同时存在已知内存泄漏的问题，我们建议是关掉的，如果需要使用，建议使用madvise方式或者hugetlbpage

一些内核版本、机型和CPU的总结

到此终于看到不需要应用做什么改变，整体性能将近有30%的提升。 在这个测试过程中发现不同CPU对性能影响很明显，相同机型也有不同的CPU型号（性能差异在20%以上–这个太坑了）

性能方面 4.19>4.9>2.6.32

没有做3.10内核版本的比较

以下仅作为大家选择ECS的时候做参考。

不同机型/CPU对性能的影响

还是先说结论：

• CPU:内存为1:2机型的性能排序：c6->c5->sn1ne->hfc5->s1
• CPU:内存为1:4机型的性能排序：g6->g5->sn2ne->hfg5->sn2

性能差异主要来源于CPU型号的不同

c6/g6:                  Intel(R) Xeon(R) Platinum 8269CY CPU @ 2.50GHz
c5/g5/sn1ne/sn2ne:      Intel(R) Xeon(R) Platinum 8163 CPU @ 2.50GHz

8269比8163大概好5-10%，价格便宜一点点，8163比E5-2682好20%以上，价格便宜10%（该买什么机型你懂了吧，价格是指整个ECS，而不是单指CPU）

要特别注意sn1ne/sn2ne 是8163和E5-2682 两种CPU型号随机的，如果买到的是E5-2682就自认倒霉吧

C5的CPU都是8163，相比sn1ne价格便宜10%，网卡性能也一样。但是8核以上的sn1ne机型就把网络性能拉开了（价格还是维持c5便宜10%），从点查场景的测试来看网络不会成为瓶颈，到16核机型网卡多队列才会需要打开。

顺便给一下部分机型的包月价格比较：

官方给出的CPU数据：

4.19内核在MySQL Server场景下的性能比较

这只是sysbench点查场景粗略比较，因为本次的目标是对X 产品性能的改进

（以上表格数据主要由 内核团队和我一起测试得到）

**重点注意2.6.32不但tps差30%，并发能力也差的比较多，如果同样用100个并发压2.6.32上的MySQL，TPS在30000左右。只有在减少并发到20个的时候压测才能达到图中最好的tps峰值：45000. **

新内核除了性能提升外带来的便利性

升级内核带来的性能提升只是在极端场景下才会需要，大部分时候我们希望节省开发人员的时间，提升工作效率。于是X 产品在新内核的基础上定制如下一些便利的工具。

麻烦的网络重传率

通过tsar或者其它方式发现网络重传率有点高，有可能是别的管理端口重传率高，有可能是往外连其它服务端口重传率高等，尤其是在整体流量小的情况下一点点管理端口的重传包拉升了整个机器的重传率，严重干扰了问题排查，所以需要进一步确认重传发生在哪个进程的哪个端口上，是否真正影响了我们的业务。

在2.6.32内核下的排查过程是：抓包，然后写脚本分析（或者下载到本地通过wireshark分析），整个过程比较麻烦，需要的时间也比较长。那么在新镜像中我们可以利用内核自带的bcc来快速得到这些信息

sudo /usr/share/bcc/tools/tcpretrans -l

从截图可以看到重传时间、pid、tcp四元组、状态，针对重传发生的端口和阶段（SYN_SENT握手、ESTABLISHED）可以快速推断导致重传的不同原因。

再也不需要像以前一样抓包、下载、写脚本分析了。

通过perf top直接看Java函数的CPU消耗

这个大家都比较了解，不多说，主要是top的时候能够把java函数给关联上，直接看截图：

sh ~/tools/perf-map-agent/bin/create-java-perf-map.sh pid
sudo perf top

快速定位Java中的锁等待

如果CPU跑不起来，可能会存在锁瓶颈，需要快速找到它们

如下测试中上面的11万tps是解决掉锁后得到的，下面的4万tps是没解决锁等待前的tps：

#[ 210s] threads: 400, tps: 0.00, reads/s: 115845.43, writes/s: 0.00, response time: 7.57ms (95%)
#[ 220s] threads: 400, tps: 0.00, reads/s: 116453.12, writes/s: 0.00, response time: 7.28ms (95%)
#[ 230s] threads: 400, tps: 0.00, reads/s: 116400.31, writes/s: 0.00, response time: 7.33ms (95%)
#[ 240s] threads: 400, tps: 0.00, reads/s: 116025.35, writes/s: 0.00, response time: 7.48ms (95%)

#[ 250s] threads: 400, tps: 0.00, reads/s: 45260.97, writes/s: 0.00, response time: 29.57ms (95%)
#[ 260s] threads: 400, tps: 0.00, reads/s: 41598.41, writes/s: 0.00, response time: 29.07ms (95%)
#[ 270s] threads: 400, tps: 0.00, reads/s: 41939.98, writes/s: 0.00, response time: 28.96ms (95%)
#[ 280s] threads: 400, tps: 0.00, reads/s: 40875.48, writes/s: 0.00, response time: 29.16ms (95%)
#[ 290s] threads: 400, tps: 0.00, reads/s: 41053.73, writes/s: 0.00, response time: 29.07ms (95%)

下面这行命令得到如下等锁的top 10堆栈（async-profiler）：

$~/tools/async-profiler/profiler.sh -e lock -d 5 1560

--- 1687260767618 ns (100.00%), 91083 samples
 [ 0] ch.qos.logback.classic.sift.SiftingAppender
 [ 1] ch.qos.logback.core.AppenderBase.doAppend
 [ 2] ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders
 [ 3] ch.qos.logback.classic.Logger.appendLoopOnAppenders
 [ 4] ch.qos.logback.classic.Logger.callAppenders
 [ 5] ch.qos.logback.classic.Logger.buildLoggingEventAndAppend
 [ 6] ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus
 [ 7] ch.qos.logback.classic.Logger.info
 [ 8] com.*****.logger.slf4j.Slf4jLogger.info
 [ 9] com.*****.utils.logger.support.FailsafeLogger.info
 [10] com.*****.util.LogUtils.recordSql



"ServerExecutor-3-thread-480" #753 daemon prio=5 os_prio=0 tid=0x00007f8265842000 nid=0x26f1 waiting for monitor entry [0x00007f82270bf000]
  java.lang.Thread.State: BLOCKED (on object monitor)
	at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:64)
	- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
	at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
	at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:282)
	at ch.qos.logback.classic.Logger.callAppenders(Logger.java:269)
	at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:470)
	at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:424)
	at ch.qos.logback.classic.Logger.info(Logger.java:628)
	at com.****.utils.logger.slf4j.Slf4jLogger.info(Slf4jLogger.java:42)
	at com.****.utils.logger.support.FailsafeLogger.info(FailsafeLogger.java:102)
	at com.****.util.LogUtils.recordSql(LogUtils.java:115)

          ns  percent  samples  top
  ----------  -------  -------  ---
160442633302   99.99%    38366  ch.qos.logback.classic.sift.SiftingAppender
    12480081    0.01%       19  java.util.Properties
     3059572    0.00%        9  com.***.$$$.common.IdGenerator
      244394    0.00%        1  java.lang.Object

堆栈中也可以看到大量的：

- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- locked <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)
- waiting to lock <0x00007f866dcec208> (a ch.qos.logback.classic.sift.SiftingAppender)

当然还有很多其他爽得要死的命令，比如一键生成火焰图等，不再一一列举，可以从业务层面的需要从这次镜像升级的便利中将他们固化到镜像中，以后排查问题不再需要繁琐的安装、配置、调试过程了。

跟内核无关的应用层的优化

到此我们基本不用任何改动得到了30%的性能提升，但是对整个应用来说，通过以上工具让我们看到了一些明显的问题，还可以从应用层面继续提升性能。

如上描述通过锁排序定位到logback确实会出现锁瓶颈，同时在一些客户场景中，因为网盘的抖动也带来了灾难性的影响，所以日志需要异步处理，经过异步化后tps 达到了32000，关键的是rt 95线下降明显，这个rt下降对X 产品这种Proxy类型的应用是非常重要的（经常被客户指责多了一层转发，rt增加了）。

日志异步化和使用协程后的性能数据：

Wisp2 协程带来的红利

在整个测试过程中都很顺利，只是发现Wisp2在阻塞不明显的场景下，抖的厉害。简单来说就是压力比较大的话Wisp2表现很稳定，一旦压力一般（这是大部分应用场景），Wisp2表现像是一会是协程状态，一会是没开协程状态，系统的CS也变化很大。

比如同一测试过程中tps抖动明显，从15000到50000：

100个并发的时候cs很小，40个并发的时候cs反而要大很多：

最终在 @梁希 同学的攻关下发布了新的jdk版本，问题基本都解决了。不但tps提升明显，rt也有很大的下降。

致谢

感谢 OS/Ali JDK 团队对这次内核版本升级的支持。

最终应用不需要任何改动可以得到 30%的性能提升，经过开启协程等优化后应用有将近80%的性能提升，同时平均rt下降了到原来的60%，rt 95线下降到原来的40%。

快点升级你们的内核，用上协程吧。同时考虑下在你们的应用中用上X 产品。

参考文章

https://help.aliyun.com/document_detail/25378.html

https://help.aliyun.com/document_detail/55263.html

https://help.aliyun.com/document_detail/52559.html (网卡)

Intel PAUSE指令变化如何影响MySQL的性能

导读

x86、arm指令都很多，无论是应用程序员还是数据库内核研发大多时候都不需要对这些指令深入理解，但是 Pause 指令和数据库操作太紧密了，本文通过一次非常有趣的性能优化来引入对 Pause 指令的理解，期望可以事半功倍地搞清楚 CPU指令集是如何影响你的程序的。

文章分成两大部分，第一部分是 MySQL 集群的一次全表扫描性能优化过程； 第二部分是问题解决后的原理分析以及Pause指令的来龙去脉和优缺点以及应用场景分析。

业务结构

为理解方便做了部分简化：

client -> Tomcat -> LVS -> MySQL（32 个 MySQLD实例集群，每个实例8Core）

场景描述

通过 client 压 Tomcat 和 MySQL 集群（对数据做分库分表），MySQL 集群是32个实例，每个业务 SQL 都需要经过 Tomcat 拆分成 256 个 SQL 发送给 32 个MySQL（每个MySQL上有8个分库），这 256 条下发给 MySQL 的 SQL 不是完全串行，但也不是完全并行，有一定的并行性。

业务 SQL 如下是一个简单的select sum求和，这个 SQL在每个MySQL上都很快（有索引）

SELECT SUM(emp_arr_amt) FROM table_c WHERE INSUTYPE='310' AND Revs_Flag='Z' AND accrym='201910' AND emp_no='1050457';

监控指标说明

• 后述或者截图中的逻辑RT/QPS是指 client 上看到的Tomcat的 RT 和 QPS；
• RT ：response time 请求响应时间，判断性能瓶颈的唯一指标;
• 物理RT/QPS是指Tomcat看到的MySQL RT 和QPS（这里的 RT 是指到达Tomcat节点网卡的 RT ，所以还包含了网络消耗）

问题描述：

通过client压一个Tomcat节点+32个MySQL，QPS大概是430，Tomcat节点CPU跑满，MySQL RT 是0.5ms，增加一个Tomcat节点，QPS大概是700，Tomcat CPU接近跑满，MySQL RT 是0.6ms，到这里性能基本随着扩容线性增加，是符合预期的。

继续增加Tomcat节点来横向扩容性能，通过client压三个Tomcat节点+32个MySQL，QPS还是700，Tomcat节点CPU跑不满，MySQL RT 是0.8ms，这就严重不符合预期了。

性能压测原则：

加并发QPS不再上升说明到了某个瓶颈，哪个环节RT增加最多瓶颈就在哪里

到这里一切都还是符合我们的经验的，看起来就是 MySQL 有瓶颈（RT 增加明显）。

排查 MySQL

现场DBA通过监控看到MySQL CPU不到20%，没有慢查询，并且尝试用client越过所有中间环节直接压其中一个MySQL，可以将 MySQL CPU 跑满，这时的QPS大概是38000（对应上面的场景client QPS为700的时候，单个MySQL上的QPS才跑到6000) 所以排除了MySQL的嫌疑(这个推理不够严谨为后面排查埋下了大坑)。

那么接下来的嫌疑在网络、LVS 等中间环节上。

LVS和网络的嫌疑

首先通过大查询排除了带宽的问题，因为这里都是小包，pps到了72万，很自然想到了网关、LVS的限流之类的

pps监控，这台物理机有4个MySQL实例上，pps 9万左右，9*32/4=72万

…………（省略巨长的分析、拉人、扯皮过程）

最终所有网络因素都被排除，核心证据是：做压测的时候反复从 Tomcat 上 ping 后面的MySQL，RT 跟没有压力的时候一样，也说明了网络没有问题(请思考这个 ping 的作用)。

问题的确认

尝试在Tomcat上打开日志，并将慢 SQL 阈值设置为100ms，这个时候确实能从日志中看到大量MySQL上的慢查询，因为这个SQL需要在Tomcat上做拆分成256个SQL，同时下发，一旦有一个SQL返回慢，整个请求就因为这个短板被拖累了。平均 RT 0.8ms，但是经常有超过100ms的话对整体影响还是很大的。

将Tomcat记录下来的慢查询（Tomcat增加了一个唯一id下发给MySQL）到MySQL日志中查找，果然发现MySQL上确实慢了，所以到这里基本确认是MySQL的问题，终于不用再纠结是否是网络问题了。

同时在Tomcat进行抓包，对网卡上的 RT 进行统计分析：

上是Tomcat上抓到的每个sql的物理RT 平均值，上面是QPS 430的时候， RT 0.6ms，下面是3个server，QPS为700，但是 RT 上升到了0.9ms，基本跟Tomcat监控记录到的物理RT一致。如果MySQL上也有类似抓包计算 RT 时间的话可以快速排除网络问题。

网络抓包得到的 RT 数据更容易被所有人接受。尝试过在MySQL上抓包，但是因为LVS模块的原因，进出端口、ip都被修改过，所以没法分析一个流的响应时间。

重心再次转向MySQL

这个时候因为问题点基本确认，再去查看MySQL是否有问题的重心都不一样了，不再只是看看CPU和慢查询，这个问题明显更复杂一些。

教训：CPU只是影响性能的一个因素，RT 才是结果，要追着 RT 跑，而不是只看 CPU

通过监控发现MySQL CPU虽然一直不高，但是经常看到running thread飙到100多，很快又降下去了，看起来像是突发性的并发查询请求太多导致了排队等待，每个MySQL实例是8Core的CPU，尝试将MySQL实例扩容到16Core（只是为了验证这个问题），QPS确实可以上升到1000（没有到达理想的1400）。

这是Tomcat上监控到的MySQL状态：

同时在MySQL机器上通过vmstat也可以看到这种飙升：

以上分析可以清晰看到虽然 MySQL 整体压力不大，但是似乎会偶尔来一波卡顿、running 任务飙升。

像这种短暂突发性的并发流量似乎监控都很难看到（基本都被平均掉了），只有一些实时性监控偶尔会采集到这种短暂突发性飙升，这也导致了一开始忽视了MySQL。

所以接下来的核心问题就是MySQL为什么会有这种飙升、这种飙升的影响到底是什么？

perf top

直接用 perf 看下 MySQLD 进程，发现 ut_delay 高得不符合逻辑：

展开看一下，基本是在优化器中做索引命中行数的选择：

跟直接在 MySQL 命令行中通过 show processlist看到的基本一致：

这是 MySQL 的优化器在对索引进行统计，统计的时候要加锁，thread running 抖动的时候通过 show processlist 看到很多 thread处于 statistics 状态。也就是高并发下加锁影响了 CPU 压不上去同时 RT 剧烈增加。

这里ut_delay 消耗了 28% 的 CPU 肯定太不正常了，于是将 innodb_spin_wait_delay 从 30 改成 6 后性能立即上去了，继续增加 Tomcat 节点，QPS也可以线性增加。

耗CPU最高的调用函数栈是…mutex_spin_wait->ut_delay，属于锁等待的逻辑。InnoDB在这里用的是自旋锁，锁等待是通过调用 ut_delay 让 CPU做空循环在等锁的时候不释放CPU从而避免上下文切换，会消耗比较高的CPU。

最终的性能

调整参数 innodb_spin_wait_delay=6 后在4个Tomcat节点下，并发40时，QPS跑到了1700，物理RT：0.7，逻辑RT：19.6，cpu：90%，这个时候只需要继续扩容 Tomcat 节点的数量就可以增加QPS

再跟调整前比较一下，innodb_spin_wait_delay=30，并发40时，QPS 500+，物理RT：2.6ms 逻辑RT：72.1ms cpu：37%

再看看调整前压测的时候的vmstat和tsar –cpu，可以看到process running抖动明显

对比修改delay后的process running就很稳定了，即使QPS大了3倍

事后思考和分析

到这里问题得到了完美解决，但是不禁要问为什么？ut_delay 是怎么工作的？ 和 innodb_spin_wait_delay 以及自旋锁的关系？

原理解析

既然调整 innodb_spin_wait_delay 就能解决这个问题，那就要先分析一下 innodb_spin_wait_delay 的作用

关于 innodb_spin_wait_delay

innodb通过大量的自旋锁(比如 InnoDB mutexes and rw-locks)来用高CPU消耗避免上下文切换，这是自旋锁的正确使用方式，在多核场景下，它们一起自旋抢同一个锁，容易造成cache ping-pong，进而多个CPU核之间会互相使对方缓存部分无效。所以这里innodb通过增加 innodb_spin_wait_delay 和 Pause 配合来缓解cache ping-pong，也就是本来通过CPU 高速自旋抢锁，换成了抢锁失败后 delay一下（Pause）但是不释放CPU，delay 时间到后继续抢锁，也就是把连续的自旋抢锁转换成了更稀疏的点状的抢锁（间隔的 delay是个随机数），这样不但避免了上下文切换也大大减少了cache ping-pong。

自旋锁如何减少了cache ping-pong

多线程竞争锁的时候，加锁失败的线程会“忙等待”，直到它拿到锁。什么叫“忙等待”呢？它并不意味着一直执行 CAS 函数，而是会与 CPU 紧密配合 ，它通过 CPU 提供的 PAUSE 指令，减少循环等待时的cache ping-pong和耗电量；对于单核 CPU，忙等待并没有意义，此时它会主动把线程休眠。

X86 PAUSE 指令

X86设计了Pause指令，也就是调用 Pause 指令的代码会抢着 CPU 不释放，但是CPU 会打个盹，比如 10个时钟周期，相对一次上下文切换是大几千个时钟周期。

这样应用一旦自旋抢锁失败可以先 Pause 一下，只是这个Pause 时间对于 MySQL 来说还不够久，所以需要增加参数 innodb_spin_wait_delay 来将休息时间放大一些。

在我们的这个场景下对每个 SQL的 RT 抖动非常敏感（放大256倍），所以过高的 delay 会导致部分SQL RT 变高。

函数 ut_delay(ut_rnd_interval(0, srv_spin_wait_delay)) 用来执行这个delay：

/***************************MySQL代码****************************//**
Runs an idle loop on CPU. The argument gives the desired delay
in microseconds on 100 MHz Pentium + Visual C++.
@return dummy value */
UNIV_INTERN
ulint
ut_delay(ulint delay)  //delay 是[0,innodb_spin_wait_delay)之间的一个随机数
{
        ulint   i, j;

        UT_LOW_PRIORITY_CPU();

        j = 0;

        for (i = 0; i < delay * 50; i++) {  //delay 放大50倍
                j += i;
                UT_RELAX_CPU();             //调用 CPU Pause
        }

        UT_RESUME_PRIORITY_CPU();

        return(j);
}

innodb_spin_wait_delay的默认值为6. spin 等待延迟是一个动态全局参数，您可以在MySQL选项文件（my.cnf或my.ini）中指定该参数，或者在运行时使用SET GLOBAL 来修改。在我们的MySQL配置中默认改成了30，导致了这个问题。

CPU 为什么要有Pause

首先可以看到 Pause 指令的作用：

• 避免上下文切换，应用层想要休息可能会用yield、sleep，这两操作对于CPU来说太重了(伴随上下文切换)
• 能给超线程腾出计算能力（HT共享核，但是有单独的寄存器等存储单元，CPU Pause的时候，对应的HT可以占用计算资源），比如同一个core上先跑多个Pause，同时再跑 nop 指令，这时 nop指令的 IPC基本不受Pause的影响
• 节能（CPU可以休息、但是不让出来），CPU Pause 的时候你从 top 能看到 CPU 100%，但是不耗能。

所以有了 Pause 指令后能够提高超线程的利用率,节能，减少上下文切换提高自旋锁的效率。

The PAUSE instruction is first introduced for Intel Pentium 4 processor to improve the performance of “spin-wait loop”. The PAUSE instruction is typically used with software threads executing on two logical processors located in the same processor core, waiting for a lock to be released. Such short wait loops tend to last between tens and a few hundreds of cycles. When the wait loop is expected to last for thousands of cycles or more, it is preferable to yield to the operating system by calling one of the OS synchronization API functions, such as WaitForSingleObject on Windows OS.

An Intel® processor suffers a severe performance penalty when exiting the loop because it detects a possible memory order violation. The PAUSE instruction provides a hint to the processor that the code sequence is a spin-wait loop. The processor uses this hint to avoid the memory order violation in most situations. The PAUSE instruction can improve the performance of the processors supporting Intel Hyper-Threading Technology when executing “spin-wait loops”. With Pause instruction, processors are able to avoid the memory order violation and pipeline flush, and reduce power consumption through pipeline stall.

从intel sdm手册以及实际测试验证来看，Pause 指令在执行过程中，基本不占用流水线执行资源。

Skylake 架构的8163 和 Broadwell架构 E5-2682 CPU型号的不同

为什么用得好好的 innodb_spin_wait_delay 参数这次就不行了呢？

这是因为以前业务一直使用的是 E5-2682 CPU，这次用的是新一代架构的 Skylake 8163，那这两款CPU在这里的核心差别是？

在Intel 64-ia-32-architectures-optimization-manual手册中提到：

The latency of the PAUSE instruction in prior generation microarchitectures is about 10 cycles, whereas in Skylake microarchitecture it has been extended to as many as 140 cycles.

The PAUSE instruction can improves the performance of processors supporting Intel Hyper-Threading Technology when executing “spin-wait loops” and other routines where one thread is accessing a shared lock or semaphore in a tight polling loop. When executing a spin-wait loop, the processor can suffer a severe performance penalty when exiting the loop because it detects a possible memory order violation and flushes the core processor’s pipeline. The PAUSE instruction provides a hint to the processor that the code sequence is a spin-wait loop. The processor uses this hint to avoid the memory order violation and prevent the pipeline flush. In addition, the PAUSE instruction de-
pipelines the spin-wait loop to prevent it from consuming execution resources excessively and consume power needlessly. (See Section 8.10.6.1, “Use the PAUSE Instruction in Spin-Wait Loops,” for more information about using the PAUSE instruction with IA-32 processors supporting Intel Hyper-Threading Technology.)

也就是**Skylake架构的CPU的PAUSE指令从之前的10 cycles 改成了 140 cycles。**这可是14倍的变化呀。

MySQL 使用 innodb_spin_wait_delay 控制 spin lock等待时间，等待时间时间从0*50个Pause到innodb_spin_wait_delay*50个Pause。
以前 innodb_spin_wait_delay 默认配置30，对于E5-2682 CPU，等待的最长时间为：
30 * 50 * 10=15000 cycles，对于2.5GHz的CPU，等待时间为6us。
对应计算 Skylake CPU的等待时间：30 *50 *140=210000 cycles，CPU主频也是2.5GHz，等待时间84us。

E5-2682 CPU型号在不同的delay参数和不同并发压力下的写入性能数据：

Skylake 8163 CPU型号在不同的delay参数和不同并发压力下的写入性能数据：

==因为8163的cycles从10改到了140，所以可以看到delay参数对性能的影响更加陡峻。==

总结分析

Intel CPU 架构不同使得 Pause 指令的CPU Cycles不同导致了 MySQL innodb_spin_wait_delay 在 spin lock 失败的时候（此时需要 Pause* innodb_spin_wait_delay*N）delay更久，使得调用方看到了MySQL更大的 RT ，进而导致 Tomcat Server上业务并发跑不起来，所以最终压力上不去。

在长链路的排查中，细化定位是哪个节点出了问题是最难的，要盯住 RT 而不是 CPU。

欲速则不达，做压测的时候还是要老老实实地从一个并发开始观察QPS、 RT ，然后一直增加压力到压不上去了，再看QPS、 RT 变化，然后确认瓶颈点。

参考文章

https://cloud.tencent.com/developer/article/1005284

mysql doc

Cache Line 伪共享发现与优化

intel spec

Intel PAUSE指令变化影响到MySQL的性能，该如何解决？

ARM软硬件协同设计：锁优化, arm不同于x86，用的是yield来代替Pause

http://cr.openjdk.java.net/~dchuyko/8186670/yield/spinwait.html

https://aloiskraus.wordpress.com/2018/06/16/why-skylakex-cpus-are-sometimes-50-slower-how-intel-has-broken-existing-code/ Windows+.NET 平台下的分析过程及修复方案

Intel PAUSE指令变化如何影响MySQL的性能

导读

x86、arm指令都很多，无论是应用程序员还是数据库内核研发大多时候都不需要对这些指令深入理解，但是 Pause 指令和数据库操作太紧密了，本文通过一次非常有趣的性能优化来引入对 Pause 指令的理解，期望可以事半功倍地搞清楚 CPU指令集是如何影响你的程序的。

文章分成两大部分，第一部分是 MySQL 集群的一次全表扫描性能优化过程； 第二部分是问题解决后的原理分析以及Pause指令的来龙去脉和优缺点以及应用场景分析。

业务结构

为理解方便做了部分简化：

client -> Tomcat -> LVS -> MySQL（32 个 MySQLD实例集群，每个实例8Core）

场景描述

业务按照 个人分库+单位分表: 32个RDS * 8个分库 * 4张分表=1024分表， 也就是 256个分库，每个分库4张表

通过 client 压 Tomcat 和 MySQL 集群（对数据做分库分表），MySQL 集群是32个实例，每个业务 SQL 都需要经过 Tomcat 拆分成 256 个 SQL 发送给 32 个MySQL 实例（每个MySQL 实例上有8个分库），这 256 条下发给 MySQL 的 SQL 不是完全串行，但也不是完全并行，有一定的并行性。

业务 SQL 如下是一个简单的select sum求和，这个 SQL在每个MySQL上都很快（有索引）

SELECT SUM(emp_arr_amt) FROM table_c WHERE INSUTYPE='310' AND Revs_Flag='Z' AND accrym='201910' AND emp_no='1050457';

监控指标说明

• 后述或者截图中的逻辑RT/QPS是指 client 上看到的Tomcat的 RT 和 QPS；
• RT ：response time 请求响应时间，判断性能瓶颈的唯一指标;
• 物理RT/QPS是指Tomcat看到的MySQL RT 和QPS（这里的 RT 是指到达Tomcat节点网卡的 RT ，所以还包含了网络消耗）

问题描述：

通过client压一个Tomcat节点+32个MySQL，QPS大概是430，Tomcat节点CPU跑满，MySQL RT 是0.5ms，增加一个Tomcat节点，QPS大概是700，Tomcat CPU接近跑满，MySQL RT 是0.6ms，到这里性能基本随着扩容线性增加，是符合预期的。

继续增加Tomcat节点来横向扩容性能，通过client压三个Tomcat节点+32个MySQL，QPS还是700，Tomcat节点CPU跑不满，MySQL RT 是0.8ms，这就严重不符合预期了。

性能压测原则：

加并发QPS不再上升说明到了某个瓶颈，哪个环节RT增加最多瓶颈就在哪里

到这里一切都还是符合我们的经验的，看起来就是 MySQL 有瓶颈（RT 增加明显）。

排查 MySQL

现场DBA通过监控看到MySQL CPU不到20%，没有慢查询，并且尝试用client越过所有中间环节直接压其中一个MySQL，可以将 MySQL CPU 跑满，这时的QPS大概是38000（对应上面的场景client QPS为700的时候，单个MySQL上的QPS才跑到6000) 所以排除了MySQL的嫌疑(这个推理不够严谨为后面排查埋下了大坑)。

那么接下来的嫌疑在网络、LVS 等中间环节上。

LVS和网络的嫌疑

首先通过大查询排除了带宽的问题，因为这里都是小包，pps到了72万，很自然想到了网关、LVS的限流之类的

pps监控，这台物理机有4个MySQL实例上，pps 9万左右，9*32/4=72万

…………（省略巨长的分析、拉人、扯皮过程）

最终所有网络因素都被排除，核心证据是：做压测的时候反复从 Tomcat 上 ping 后面的MySQL，RT 跟没有压力的时候一样，也说明了网络没有问题(请思考这个 ping 的作用)。

问题的确认

尝试在Tomcat上打开日志，并将慢 SQL 阈值设置为100ms，这个时候确实能从日志中看到大量MySQL上的慢查询，因为这个SQL需要在Tomcat上做拆分成256个SQL，同时下发，一旦有一个SQL返回慢，整个请求就因为这个短板被拖累了。平均 RT 0.8ms，但是经常有超过100ms的话对整体影响还是很大的。

将Tomcat记录下来的慢查询（Tomcat增加了一个唯一id下发给MySQL）到MySQL日志中查找，果然发现MySQL上确实慢了，所以到这里基本确认是MySQL的问题，终于不用再纠结是否是网络问题了。

同时在Tomcat进行抓包，对网卡上的 RT 进行统计分析：

上是Tomcat上抓到的每个sql的物理RT 平均值，上面是QPS 430的时候， RT 0.6ms，下面是3个server，QPS为700，但是 RT 上升到了0.9ms，基本跟Tomcat监控记录到的物理RT一致。如果MySQL上也有类似抓包计算 RT 时间的话可以快速排除网络问题。

网络抓包得到的 RT 数据更容易被所有人接受。尝试过在MySQL上抓包，但是因为LVS模块的原因，进出端口、ip都被修改过，所以没法分析一个流的响应时间。

重心再次转向MySQL

这个时候因为问题点基本确认，再去查看MySQL是否有问题的重心都不一样了，不再只是看看CPU和慢查询，这个问题明显更复杂一些。

教训：CPU只是影响性能的一个因素，RT 才是结果，要追着 RT 跑，而不是只看 CPU

通过监控发现MySQL CPU虽然一直不高，但是经常看到running thread飙到100多，很快又降下去了，看起来像是突发性的并发查询请求太多导致了排队等待，每个MySQL实例是8Core的CPU，尝试将MySQL实例扩容到16Core（只是为了验证这个问题），QPS确实可以上升到1000（没有到达理想的1400）。

这是Tomcat上监控到的MySQL状态：

同时在MySQL机器上通过vmstat也可以看到这种飙升：

以上分析可以清晰看到虽然 MySQL 整体压力不大，但是似乎会偶尔来一波卡顿、running 任务飙升。

像这种短暂突发性的并发流量似乎监控都很难看到（基本都被平均掉了），只有一些实时性监控偶尔会采集到这种短暂突发性飙升，这也导致了一开始忽视了MySQL。

所以接下来的核心问题就是MySQL为什么会有这种飙升、这种飙升的影响到底是什么？

perf top

直接用 perf 看下 MySQLD 进程，发现 ut_delay 高得不符合逻辑：

展开看一下，基本是在优化器中做索引命中行数的选择：

跟直接在 MySQL 命令行中通过 show processlist看到的基本一致：

这是 MySQL 的优化器在对索引进行统计，统计的时候要加锁，thread running 抖动的时候通过 show processlist 看到很多 thread处于 statistics 状态。也就是高并发下加锁影响了 CPU 压不上去同时 RT 剧烈增加。

这里ut_delay 消耗了 28% 的 CPU 肯定太不正常了，于是将 innodb_spin_wait_delay 从 30 改成 6 后性能立即上去了，继续增加 Tomcat 节点，QPS也可以线性增加。

耗CPU最高的调用函数栈是…mutex_spin_wait->ut_delay，属于锁等待的逻辑。InnoDB在这里用的是自旋锁，锁等待是通过调用 ut_delay 让 CPU做空循环在等锁的时候不释放CPU从而避免上下文切换，会消耗比较高的CPU。

最终的性能

调整参数 innodb_spin_wait_delay=6 后在4个Tomcat节点下，并发40时，QPS跑到了1700，物理RT：0.7，逻辑RT：19.6，cpu：90%，这个时候只需要继续扩容 Tomcat 节点的数量就可以增加QPS

再跟调整前比较一下，innodb_spin_wait_delay=30，并发40时，QPS 500+，物理RT：2.6ms 逻辑RT：72.1ms cpu：37%

再看看调整前压测的时候的vmstat和tsar –cpu，可以看到process running抖动明显

对比修改delay后的process running就很稳定了，即使QPS大了3倍

事后思考和分析

到这里问题得到了完美解决，但是不禁要问为什么？ut_delay 是怎么工作的？ 和 innodb_spin_wait_delay 以及自旋锁的关系？

原理解析

既然调整 innodb_spin_wait_delay 就能解决这个问题，那就要先分析一下 innodb_spin_wait_delay 的作用

关于 innodb_spin_wait_delay

innodb通过大量的自旋锁(比如 InnoDB mutexes and rw-locks)来用高CPU消耗避免上下文切换，这是自旋锁的正确使用方式，在多核场景下，它们一起自旋抢同一个锁，容易造成cache ping-pong，进而多个CPU核之间会互相使对方缓存部分无效。所以这里innodb通过增加 innodb_spin_wait_delay 和 Pause 配合来缓解cache ping-pong，也就是本来通过CPU 高速自旋抢锁，换成了抢锁失败后 delay一下（Pause）但是不释放CPU，delay 时间到后继续抢锁，也就是把连续的自旋抢锁转换成了更稀疏的点状的抢锁（间隔的 delay是个随机数），这样不但避免了上下文切换也大大减少了cache ping-pong。

自旋锁如何减少了cache ping-pong

多线程竞争锁的时候，加锁失败的线程会“忙等待”，直到它拿到锁。什么叫“忙等待”呢？它并不意味着一直执行 CAS 函数，而是会与 CPU 紧密配合 ，它通过 CPU 提供的 PAUSE 指令，减少循环等待时的cache ping-pong和耗电量；对于单核 CPU，忙等待并没有意义，此时它会主动把线程休眠。

X86 PAUSE 指令

X86设计了Pause指令，也就是调用 Pause 指令的代码会抢着 CPU 不释放，但是CPU 会打个盹，比如 10个时钟周期，相对一次上下文切换是大几千个时钟周期。

这样应用一旦自旋抢锁失败可以先 Pause 一下，只是这个Pause 时间对于 MySQL 来说还不够久，所以需要增加参数 innodb_spin_wait_delay 来将休息时间放大一些。

在我们的这个场景下对每个 SQL的 RT 抖动非常敏感（放大256倍），所以过高的 delay 会导致部分SQL RT 变高。

函数 ut_delay(ut_rnd_interval(0, srv_spin_wait_delay)) 用来执行这个delay：

/***************************MySQL代码****************************/
/**Runs an idle loop on CPU. The argument gives the desired delay
in microseconds on 100 MHz Pentium + Visual C++.
@return dummy value */
UNIV_INTERN
ulint
ut_delay(ulint delay)  //delay 是[0,innodb_spin_wait_delay)之间的一个随机数
{
        ulint   i, j;
        UT_LOW_PRIORITY_CPU();
        j = 0;

        for (i = 0; i < delay * 50; i++) {  //delay 放大50倍
                j += i;
                UT_RELAX_CPU();             //调用 CPU Pause
        }

        UT_RESUME_PRIORITY_CPU();
        return(j);
}

innodb_spin_wait_delay的默认值为6. spin 等待延迟是一个动态全局参数，可以在MySQL选项文件（my.cnf或my.ini）中指定该参数，或者在运行时使用SET GLOBAL 来修改。在我们的MySQL配置中默认改成了30，导致了这个问题。

CPU 为什么要有Pause

首先可以看到 Pause 指令的作用：

• 避免上下文切换，应用层想要休息可能会用yield、sleep，这两操作对于CPU来说太重了(伴随上下文切换)
• 能给超线程腾出计算能力（HT共享核，但是有单独的寄存器等存储单元，CPU Pause的时候，对应的HT可以占用计算资源），比如同一个core上先跑多个Pause，同时再跑 nop 指令，这时 nop指令的 IPC基本不受Pause的影响
• 节能（CPU可以休息、但是不让出来），CPU Pause 的时候你从 top 能看到 CPU 100%，但是不耗能。

所以有了 Pause 指令后能够提高超线程的利用率,节能，减少上下文切换提高自旋锁的效率。

The PAUSE instruction is first introduced for Intel Pentium 4 processor to improve the performance of “spin-wait loop”. The PAUSE instruction is typically used with software threads executing on two logical processors located in the same processor core, waiting for a lock to be released. Such short wait loops tend to last between tens and a few hundreds of cycles. When the wait loop is expected to last for thousands of cycles or more, it is preferable to yield to the operating system by calling one of the OS synchronization API functions, such as WaitForSingleObject on Windows OS.

An Intel® processor suffers a severe performance penalty when exiting the loop because it detects a possible memory order violation. The PAUSE instruction provides a hint to the processor that the code sequence is a spin-wait loop. The processor uses this hint to avoid the memory order violation in most situations. The PAUSE instruction can improve the performance of the processors supporting Intel Hyper-Threading Technology when executing “spin-wait loops”. With Pause instruction, processors are able to avoid the memory order violation and pipeline flush, and reduce power consumption through pipeline stall.

从intel sdm手册以及实际测试验证来看，Pause 指令在执行过程中，基本不占用流水线执行资源。

Skylake 架构的8163 和 Broadwell架构 E5-2682 CPU型号的不同

为什么用得好好的 innodb_spin_wait_delay 参数这次就不行了呢？

这是因为以前业务一直使用的是 E5-2682 CPU，这次用的是新一代架构的 Skylake 8163，那这两款CPU在这里的核心差别是？

在Intel 64-ia-32-architectures-optimization-manual手册中提到：

The latency of the PAUSE instruction in prior generation microarchitectures is about 10 cycles, whereas in Skylake microarchitecture it has been extended to as many as 140 cycles.

The PAUSE instruction can improves the performance of processors supporting Intel Hyper-Threading Technology when executing “spin-wait loops” and other routines where one thread is accessing a shared lock or semaphore in a tight polling loop. When executing a spin-wait loop, the processor can suffer a severe performance penalty when exiting the loop because it detects a possible memory order violation and flushes the core processor’s pipeline. The PAUSE instruction provides a hint to the processor that the code sequence is a spin-wait loop. The processor uses this hint to avoid the memory order violation and prevent the pipeline flush. In addition, the PAUSE instruction de-
pipelines the spin-wait loop to prevent it from consuming execution resources excessively and consume power needlessly. (See Section 8.10.6.1, “Use the PAUSE Instruction in Spin-Wait Loops,” for more information about using the PAUSE instruction with IA-32 processors supporting Intel Hyper-Threading Technology.)

也就是**Skylake架构的CPU的PAUSE指令从之前的10 cycles 改成了 140 cycles。**这可是14倍的变化呀。

MySQL 使用 innodb_spin_wait_delay 控制 spin lock等待时间，等待时间时间从0*50个Pause到innodb_spin_wait_delay*50个Pause。
以前 innodb_spin_wait_delay 默认配置30，对于E5-2682 CPU，等待的最长时间为：
30 * 50 * 10=15000 cycles，对于2.5GHz的CPU，等待时间为6us。
对应计算 Skylake CPU的等待时间：30 *50 *140=210000 cycles，CPU主频也是2.5GHz，等待时间84us。

E5-2682 CPU型号在不同的delay参数和不同并发压力下的写入性能数据：

Skylake 8163 CPU型号在不同的delay参数和不同并发压力下的写入性能数据：

==因为8163的cycles从10改到了140，所以可以看到delay参数对性能的影响更加陡峻。==

总结分析

Intel CPU 架构不同使得 Pause 指令的CPU Cycles不同导致了 MySQL innodb_spin_wait_delay 在 spin lock 失败的时候（此时需要 Pause* innodb_spin_wait_delay*N）delay更久，使得调用方看到了MySQL更大的 RT ，进而导致 Tomcat Server上业务并发跑不起来，所以最终压力上不去。

在长链路的排查中，细化定位是哪个节点出了问题是最难的，要盯住 RT 而不是 CPU。

欲速则不达，做压测的时候还是要老老实实地从一个并发开始观察QPS、 RT ，然后一直增加压力到压不上去了，再看QPS、 RT 变化，然后确认瓶颈点。

我想追加几个问题帮大家理解

为什么要有自旋锁(内核里面的spinlock)?

等锁的时候可以释放CPU进入等待，这叫悲观锁，代价是释放CPU必然导致上下文切换，一次上下文切换至少需要几千个时钟周期，也就是CPU需要几千个时钟周期来完成上下文切换的工作(几千个时钟周期没有产出–真浪费)

或者等锁的时候不释放CPU，赌很快能等到锁，这叫乐观锁，Linux OS用的是spinlock（类似大家看到的CAS），也就是CPU不释放一直不停地检查能否拿到锁，一个时钟周期检查一次太快了(想想你去银行柜台办业务，每秒钟问一次柜员轮到你了没有！)，所以CPU工程师就在想能不能提供一条指令一直占着CPU很久，这条指令就是pause，每一个spinlock就会调用pause休息几十、几百个时钟周期后再去看看能否抢到所(柜台给你提供了沙发茶水，你坐一会再去问柜员)

执行Pause指令的时候CPU真的休息了吗？

如果没有事情做的话，CPU是会停下来(省电)，如果开了超线程，如果一个核执行了Pause，那么对这个核的另一个超线程来说，白捡了100%的CPU，别人休息（Pause、stall）的时候正好给我用(这是超线程的本质)！

这也是为什么有些场景2个超线程能发挥2倍能力，有些场景2个超线程只能跑出1倍能力。

相对比上下文切换浪费的几千个时钟周期，Pause(spinlock)真是一点都没浪费。但如果你一直spinlock 几万、几十万个时钟周期都没等到锁还不释放也不对，这会导致其他线程调度不到CPU而饿死。一般自旋一段时间后都会放弃CPU转为上下文切换，所以MySQL 加了参数 innodb_spin_wait_delay 来控制spinlock的长短。

并发高导致自旋锁效率低？

如果并发高，都抢同一个锁，这里的效率会随着并发的增加而降低，不展开了，记住这个结论，类似太多人在柜台问轮到自己没有，留给柜员办业务的时间反而少了！

ARM

ARM 指令集中有 nop 来让流水线空转一个时钟周期，汇编里面的 yield 命令底层就是执行 nop 来达到目的，但是这还不够好，在64位的ARM 指令集里面增加了 ISB (instruction synchronization barrier) 来实现类似 Pause 的作用 ：

On arm64 we have seen on several databases that ISB (instruction synchronization barrier) is better to use than yield in a spin loop. The yield instruction is a nop. The isb instruction puts the processor to sleep for some short time. isb is a good equivalent to the pause instruction on x86.

对比

Below is an experiment that shows the effects of yield and isb on Arm64 and the
time of a pause instruction on x86 Intel processors. The micro-benchmarks use
https://github.com/google/benchmark.git

测试代码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18

$ cat a.cc
static void BM_scalar_increment(benchmark::State& state) {
  int i = 0;
  for (auto _ : state)
    benchmark::DoNotOptimize(i++);
}
BENCHMARK(BM_scalar_increment);
static void BM_yield(benchmark::State& state) {
  for (auto _ : state)
    asm volatile("yield"::);
}
BENCHMARK(BM_yield);
static void BM_isb(benchmark::State& state) {
  for (auto _ : state)
    asm volatile("isb"::);
}
BENCHMARK(BM_isb);
BENCHMARK_MAIN();

测试结果

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

$ g++ -o run a.cc -O2 -lbenchmark -lpthread
$ ./run
--------------------------------------------------------------
Benchmark                    Time             CPU   Iterations
--------------------------------------------------------------

AWS Graviton2 (Neoverse-N1) processor:
BM_scalar_increment      0.485 ns        0.485 ns   1000000000
BM_yield                 0.400 ns        0.400 ns   1000000000
BM_isb                    13.2 ns         13.2 ns     52993304

AWS Graviton (A-72) processor:
BM_scalar_increment      0.897 ns        0.874 ns    801558633
BM_yield                 0.877 ns        0.875 ns    800002377
BM_isb                    13.0 ns         12.7 ns     55169412

Apple Arm64 M1 processor:
BM_scalar_increment      0.315 ns        0.315 ns   1000000000
BM_yield                 0.313 ns        0.313 ns   1000000000
BM_isb                    9.06 ns         9.06 ns     77259282

static void BM_pause(benchmark::State& state) {
  for (auto _ : state)
    asm volatile("pause"::);
}
BENCHMARK(BM_pause);

Intel Skylake processor:
BM_scalar_increment      0.295 ns        0.295 ns   1000000000
BM_pause                  41.7 ns         41.7 ns     16780553

Tested on Graviton2 aarch64-linux with `./x.py test`.

依照如上测试结果可以看出在 ARM 指令集下一次 yield 基本耗费一个时钟周期，但是一次 isb 需要 20-30 个时钟周期，而在intel Skylate 下一次Pause 需要140个时钟周期

所以MySQL 的 aarch64 版本在2020年也终于进行了改进

参考文章

https://cloud.tencent.com/developer/article/1005284

mysql doc

Cache Line 伪共享发现与优化

intel spec

Intel PAUSE指令变化影响到MySQL的性能，该如何解决？

ARM软硬件协同设计：锁优化, arm不同于x86，用的是yield、ISB 来代替Pause

http://cr.openjdk.java.net/~dchuyko/8186670/yield/spinwait.html

https://aloiskraus.wordpress.com/2018/06/16/why-skylakex-cpus-are-sometimes-50-slower-how-intel-has-broken-existing-code/ Windows+.NET 平台下的分析过程及修复方案

epoll的LT和ET

• LT水平触发(翻译为 条件触发 更合适）

  如果事件来了，不管来了几个，只要仍然有未处理的事件，epoll都会通知你。比如来了，打印一行通知，但是不去处理事件，那么会不停滴打印通知。水平触发模式的 epoll 的扩展性很差。

• ET边沿触发

  如果事件来了，不管来了几个，你若不处理或者没有处理完，除非下一个事件到来，否则epoll将不会再通知你。 比如事件来了，打印一行通知，但是不去处理事件，那么不再通知，除非下个事件来了

LT比ET会多一次重新加入就绪队列的动作，也就是意味着一定有一次poll不到东西，效率是有影响但是队列长度有限所以基本可以不用考虑。但是LT编程方式上要简单多了，所以LT也是默认的。

举个 🌰：你有急事打电话找人，如果对方一直不接，那你只有一直打，直到他接电话为止，这就是 lt 模式；如果不急，电话打过去对方不接，那就等有空再打，这就是 et 模式。

条件触发的问题：不必要的唤醒

1. 内核：收到一个新建连接的请求
2. 内核：由于 “惊群效应” ，唤醒两个正在 epoll_wait() 的线程 A 和线程 B
3. 线程A：epoll_wait() 返回
4. 线程B：epoll_wait() 返回
5. 线程A：执行 accept() 并且成功
6. 线程B：执行 accept() 失败，accept() 返回 EAGAIN

边缘触发的问题：不必要的唤醒以及饥饿

不必要的唤醒：

1. 内核：收到第一个连接请求。线程 A 和 线程 B 两个线程都在 epoll_wait() 上等待。由于采用边缘触发模式，所以只有一个线程会收到通知。这里假定线程 A 收到通知
2. 线程A：epoll_wait() 返回
3. 线程A：调用 accpet() 并且成功
4. 内核：此时 accept queue 为空，所以将边缘触发的 socket 的状态从可读置成不可读
5. 内核：收到第二个建连请求
6. 内核：此时，由于线程 A 还在执行 accept() 处理，只剩下线程 B 在等待 epoll_wait()，于是唤醒线程 B
7. 线程A：继续执行 accept() 直到返回 EAGAIN
8. 线程B：执行 accept()，并返回 EAGAIN，此时线程 B 可能有点困惑(“明明通知我有事件，结果却返回 EAGAIN”)
9. 线程A：再次执行 accept()，这次终于返回 EAGAIN

饥饿：

1. 内核：接收到两个建连请求。线程 A 和 线程 B 两个线程都在等在 epoll_wait()。由于采用边缘触发模式，只有一个线程会被唤醒，我们这里假定线程 A 先被唤醒
2. 线程A：epoll_wait() 返回
3. 线程A：调用 accpet() 并且成功
4. 内核：收到第三个建连请求。由于线程 A 还没有处理完(没有返回 EAGAIN)，当前 socket 还处于可读的状态，由于是边缘触发模式，所有不会产生新的事件
5. 线程A：继续执行 accept() 希望返回 EAGAIN 再进入 epoll_wait() 等待，然而它又 accept() 成功并处理了一个新连接
6. 内核：又收到了第四个建连请求
7. 线程A：又继续执行 accept()，结果又返回成功

ET的话会要求应用一直要把消息处理完毕，比如nginx用ET模式，来了一个上传大文件并压缩的任务，会造成这么一个循环：

nginx读数据（未读完）->Gzip(需要时间，套接字又有数据过来)->读数据（未读完）->Gzip …..

新的accpt进来，因为前一个nginx worker已经被唤醒并且还在read(这个时候内核因为accept queue为空所以已经将socket设置成不可读），所以即使其它worker 被唤醒，看到的也是一个不可读的socket，所以很快因为EAGAIN返回了。

这样就会造成nginx的这个worker假死了一样。如果上传速度慢，这个循环无法持续存在，也就是一旦读完nginx切走（再有数据进来等待下次触发），不会造成假死。

JDK中的NIO是条件触发（level-triggered），不支持ET。netty，nginx和redis默认是边缘触发（edge-triggered），netty因为JDK不支持ET，所以自己实现了Netty-native的抽象，不依赖JDK来提供ET。

边缘触发会比条件触发更高效一些，因为边缘触发不会让同一个文件描述符多次被处理,比如有些文件描述符已经不需要再读写了,但是在条件触发下每次都会返回,而边缘触发只会返回一次。

如果设置边缘触发,则必须将对应的文件描述符设置为非阻塞模式并且循环读取数据。否则会导致程序的效率大大下降或丢消息。

poll和epoll默认采用的都是条件触发,只是epoll可以修改成边缘触发。条件触发同时支持block和non-block，使用更简单一些。

epoll LT惊群的发生

1
2
3
4
5
6
7
8
9
10
11
12
13
14

// 否则会阻塞在IO系统调用，导致没有机会再epoll
set_socket_nonblocking(sd);
epfd = epoll_create(64);
event.data.fd = sd;
epoll_ctl(epfd, EPOLL_CTL_ADD, sd, &event);
while (1) {
    epoll_wait(epfd, events, 64, xx);
    ... // 危险区域！如果有共享同一个epfd的进程/线程调用epoll_wait，它们也将会被唤醒！
    // 这个accept将会有多个进程/线程调用，如果并发请求数很少，那么将仅有几个进程会成功：
    // 1. 假设accept队列中有n个请求，则仅有n个进程能成功，其它将全部返回EAGAIN (Resource temporarily unavailable)
    // 2. 如果n很大(即增加请求负载)，虽然返回EAGAIN的比率会降低，但这些进程也并不一定取到了epoll_wait返回当下的那个预期的请求。
    csd = accept(sd, &in_addr, &in_len); 
    ...
}

再看一遍LT的描述“如果事件来了，不管来了几个，只要仍然有未处理的事件，epoll都会通知你。”，显然，epoll_wait刚刚取到事件的时候的时候，不可能马上就调用accept去处理，事实上，逻辑在epoll_wait函数调用的ep_poll中还没返回的，这个时候，显然符合“仍然有未处理的事件”这个条件，显然这个时候为了实现这个语义，需要做的就是通知别的同样阻塞在同一个epoll句柄睡眠队列上的进程！在实现上，这个语义由两点来保证：

保证1：在LT模式下，“就绪链表”上取出的epi上报完事件后会重新加回“就绪链表”；
保证2：如果“就绪链表”不为空，且此时有进程阻塞在同一个epoll句柄的睡眠队列上，则唤醒它。

epoll LT模式下有进程被不必要唤醒，这一点并不是内核无意而为之的，内核肯定是知道这件事的，这个并不像之前accept惊群那样算是内核的一个缺陷。epoll LT模式只是提供了一种模式，误用这种模式将会造成类似惊群那样的效应。但是不管怎么说，为了讨论上的方便，后面我们姑且将这种效应称作epoll LT惊群吧。

epoll ET模式可以解决上面的问题，但是带来了新的麻烦

由于epi entry的callback即ep_poll_callback所做的事情仅仅是将该epi自身加入到epoll句柄的“就绪链表”，同时唤醒在epoll句柄睡眠队列上的task，所以这里并不对事件的细节进行计数，比如说，如果ep_poll_callback在将一个epi加入“就绪链表”之前发现它已经在“就绪链表”了，那么就不会再次添加，因此可以说，一个epi可能pending了多个事件，注意到这点非常重要！

一个epi上pending多个事件，这个在LT模式下没有任何问题，因为获取事件的epi总是会被重新添加回“就绪链表”，那么如果还有事件，在下次check的时候总会取到。然而对于ET模式，仅仅将epi从“就绪链表”删除并将事件本身上报后就返回了，因此如果该epi里还有事件，则只能等待再次发生事件，进而调用ep_poll_callback时将该epi加入“就绪队列”。这意味着什么？

这意味着，应用程序，即epoll_wait的调用进程必须自己在获取事件后将其处理干净后方可再次调用epoll_wait，否则epoll_wait不会返回，而是必须等到下次产生事件的时候方可返回。这会导致事件堆积，所以一般会死循环一直拉取事件，直到拉取不到了再返回。

参考资料

Epoll is fundamentally broken

Epoll is fundamentally broken 1/2

https://wenfh2020.com/2021/11/21/question-nginx-epoll-et/

如何在工作中学习-2019V2版

2018版简单一些，可以看这里，2019版加入了一些新的理解和案例，目的是想要让文章中所说的不是空洞的口号，而是可以具体执行的命令，拉平对读者的要求。

先说一件值得思考的事情：高考的时候大家都是一样的教科书，同一个教室，同样的老师辅导，时间精力基本差不多，可是最后别人考的是清华北大或者一本，而你的实力只能考个三本，为什么？ 当然这里主要是智商的影响，那么其他因素呢？智商解决的问题能不能后天用其他方式来补位一下？

学习的闭环：先了解知识，再实战演练，然后总结复盘。很多时候只是停留在知识学习层面，没有实践，或者实践后没有思考复盘优化，都导致无法深入的理解掌握知识点(from: 瑾妤)

关键问题点

为什么你的知识积累不了？

有些知识看过就忘、忘了再看，实际碰到问题还是联系不上这个知识，这其实是知识的积累出了问题，没有深入的理解自然就不能灵活运用，也就谈不上解决问题了。这跟大家一起看相同的高考教科书但是高考结果不一样是一个原因。问题出在了理解上，每个人的理解能力不一样（智商），绝大多数人对知识的理解要靠不断地实践（做题）来巩固。

同样实践效果不一样？

同样工作一年碰到了10个问题（或者说做了10套高考模拟试卷），但是结果不一样，那是因为在实践过程中方法不够好。或者说你对你为什么做对了、为什么做错了没有去复盘

假如碰到一个问题，身边的同事解决了，而我解决不了。那么我就去想这个问题他是怎么解决的，他看到这个问题后的逻辑和思考是怎么样的，有哪些知识指导了他这么逻辑推理，这些知识哪些我也知道但是我没有想到这么去运用推理（说明我对这个知识理解的不到位导致灵活运用缺乏）；这些知识中又有哪些是我不知道的（知识缺乏，没什么好说的快去Google什么学习下–有场景案例和目的加持，学习理解起来更快）。

等你把这个问题基本按照你同事掌握的知识和逻辑推理想明白后，需要再去琢磨一下他的逻辑推理解题思路中有没有不对的，有没有啰嗦的地方，有没有更直接的方式（对知识更好地运用）。

我相信每个问题都这么去实践的话就不应该再抱怨灵活运用、举一反三，同时知识也积累下来了，这种场景下积累到的知识是不会那么容易忘记的。

这就是向身边的牛人学习，同时很快超过他的办法。这就是为什么高考前你做了10套模拟题还不如其他人做一套的效果好

知识+逻辑 基本等于你的能力，知识让你知道那个东西，逻辑让你把东西和问题联系起来

这里的问题你可以理解成方案、架构、设计等

系统化的知识哪里来？

知识之间是可以联系起来的并且像一颗大树一样自我生长，但是当你都没理解透彻，自然没法产生联系，也就不能够自我生长了。

真正掌握好的知识点会慢慢生长连接最终组成一张大网

但是我们最容易陷入的就是掌握的深度、系统化（工作中碎片时间过多，学校里缺少时间）不够，所以一个知识点每次碰到花半个小时学习下来觉得掌握了，但是3个月后就又没印象了。总是感觉自己在懵懵懂懂中，或者一个领域学起来总是不得要领，根本的原因还是在于：宏观整体大图了解不够（缺乏体系，每次都是盲人摸象）；关键知识点深度不够，理解不透彻，这些关键点就是这个领域的骨架、支点、抓手。缺了抓手自然不能生长，缺了宏观大图容易误入歧途。

我们有时候发现自己在某个领域学起来特别快，但是换个领域就总是不得要领，问题出在了上面，即使花再多时间也是徒然。这也就是为什么学霸看两个小时的课本比你看两天效果还好，感受下来还觉得别人好聪明，是不是智商比我高啊。

所以新进入一个领域的时候要去找他的大图和抓手。

好的同事总是能很轻易地把这个大图交给你，再顺便给你几个抓手，你就基本入门了，这就是培训的魅力，这种情况肯定比自学效率高多了。但是目前绝大部分的培训都做不到这点

好的逻辑又怎么来？

实践、复盘

讲个前同事的故事

有一个前同事是5Q过来的，负责技术（所有解决不了的问题都找他），这位同学从chinaren出道，跟着王兴一块创业5Q，5Q在学校靠鸡腿打下大片市场，最后被陈一舟的校内收购（据说被收购后5Q的好多技术都走了，最后王兴硬是呆在校内网把合约上的所有钱都拿到了）。这位同学让我最佩服的解决问题的能力，好多问题其实他也不一定就擅长，但是他就是有本事通过Help、Google不停地验证尝试就把一个不熟悉的问题给解决了，这是我最羡慕的能力，在后面的职业生涯中一直不停地往这个方面尝试。

应用刚启动连接到数据库的时候比较慢，但又不是慢查询

1. 这位同学的解决办法是通过tcpdump来分析网络包，看网络包的时间戳和网络包的内容，然后找到了具体卡在了哪里。

2. 如果是专业的DBA可能会通过show processlist 看具体连接在做什么，比如看到这些连接状态是 authentication 状态，然后再通过Google或者对这个状态的理解知道创建连接的时候MySQL需要反查IP、域名这里比较耗时，通过配置参数 skip-name-resolve 跳过去就好了。

3. 如果是MySQL的老司机，一上来就知道连接慢的话跟 skip-name-resolve 关系最大。

   在我眼里这三种方式都解决了问题，最后一种最快但是纯靠积累和经验，换个问题也许就不灵了；第一种方式是最牛逼和通用的，只需要最少的知识就把问题解决了。

我当时跟着他从sudo、ls等linux命令开始学起。当然我不会轻易去打搅他问他，每次碰到问题我尽量让他在我的电脑上来操作，解决后我再自己复盘，通过history调出他的所有操作记录，看他在我的电脑上用Google搜啥了，然后一个个去学习分析他每个动作，去想他为什么搜这个关键字，复盘完还有不懂的再到他面前跟他面对面的讨论他为什么要这么做，指导他这么做的知识和逻辑又是什么。

如何向身边的同学学习

钉钉提问的技巧

我进现在的公司的时候是个网络小白，但是业务需要我去解决这些问题，于是我就经常在钉钉上找内部的专家来帮请教一些问题，首先要感谢他们的耐心，同时我觉得跟他们提问的时候的方法大家可以参考一下。

首先，没有客套直奔主题把问题描述清楚，钉钉消息本来就不是即时的，就不要问在不在、能不能问个问题、你好（因为这些问题会浪费他一次切换，真要客套把 你好 写在问题前面在一条消息中发出去）。

其次，我会截图把现象接下来，关键部分红框标明。如果是内部机器还会帮对方申请登陆账号，打通ssh登陆，然后把ssh登陆命令和触发截图现象命令的文字一起钉钉发过去。也就是对方收到我的消息，看到截图的问题后，他只要复制粘贴我发给他的文字信息就看到现象了。为什么要帮他申请账号，有时候账号要审批，要找人，对方不知道到哪里申请等等；这么复杂对方干脆就装作没看见你的消息好了。

为什么还要把ssh登陆命令、重现文字命令发给他呢，怕他敲错啊，敲错了还得来问你，一来一回时间都浪费了。你也许会说我截图上有重现命令啊，那么凭什么他帮你解决问题他还要瞪大眼睛看你的截图把你的命令抄下来？比如容器ID一长串，你是截图了，结果他把b抄成6了，重现不了，还得问你，又是几个来回……

提完问题后有三种情况：抱歉，我也不知道；这个问题你要问问谁，他应该知道；沉默

没关系钉钉的优势是复制粘贴方便，你就换个人再问，可能问到第三个人终于搞定了。那么我会回来把结果告诉前面我问过的同学，即使他是沉默的那个。因为我骚扰过人家，要回来填这个坑，另外也许他真的不知道，那么同步给他也可以帮到他。结果就是他觉得我很靠谱，信任度就建立好了，下次再有问题会更卖力地一起来解决。

一些不好的

有个同学看了我的文章（晚上11点看的），马上发了钉钉消息过来问文章中用到的工具是什么。我还没睡觉但是躺床上看东西，有钉钉消息提醒，但没有切过去回复（不想中断我在看的东西）。5分钟后这个同学居然钉了我一下，我当时是很震惊的，这是你平时学习，不是我的产品出了故障，现在晚上11点。

提问题的时间要考虑对方大概率在电脑前，打字快。否则要紧的话就提选择题类型的问题

问题要尽量是封闭的，比如钉钉上不适合问的问题：

• 为什么我们应用的TPS压不上去，即使CPU还有很多空闲（不好的原因：太开放，原因太多，对方要打字2000才能给你解释清楚各种可能的原因，你要不是他老板就不要这样问了）
• 用多条消息来描述一个问题，一次没把问题描述清楚，需要对方中断多次

场景式学习、体感的来源、面对问题学习

前面提到的对知识的深入理解这有点空，如何才能做到深入理解？

举个学习TCP三次握手例子

经历稍微丰富点的工程师都觉得TCP三次握手看过很多次、很多篇文章了，但是文章写得再好似乎当时理解了，但是总是过几个月就忘了或者一看就懂，过一阵子被人一问就模模糊糊了，或者两个为什么就答不上了，自己都觉得自己的回答是在猜或者不确定

为什么会这样呢？而学其它知识就好通畅多了，我觉得这里最主要的是我们对TCP缺乏体感，比如没有几个工程师去看过TCP握手的代码，也没法想象真正的TCP握手是如何在电脑里运作的（打电话能给你一些类似的体感，但是细节覆盖面不够）。

如果这个时候你一边学习的时候一边再用wireshark抓包看看三次握手具体在干什么，比抽象的描述实在多了，你能看到具体握手的一来一回，并且看到一来一回带了哪些内容，这些内容又是用来做什么、为什么要带，这个时候你再去看别人讲解的理论顿时会觉得好理解多了，以后也很难忘记。

但是这里很多人执行能力不强，想去抓包，但是觉得要下载安装wireshark，要学习wireshark就放弃了。只看不动手当然是最舒适的，但是这个最舒适给了你在学习的假象，没有结果。

这是不是跟你要解决一个难题非常像，这个难题需要你去做很多事，比如下载源代码（翻不了墙，放弃）；比如要编译（还要去学习那些编译参数，放弃）；比如要搭建环境（太琐屑，放弃）。你看这中间九九八十一难你放弃了一难都取不了真经。这也是为什么同样学习、同样的问题，他能学会，他能解决，你不可以。

再来看一个解决问题的例子

会员系统双11优化这个问题对我来说，我是个外来者，完全不懂这里面的部署架构、业务逻辑。但是在问题的关键地方（会员认为自己没问题–压力测试正常的；淘宝API更是认为自己没问题，alimonitor监控显示正常），结果就是会员的同学说我们没有问题，淘宝API肯定有问题，然后就不去思考自己这边可能出问题的环节了。思想上已经甩包了，那么即使再去review流程、环节也就不会那么仔细，自然更是发现不了问题了。

但是我的经验告诉我要有证据地甩包，或者说拿着证据优雅地甩包，这迫使我去找更多的细节证据（证据要给力哦，不能让人家拍回来）。如果我是这么说的，这个问题在淘宝API这里，你看理由是…………，我做了这些实验，看到了这些东东。那么淘宝API那边想要证明我的理由错了就会更积极地去找一些数据。

事实上我就是做这些实验找证据过程中发现了会员的问题，这就是态度、执行力、知识、逻辑能力综合下来拿到的一个结果。我最不喜欢的一句话就是我的程序没问题，因为我的逻辑是这样的，不会错的。你当然不会写你知道的错误逻辑，程序之所以有错误都是在你的逻辑、意料之外的东西。有很多次一堆人电话会议中扯皮的时候，我一般把电话静音了，直接上去人肉一个个过对方的逻辑，一般来说电话会议还没有结束我就给出来对方逻辑之外的东西。

场景式学习

我带2岁的小朋友看刷牙的画本的时候，小朋友理解不了喝口水含在嘴里咕噜咕噜不要咽下去，然后刷牙的时候就都喝下去了。我讲到这里的时候立马放下书把小朋友带到洗手间，先开始我自己刷牙了，示范一下什么是咕噜咕噜（放心，他还是理解不了的，但是至少有点感觉了，水在口里会响，然后水会吐出来）。示范完然后辅导他刷牙，喝水的时候我和他一起直接低着头，喝水然后立马水吐出来了，让他理解了到嘴里的东西不全是吞下去的。然后喝水晃脑袋，有点声音了（离咕噜咕噜不远了）。训练几次后小朋友就理解了咕噜咕噜，也学会了咕噜咕噜。这就是场景式学习的魅力。

很多年前我有一次等电梯，边上还有一个老太太，一个年轻的妈妈带着一个4、5岁的娃。应该是刚从外面玩了回来，妈妈在教育娃娃刚刚在外面哪里做错了，那个小朋友也是气嘟嘟地。进了电梯后都不说话，小朋友就开始踢电梯。这个时候那个年轻的妈妈又想开始教育小朋友了。这时老太太教育这个妈妈说，这是小朋友不高兴，做出的反抗，就是想要用这个方式抗议刚刚的教育或者挑逗起妈妈的注意。这个时候要忽视他，不要去在意，他踢几下后（虽然没有公德这么小懂不了这么多）脚也疼还没人搭理他这个动作，就觉得真没劲，可能后面他都不踢电梯了，觉得这是一个非常无聊还挨疼的事情。那么我在这个场景下立马反应过来，这就是很多以前我对一些小朋友的行为不理解的原因啊，这比书上看到的深刻多了。就是他们生气了在那里做妖挑逗你骂他、打他或者激怒你来吸引大人的注意力。

钉子式学习方法和系统性学习方法

系统性就是想掌握MySQL，那么搞几本MySQL专著和MySQL 官方DOC看下来，一般课程设计的好的话还是比较容易普遍性地掌握下来，绝大部分时候都是这种学习方法，可是问题在于在种方式下学完后当时看着似乎理解了，但是很容易忘记，一片一片地系统性的忘记。还是一般人对知识的理解没那么容易真正理解。

钉子式的学习方式，就是在一大片知识中打入几个桩，反复演练将这个桩不停地夯实，夯温，做到在这个知识点上用通俗的语言跟小白都能讲明白，然后在这几个桩中间发散像星星之火燎原一样把整个一片知识都掌握下来。这种学习方法的缺点就是很难找到一片知识点的这个点，然后没有很好整合的话知识过于零散。

我们常说的一个人很聪明，就是指系统性的看看书就都理解了，是真的理解那种，还能灵活运用，但是大多数普通人就不是这样的，看完书似乎理解了，实际几周后基本都忘记了，真正实践需要用的时候还是用不好。

实际这两种学习方法要互相结合，对普通人来讲钉子式学习方法更好一些，掌握几个钉子后再系统性地学习也容易多了；对非常聪明的人来说系统性地学习效率更高一些。

举个Open-SSH的例子

为了做通 SSH 的免密登陆，大家都需要用到 ssh-keygen/ssh-copy-id， 如果我们把这两个命令当一个小的钉子的话，会去了解ssh-keygen做了啥（生成了密钥对），或者ssh-copy-id 的时候报错了（原来是需要秘钥对），然后将 ssh-keygen 生成的pub key复制到server的~/.ssh/authorized_keys 中。

然后你应该会对这个原理要有一些理解（更大的钉子），于是理解了密钥对，和ssh验证的流程，顺便学会怎么看ssh debug信息，那么接下来网络上各种ssh攻略、各种ssh卡顿的解决都是很简单的事情了。

比如你通过SSH可以解决这些问题：

• 免密登陆
• ssh卡顿
• 怎么去掉ssh的时候需要手工多输入yes
• 怎么样一次登录，多次复用
• 我的ssh怎么很快就断掉了
• 我怎么样才能一次通过跳板机ssh到目标机器
• 我怎么样通过ssh科学上网
• 我的ansible（底层批量命令都是基于ssh）怎么这么多问题，到底是为什么
• 我的git怎么报网络错误了
• xshell我怎么配置不好
• https为什么需要随机数加密，还需要签名
• …………

这些问题都是一步步在扩大ssh的外延，让这个钉子变成一个巨大的桩。

然后就会学习到一些高级一些的ssh配置，比如干掉ssh的时候经常要yes一下(StrictHostKeyChecking=no), 或者怎么配置一下ssh就不会断线了（ServerAliveInterval=15），或者将 ssh跳板机->ssh server的过程做成 ssh server一步就可以了(ProxyCommand)，进而发现用 ssh的ProxyCommand很容易科学上网了，或者git有问题的时候轻而易举地把ssh debug打开，对git进行debug了……

这基本都还是ssh的本质范围，像ansible、git在底层都是依赖ssh来通讯的，你会发现学、调试xshell、ansible和git简直太容易了。

另外理解了ssh的秘钥对，也就理解了非对称加密，同时也很容易理解https流程（SSL），同时知道对称和非对称加密各自的优缺点，SSL为什么需要用到这两种加密算法了。

你看一个简单日常的知识我们只要沿着它用钉子精神，深挖细挖你就会发现知识之间的连接，这个小小的知识点成为你知识体系的一根结实的柱子。

我见过太多年老的工程师、年轻的工程师，天天在那里ssh 密码，ssh 跳板机，ssh 目标机，一小会ssh断了，重来一遍；或者ssh后卡住了，等吧……

在这个问题上表现得没有求知欲、没有探索精神、没有一次把问题搞定的魄力，所以就习惯了，然后年轻的工程师也变成了年老的工程师 :)

空洞的口号

很多文章都会教大家：举一反三、灵活运用、活学活用、多做多练。但是只有这些口号是没法落地的，落地的基本原则就是前面提到的，却总是被忽视了。

什么是工程效率，什么是知识效率

有些人纯看理论就能掌握好一门技能，还能举一反三，这是知识效率，这种人非常少；

大多数普通人都是看点知识然后结合实践来强化理论，要经过反反复复才能比较好地掌握一个知识，这就是工程效率，讲究技巧、工具来达到目的。

肯定知识效率最牛逼，但是拥有这种技能的人毕竟非常少（天生的高智商吧）。从小我们周边那种不怎么学的学霸型基本都是这类，这种学霸都还能触类旁通非常快的掌握一个新知识，非常气人。剩下的绝大部分只能拼时间+方法+总结等也能掌握一些知识

非常遗憾我就是工程效率型，只能羡慕那些知识效率型的学霸。但是这事又不能独立看待有些人在某些方向上是工程效率型，有些方向就又是知识效率型（有一种知识效率型是你掌握的实在太多也就比较容易触类旁通了，这算灰色知识效率型）

使劲挖掘自己在知识效率型方面的能力吧，两者之间当然没有明显的界限，知识积累多了逻辑训练好了在别人看来你的智商就高了

总结

高质量学习+反思和输出，才能建立自己的知识脉络和体系。

①学习力-学习总结能力；

②输出力-逻辑思维和沟通表达能力；

③反思力-自省和修正能力；

某个领域的知识体系犹如一棵大树的根、干、枝、叶。

①损之又损得其道，为其根

②基本的方法论，为其干

③领域的通用知识，为其枝

④与业务绑定的特定知识，为其叶

在这个之上，你所取得的成就，为其花和果

学习能力+思考能力+行动能力=结果

最好的学习方法：带着问题、场景学习（目标明确）

为什么看电影注意力特别好，做正事注意力集中不了

首先接受这个现实，医学上把这叫作注意力缺失症，基本所有人都有这种毛病，因为做正事比较枯燥、困难，让人不舒服，集中不了注意力，逃避很正常！

改善方法：做笔记、收集素材、写作

极易被手机、微博、朋友圈干扰

意志力—还没有好办法

改变条件反射，多逻辑思考

有科学家通过研究，发现一个人一天的行为中，5%是非习惯性的，用思考脑的逻辑驱动，95%是习惯性的，用反射脑的直觉驱动，决定我们一生的，永远是95%的反射脑（习惯），而不是5%的思考脑（逻辑）

互联网+手机时代：浏览信息的时间多了，自己思考和琢磨的时间少了，专注在无效事情上的时间多了，专注在自我成长上的时间少了。

容易忘记

学东西当时感觉很好，但是过几周基本都忘记了

这很正常，主要还是理解不够，理解不够也正常，这就是普通人的智商和理解能力。

改善：做笔记，利用碎片时间回顾

总结成系统性的文章，知识体系化，不会再忘记了。

执行力和自律

执行力和自律在我们的工作和生活中出现的频率非常高，因为这是我们成长或做成事时必须要有的2个关键词，但是很长一段时间里，对于提升执行力，疑惑很大。同时在工作场景中可能会被老板多次要求提升执行力，抽象又具体，但往往只有提升执行力的要求没有如何提升的方法和认知，这是普遍点到即止的现象，普遍提升不了执行力的现象。

“要有执行力”就是一句空话，谁都想，但是臣妾做不到。

人生由成长（学习）和享受（比如看电影、刷朋友圈）构成，成长太艰难，享受就很自然符合人性

怎么办？

划重点：执行力就是想明白，然后一步一步做下去。

跳出舒适区

重复、没有进步的时候就是舒适区，人性就是喜欢适合自己、符合自己技能的环境，解决问题容易；对陌生区域有恐惧感。

有时候是缺机会和场景驱动自我去学习，要找到从舒适到陌生区域的交融点，慢慢跨出去。
比如从自己熟悉的知识体系中入手，从已有的抓手和桩开始突击不清楚的问题，也就是横向、纵向多深挖，自然恐惧区就越来越小了，舒适区慢慢在扩张

养成写文章的习惯非常重要

对自我碎片知识的总结、加深理解的良机，将知识体系化、结构化，形成知识体系中的抓手、桩。

缺的不是鸡汤，而是勺子，勺子就是具体的步骤，可以复制，对人、人性要求很低的动作。

生活本质是生产（工作学习成长）和消费(娱乐、刷朋友圈等)，消费总是符合人性的，当是对自己的适当奖励，不要把自己搞成机器人

可以做的是生产的时候效率更高

知识分两种

一种是通用知识（不是说对所有人通用，而是说在一个专业领域去到哪个公司都能通用）；另外一种是跟业务公司绑定的特定知识

通用知识没有任何疑问碰到后要非常饥渴地扑上去掌握他们（受益终生，这还有什么疑问吗？）。对于特定知识就要看你对业务需要掌握的深度了，肯定也是需要掌握一些的，特定知识掌握好的一般在公司里混的也会比较好

到底是谁reset了你的连接

通过一个案例展示TCP连接是如何被reset的，以及identification、ttl都可以帮我们干点啥。

背景

用户经常连不上服务，经过抓包发现是链路上连接被reset了，需要定位到是哪个设备发起的reset

比如：

1. 用户用navicat从自己访问云上的MySQL的时候，点开数据库总是报错（不是稳定报错，有一定的概率报错）
2. 某家居客户通过专线访问云上MySQL，总是被reset( 内网ip地址重复–都是192.168.*， 导致连接被reset)

进程被kill、异常退出时，针对它打开的连接，内核就会发送 RST 报文来关闭。RST 的全称是 Reset 复位的意思，它可以不走四次挥手强制关闭连接，但当报文延迟或者重复传输时，这种方式会导致数据错乱，所以这是不得已而为之的关闭连接方案。当然还有其它场景也会触发reset

抓包

在 Navicat 机器上抓包如下：

从抓包可以清楚看到 Navicat 发送 Use Database后收到了 MySQL（来自3306端口）的Reset重接连接命令，所以连接强行中断，然后 Navicat报错了。注意图中红框中的 Identification 两次都是13052，先留下不表，这是个线索。

MySQL Server上抓包

特别说明下，MySQL上抓到的不是跟Navicat上抓到的同一次报错，所以报错的端口等会不一样

从这个图中可以清楚看到reset是从 Navicat 客户端发过来的，并且 Use Database被拦截了，没有发到MySQL上。

从这里基本可以判断是客户的防火墙之类的中间设备监控到了关键字之类的触发了防火墙向两边发送了reset，导致了 Navicat 报错。

如果连接已经断开

如果连接已经断开后还收到Client的请求包，因为连接在Server上是不存在的，这个时候Server收到这个包后也会发一个reset回去，这个reset的特点是identification是0.

到底是谁动了这个连接呢？

得帮客户解决问题

虽然原因很清楚，但是客户说连本地 MySQL就没这个问题，连你的云上MySQL就这样，你让我们怎么用？你们得帮我们找到是哪个设备。

这不废话么，连本地没经过这么多防火墙、网关当然没事了。但是客户第一，不能这么说，得找到问题所在。

Identification 和 TTL

线索一 Identification

还记得第一个截图中的两个相同的identification 13052吧，让我们来看看基础知识：

（摘自 TCP卷一），简单来说这个 identification 用来标识一个连接中的每个包，这个序号按包的个数依次递增，通信双方是两个不同的序列。主要是用于ip packet的reassemble。

所以如果这个reset是MySQL发出来的话，因为MySQL发出的前一个包的 identification 是23403，所以这个必须是23404，实际上居然是13502（而且还和Navicat发出的 Use Database包是同一个 identification），这是非常不对的。

所以可以大胆猜测，这里有个中间设备收到 Use Database后触发了不放行的逻辑，于是冒充 Navicat给 MySQL Server发了reset包，src ip/src port/seq等都直接用Navicat的，identification也用Navicat的，所以 MySQL Server收到的 Reset看起来很正常（啥都是对的，没留下一点冒充的痕迹）。

但是这个中间设备还要冒充MySQL Server给 Navicat 也发个reset，有点难为中间设备了，这个时候中间设备手里只有 Navicat 发出来的包， src ip/src port/seq 都比较好反过来，但是 identification 就不好糊弄了，手里只有 Navicat的，因为 Navicat和MySQL Server是两个序列的 identification，这下中间设备搞不出来MySQL Server的identification，怎么办？ 只能糊弄了，就随手用 Navicat 自己的 identification填回去了（所以看到这么个奇怪的 identification）

identification不对不影响实际连接被reset，也就是验证包的时候不会判断identification的正确性。

TTL

identification基本撇清了MySQL的嫌疑，还得进一步找到是哪个机器，我们先来看一个基础知识 TTL(Time-to-Live):

然后我们再看看 Navicat收到的这个reset包的ttl是63，而正常的MySQL Server回过来的包是47，而发出的第一个包初始ttl是64，所以这里可以很清楚地看到在Navicat 下一跳发出的这个reset

既然是下一跳干的直接拿这个包的src mac地址，然后到内网中找这个内网设备就可以了，最终找到是一个锐捷的防火墙。

如果不是下一跳可以通过 traceroute/mtr 来找到这个设备的ip

某家居的reset

从图中可以清楚看到都是3306收到ttl为62的reset，正常ttl是61，所以推定reset来自client的下一跳上。

某ISV vpn环境reset

client通过公网到server有几十跳，偶尔会出现连接被reset。反复重现发现只要是： select * from table1 ; 就一定reset，但是select * from table1 limit 1 之有极低的概率会被reset，reset的概率跟查询结果的大小比较相关。

于是在server和client上同时抓到了一次完整的reset

如下图红框 Server正常发出了一个大小为761的response包，id 51101，注意seq号，另外通过上下文知道server client之间的rt是15ms左右（15ms后 server收到了一个reset id为0）

下图是client收到的 id 51101号包，seq也正常，只是原来的response内容被替换成了reset，可以推断是中间环节检测到id 51101号包触发了某个条件，然后向server、client同时发出了reset，server收到的reset包是id 是0（伪造出来的），client收到的reset包还是51101，可以判断出是51101号包触发的reset，中间环节披着51101号包的外衣将response替换成了reset，这种双向reset基本是同时发出，从server和client的接收时间来看，这个中间环节挨着client，同时server收到的reset 的id是0，结合ttl等综合判断client侧的防火墙发出了这个reset

最终排查后client端

公司部分网络设置了一些拦截措施，然后现在把这次项目中涉及到的服务器添加到了白名单中，现在运行正常了

扩展一下

假如这里不是下一跳，而是隔了几跳发过来的reset，那么这个src mac地址就不是发reset设备的mac了，那该怎么办呢？

可以根据中间的跳数(TTL)，再配合 traceroute 来找到这个设备的ip

SLB reset

如果连接闲置15分钟(900秒)后，SLB会给两端发送reset，设置的ttl为102（102年，下图经过3跳后到达RS 节点所以看到的是99），identification 为31415（π）

被忽略的reset

不是收到reset就一定释放连接，OS还是会验证一下这个reset 包的有效性，主要是通过reset包的seq是否落在接收窗口内来验证，当然五元组一定要对。

但是对于SLB来说，收到reset就会clean 连接的session（SLB没做合法性验证），一般等session失效后（10秒）

SLB主动reset的话

ttl是102, identification是31415，探活reset不是这样的。

如下图就是SLB发出来的reset packet

总结

基础知识很重要，但是知道ttl、identification到会用ttl、identification是两个不同的层次。只是看书的话未必会有很深的印象，实际也不一定会灵活使用。

平时不要看那么多书，会用才是关键。

参考资料

TCP中并不是所有的RST都有效

该死的错误

virtualbox+ubuntu用了快10年了，各种莫名其妙的问题，一直没有换掉，也怪自己 virtualbox+ubuntu组合也许确实奇葩吧，每次碰到问题都没法google到真正的答案了。

问题

用的过程中突然发现挂载的数据盘找不到了（主要存放工作文件）， 看历史记录发现自己执行了：

sudo dd if=/dev/urandom of=/dev/sdb1 bs=1M count=512

/dev/sdb1 对应的正是我的大磁盘，哭死去，怪自己不认识 /dev/sdb1！！ 从来不知道自己挂载的磁盘的真正名字，df -lh 也没仔细看过，导致了这次故障

出问题的history:

29214  01/11/19 10:29:05 vi /tmp/tmp.txt
29215  01/11/19 10:29:18 cat /tmp/tmp.txt |grep "^172.16"
29216  01/11/19 10:29:27 cat /tmp/tmp.txt |grep "^172.16" >cainiao.txt
29217  01/11/19 10:29:31 wc -l cainiao.txt
29218  01/11/19 10:33:13 cat cainiao.txt 
29219  01/11/19 13:36:55 sudo dd if=/dev/urandom of=/dev/sdb1 bs=1M count=512 //故障发生
29220  01/11/19 13:37:08 cd ..
29221  01/11/19 13:37:46 cd / //尝试解决
29222  01/11/19 19:13:45 ls -lh
29223  01/11/19 19:13:49 cd ali 
29224  03/11/19 10:24:56 dmesg
29225  03/11/19 10:27:28 dmesg |grep -i sda
29226  03/11/19 10:27:59 dmesg |grep -i sata
29227  04/11/19 10:19:46 dmesg
29228  04/11/19 10:20:20 dmesg |grep -i sda
29229  04/11/19 10:25:21 dmesg 
29230  04/11/19 10:25:25 dmesg 
29231  04/11/19 10:25:34 dmesg |grep -i sda

尝试

各种重启还是无效，重新删掉数据盘再次挂载启动后依然看不见

mount

virtualbox的启动参数里明确能看到这快盘，和挂载配置

启动后通过fdisk可以看见这块大硬盘

$sudo fdisk -l

Disk /dev/sda: 20 GiB, 21474836480 bytes, 41943040 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x01012f4d

Device     Boot    Start      End  Sectors Size Id Type
/dev/sda1  *        2048 33554431 33552384  16G 83 Linux
/dev/sda2       33556478 41940991  8384514   4G  5 Extended
/dev/sda5       33556480 41940991  8384512   4G 82 Linux swap / Solaris

Disk /dev/sdb: 50 GiB, 53687091200 bytes, 104857600 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x000e88f6

Device     Boot    Start       End  Sectors Size Id Type
/dev/sdb1  *        2048  96471039 96468992  46G 83 Linux
/dev/sdb2       96473086 104855551  8382466   4G  5 Extended
/dev/sdb5       96473088 104855551  8382464   4G 82 Linux swap / Solaris

Disk /dev/sdc: 50 GiB, 53687091200 bytes, 104857600 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x000e88f6

Device     Boot    Start       End  Sectors Size Id Type
/dev/sdc1  *        2048  96471039 96468992  46G 83 Linux
/dev/sdc2       96473086 104855551  8382466   4G  5 Extended
/dev/sdc5       96473088 104855551  8382464   4G 82 Linux swap / Solaris

尝试手工mount （这时看到的才是root cause）

write-protected, mounting read-only 和 bad superblock 错误

尝试 fsck(危险动作）

sudo fsck -y /dev/sdb1

然后再次mount成功了

sudo mount  /dev/sdb1 /media/ren/a64abcac-657d-42ee-8e7b-575eac99bce3

lsblk(修复后）

$sudo lsblk
NAME   MAJ:MIN RM  SIZE RO TYPE MOUNTPOINT
sda      8:0    0   20G  0 disk 
├─sda1   8:1    0   16G  0 part /
├─sda2   8:2    0    1K  0 part 
└─sda5   8:5    0    4G  0 part [SWAP]
sdb      8:16   0   50G  0 disk 
├─sdb1   8:17   0   46G  0 part /media/ren/a64abcac-657d-42ee-8e7b-575eac99bce3
├─sdb2   8:18   0    1K  0 part 
└─sdb5   8:21   0    4G  0 part 
sr0     11:0    1 73.6M  0 rom  /media/ren/VBox_GAs_6.0.10

进到mount后的目录中，查看磁盘大小正常，但是文件看不见了

du 发现文件都在lost+found目录下，但是文件夹名字都改成了 inode名字

根据文件夹大小找出之前的文件夹（比较大的），将其复制出来，一切正常了

修复记录

其中sda是系统盘，sdb是修复后的大磁盘， sdc 是修复前的大磁盘（备份过的）

$sudo fdisk -l

Disk /dev/sda: 20 GiB, 21474836480 bytes, 41943040 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x01012f4d

Device     Boot    Start      End  Sectors Size Id Type
/dev/sda1  *        2048 33554431 33552384  16G 83 Linux
/dev/sda2       33556478 41940991  8384514   4G  5 Extended
/dev/sda5       33556480 41940991  8384512   4G 82 Linux swap / Solaris

Disk /dev/sdb: 50 GiB, 53687091200 bytes, 104857600 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x000e88f6

Device     Boot    Start       End  Sectors Size Id Type
/dev/sdb1  *        2048  96471039 96468992  46G 83 Linux
/dev/sdb2       96473086 104855551  8382466   4G  5 Extended
/dev/sdb5       96473088 104855551  8382464   4G 82 Linux swap / Solaris

Disk /dev/sdc: 50 GiB, 53687091200 bytes, 104857600 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x000e88f6

Device     Boot    Start       End  Sectors Size Id Type
/dev/sdc1  *        2048  96471039 96468992  46G 83 Linux
/dev/sdc2       96473086 104855551  8382466   4G  5 Extended
/dev/sdc5       96473088 104855551  8382464   4G 82 Linux swap / Solaris

可以看到没有修复的磁盘 uuid不太正常，类型也识别为 dos(正常应该是ext4）

[ren@vb 18:12 /home/ren]
$sudo blkid /dev/sdc
/dev/sdc: PTUUID="000e88f6" PTTYPE="dos"

[ren@vb 18:12 /home/ren]
$sudo blkid /dev/sdc1
/dev/sdc1: PARTUUID="000e88f6-01"

[ren@vb 18:12 /home/ren]
$sudo blkid /dev/sdb
/dev/sdb: PTUUID="000e88f6" PTTYPE="dos"

[ren@vb 18:12 /home/ren]
$sudo blkid /dev/sdb1
/dev/sdb1: UUID="a64abcac-657d-42ee-8e7b-575eac99bce3" TYPE="ext4" PARTUUID="000e88f6-01"

尝试mount失败

[ren@vb 18:14 /home/ren]
$sudo mkdir /media/ren/hd

[ren@vb 18:15 /home/ren]
$sudo mount /dev/sd
sda   sda1  sda2  sda5  sdb   sdb1  sdb2  sdb5  sdc   sdc1  sdc2  sdc5  

[ren@vb 18:15 /home/ren]
$sudo mount /dev/sdc1 /media/ren/hd
mount: /dev/sdc1 is write-protected, mounting read-only
mount: wrong fs type, bad option, bad superblock on /dev/sdc1,
       missing codepage or helper program, or other error

       In some cases useful info is found in syslog - try
       dmesg | tail or so.

dmesg中比较正常和不正常的磁盘日志，是看不出来差别的（还没有触发mount动作）

[ren@vb 18:16 /home/ren]
$dmesg |grep sdc
[一 11月  4 18:06:47 2019] sd 4:0:0:0: [sdc] 104857600 512-byte logical blocks: (53.6 GB/50.0 GiB)
[一 11月  4 18:06:47 2019] sd 4:0:0:0: [sdc] Write Protect is off
[一 11月  4 18:06:47 2019] sd 4:0:0:0: [sdc] Mode Sense: 00 3a 00 00
[一 11月  4 18:06:47 2019] sd 4:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[一 11月  4 18:06:47 2019]  sdc: sdc1 sdc2 < sdc5 >
[一 11月  4 18:06:47 2019] sd 4:0:0:0: [sdc] Attached SCSI disk

[ren@vb 18:17 /home/ren]
$dmesg |grep sdb
[一 11月  4 18:06:47 2019] sd 3:0:0:0: [sdb] 104857600 512-byte logical blocks: (53.6 GB/50.0 GiB)
[一 11月  4 18:06:47 2019] sd 3:0:0:0: [sdb] Write Protect is off
[一 11月  4 18:06:47 2019] sd 3:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[一 11月  4 18:06:47 2019] sd 3:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[一 11月  4 18:06:47 2019]  sdb: sdb1 sdb2 < sdb5 >
[一 11月  4 18:06:47 2019] sd 3:0:0:0: [sdb] Attached SCSI disk
[一 11月  4 18:07:02 2019] EXT4-fs (sdb1): mounted filesystem without journal. Opts: (null)

复盘捞到的 syslog 日志

Nov  4 18:06:57 vb systemd[1]: Device dev-disk-by\x2duuid-5241a10b\x2d5dde\x2d4051\x2d8d8b\x2d05718dd56445.device appeared twice with different sysfs paths /sys/devices/pci0000:00/0000:00:0d.0/ata4/host3/target3:0:0/3:0:0:0/block/sdb/sdb5 and /sys/devices/pci0000:00/0000:00:0d.0/ata5/host4/target4:0:0/4:0:0:0/block/sdc/sdc5
Nov  4 18:06:57 vb kernel: [    6.754716] sd 4:0:0:0: [sdc] 104857600 512-byte logical blocks: (53.6 GB/50.0 GiB)
Nov  4 18:06:57 vb kernel: [    6.754744] sd 4:0:0:0: [sdc] Write Protect is off
Nov  4 18:06:57 vb kernel: [    6.754747] sd 4:0:0:0: [sdc] Mode Sense: 00 3a 00 00
Nov  4 18:06:57 vb kernel: [    6.754757] sd 4:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Nov  4 18:06:57 vb kernel: [    6.767797]  sdc: sdc1 sdc2 < sdc5 >
Nov  4 18:06:57 vb kernel: [    6.768061] sd 4:0:0:0: [sdc] Attached SCSI disk

磁盘自检失败，进入emergency mode

修复参考方案：https://www.jianshu.com/p/7433e0bb38e9

1
2
3

welcome to emergency mode. ......  journalctl -xb...
Press enter for maintenance
(or type Control-D to continue): 

解决方法有两个：

第一种：跳过检测受损分区

１、按照提示　执行　journalctl -xb

　　在日志记录中向下翻页找到损坏的分区是哪个，一般是红色的字体，也可以输入/ fsck fail，按N/n来快速查找（我的是/dev/sda11，这个分区我挂载的是/home）

２、vi /etc/fstab

编辑fstab这个文件，注释掉对应的mount行。或将损坏的分区后面的数字从２改为０（０代表启动时不检查该分区）

３、执行reboot 　重启

第二种方法：修复受损的分区

１、执行命令 umount /dev/sdb1 （对应自己出错的设备）卸载设备;

２、执行命令 fsck -y /dev/sdb1 执行fsck校验并修复文件;

3、重新mount就可以使用了

两种方法我都解决了我的问题，不过我还是使用了第二种，第一种总感觉治标不治本！

奇葩问题

virtualbox 太多命名其妙的问题了，争取早日换掉

磁盘uuid重复后，生成新的uuid

[/drives/c/Program Files/Oracle/VirtualBox]
$./VBoxManage.exe internalcommands sethduuid “D:\vb\ubuntu-disk.vmdk”

Windows系统突然dns不工作了

VirtualBox为啥导致了这个问题就是一个很偏的方向，我实在无能为力了，尝试找到了一个和VirtualBox的DNS相关的开关命令，只能死马当活马医了（像极了算命大师和老中医）

./VBoxManage.exe  modifyvm "ubuntu" --natdnshostresolver1 on

ubuntu 鼠标中键不能复制粘贴的恢复办法 gpointing-device-settings

http://askubuntu.com/questions/302077/how-to-enable-paste-in-terminal-with-middle-mouse-button

ubuntu无法关闭锁屏，无法修改配置：

sudo mv ~/.config/dconf ~/.config/dconf.bak //删掉dconf就好了
https://unix.stackexchange.com/questions/296231/cannot-save-changes-made-in-gnome-settings

感受

自己不懂 /dev/sdb 导致了这次问题

这种错误居然从virtualbox或者ubuntu的系统日志中找不到相关信息，这个应该是没有触发挂载。自己对mount、fsck不够熟悉也是主要原因，运气好在fsck 居然没丢任何数据

历史老问题

这种额外挂载的磁盘在ubuntu下启动后不会出现，需要在ubuntu文件系统中人肉访问一次，就触发了挂载动作，然后在bash中才可以正常使用，这个问题我折腾了N年都没解决，实际这次发现是自己对挂载、fstab不够了解。

在 /etc/fstab 中增加boot时挂载这个问题终于解决掉了

UUID=a64abcac-657d-42ee-8e7b-575eac99bce3 /media/ren/a64abcac-657d-42ee-8e7b-575eac99bce3  ext4 defaults 1 1

epoll和惊群

本文尝试追踪不同的内核版本增加的方案来看内核是如何来尝试解决惊群问题的。以及像 SO_REUSEPORT 和EPOLLEXCLUSIVE又带来了什么小问题。

什么是惊群

惊群效应也有人叫做雷鸣群体效应，惊群就是多进程（多线程）在同时阻塞等待同一个事件的时候（休眠状态），如果等待的这个事件发生，那么他就会唤醒等待的所有进程（或者线程），但是最终却只可能有一个进程（线程）获得这个事件的“控制权”，对该事件进行处理，而其他进程（线程）获取“控制权”失败，只能重新进入休眠状态，这种现象和性能浪费就叫做惊群。

惊群的本质在于多个线程处理同一个事件。

为了更好的理解何为惊群，举一个很简单的例子，当你往一群鸽子中间扔一粒谷子，所有的鸽子都被惊动前来抢夺这粒食物，但是最终只有一只鸽子抢到食物。这里鸽子表示进程（线程），那粒谷子就是等待处理的事件。

linux 内核通过睡眠队列来组织所有等待某个事件的 task，而 wakeup 机制则可以异步唤醒整个睡眠队列上的 task，wakeup 逻辑在唤醒睡眠队列时，会遍历该队列链表上的每一个节点，调用每一个节点的 callback，从而唤醒睡眠队列上的每个 task，为什么要欢行所有的task，关键在于内核不知道这个消息是一个task处理就够了还是从逻辑上这些wakeup的所有task都要处理，所以只能全部唤醒。这样，在一个 connect 到达这个 lisent socket 的时候，内核会唤醒所有睡眠在 accept 队列上的 task。N 个 task 进程(线程)同时从 accept 返回，但是，只有一个 task 返回这个 connect 的 fd，其他 task 都返回-1(EAGAIN)。这是典型的 accept”惊群”现象。

如果一个连接的请求需要通知多个线程，就容易出现惊群。比如accept，一般都是一个线程负责accept新连接然后分发，这样不会有惊群，但是如果一个线程成为瓶颈那么就要安排多个线程来accept，当有新连接进来默认只能通知所有线程都来处理，这就是惊群。如果用reuseport来用多个线程监听同一个端口的话，在内核层面会通过hash将新连接派发给一个具体的worker这样也不会有惊群了。

连接建立后，一般的处理逻辑就是将连接一对一挂到一个epoll 红黑树上，一般会有多个epoll 红黑树，然后每个epoll都由一个固定的线程来处理上面的消息，这种是不会有惊群的。也是典型的server处理模式（nginx、tomcat、netty都是如此）

关键点：多个进程监听相同事件（或者说一个epoll有多个进程来处理）

先上总结

如果服务器采用accept阻塞调用方式群在2.6内核就通过增加WQ_FLAG_EXCLUSIVE在内核中就行排他解决惊群了；

只有epoll的accept才有惊群，这是因为epoll监听句柄中后续可能是accept(建连接)，也有可能是read/write网络IO事件，accept有时候一个进程处理不过来、或者accept跟读写混用进程处理，所以内核层面没直接解决epoll的惊群，交由上层应用来根据IO事件如何处理。

epoll的惊群在3.10内核加了SO_REUSEPORT来解决惊群，但如果处理accept的worker也要处理read/write（Nginx的工作方式）就可能导致不同的worker有的饥饿有的排队假死一样；4.5的内核增加EPOLLEXCLUSIVE在内核中直接将worker放在一个大queue，同时感知worker状态来派发任务更好地解决了惊群，但是因为LIFO的机制导致在压力不大的情况下，任务主要派发给少数几个worker（能接受，压力大就会正常了）。

无IO复用时Accept

无IO复用（就只能一个进程监听listen 端口）的accept 不会有惊群，epoll_wait 才会。accept一定是只需要一个进程处理消息，内核可以解决。但是select、epoll就不一定了，所以内核只能唤醒所有的。

在linux2.6版本以后，linux内核已经解决了accept()函数的“惊群”现象，大概的处理方式就是，当内核接收到一个客户连接后，只会唤醒等待队列上的第一个进程（线程）,所以如果服务器采用accept阻塞调用方式，在2.6的linux系统中已经没有“惊群效应”了。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16

 /* nr_exclusive的值默认设为1 */
 #define wake_up_interruptible_sync_poll(x, m)              \
    __wake_up_sync_key((x), TASK_INTERRUPTIBLE, 1, (void *) (m))

tcp_v4_rcv
tcp_v4_do_rcv
tcp_child_process
sock_def_readable
wake_up_interruptible_sync_poll
__wake_up_common
 /* 从头遍历监听socket的等待队列，唤醒等待进程，有EXCLUSIVE标识时只唤醒一个进程 */
list_for_each_entry_safe(curr, next, &q->task_list, task_list)
    /* func最终调用try_to_wake_up，设置进程状态为TASK_RUNNING，并把进程插入CPU运行队列，来唤醒睡眠的进程 */
    if (curr->func(curr, mode, wake_flags, key) && (flags & WQ_FLAG_EXCLUSIVE)  &&
       !--nr_exclusive)
       break; 

sock中定义了几个I/O事件，当协议栈遇到这些事件时，会调用它们的处理函数。当监听socket收到新的连接时，会触发有数据可读事件，调用sock_def_readable，唤醒socket等待队列中的进程。进程被唤醒后，会执行accept的后续操作，最终返回新连接的描述符。

这个socket等待队列是一个FIFO，所以最终是均衡的，也不需要惊群，有tcp connection ready的话直接让等待队列中第一个的线程出队就好了。

2.6内核层面添加了一个WQ_FLAG_EXCLUSIVE标记，告诉内核进行排他性的唤醒，即唤醒一个进程后即退出唤醒的过程(适合accept，但是不适合 epoll–因为epoll除了有accept，还有其它IO事件）

所以这就是大家经常看到的accept不存在惊群问题，内核10年前就解决了这个问题的场景，实际指的是非epoll下的accept 惊群。

epoll的Accept

epoll监听句柄，后续可能是accept，也有可能是read/write网络IO事件，这些IO事件不一定只能由一个进程处理（很少见需要多个进程处理的），所以内核层面没直接解决epoll的惊群，交由上层应用来根据IO事件如何处理。

也就是只要是epoll事件，os默认会唤醒监听这个epoll的所有线程。所以常见的做法是一个epoll绑定到一个thread。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

//主进程中：
ngx_init_cycle
ngx_open_listening_sockets
    socket
    bind
    listen
    epoll_create
    epoll_ctl

//子进程中：
ngx_event_process_init
ngx_prcocess_events_and_timers
ngx_epoll_process_events
    epoll_wait
    rev->handler(rev) // 对于listening socket，handler是ngx_event_accept

和普通的accept不同，使用epoll时，是在epoll_wait()返回后，发现监听socket有可读事件，才调用accept()。由于epoll_wait()是LIFO，导致多个子进程在accept新连接时，也变成了LIFO。

epoll_wait
ep_poll
    /* 创建等待任务，把等待任务加入到epfd等待队列的头部，而不是尾部 */
    init_waitqueue_entry(&wait, current) 
    __add_wait_queue_exclusive(&ep->wq, &wait)
    ...
    __remove_wait-queue(&ep->wq, &wait) /* 最终从epfd等待队列中删除 */

回调触发逻辑：

tcp_v4_rcv
tcp_v4_do_rcv
tcp_child_process
sock_def_readable /* sock I/O 有数据可读事件 */
wake_up_interruptible_sync_poll
__wake_up_common
    /* curr->func是等待任务的回调函数，在ep_insert初始化等待任务时，设置为ep_poll_callback */
    if (curr->func(curr, mode, wake_flags, key) && (flags & WQ_FLAG_EXCLUSIVE)  &&
        !--nr_exclusive)
        break;

那么这种情况下内核如何来解决惊群呢？

SO_REUSEPORT

虽然通过将一个epoll绑定到一个thread来解决竞争问题，但是对于高并发的处理一个thread明显不够，所以有时候不得不设置多个thread来处理一个epoll上的所有socket事件（比如accept）

在3.10的内核中通过引入SO_REUSEPORT解决了这个epoll accept惊群的问题。

linux man文档中一段文字描述其作用：

The new socket option allows multiple sockets on the same host to bind to the same port, and is intended to improve the performance of multithreaded network server applications running on top of multicore systems.

SO_REUSEPORT支持多个进程或者线程绑定到同一端口，提高服务器程序的性能，解决的问题：

• 允许多个套接字 bind()/listen() 同一个TCP/UDP端口
• 每一个线程拥有自己的服务器套接字
• 在服务器套接字上没有了锁的竞争
• 内核层面实现负载均衡，内核通过socket的五元组来hash到不同的socket listener上
• 安全层面，监听同一个端口的套接字只能位于同一个用户下面

其核心的实现主要有三点：

• 扩展 socket option，增加 SO_REUSEPORT 选项，用来设置 reuseport。
• 修改 bind 系统调用实现，以便支持可以绑定到相同的 IP 和端口
• 修改处理新建连接的实现，查找 listener 的时候，能够支持在监听相同 IP 和端口的多个 sock 之间均衡选择。

• Nginx的accept_mutex通过抢锁来控制是否将监听套接字加入到epoll 中。监听套接字只在一个子进程的 epoll 中，当新的连接来到时，其他子进程当然不会惊醒了。通过 accept_mutex加锁性能要比reuseport差
• Linux内核解决了epoll_wait 惊群的问题，Nginx 1.9.1利用Linux3.10 的reuseport也能解决惊群、提升性能。
• 内核的reuseport中相当于所有listen同一个端口的多个进程是一个组合，内核收包时不管查找到哪个socket，都能映射到他们所属的 reuseport 数组，再通过五元组哈希选择一个socket，这样只有这个socket队列里有数据，所以即便所有的进程都添加了epoll事件，也只有一个进程会被唤醒。

以nginx为例，一个worker处理一个epoll(对应一个红黑树)上的所有事件，一般连接新建由accept线程专门处理，连接建立后会加入到某个epoll上，也就是以后会由一个固定的worker/线程来处理。

• 每个 Worker 都会有一个属于自己的 epoll 对象
• 每个 Worker 会关注所有的 listen 状态上的新连接事件（可以通过accept_mutex或者reuseport来解决惊群）
• 对于用户连接，只有一个 Worker 会处理，其它 Worker 不会持有该用户连接的 socket（不会惊群）

当有包进来，根据5元组，如果socket是ESTABLISHED那么直接给对应的socket，如果是握手，则跟据SO_REUSEPORT匹配到对应的监听port的多个线程中的一个

因为Established socket对应于一个唯一的worker，其上所有的读写事件一般是只有一个worker在监听一个的epoll，所以不存在惊群。Listen Socket才可能会对应多个worker，才有可能惊群。

图片来自：https://wenfh2020.com/2021/11/22/question-thundering-herd/

Nginx下SO_REUSEPORT 带来的小问题

从下图可以看出Nginx的一个worker即处理上面的accept也处理对应socket的read/write，如果一个read/write比较耗时的话也会影响到这个worker下的别的socket上的read/write或者accept

SO_REUSEPORT打开后，去掉了上图的共享锁，变成了如下结构：

再有请求进来不再是各个进程一起去抢，而是内核通过五元组Hash来分配，所以不再会惊群了。但是可能会导致撑死或者饿死的问题，比如一个worker一直在做一件耗时的任务（比如压缩、解码），但是内核通过hash分配新连接过来的时候是不知道worker在忙（抢锁就不会发生这种情况，你没空就不会去抢），以Nginx为例

因为Nginx是ET模式，epoll处理worker要一直将事件处理完毕才能进入epoll_wait（才能响应新的请求）。带来了新的问题：如果有一个慢请求（比如gzip压缩文件需要2分钟），那么处理这个慢请求的进程在reuseport模式下还是会被内核分派到新的连接（或者这个worker上的其它请求），但是这个时候worker一直在压缩如同hang死了，新分配进来的请求无法处理。如果不是reuseport模式，他在处理慢请求就根本腾不出来时间去在惊群中抢到锁。但是还是会影响Established 连接上的请求，这个影响和Reuseport没有关系，是一个线程处理多个Socket带来的必然结果 当然这里如果Nginx把accept和read/write分开用不同的线程来处理也不会有这个问题，毕竟accept正常都很快。

上面Nginx Hang死的原因是：Nginx 使用了边缘触发模式，因此Nginx 在套接字有可读性事件的情况下，必须把所有数据都读掉才行，在gzip buffer < connection rcvbuf 同时后端比较快时候，一次性读不完连接上所有数据，就会出现读数据->压缩->新数据到达->继续读数据-> 继续压缩… 的循环，由于压缩需要时间，此时套接字上又来了新的数据，只要数据来的速度比压缩的快，就会出现数据一直读不完的情况，CPU 就一直切不出去。

解决：OSS gzip_buffers 配置为 64*8k = 512K，给后端进程增加了设置sndbuf/rcvbuf 指令之后通过配置Tengine 与后 oss_server 之间的连接的rcvbuf 到512k 以内，这样就能解决这个问题了，实测这个修改几乎不影响后端整体吞吐，同时也不会出现Nginx worker Hang 的情况。

如果不开启SO_REUSEPORT模式，那么即使有一个worker在处理慢请求，那么他就不会去抢accept锁，也就没有accept新连接，这样就不应影响新连接的处理。当然也有极低的概率阻塞accept（准确来说是刚accept，还没处理完accept后的请求，就又切换到耗时的处理去了，导致这个新accept的请求没得到处理）

开了reuse_port 之后每个worker 都单独有个syn 队列，能按照nginx worker 数成倍提升抗synflood 攻击能力。

但是开启了SO_REUSEPORT后，内核没法感知你的worker是不是特别忙，只是按Hash逻辑派发accept连接。也就是SO_REUSEPORT会导致rt偏差更大（抖动明显一些）。这跟MySQL Thread Pool导致的卡顿原理类似，多个Pool类似这里的SO_REUSEPORT。

用图形展示大概如下：

比如中间的worker即使处理得很慢，内核还是正常派连接过来，即使其它worker空闲, 这会导致 RT 抖动加大：

Here is the same test run against the SO_REUSEPORT multi-queue NGINX setup (c):

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15

$ ./benchhttp -n 100000 -c 200 -r target:8181 http://a.a/
        | cut -d " " -f 1
        | ./mmhistogram -t "Duration in ms (multiple queues)"
min:1.49 avg:31.37 med=24.67 max:144.55 dev:25.27 count:100000
Duration in ms (multiple queues):
 value |-------------------------------------------------- count
     0 |                                                   0
     1 |                                                 * 1023
     2 |                                         ********* 5321
     4 |                                 ***************** 9986
     8 |                  ******************************** 18443
    16 |    ********************************************** 25852
    32 |************************************************** 27949
    64 |                              ******************** 11368
   128 |                                                   58

相对地一个accept queue多个 worker的模式 running against a single-queue NGINX:

1
2
3
4
5
6
7
8
9
10
11
12
13
14

$ ./benchhttp -n 100000 -c 200 -r target:8181 http://a.a/
        | cut -d " " -f 1
        | ./mmhistogram -t "Duration in ms (single queue)"
min:3.61 avg:30.39 med=30.28 max:72.65 dev:1.58 count:100000
Duration in ms (single queue):
 value |-------------------------------------------------- count
     0 |                                                   0
     1 |                                                   0
     2 |                                                   1
     4 |                                                   16
     8 |                                                   67
    16 |************************************************** 91760
    32 |                                              **** 8155
    64 |                                                   1

可以看到一个accept queue多个 worker的模式下 RT 极其稳定

SO_REUSEPORT另外的问题

在OS层面一个连接hash到了某个socket fd，但是正好这个 listen socket fd 被关了，已经被分到这个 listen socket fd 的 accept 队列上的请求会被丢掉，具体可以参考 和 LWN 上的 comment

从 Linux 4.5 开始引入了 SO_ATTACH_REUSEPORT_CBPF 和 SO_ATTACH_REUSEPORT_EBPF 这两个 BPF 相关的 socket option。通过巧妙的设计，应该可以避免掉建连请求被丢掉的情况。

EPOLLEXCLUSIVE

epoll引起的accept惊群，在4.5内核中再次引入EPOLLEXCLUSIVE来解决，且需要应用层的配合，Ngnix 在 1.11.3 之后添加了NGX_EXCLUSIVE_EVENT来支持。像tengine尚不支持，所以只能在应用层面上来避免惊群，开启accept_mutex才可避免惊群。

在epoll_ctl ADD描述符时设置 EPOLLEXCLUSIVE 标识。

1
2
3
4
5
6
7
8
9
10
11
12
13
14

epoll_ctl
ep_insert
ep_ptable_queue_proc
    /* 在这里，初始化等待任务，把等待任务加入到socket等待队列的头部 */
     * 注意，和标准accept的等待任务不同，这里并没有给等待任务设置WQ_FLAG_EXCLUSIVE。
     */
    init_waitqueue_func_entry(&pwq->wait, ep_poll_callback);
    /* 检查应用程序是否设置了EPOLLEXCLUSIVE标识 */
    if (epi->event.events & EPOLLEXCLUSIVE)
        /* 新增逻辑，等待任务携带WQ_FLAG_EXCLUSIVE标识，之后只唤醒一个进程 */
        add_wait_queue_exclusive(whead, &pwq->wait);
    else
        /* 原来逻辑，等待任务没有WQ_FLAG_EXCLUSIVE标识，会唤醒所有等待进程 */
        add_wait_queue(whead, &pwq->wait);

在加入listen socket的sk_sleep队列的唤醒队列里使用了 add_wait_queue_exculsive()函数，当tcp收到三次握手最后一个 ack 报文时调用sock_def_readable时，只唤醒一个等待源，从而避免‘惊群’.
调用栈如下：

//  tcp_v4_do_rcv()
//  -->tcp_child_process()
//  --->sock_def_readable()
//  ---->wake_up_interruptible_sync_poll()
//  ----->__wake_up_sync_key()

EPOLLEXCLUSIVE可以在单个Listen Queue对多个Worker Process的时候均衡压力，不会惊群。

连接从一个队列里由内核分发，不需要惊群，对worker是否忙也能感知（忙的worker就不分发连接过去）

图中的电话机相当于一个worker，只是实际内核中空闲的worker像是在一个堆栈中（LIFO），有连接过来，worker堆栈会出栈，处理完毕又入栈，如此反复。而需要处理的消息是一个队列（FIFO），所以总会发现栈顶的几个worker做的事情更多。

多个worker共享一个 accept queue 带来的问题

下面这个case是观察发现Nginx在压力不大的情况下会导致最后几个核cpu消耗时间更多一些，如下图看到的：

这是如前面所述，所有worker像是在一个栈（LIFO）中等着任务处理，在压力不大的时候会导致连接总是在少数几个worker上（栈底的worker没什么机会出栈），如果并发任务多，导致worker栈经常空掉，这个问题就不存在了。当然最终来看EPOLLEXCLUSIVE没有产生什么实质性的不好的影响。值得推荐

图中LIFO场景出现是在多个worker共享一个accept queue的epoll场景下，如果用 SO_REUSEPORT 搞成每个worker一个accept queue就不存在这个问题了

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

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

比如这个case，压力低的worker进程和压力高的worker进程差异比较大：

比较下EPOLLEXCLUSIVE 和 SO_REUSEPORT

EPOLLEXCLUSIVE 和 SO_REUSEPORT 都是在内核层面将连接分到多个worker，解决了epoll下的惊群，SO_REUSEPORT 会更均衡一些，EPOLLEXCLUSIVE在压力不大的时候会导致连接总是在少数几个worker上（但这个不会产生任何不利影响）。 SO_REUSEPORT在最坏的情况下会导致一个worker即使Hang了，OS也依然会派连接过去，这是非常致命的，所以4.5内核引入了 EPOLLEXCLUSIVE（总是给闲置等待队列的第一个worker派连接）

相对 SO_REUSEPORT导致的stuck, EPOLLEXCLUSIV 还是更好接受一些。

参考资料

Linux惊群效应详解（最详细的了吧）

再谈Linux epoll惊群问题的原因和解决方案

epoll lifo引发的nginx “负载不均”

Why does one NGINX worker take all the load?

一次Nginx Gzip 导致的诡异健康检查失败问题调查

Gzip 导致 Nginx worker Hang 问题解法

Socket多进程分发原理

从SO_REUSEPORT服务器的一个弊端看多队列服务模型

https://my.oschina.net/alchemystar/blog/3008840

前言

本文希望解析清楚，当我们在代码中写下 socket.setSendBufferSize 和 sysctl 看到的rmem/wmem系统参数以及最终我们在TCP常常谈到的接收发送窗口的关系，以及他们怎样影响TCP传输的性能，同时如何通过图形来展示哪里是传输瓶颈。

拥塞窗口相关文章比较多，他们跟带宽紧密相关，所以大家比较好判断，反而是接收、发送窗口一旦出现瓶颈，就没这么好判断了。

先明确一下：文章标题中所说的Buffer指的是sysctl中的 rmem或者wmem，如果是代码中指定的话对应着SO_SNDBUF或者SO_RCVBUF，从TCP的概念来看对应着发送窗口或者接收窗口

最后补充各种场景下的传输案例，一站式将影响传输速度的各种原因都拿下，值得收藏。

本文主要分析rt、buffer如何影响TCP的传输性能，更多其他因素影响TCP性能的案例见：TCP传输速度案例分析

TCP性能和发送接收Buffer的关系

先从碰到的一个实际问题看起：

应用通过专线跨网络访问云上的服务，专线100M，时延20ms，一个SQL查询了22M数据，结果花了大概25秒，这太慢了，不正常。

如果通过云上client访问云上服务执行这个SQL那么1-2秒就返回了（不跨网络服务是正常的，说明服务本身没有问题）。

如果通过http或者scp从云下向云上传输这22M的数据大概两秒钟也传送完毕了（说明网络带宽不是瓶颈），

所以这里问题的原因基本上是我们的服务在这种网络条件下有性能问题，需要找出为什么。

抓包分析 tcpdump+wireshark

抓包分析这22M的数据传输，如下图（wireshark 时序图），横轴是时间，纵轴是sequence number：

粗一看没啥问题，因为时间太长掩盖了问题。把这个图形放大，只看中间50ms内的传输情况（横轴是时间，纵轴是sequence number，一个点代表一个包）

可以看到传输过程总有一个20ms的等待平台，这20ms没有发送任何包，换个角度，看看窗口尺寸图形：

从bytes in flight也大致能算出来总的传输速度 16K*1000/20=800Kb/秒

我们的应用代码中会默认设置 socketSendBuffer 为16K:

socket.setSendBufferSize(16*1024) //16K send buffer

原理解析

如果tcp发送buffer也就是SO_SNDBUF只有16K的话，这些包很快都发出去了，但是这16K的buffer不能立即释放出来填新的内容进去，因为tcp要保证可靠，万一中间丢包了呢。只有等到这16K中的某些包ack了，才会填充一些新包进来然后继续发出去。由于这里rt基本是20ms，也就是16K发送完毕后，等了20ms才收到一些ack，在这等ack的20ms 的时间内应用、内核什么都不能做，所以就是如前面第二个图中的大概20ms的等待平台。这块请参考[这篇文章][7]

比如下图，wmem大小是8，发出1-8后，buffer不能释放，等到收到ack1-4后，释放1-4，buffer也就是释放了一半，这一半可以填充新的发送数据进来了。 上面的问题在于ack花了很久，导致buffer一直不能释放。

sendbuffer相当于发送仓库的大小，仓库的货物都发走后，不能立即腾出来发新的货物，而是要等对方确认收到了(ack)才能腾出来发新的货物。 传输速度取决于发送仓库（sendbuffer）、接收仓库（recvbuffer）、路宽（带宽）的大小，如果发送仓库（sendbuffer）足够大了之后接下来的瓶颈就会是高速公路了（带宽、拥塞窗口）。而实际上这个案例中带宽够、接收仓库也够，但是发送仓库太小了，导致发送过程断断续续，所以非常慢。

如果是UDP，就没有可靠的概念，有数据统统发出去，根本不关心对方是否收到，也就不需要ack和这个发送buffer了。

几个发送buffer相关的内核参数

$sudo sysctl -a | egrep "rmem|wmem|tcp_mem|adv_win|moderate"
net.core.rmem_default = 212992
net.core.rmem_max = 212992
net.core.wmem_default = 212992 //core是给所有的协议使用的,
net.core.wmem_max = 212992
net.ipv4.tcp_adv_win_scale = 1 //
net.ipv4.tcp_moderate_rcvbuf = 1
net.ipv4.tcp_rmem = 4096	87380	6291456  //最小值  默认值  最大值
net.ipv4.tcp_wmem = 4096	16384	4194304 //tcp这种就自己的专用选项就不用 core 里面的值了
net.ipv4.udp_rmem_min = 4096
net.ipv4.udp_wmem_min = 4096
vm.lowmem_reserve_ratio = 256	256	32
net.ipv4.tcp_mem = 88560        118080  177120
vm.lowmem_reserve_ratio = 256   256     32

net.ipv4.tcp_wmem 默认就是16K，而且内核是能够动态调整的，只不过我们代码中这块的参数是很多年前从 Cobar 中继承过来的，初始指定了sendbuffer的大小。代码中设置了这个参数后就关闭了内核的动态调整功能，这就是为什么http或者scp都很快，因为他们的send buffer是动态调整的。

接收buffer是有开关可以动态控制的，发送buffer没有开关默认就是开启，关闭只能在代码层面来控制

net.ipv4.tcp_moderate_rcvbuf

解决方案

调整 socketSendBuffer 到256K，查询时间从25秒下降到了4秒多，但是比理论带宽所需要的时间略高

继续查看系统 net.core.wmem_max 参数默认最大是130K，所以即使我们代码中设置256K实际使用的也是130K，继续调大这个系统参数后整个网络传输时间大概2秒(跟100M带宽匹配了，scp传输22M数据也要2秒），整体查询时间2.8秒。测试用的mysql client短连接，如果代码中的是长连接的话会块300-400ms（消掉了握手和慢启动阶段），这基本上是理论上最快速度了

如果调用setsockopt()设置了socket选项SO_SNDBUF，将关闭发送端缓冲的自动调节机制，tcp_wmem将被忽略，SO_SNDBUF的最大值由net.core.wmem_max限制。

这个案例关于wmem的结论

默认情况下Linux系统会自动调整这个buffer（net.ipv4.tcp_wmem）, 也就是不推荐程序中主动去设置SO_SNDBUF，除非明确知道设置的值是最优的。

从这里我们可以看到，有些理论知识点虽然我们知道，但是在实践中很难联系起来，也就是常说的无法学以致用，最开始看到抓包结果的时候比较怀疑发送、接收窗口之类的，没有直接想到send buffer上，理论跟实践没联系上。

BDP(Bandwidth-Delay Product) 带宽时延积

BDP=rtt*(带宽/8)

这个 buffer 调到1M测试没有帮助，从理论计算BDP（带宽时延积） 0.02秒*(100Mb/8)=250KB 所以 *SO_SNDBUF为256Kb的时候基本能跑满带宽了，再大也没有什么实际意义了 。也就是前面所说的仓库足够后瓶颈在带宽上了。

因为这里根据带宽、rtt计算得到的BDP是250K，BDP跑满后拥塞窗口（带宽、接收窗口和rt决定的）即将成为新的瓶颈，所以调大buffer没意义了。

Bandwidth-delay product (BDP)

Product of data link’s capacity and its end-to-end delay. The result is the maximum amount of unacknowledged data that can be in flight at any point in time.

接下来看看接收buffer(rmem)和接收窗口的关系

用这样一个案例下来验证接收窗口的作用：

有一个batch insert语句，整个一次要插入5532条记录，所有记录大小总共是376K，也就是这个sql语句本身是376K。

SO_RCVBUF很小的时候并且rtt很大对性能的影响

如果rtt是40ms，总共需要5-6秒钟：

基本可以看到server一旦空出来点窗口，client马上就发送数据，由于这点窗口太小，rtt是40ms，也就是一个rtt才能传3456字节的数据，整个带宽才用到80-90K，完全没跑满。

比较明显间隔 40ms 一个等待台阶，台阶之间两个包大概3K数据，总的传输效率如下：

斜线越陡表示速度越快，从上图看整体SQL上传花了5.5秒，执行0.5秒。

此时对应的窗口尺寸：

窗口由最开始28K(20个1448）很快降到了不到4K的样子，然后基本游走在即将满的边缘，虽然读取慢，幸好rtt也大，导致最终也没有满。（这个是3.1的Linux，应用SO_RCVBUF设置的是8K，用一半来做接收窗口）

SO_RCVBUF很小的时候并且rtt很小对性能的影响

如果同样的语句在 rtt 是0.1ms的话

虽然明显看到接收窗口经常跑满，但是因为rtt很小，一旦窗口空出来很快就通知到对方了，所以整个过小的接收窗口也没怎么影响到整体性能

如上图11.4秒整个SQL开始，到11.41秒SQL上传完毕，11.89秒执行完毕（执行花了0.5秒），上传只花了0.01秒

接收窗口情况：

如图，接收窗口由最开始的28K降下来，然后一直在5880和满了之间跳动

从这里可以得出结论，接收窗口的大小对性能的影响，rtt越大影响越明显，当然这里还需要应用程序配合，如果应用程序一直不读走数据即使接收窗口再大也会堆满的。

SO_RCVBUF和tcp window full的坏case

上图中红色平台部分，停顿了大概6秒钟没有发任何有内容的数据包，这6秒钟具体在做什么如下图所示，可以看到这个时候接收方的TCP Window Full，同时也能看到接收方（3306端口）的TCP Window Size是8192（8K），发送方（27545端口）是20480.

这个状况跟前面描述的recv buffer太小不一样，8K是很小，但是因为rtt也很小，所以server总是能很快就ack收到了，接收窗口也一直不容易达到full状态，但是一旦接收窗口达到了full状态，居然需要惊人的6秒钟才能恢复，这等待的时间有点太长了。这里应该是应用读取数据太慢导致了耗时6秒才恢复，所以最终这个请求执行会非常非常慢（时间主要耗在了上传SQL而不是执行SQL）.

实际原因不知道，从读取TCP数据的逻辑来看这里没有明显的block，可能的原因：

• request的SQL太大，Server（3306端口上的服务）从TCP读取SQL需要放到一块分配好的内存，内存不够的时候需要扩容，扩容有可能触发fgc，从图形来看，第一次满就卡顿了，而且每次满都卡顿，不像是这个原因
• request请求一次发过来的是多个SQL，应用读取SQL后，将SQL分成多个，然后先执行第一个，第一个执行完后返回response，再读取第二个。图形中卡顿前没有response返回，所以也不是这个原因
• ……其它未知原因

接收方不读取数据导致的接收窗口满同时有丢包发生

服务端返回数据到client端，TCP协议栈ack这些包，但是应用层没读走包，这个时候 SO_RCVBUF 堆积满，client的TCP协议栈发送 ZeroWindow 标志给服务端。也就是接收端的 buffer 堆满了（但是服务端这个时候看到的bytes in fly是0，因为都ack了），这时服务端不能继续发数据，要等 ZeroWindow 恢复。

那么接收端上层应用不读走包可能的原因：

• 应用代码卡顿、GC等等
• 应用代码逻辑上在做其它事情（比如Server将SQL分片到多个DB上，Server先读取第一个分片，如果第一个分片数据很大很大，处理也慢，那么即使第二个分片数据都返回到了TCP 的recv buffer，应用也没去读取其它分片的结果集，直到第一个分片读取完毕。如果SQL带排序，那么Server会轮询读取多个分片，造成这种卡顿的概率小了很多）

上图这个流因为应用层不读取TCP数据，导致TCP接收Buffer满，进而接收窗口为0，server端不能再发送数据而卡住，但是ZeroWindow的探测包，client都有正常回复，所以1903秒之后接收方窗口不为0后（window update）传输恢复。

这个截图和前一个类似，是在Server上(3003端口)抓到的包，不同的是接收窗口为0后，server端多次探测（Server上抓包能看到），但是client端没有回复 ZeroWindow（也有可能是回复了，但是中间环节把ack包丢了,或者这个探测包client没收到），造成server端认为client死了、不可达之类，进而反复重传，重传超过15次之后，server端认为这个连接死了，粗暴单方面断开（没有reset和fin,因为没必要，server认为网络连通性出了问题）。

等到1800秒后，client的接收窗口恢复了，发个window update给server，这个时候server认为这个连接已经断开了，只能回复reset

网络不通，重传超过一定的时间（tcp_retries2)然后断开这个连接是正常的，这里的问题是：

1. 为什么这种场景下丢包了，而且是针对某个stream一直丢包

可能是因为这种场景下触发了中间环节的流量管控，故意丢包了（比如proxy、slb、交换机都有可能做这种选择性的丢包）

这里server认为连接断开，没有发reset和fin,因为没必要，server认为网络连通性出了问题。client还不知道server上这个连接清理掉了，等client回复了一个window update，server早就认为这个连接早断了，突然收到一个update，莫名其妙，只能reset

接收窗口和SO_RCVBUF的关系

ss 查看socket buffer大小

初始接收窗口一般是 mss乘以初始cwnd（为了和慢启动逻辑兼容，不想一下子冲击到网络），如果没有设置SO_RCVBUF，那么会根据 net.ipv4.tcp_rmem 动态变化，如果设置了SO_RCVBUF，那么接收窗口要向下面描述的值靠拢。

初始cwnd可以大致通过查看到：

ss -itmpn dst "10.81.212.8"
State      Recv-Q Send-Q Local Address:Port  Peer Address:Port
ESTAB      0      0      10.xx.xx.xxx:22     10.yy.yy.yyy:12345  users:(("sshd",pid=1442,fd=3))
         skmem:(r0,rb369280,t0,tb87040,f4096,w0,o0,bl0,d92)

Here we can see this socket has Receive Buffer 369280 bytes, and Transmit Buffer 87040 bytes.Keep in mind the kernel will double any socket buffer allocation for overhead. 
So a process asks for 256 KiB buffer with setsockopt(SO_RCVBUF) then it will get 512 KiB buffer space. This is described on man 7 tcp. 

初始窗口计算的代码逻辑，重点在17行：

    /* TCP initial congestion window as per rfc6928 */
    #define TCP_INIT_CWND           10
    /* 3. Try to fixup all. It is made immediately after connection enters

       established state.
             */
            void tcp_init_buffer_space(struct sock *sk)
            {
          int tcp_app_win = sock_net(sk)->ipv4.sysctl_tcp_app_win;
          struct tcp_sock *tp = tcp_sk(sk);
          int maxwin;
        
        if (!(sk->sk_userlocks & SOCK_SNDBUF_LOCK))
                tcp_sndbuf_expand(sk);

		//初始最大接收窗口计算过程
        tp->rcvq_space.space = min_t(u32, tp->rcv_wnd, TCP_INIT_CWND * tp->advmss);
        tcp_mstamp_refresh(tp);
        tp->rcvq_space.time = tp->tcp_mstamp;
        tp->rcvq_space.seq = tp->copied_seq;

        maxwin = tcp_full_space(sk);

        if (tp->window_clamp >= maxwin) {
                tp->window_clamp = maxwin;

                if (tcp_app_win && maxwin > 4 * tp->advmss)
                        tp->window_clamp = max(maxwin -
                                               (maxwin >> tcp_app_win),
                                               4 * tp->advmss);
        }

        /* Force reservation of one segment. */
        if (tcp_app_win &&
            tp->window_clamp > 2 * tp->advmss &&
            tp->window_clamp + tp->advmss > maxwin)
                tp->window_clamp = max(2 * tp->advmss, maxwin - tp->advmss);

        tp->rcv_ssthresh = min(tp->rcv_ssthresh, tp->window_clamp);
        tp->snd_cwnd_stamp = tcp_jiffies32;
}

传输过程中，最大接收窗口会动态调整，当指定了SO_RCVBUF后，实际buffer是两倍SO_RCVBUF，但是要分出一部分（2^net.ipv4.tcp_adv_win_scale)来作为乱序报文缓存以及metadata

1. net.ipv4.tcp_adv_win_scale = 2 //2.6内核，3.1中这个值默认是1

如果SO_RCVBUF是8K，总共就是16K，然后分出2^2分之一，也就是4分之一，还剩12K当做接收窗口；如果设置的32K，那么接收窗口是48K（64-16）

​ static inline int tcp_win_from_space(const struct sock sk, int space)
​ {//space 传入的时候就已经是 2SO_RCVBUF了
​ int tcp_adv_win_scale = sock_net(sk)->ipv4.sysctl_tcp_adv_win_scale;

        return tcp_adv_win_scale <= 0 ?
                (space>>(-tcp_adv_win_scale)) :
                space - (space>>tcp_adv_win_scale); //sysctl参数tcp_adv_win_scale 
}

tcp_adv_win_scale 的取值

接收窗口有最大接收窗口和当前可用接收窗口。

一般来说一次中断基本都会将 buffer 中的包都取走。

绿线是最大接收窗口动态调整的过程，最开始是1460*10，握手完毕后略微调整到1472*10（可利用body增加了12），随着数据的传输开始跳涨

上图是四个batch insert语句，可以看到绿色接收窗口随着数据的传输越来越大，图中蓝色竖直部分基本表示SQL上传，两个蓝色竖直条的间隔代表这个insert在服务器上真正的执行时间。这图非常陡峭，表示上传没有任何瓶颈.

设置 SO_RCVBUF 后通过wireshark观察到的接收窗口基本

下图是设置了 SO_RCVBUF 为8192的实际情况：

从最开始的14720，执行第一个create table语句后降到14330，到真正执行batch insert就降到了8192*1.5. 然后一直保持在这个值

实验：分别改小server wmem/client rmem 来对比对速度的影响

server 设置 wmem=4096, client curl get server的文件，速度60mbps, 两边的rtt都很好

client 设置 rmem=4096，client curl get server的文件，速度6mbps, 为什么速度差别这么大？

为什么server 设置 wmem=4096后速度还是很快，因为server 每次收到ack，立即释放wmem来发新的网络包(内存级别的时延)，但如果rmem比较小当rmem满了到应用读走rmem，rmem有空闲后需要rtt时间反馈到server端server才会继续发包（网络级时延比内存级时延高几个数量级）。一句话总结：就是rmem从有空到包进来会有很大的间隔(rtt), wmem有空到写包进来没有时延

从kernel来看buffer相关信息

kernel相关参数

sudo sysctl -a | egrep "rmem|wmem|tcp_mem|adv_win|moderate"
net.core.rmem_default = 212992
net.core.rmem_max = 212992
net.core.wmem_default = 212992 //core是给所有的协议使用的,
net.core.wmem_max = 212992
net.ipv4.tcp_adv_win_scale = 1
net.ipv4.tcp_moderate_rcvbuf = 1
net.ipv4.tcp_rmem = 4096	87380	6291456
net.ipv4.tcp_wmem = 4096	16384	4194304 //tcp有自己的专用选项就不用 core 里面的值了
net.ipv4.udp_rmem_min = 4096
net.ipv4.udp_wmem_min = 4096
vm.lowmem_reserve_ratio = 256	256	32
net.ipv4.tcp_mem = 88560        118080  177120

发送buffer系统比较好自动调节，依靠发送数据大小和rt延时大小，可以相应地进行调整；但是接受buffer就不一定了，接受buffer的使用取决于收到的数据快慢和应用读走数据的速度，只能是OS根据系统内存的压力来调整接受buffer。系统内存的压力取决于 net.ipv4.tcp_mem.

需要特别注意：tcp_wmem 和 tcp_rmem 的单位是字节，而 tcp_mem 的单位的页面

kernel相关源码

从内核代码来看如果应用代码设置了sndbuf(比如java代码中：socket.setOption(sndbuf, socketSendBuffer))那么实际会分配socketSendBuffer*2的大小出来

比如应用代码有如下设置：

1
2
3
4
5
6
7
8
9
10
11

protected int socketRecvBuffer = 32 * 1024;   //接收32K
protected int socketSendBuffer = 64 * 1024;   //发送64K，实际会分配128K

     // If bufs set 0, using '/etc/sysctl.conf' system settings on default
     // refer: net.ipv4.tcp_wmem / net.ipv4.tcp_rmem
     if (socketRecvBuffer > 0) {
         socket.setReceiveBufferSize(socketRecvBuffer);
     }
     if (socketSendBuffer > 0) {
         socket.setSendBufferSize(socketSendBuffer);
     }

实际会看到这样的：

1
2

tcp ESTAB 45 0 10.0.186.140:3306 10.0.186.70:26494 skmem:(r768,rb65536,t0,tb131072,f3328,w0,o0,bl0,d0)
tcp ESTAB 0 0 10.0.186.140:3306 10.0.186.70:26546 skmem:(r0,rb65536,t0,tb131072,f4096,w0,o0,bl0,d0)

为什么kernel要double 接收和发送buffer可以参考man7中的socket帮助信息

tcp包发送流程

用tc构造延时和带宽限制的模拟重现环境

sudo tc qdisc del dev eth0 root netem delay 20ms
sudo tc qdisc add dev eth0 root tbf rate 500kbit latency 50ms burst 15kb

内核观测tcp_mem是否不足

因 tcp_mem 达到限制而无法发包或者产生抖动的问题，我们也是可以观测到的。为了方便地观测这类问题，Linux 内核里面预置了静态观测点：sock_exceed_buf_limit（需要 4.16+ 的内核版本）。

$ echo 1 > /sys/kernel/debug/tracing/events/sock/sock_exceed_buf_limit/enable

然后去看是否有该事件发生：

$ cat /sys/kernel/debug/tracing/trace_pipe

如果有日志输出（即发生了该事件），就意味着你需要调大 tcp_mem 了，或者是需要断开一些 TCP 连接了。

或者通过systemtap来观察

如下是tcp_sendmsg流程，sk_stream_wait_memory就是tcp_wmem不够的时候触发等待：

如果sendbuffer不够就会卡在上图中的第一步 sk_stream_wait_memory, 通过systemtap脚本可以验证：

 #!/usr/bin/stap
    # Simple probe to detect when a process is waiting for more socket send
    # buffer memory. Usually means the process is doing writes larger than the
    # socket send buffer size or there is a slow receiver at the other side.
    # Increasing the socket's send buffer size might help decrease application
    # latencies, but it might also make it worse, so buyer beware.

probe kernel.function("sk_stream_wait_memory")
{
    printf("%u: %s(%d) blocked on full send buffern",
        gettimeofday_us(), execname(), pid())
}

probe kernel.function("sk_stream_wait_memory").return
{
    printf("%u: %s(%d) recovered from full send buffern",
        gettimeofday_us(), execname(), pid())
}

# Typical output: timestamp in microseconds: procname(pid) event
#
# 1218230114875167: python(17631) blocked on full send buffer
# 1218230114876196: python(17631) recovered from full send buffer
# 1218230114876271: python(17631) blocked on full send buffer
# 1218230114876479: python(17631) recovered from full send buffer

其它案例分析

从如下案例可以看到在时延5ms和1ms的时候，分别执行相同的SQL，SQL查询结果13M，耗时分别为4.6和0.8秒

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

$time mysql  -h127.1  -e "select * from test;" >/tmp/result.txt
real    0m3.078s
user    0m0.273s
sys     0m0.028s

$ping -c 1 127.0.0.1
PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=5.01 ms

--- 127.0.0.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 5.018/5.018/5.018/0.000 ms

$ls -lh /tmp/result.txt
-rw-rw-r-- 1 admin admin 13M Mar 12 12:51 /tmp/result.txt

//减小时延后继续测试
$ping 127.0.0.1
PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=1.01 ms
64 bytes from 127.0.0.1: icmp_seq=2 ttl=64 time=1.02 ms
^C
--- 127.0.0.1 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1001ms
rtt min/avg/max/mdev = 1.016/1.019/1.022/0.003 ms

$time mysql  -h127.1  -e "select * from test;" >/tmp/result.txt
real    0m0.838s
user    0m0.271s
sys     0m0.030s

//通过ss可以看到这个连接的buffer 大小相关信息，3306端口socket的send buffer为32K；
//7226为客户端，发送buffer为128K，OS默认参数 
tcp ESTAB 0 0 127.0.0.1:7226 127.0.0.1:3306 skmem:(r0,rb131072,t2,tb2626560,f24576,w0,o0,bl0,d0)
tcp ESTAB 0 20480 127.0.0.1:3306 127.0.0.1:7226 skmem:(r0,rb16384,t0,tb32768,f1792,w26880,o0,bl0,d0)

在这个案例中 send buffer为32K（代码中设置的16K，内核会再翻倍，所以是32K），如果时延5毫秒时，一秒钟最多执行200次来回，也就是一秒钟能传输：200*32K=6.4M，总大小为13M，也就是最快需要2秒钟才能传输行完，另外MySQL innodb执行耗时0.5ms，也就是极限速度也就是2.5秒+了。

这个场景下想要快得减少rt或者增加send buffer， 增加接收端的buffer没有意义，比如如下代码增加client的 –net-buffer-length=163840000 没有任何帮助

time mysql –net-buffer-length=163840000 -h127.1 -e “select * from test;” >/tmp/result.txt

在2 MiB buffer下rt和 throughput的关系

wmem 和send_buffer的关系

设置 net.ipv4.tcp_wmem=4096 4096 4096（单位是bytes），目的是想控制wmem很小，实际测试发现bytes in flight(发走还没有ack的数据）超过了4096，那么tcp_wmem和 send_buffer/bytes in flight 到底是什么关系呢？

应用write->wmem/snd_buffer->wmem_queued(在这里等ack，ack没来queued不释放)->client

skmem:(r0,rb369280,t0,tb4096,f6000,w157840,o0,bl0

w157840–这个对应我们理解的send buffer. 也就是wmem 不负责等ack，send完就释放，wmem_queued负责等

总结

• 一般来说绝对不要在程序中手工设置SO_SNDBUF和SO_RCVBUF，内核自动调整比你做的要好；
• SO_SNDBUF一般会比发送滑动窗口要大，因为发送出去并且ack了的才能从SO_SNDBUF中释放；
• 代码中设置的SO_SNDBUF和SO_RCVBUF在内核中会翻倍分配；
• TCP接收窗口跟SO_RCVBUF关系很复杂；
• SO_RCVBUF太小并且rtt很大的时候会严重影响性能；
• 接收窗口比发送窗口复杂多了；
• 发送窗口/SO_SNDBUF–发送仓库，带宽/拥塞窗口–马路通畅程度，接收窗口/SO_RCVBUF–接收仓库；
• 发送仓库、马路宽度、长度（rt）、接收仓库一起决定了传输速度–类比一下快递过程。

总之记住一句话：不要设置socket的SO_SNDBUF和SO_RCVBUF

关于传输速度的总结：窗口要足够大，包括发送、接收、拥塞窗口等，自然就能将BDP跑满

相关和参考文章

2024 Netflix： Investigation of a Cross-regional Network Performance Issue 因为内核升级去掉了内核参数 sysctl_tcp_adv_win_scale，换了一个新的计算方式，导致原来30秒 内能传输完毕的请求在新内核机制下传输不完，从而导致了业务端的请求超时 This commit obsoleted sysctl_tcp_adv_win_scale and introduced a scaling_ratio that can more accurately calculate the overhead or window size, which is the right thing to do. With the change, the window size is now rcvbuf * scaling_ratio. 简而言之，内核升级后，接收缓存大小减半。因此，吞吐量也减半，导致数据传输时间翻倍。

Netflix 这次业务问题是Kafka， 其代码里不应该设置TCP 接收buffer 大小，而是要让kernel来自动调节

2022 https://blog.cloudflare.com/when-the-window-is-not-fully-open-your-tcp-stack-is-doing-more-than-you-think 你设置的rmem 不会全部用来存放数据，每个包还有一些meta数据需要存放，元数据的大小会有很大的差异，导致内核需要来保守预估

receive window is not fully opened immediately. Linux keeps the receive window small, as it tries to predict the metadata cost and avoid overshooting the memory budget, therefore hitting TCP collapse. By default, with the net.ipv4.tcp_adv_win_scale=1, the upper limit for the advertised window is 50% of “free” memory. rcv_ssthresh starts up with 64KiB and grows linearly up to that limit.

用stap从内核角度来分析buffer、rt和速度

[The story of one latency spike][https://blog.cloudflare.com/the-story-of-one-latency-spike/] : 应用偶发性出现了rt 很高的时延，通过两个差量 ping 来定位具体节点

Using a large chunk of receive buffer space for the metadata is not really what the programmer wants. To counter that, when the socket is under memory pressure complex logic is run with the intention of freeing some space. One of the operations is tcp_collapse and it will merge adjacent TCP packets into one larger sk_buff. This behavior is pretty much a garbage collection (GC)—and as everyone knows, when the garbage collection kicks in, the latency must spike.

原因：将 tcp_rmem 最大值设置得太大，在内存压力场景下触发了GC（tcp_collapse），将 tcp_rmem 调小后（32M->2M）不再有偶发性 rt 很高的延时

从 net_rx_action 追到 tcp_collapse 的逻辑没太理解（可能是对内核足够了解）

[What is rcv_space in the ‘ss –info’ output, and why it’s value is larger than net.core.rmem_max][28]

arthas常用命令速记

https://github.com/alibaba/arthas

thread

1
2

thread -n 3
thread 16

jad 反编译

jad org.slf4j.Logger
jad org.slf4j.Logger -c 61bbe9ba

jad com.taobao.tddl.common.IdGenerator
jad --source-only com.taobao.tddl.common.IdGenerator
jad --source-only com.taobao.tddl.common.IdGenerator > /tmp/IdGenerator.java

反编译生成java代码

mc 编译生成新的class

将修改后的java代码编译成class（因为依赖的关系可能失败）

mc /tmp/IdGenerator.java -d /tmp

redefine 加载新的class

将修改后的class代码热加载

redefine /tmp/IdGenerator.class
redefine -c 1e80bfe8 /tmp/com/alibaba/middleware/drds/worker/task/RegisterTask.class

可以再次jad 反编译确认class中是修改后的代码：

jad --source-only com.alibaba.cobar.server.ServerConnection > /tmp/SC.java

有时候 redefine 看到成功，可是实际并不一定，最好再次 jad 确认一下。

线上环境快速修改代码验证三部曲：jad反编译得到源代码、修改后mc编译成class、redefine替换新的class。

classload

classloader -l
classloader -c 1e80bfe8 -r com/alibaba/middleware/drds/worker/task/RegisterTask.class
classload -t
classload -c 6e0be858
classloader ch.qos.logback.core.AppenderBase

sc

sc -d com.taobao.tddl.common.IdGenerator
sc -df ch.qos.logback.core.AppenderBase

sm

列出class的方法

sm ch.qos.logback.core.AppenderBase -d

getstatic 查看静态成员

通过getstatic查看静态成员，来追踪一个logger没有设置level的话他的输出级别到底是什么？

先 sc 获取classloader的hash

sc -df io.netty.channel.nio.NioEventLoop

getstatic -c 1e80bfe8 io.netty.channel.nio.NioEventLoop logger 'getClass().getName()'
field: logger
@String[io.netty.util.internal.logging.Slf4JLogger]
Affect(row-cnt:1) cost in 5 ms.

然后查看 logger的具体内容，可以看到level等，level为null的话会从父logger继承：

getstatic -c 1e80bfe8 io.netty.channel.nio.NioEventLoop logger 'logger'
field: logger
@Logger[
    serialVersionUID=@Long[5454405123156820674],
    FQCN=@String[ch.qos.logback.classic.Logger],
    name=@String[io.netty.channel.nio.NioEventLoop],
    level=null,
    effectiveLevelInt=@Integer[20000],
    parent=@Logger[Logger[io.netty.channel.nio]],
    childrenList=null,
    aai=null,
    additive=@Boolean[true],
    loggerContext=@LoggerContext[ch.qos.logback.classic.LoggerContext[default]],
]

再次用getstatic命令来确定jar包的location：

getstatic -c 1e80bfe8 io.netty.channel.nio.NioEventLoop logger 'logger.getClass().getProtectionDomain().getCodeSource().getLocation()'
field: logger
@URL[
    BUILTIN_HANDLERS_PREFIX=@String[sun.net.www.protocol],
    serialVersionUID=@Long[-7627629688361524110],
    protocolPathProp=@String[java.protocol.handler.pkgs],
    protocol=@String[file],
    host=@String[],
    port=@Integer[-1],
    file=@String[/home/admin/drds-worker/lib/logback-classic-1.1.8.jar],
    query=null,
    authority=@String[],
    path=@String[/home/admin/drds-worker/lib/logback-classic-1.1.8.jar],
    userInfo=null,
    ref=null,
    hostAddress=null,
    handler=@Handler[sun.net.www.protocol.file.Handler@5a98007],
    hashCode=@Integer[-1217964899],
    tempState=null,
    factory=null,
    handlers=@Hashtable[isEmpty=false;size=3],
    streamHandlerLock=@Object[java.lang.Object@3bf379e9],
    serialPersistentFields=@ObjectStreamField[][isEmpty=false;size=7],
]

然后通过getstatic来获取到这个parent属性的内容。然后通过多个parent操作，可以发现level都是INFO，最终发现ROOT level是INFO：

getstatic -c 1e80bfe8 io.netty.channel.nio.NioEventLoop logger 'logger.parent.parent.parent.parent.parent'
field: logger
@Logger[
    serialVersionUID=@Long[5454405123156820674],
    FQCN=@String[ch.qos.logback.classic.Logger],
    name=@String[ROOT],
    level=@Level[INFO],
    effectiveLevelInt=@Integer[20000],
    parent=null,
    childrenList=@CopyOnWriteArrayList[isEmpty=false;size=4],
    aai=@AppenderAttachableImpl[ch.qos.logback.core.spi.AppenderAttachableImpl@3f0908e1],
    additive=@Boolean[true],
    loggerContext=@LoggerContext[ch.qos.logback.classic.LoggerContext[default]],
]

vmtool

查看任意成员变量

查看 Druid 参数

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
78
79
80
81
82
83
84
85

[arthas@922863]$ sc -df com.alibaba.druid.pool.DruidDataSource //Str 类名，通过类名获取 classload 
 class-info        Str
 code-source       /root/java/
 name              Str
 isInterface       false
 isAnnotation      false
 isEnum            false
 isAnonymousClass  false
 isArray           false
 isLocalClass      false
 isMemberClass     false
 isPrimitive       false
 isSynthetic       false
 simple-name       Str
 modifier
 annotation
 interfaces
 super-class       +-java.lang.Object
 class-loader      +-sun.misc.Launcher$AppClassLoader@4e0e2f2a  
                     +-sun.misc.Launcher$ExtClassLoader@3b9a45b3
 classLoaderHash   4e0e2f2a  //classload
 fields            name     name
                   type     java.lang.String
                   modifier private

//执行模板示例
[arthas@922863]$ vmtool --action getInstances --classLoaderClass sun.misc.Launcher$AppClassLoader --className Str  --express 'instances[0].name'

vmtool --action getInstances -c 6d06d69c  --className com.alibaba.druid.pool.DruidDataSource --express 'instances[0]'

//通过vmtool 列出DruidDataSource的所有对象
[arthas@80]$ vmtool --action getInstances -c 272ce069 --className com.alibaba.druid.pool.DruidDataSource --limit 5

vmtool --action getInstances -c 3e57cd70 --className com.alibaba.druid.pool.DruidDataSource --express 'instances[2]'

//列出其中的一个详细值
[arthas@80]$ vmtool --action getInstances -c 272ce069 --className com.alibaba.druid.pool.DruidDataSource --express 'instances[3]'
username=@String[test],
jdbcUrl=@String[jdbc:mysql://test.com:3006/plantegg?useUnicode=true&characterEncoding=UTF-8&rewriteBatchedStatements=true&amp&allowMultiQueries=true&socketTimeout=60000&connectTimeout=10000],
 driverClass=@String[com.mysql.jdbc.Driver],
 initialSize=@Integer[10],
 maxActive=@Integer[100],
 minIdle=@Integer[10],
 maxIdle=@Integer[8],
 maxWait=@Long[60000],
 connectTimeout=@Integer[10000],
 socketTimeout=@Integer[60000],
 connectTimeoutStr=@String[10000],
 socketTimeoutSr=null,
 queryTimeout=@Integer[0],
 transactionQueryTimeout=@Integer[0],
 createTimespan=@Long[909765246],
 maxWaitThreadCount=@Integer[-1],
 …………
 CreateTime:"2024-10-24 15:57:21",
  ActiveCount:1,
  PoolingCount:9,
  CreateCount:10, //对应 initialSize，没压力的服务
  DestroyCount:0,
  CloseCount:318741,
  ConnectCount:318742,
  Connections:[
    {ID:2079580272, ConnectTime:"2024-10-24 15:57:26", UseCount:0, LastActiveTime:"2024-10-24 15:57:26"},
    {ID:1498019812, ConnectTime:"2024-10-24 15:57:26", UseCount:0, LastActiveTime:"2024-10-24 15:57:26"},
    {ID:1803829323, ConnectTime:"2024-10-24 15:57:26", UseCount:0, LastActiveTime:"2024-10-24 15:57:26"},
    {ID:1735514761, ConnectTime:"2024-10-24 15:57:26", UseCount:0, LastActiveTime:"2024-10-24 15:57:26"},
    {ID:56972919, ConnectTime:"2024-10-24 15:57:26", UseCount:0, LastActiveTime:"2024-10-24 15:57:26"},
    {ID:352679720, ConnectTime:"2024-10-24 15:57:26", UseCount:1, LastActiveTime:"2024-10-24 16:00:12"},
    {ID:1556806619, ConnectTime:"2024-10-24 15:57:26", UseCount:59597, LastActiveTime:"2024-10-24 17:48:08"},
    {ID:889640793, ConnectTime:"2024-10-24 15:57:26", UseCount:104286, LastActiveTime:"2024-10-24 17:51:10"},
    {ID:486144352, ConnectTime:"2024-10-24 15:57:26", UseCount:89027, LastActiveTime:"2024-10-24 17:51:11"}
  ]
}],

//列出第一个对象的 createDirectCount 属性
[arthas@30019]$ vmtool --action getInstances -c 7852e922  --className com.alibaba.druid.pool.DruidDataSource --express 'instances[0].createDirectCount'
@Integer[0]

//MetaDBUtilImpl 会通过url 去构建DataSource， 这样展开能看到url 连接串参数
vmtool --action getInstances --className com.a.rds.ha.util.MetaDBUtilImpl -x 3 //-x 表示展开深度
               @DruidPooledConnection[com.a.rds.mysql.jdbc.S*Connection@6e567347]:@Object[java.lang.Object@4c3bd27b],
             @DruidPooledConnection[com.a.rds.mysql.jdbc.S*Connection@4e1884d5]:@Object[java.lang.Object@4c3bd27b],
                @DruidPooledConnection[com.a.rds.mysql.jdbc.S*Connection@33c4853b]:@Object[java.lang.Object@4c3bd27b],
              @DruidPooledConnection[com.a.rds.mysql.jdbc.S*Connection@6ca0fdd6]:@Object[java.lang.Object@4c3bd27b],
                @DruidPooledConnection[com.a.rds.mysql.jdbc.S*Connection@6fb0c93a]:@Object[java.lang.Object@4c3bd27b],

查看 Jedis 连接池：

1

vmtool --action getInstances --className redis.clients.jedis.util.Pool --express 'instances[0]'

logger 查看和修改 logger配置

列出所有logger，然后修改logger的level

classloader -l  //列出所有 classloader 一般是这个：sun.misc.Launcher$AppClassLoader
或者：
 sc -df com.aliyun.apsaradb.dbaasmetaapi.common.GlobalExceptionHandler  //class 名字可以到日志中取到
 
logger -c 27bc2616
ognl -c 6e0be858 '@com.alibaba.cobar.server.ServerConnection@logger'
ognl -c 6e0be858 '@org.slf4j.LoggerFactory@getLogger("root").setLevel(@ch.qos.logback.classic.Level@DEBUG)'

ognl -c 37f8bb67 '@org.slf4j.LoggerFactory@getLogger("root").setLevel(@ch.qos.logback.classic.Level@OFF)'


logger --include-no-appender //查看没有 appender 的日志
 name              com.aliyun.apsaradb.dbaasmetaapi.dao.mapper.CustinsReplicatorMapper.selectByExample
 class             ch.qos.logback.classic.Logger
 classLoader       org.springframework.boot.loader.LaunchedURLClassLoader@37f8bb67
 classLoaderHash   37f8bb67
 level             OFF //已被关
 effectiveLevel    OFF
 additivity        true
 codeSource        jar:file:/usr/local/rds/dbaas-meta-api/dbaas-meta-api.jar!/BOOT-INF/lib/logback-classic-1.2.3.jar!/
                   
 name              com.aliyun.apsaradb.dbaasmetaapi.dao.mapper.CcBuMapper.selectByExample
 class             ch.qos.logback.classic.Logger
 classLoader       org.springframework.boot.loader.LaunchedURLClassLoader@37f8bb67
 classLoaderHash   37f8bb67
 level             OFF //已被关
 effectiveLevel    OFF
 additivity        true
 codeSource        jar:file:/usr/local/rds/dbaas-meta-api/dbaas-meta-api.jar!/BOOT-INF/lib/logback-classic-1.2.3.jar!/              
 
ognl -c 37f8bb67 '@org.slf4j.LoggerFactory@getLogger("com.aliyun.apsaradb.dbaasmetaapi.dao.mapper.CustinsReplicatorMapper.selectByExample").setLevel(@ch.qos.logback.classic.Level@OFF)'

或者

logger --name ROOT --level debug

trace 耗时超过10ms的方法堆栈

查看调用耗时超过 10ms的函数堆栈

stack ch.qos.logback.core.AppenderBase doAppend
trace -j ch.qos.logback.core.AppenderBase doAppend '#cost > 10'

截图中红框的数字表示代码行号

ongl 调用static函数并查看返回值

ognl '#value1=@com.alibaba.middleware.drds.manager.common.utils.AddressUtil@getHostIp(), {#value1}'
@ArrayList[
	@String[10.0.174.135],
]


 ognl '#value1=@com.alibaba.middleware.drds.worker.Config@getInstance(), {#value1}'
	@ArrayList[
@Config[Config(receivedManagerInfo=true, registeredToManager=true, workerRpcPort=8188, managerIp=10.0.171.193, managerPort=8080, drdsServerPort=3306, drdsManagerPort=3406, host=10.0.118.18, vpcId=vpc-bp1tsocjn451k7ur52vwl, urlToGetVpcId=http://100.100.100.200/latest/meta-data/vpc-id, heartBeatIntervalSeconds=180, registerInveralSeconds=2, manageDrdsIntervalSeconds=60, miniVersion=1, version=0.0.0.41, registerUrl=http://hostPlaceHolder:portPlaceHolder/v1/worker/register, heartBeatUrl=http://hostPlaceHolder:portPlaceHolder/v1/worker/heartBeat, manageDrdsServerUrl=http://hostPlaceHolder:portPlaceHolder/v1/worker/manageDrdsServer, gotVpcId=true, nodeType=drds-server, watcher=null, scheduledThreadPoolExecutor=java.util.concurrent.ScheduledThreadPoolExecutor@3aa3f85f[Running, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0])],
]

#Netty的SelectorProvider.provider()创建Selector驱动的时候通过JDK create到的Selector驱动
#如果是windows平台：WindowsSelectorProvider(); macOS
#下面是Linux平台的默认Selector驱动：
$ options unsafe true
$ ognl  '#value1=@sun.nio.ch.DefaultSelectorProvider@create(), {#value1}'
@ArrayList[
    @EPollSelectorProvider[sun.nio.ch.EPollSelectorProvider@5bf6cb51],
]
#或者
$  ognl  '#value1=@java.nio.channels.spi.SelectorProvider@provider(), {#value1}'
@ArrayList[
    @EPollSelectorProvider[sun.nio.ch.EPollSelectorProvider@74c4ede7],
]

tt 观察函数调用和回放

先通过tt观察某个函数的调用，然后再用 tt -i 回放这个调用并查看返回值等

tt -t com.alibaba.middleware.drds.manager.common.utils.AddressUtil getHostIp
tt -t com.alibaba.middleware.drds.worker.task.RegisterTask getHostInfoIfNeeded
tt -i 1000
tt -i 1000 -p
tt -n 3 -t com.alibaba.middleware.drds.worker.task.RegisterTask getHostInfoIfNeeded
tt -n 3 -t com.alibaba.middleware.drds.manager.common.utils.AddressUtil getHostIp

 tt -i 1010 -p
	 RE-INDEX      1010
	 GMT-REPLAY    2019-09-27 12:59:05
	 OBJECT        NULL
	 CLASS         com.alibaba.middleware.drds.manager.common.utils.AddressUtil
	 METHOD        getHostIp
	 IS-RETURN     true
	 IS-EXCEPTION  false
	 COST(ms)      0.577817
	 RETURN-OBJ    @String[10.0.118.18]

watch 查看函数调用的参数内容和返回值

指定输出结果的属性遍历深度，默认为 1：

watch  com.alibaba.middleware.drds.manager.common.utils.AddressUtil getHostIp "{params,returnObj}" -x 2

watch com.alibaba.middleware.drds.worker.task.RegisterTask getHostInfoIfNeeded "{params,returnObj}" -x 2
	Press Q or Ctrl+C to abort.
	Affect(class-cnt:1 , method-cnt:1) cost in 56 ms.
	ts=2019-09-27 13:24:00; [cost=0.2698ms] result=@ArrayList[
	    @Object[][isEmpty=true;size=0],
	    @Boolean[true],
	]
	ts=2019-09-27 13:24:02; [cost=0.030039ms] result=@ArrayList[
	    @Object[][isEmpty=true;size=0],
	    @Boolean[true],
	]

可以看到处理请求的handler是 om.example.demo.arthas.user.UserController.findUserById：

$ watch org.springframework.web.servlet.DispatcherServlet getHandler returnObj
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 332 ms.
ts=2019-06-04 11:38:06; [cost=2.75218ms] result=@HandlerExecutionChain[
    logger=@SLF4JLocationAwareLog[org.apache.commons.logging.impl.SLF4JLocationAwareLog@665c08a],
    handler=@HandlerMethod[public com.example.demo.arthas.user.User com.example.demo.arthas.user.UserController.findUserById(java.lang.Integer)],
    interceptors=null,
    interceptorList=@ArrayList[isEmpty=false;size=2],
    interceptorIndex=@Integer[-1],
]

• watch 命令定义了4个观察事件点，即 -b 方法调用前，-e 方法异常后，-s 方法返回后，-f 方法结束后
• 4个观察事件点 -b、-e、-s 默认关闭，-f 默认打开，当指定观察点被打开后，在相应事件点会对观察表达式进行求值并输出
• 这里要注意方法入参和方法出参的区别，有可能在中间被修改导致前后不一致，除了 -b 事件点 params 代表方法入参外，其余事件都代表方法出参
• 当使用 -b 时，由于观察事件点是在方法调用前，此时返回值或异常均不存在

参考资料

官方文档