文章目录
一、程序报错
发现BSC节点报错: write: broken pipe
2022/04/11 11:23:00 http: panic serving 172.31.34.109:32952: write tcp 172.31.6.64:9093->172.31.34.109:32952: write: broken pipe
goroutine 145578 [running]:
net/http.(*conn).serve.func1(0xc000399720)
/usr/local/go/src/net/http/server.go:1824 +0x153
panic(0xfbc720, 0xc008f36be0)
/usr/local/go/src/runtime/panic.go:971 +0x499
github.com/gin-gonic/gin/render.JSON.Render(...)
/go/pkg/mod/github.com/gin-gonic/gin@v1.7.7/render/json.go:56
github.com/gin-gonic/gin.(*Context).Render(0xc00621d600, 0xc8, 0x133ab98, 0xc00be29b10)
/go/pkg/mod/github.com/gin-gonic/gin@v1.7.7/context.go:927 +0x149
github.com/gin-gonic/gin.(*Context).JSON(...)
/go/pkg/mod/github.com/gin-gonic/gin@v1.7.7/context.go:970
bsc-wallet/router/apicommon.ReturnSuccessResponse(0xc00621d600, 0x0, 0x10c16c7, 0x7, 0xee3960, 0xc00ae84d20)
/go/src/bsc-wallet/router/apicommon/common.go:38 +0xc5
bsc-wallet/router/handler.BlockInfo(0xc00621d600)
/go/src/bsc-wallet/router/handler/wallethandler.go:395 +0x27e
github.com/gin-gonic/gin.(*Context).Next(...)
/go/pkg/mod/github.com/gin-gonic/gin@v1.7.7/context.go:168
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest(0xc000120340, 0xc00621d600)
/go/pkg/mod/github.com/gin-gonic/gin@v1.7.7/gin.go:555 +0x2b0
github.com/gin-gonic/gin.(*Engine).ServeHTTP(0xc000120340, 0x133ec38, 0xc0067767e0, 0xc00621d500)
/go/pkg/mod/github.com/gin-gonic/gin@v1.7.7/gin.go:511 +0x16b
net/http.serverHandler.ServeHTTP(0xc0001881c0, 0x133ec38, 0xc0067767e0, 0xc00621d500)
/usr/local/go/src/net/http/server.go:2887 +0xa3
net/http.(*conn).serve(0xc000399720, 0x13405b8, 0xc0059e4a40)
/usr/local/go/src/net/http/server.go:1952 +0x8cd
created by net/http.(*Server).Serve
/usr/local/go/src/net/http/server.go:3013 +0x39b
这个错误的字面意思为:客户端可能会在收到服务端响应之前断开连接
二、问题原因
想到的问题原因可能是以下两种原因:
- 服务端所在的服务器,超过了最大连接数
- 客户端在接收到服务端响应之前断开连接
2.1 连接数过大
当我们有一些高并发请求量环境时,会遇到来自于系统级别的连接数限制问题,这是因为CentOS根据系统硬件信息自己默认初始了一个限制连接数量,往往这个数量是我们遇到的问题,所以今天我们需要修改系统的默认值来达到我们需要的要求,解决一定的高并发产生的连接数问题。
- 使用以下命令查看当前最大连接数:
# ulimit -n
1024
- 临时修改: 该方法只在当前起作用
# ulimit -n 65535
# ulimit -n
65535
- 永久修改:修改以下配置文件
# vim /etc/security/limits.conf
* soft nofile 65535
* hard nofile 65535
* soft nproc 65535
* hard nproc 65535
即便你使用limit -n 1024 等这样的修改是无法其效果的,
以及各种修改可能都不起作用:
经过我们的大量研究最终解决了该问题
2.2 调用者在接收到服务端响应之前断开连接
该问题可能是因为:client端获取响应数据,突然异常退出或直接close连接。
client退出后,server将会发送两次数据,server第一次发送给client,client返回给server RST。第二次在这个RST的连接上,server继续发送,出现broken pipe。即如下错误:
2022/04/11 12:27:53 http: panic serving 172.31.34.109:45842: write tcp 172.31.6.64:9093->172.31.34.109:45842: write: broken pipe
那么此时就会出现两个问题,server端迟迟没有响应数据给client端,那么也有可能是以下两个原因:
- server端去节点请求数据的时候,节点一直没有返回
- 连接数过高,请求需要排队处理,可能有的请求还没有处理完,就已经请求超时了
关于此问题已向client端进行求证,目前连接server端设置的超时时间是:连接超时:0.5秒,响应超时5秒
2.2.1 排查服务器上的连接数
- 查看系统连接数
# 获取当前socket连接状态统计信息
# cat /proc/net/sockstat
sockets: used 1138
TCP: inuse 21 orphan 0 tw 0 alloc 786 mem 220
UDP: inuse 4 mem 2
UDPLITE: inuse 0
RAW: inuse 0
FRAG: inuse 0 memory 0
# 统计当前各种状态的连接的数量的命令
# netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
CLOSE_WAIT 1020
ESTABLISHED 59
- 查看端口范围
# 允许系统打开的端口范围,用于向外链接的端口范围
# cat /proc/sys/net/ipv4/ip_local_port_range
32768 60999
- 查看文件打开数
# 查看当前打开文件数
# 如果执行缓慢,那么执行结果显示系统当前打开文件数500w
# lsof | wc -l
4792741
# 把当前打开文件列表保存
# lsof>>/tmp/lsof.log
# 查看 5-6万 行之间的数据
sed -n '50000,60000p' /tmp/lsof.log
结果,bsc,且没有关闭:
COMMAND PID PPID USER PGID FD DEVICE SIZE NODE NAME
进程名称 进程标识符 父进程标识符 进程所有者 进程所属组 文件描述符 指定磁盘名称 文件大小 索引节点 打开文件的确切名称
bsc-wallet 2105 2125 root 1872u sock 0,7 0t0 2800355 protocol: TCPv6
bsc-wallet 2105 2125 root 1873u sock 0,7 0t0 2802021 protocol: TCPv6
bsc-wallet 2105 2125 root 1874u sock 0,7 0t0 2765499 protocol: TCPv6
bsc-wallet 2105 2125 root 1875u sock 0,7 0t0 2803112 protocol: TCPv6
bsc-wallet 2105 2125 root 1876u sock 0,7 0t0 2769274 protocol: TCPv6
bsc-wallet 2105 2125 root 1877u sock 0,7 0t0 2803114 protocol: TCPv6
bsc-wallet 2105 2125 root 1878u sock 0,7 0t0 2770305 protocol: TCPv
2.2.2 查看连接状态为CLOSE_WAIT的连接情况
- 统计当前各种状态的连接的数量的命令
# netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
CLOSE_WAIT 1169
ESTABLISHED 84
- 查看CLOSE_WAIT是哪台服务器请求的,以及请求数
# netstat -a |grep "CLOSE_WAIT"|awk '{print $5}'|awk -F '.' '{print $1}' |sort | uniq -c | sort -nr
1382 ip-172-31-34-109
2.2.3 延时测试
可以看到情况为:另外一台服务器上面的服务(客户端)请求到bsc-clinet(服务端)时,由于在他设置的超时时间内未返回请求数据,客户端主动关闭了连接,导致服务端所在的服务器出现大量关于该服务端的CLOSE_WAIT的连接状态,最后服务端无法提供服务,报错: write: broken pipe
服务端未出现 CLOSE_WAIT 时的响应时间及延时
- 服务端目前没有CLOSE_WAIT连接状态
# netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
ESTABLISHED 21
- 获取服务端请求响应时间
# curl -o /dev/null -s -w %{time_namelookup}::%{time_connect}::%{time_starttransfer}::%{time_total}::%{speed_download}"\n" -d "number=16619272&sign=b8aaab58e4d73753430c473ba29756d3" http://127.0.0.1:9093/api/block/blockInfo
0.000::0.000::0.088::0.088::1572245.000
-o:把curl 返回的html、js 写到垃圾回收站[ /dev/null]
-s:去掉所有状态
-w:按照后面的格式写出rt
time_namelookup:DNS 解析域名www.36nu.com的时间
time_commect:client和server端建立TCP 连接的时间
time_starttransfer:从client发出请求;到web的server 响应第一个字节的时间
time_total:client发出请求;到web的server发送会所有的相应数据的时间
speed_download:下周速度 单位 byte/s
上面这条命令及返回结果可以这么理解:
0.000: DNS 服务器解析www.36nu.com 的时间单位是s
0.000: client发出请求,到c/s 建立TCP 的时间;里面包括DNS解析的时间
0.088: client发出请求;到s响应发出第一个字节开始的时间;包括前面的2个时间
0.088: client发出请求;到s把响应的数据全部发送给client;并关闭connect的时间
1572245.000 :下载数据的速度
建立TCP连接到server返回client第一个字节的时间:0.088s – 0.000s = 0.088s
server把响应数据发送给client的时间:0.088s – 0.088s = 0.000s
- 模拟客户端超时时间:连接超时:1秒,响应超时5秒
使用CURL时,有两个超时时间:一个是连接超时时间,另一个是数据传输的最大允许时间。
连接超时时间用–connect-timeout参数来指定,数据传输的最大允许时间用-m参数来指定。
# curl --connect-timeout 1 -m 5 -d "number=16619272&sign=b8aaab58e4d73753430c473ba29756d3" http://127.0.0.1:9093/api/block/blockInfo
超时时间没有问题,可以返回数据
服务端出现 CLOSE_WAIT 时的响应时间及延时
- 服务端目有大量有CLOSE_WAIT连接状态
# netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'
CLOSE_WAIT 1185
ESTABLISHED 31
- 获取服务端请求响应时间
# curl -o /dev/null -s -w %{time_namelookup}::%{time_connect}::%{time_starttransfer}::%{time_total}::%{speed_download}"\n" -d "number=16619272&sign=b8aaab58e4d73753430c473ba29756d3" http://127.0.0.1:9093/api/block/blockInfo
无法请求到服务端
- 模拟客户端超时
连接超时的话,出错提示形如:
curl: (7) Failed connect to 127.0.0.1:9093; Connection refused
数据传输的最大允许时间超时的话,出错提示形如:
curl: (28) Operation timed out after 30001 milliseconds with 0 out of -1 bytes received
三、解决方法
服务端出现大量的CLOSE_WAIT
连接状态,并且都是客户端请求过来的,说明是客户端主动关闭该连接,客户端需要修改以下两个问题:
- 客户端必须使用HTTP长连接池
- 客户端设置的响应超时时间5秒过于理想化,应修改该超时时间
当然,服务端此时需要请求其它服务获取数据返回给客户端,所以服务端请求时,也必须使用HTTP长连接池,延时可能也会影响该问题的出现,不过最主要的原因还是在客户端上,先修改以上两个问题即可。
以上,就是今天分享的全部内容了。
希望大家通过以上方式可以解决自己的实际需求,解决自己目前所遇到的问题。
如果有任何疑问,可以扫描下面的二维码,添加我的个人微信,备注:地区-职业方向-昵称,欢迎来撩,加入技术交流群,与更多的技术大佬学习交流。
原创不易,码字不易。 觉得这篇文章对你有点用的话,麻烦你为本文点个赞,留言或转发一下,因为这将是我输出更多优质文章的动力,感谢!