服务器假死 http 状态码,关于golang:Golang之HTTP服务『假死』问题排查

最新推荐文章于 2025-01-05 18:53:43 发布

转载最新推荐文章于 2025-01-05 18:53:43 发布 · 928 阅读

文章标签：

博客描述了在Golang服务中遇到的一个问题，即HTTP请求出现504超时，服务端无响应。通过分析发现，问题源于大量协程在写日志时阻塞，进一步排查确定是日志写入管道的子协程异常退出导致。解决方案包括使用非阻塞方式写入管道，以避免阻塞HTTP请求处理。

问题形容

下午15点左右，QA反馈灰度环境大量申请超时。kibana查问灰度网关日志，的确存在局部申请响应工夫超过60秒，HTTP状态码504。进一步剖析日志，所有504申请的上游地址都是xxxx:80。

目前该服务部署了两套环境，k8s + kvm，k8s环境上游ingress(即Nginx)端口80，kvm环境上游Golang服务端口19001。且，k8s环境该服务只部署一个pod。是单单k8s环境服务有问题吗？

登录到k8s服务终端，手动curl申请(healthCheck接口，没有简单的业务解决，间接返回数据)，发现申请没有任何响应，且始终阻塞。很大概率是该Golang服务有问题了。

排查过程

healthCheck接口逻辑十分的简略，为什么会阻塞呢？服务没有接管到该申请吗？tcpdump抓包看看：

//xxxx为k8s入口ingress地址

curl http://xxxx/v1/healthCheck -H "Host:studentlive.xueersi.com"

//三次握手

10:20:21.940968 IP xxxx.40970 > server.19001: Flags [S], seq 3201212889, win 29200, length 0

10:20:21.941003 IP server.19001 > xxxx.40970: Flags [S.], seq 1905160768, ack 3201212890, win 28960, length 0

10:20:21.941175 IP xxxx.40970 > server.19001: Flags [.], ack 1905160769, win 58, length 0

//发送HTTP申请数据

10:20:21.941219 IP xxxx.40970 > server.19001: Flags [P.], seq 3201212890:3201213201, ack 1905160769, win 58, length 311

10:20:21.941223 IP server.19001 > xxxx.40970: Flags [.], ack 3201213201, win 59, length 0

//客户端被动断开连接

10:21:21.945740 IP xxxx.40970 > server.19001: Flags [F.], seq 3201213201, ack 1905160769, win 58, length 0

10:21:21.985062 IP server.19001 > xxxx.40970: Flags [.], ack 3201213202, win 59, length 0

能够看到，三次握手胜利，客户端发送了HTTP数据，服务端也失常返回ACk；然而没下文了，客户端期待60秒后，被动断开了连贯。(Nginx配置：proxy_read_timeout=60秒)。

服务端接管到客户端申请为什么没有响应呢？能够dlv跟踪调试申请解决流程，看看是在哪一个环节阻塞了；另外，服务都开启了pprof，能够先看看以后服务的状态。

curl http://localhost:17009/debug/pprof/

16391 goroutine

……

协程数目十分多，有1.6w，而灰度环境目前流量已切走；实践上不应该存在这么多协程的。

持续应用pprof查看协程统计详细信息：

go tool pprof http://localhost:17009/debug/pprof/goroutine

(pprof) traces

----------+-------------------------------------------------------

7978 runtime.gopark

runtime.goparkunlock

runtime.chansend

runtime.chansend1

git.100tal.com/wangxiao_go_lib/xesLogger/log4go.(*FileLogTraceWriter).LogWrite

git.100tal.com/wangxiao_go_lib/xesLogger/log4go.Logger.LogTraceMap

git.100tal.com/wangxiao_go_lib/xesLogger/log4go.LogTraceMap

git.100tal.com/wangxiao_go_lib/xesLogger/builders.(*TraceBuilder).LoggerX

git.100tal.com/wangxiao_go_lib/xesLogger.Ix

git.100tal.com/wangxiao_go_lib/xesGoKit/middleware.Logger.func1

github.com/gin-gonic/gin.(*Context).Next

github.com/gin-gonic/gin.(*Engine).handleHTTPRequest

github.com/gin-gonic/gin.(*Engine).ServeHTTP

net/http.serverHandler.ServeHTTP

net/http.(*conn).serve

能够看到，大量协程在写日志(LogWrite)时候，阻塞了(管道写阻塞runtime.chansend)，触发了协程切换。

代码Review

通过下面的排查，曾经能够根本确认申请是阻塞在写日志这里了；上面须要排查下写日志为什么会阻塞申请呢。写日志的逻辑是这样的：

//写日志办法；只是写管道

func (w *FileLogTraceWriter) LogWrite(rec *LogRecord) {

w.rec

}

func NewFileLogTraceWriter(fname string, rotate bool) *FileLogTraceWriter {

//子协程，从管道读取数据写入buffer

go func() {

for {

select {

case rec, ok :=

}

//子协程，从buffer读取数据写入文件

go func() {

for {

select {

case lb, ok :=

}

咱们看到，HTTP解决申请，在写日志时候，调用LogWrite办法将日志写入管道。而在初始化FileLogTraceWriter时候，会启动子协程从管道中死循环读取日志数据。日志写入管道阻塞了，很有可能是这个子协程出异样了。

查找这两个子协程堆栈：

1 runtime.gopark

runtime.selectgo

git.100tal.com/wangxiao_go_lib/xesLogger/log4go.NewFileLogTraceWriter.func2

NewFileLogTraceWriter.func2阻塞在select处；NewFileLogTraceWriter.func1协程不存在。

问题明确了，从管道中生产日志的子协程因为某些起因退出了。该协程有两处逻辑，在呈现谬误时候，间接return，会导致协程的完结。只惋惜灰度环境没有采集日志，工夫太长日志都不存在了，无奈确定协程退出的真正起因。

另外，查看日志文件的状态等都是失常的：

//日志门路，权限等失常

# ll /home/logs/xeslog/talcamp/talcamp.log

-rw-r--r-- 1 root root 0 Nov 10 00:00 /home/logs/xeslog/talcamp/talcamp.log

//服务失常关上日志文件

# lsof -p 67 | grep "talcamp.log"

9 /home/www/talcamp/bin/talcamp /home/logs/xeslog/talcamp/talcamp.log

非阻塞革新

HTTP申请解决协程，通过写管道形式写日志，就是为了不阻塞本人。然而发现，当管道消费者异样时候，还是会造成阻塞。web服务，写日志是必然的同时也是非必须的，如何能力保障写日志不会阻塞HTTP申请解决呢？其实写管道也能够是非阻塞形式的：

有趣味的能够查看runtime/chan.go文件学习。

// 非阻塞写实现

// compiler implements

// select {

// case c

// ... foo

// default:

// ... bar

// }

// as

// if selectnbsend(c, v) {

// ... foo

// } else {

// ... bar

// }

func selectnbsend(c *hchan, elem unsafe.Pointer) (selected bool) {

return chansend(c, elem, false, getcallerpc())

}

// 非阻塞读实现

//compiler implements

// select {

// case v =

// ... foo

// default:

// ... bar

// }

// as

// if selectnbrecv(&v, c) {

// ... foo

// } else {

// ... bar

// }

func selectnbrecv(elem unsafe.Pointer, c *hchan) (selected bool) {

selected, _ = chanrecv(c, elem, false)

return

}

查看Golang SDK源码，基于select能够实现管道的非阻塞读写(chanrecv与chansend函数，第三个参数标识是否阻塞以后协程)。另外，咱们也能够稍加革新，实现管道带超时工夫的读写。