服务器假死 http 状态码,关于golang:Golang之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/
16391goroutine……
協程數目十分多，有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函數，第三個參數標識是否阻塞以后協程)。另外，咱們也能夠稍加革新，實現管道帶超時工夫的讀寫。
總結
以上是生活随笔為你收集整理的服务器假死 http 状态码,关于golang:Golang之HTTP服务『假死』问题排查的全部內容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： JavaScript——利用onblur
- 下一篇： libvirt零知识学习2 —— lib