Golang之HTTP server 502问题分析

问题引入

  生产环境Golang服务有时会产生502报警，排查发现大多是以下三种原因造成的：

1. http.Server配置了WriteTimeout，请求处理超时，Golang断开连接；
2. http.Server配置了IdleTimeout，且网关和Golang之间使用长连接，，Golang断开连接；
3. Golang服务出现了panic造成服务重启；

  第三种case非常简单，本文将重点分析前两种case背后的深层原因。

  注：请求链路为 客户端 ===> Nginx ===> Golang

WriteTimeout

  Golang sdk的注释说明为 “WriteTimeout is the maximum duration before timing out writes of the response” 。http.Server在读取客户端请求完成时，设置了写超时时间：

func (c *conn) readRequest(ctx context.Context) (w *response, err error) {
    if d := c.server.WriteTimeout; d != 0 {
		defer func() {
			c.rwc.SetWriteDeadline(time.Now().Add(d))
		}()
	}
}

  显然，当请求处理时间超过WriteTimeout，会产生超时现象。为什么超时后会出现502呢？

一个小小的实验

  我们先模拟以下请求处理超时的现象：

package main

import (
	"net/http"
	"time"
)

type GinHandler struct {
}

func (* GinHandler) ServeHTTP(w http.ResponseWriter, r *http.Request){
	time.Sleep(time.Duration(5) * time.Second)
	w.Write([]byte("hello golang"))

}


func main() {
	server := &http.Server{
		Addr:"0.0.0.0:8080",
		Handler: &GinHandler{},
		ReadTimeout: time.Second * 3,
		WriteTimeout: time.Second *3,
	}

	server.ListenAndServe()
}

  请求结果如下：

time  curl http://127.0.0.1/test -H "Host:test.xueersi.com"

502 Bad Gateway

real    0m5.011s

  查看Nginx的错误日志，可以看到是上游主动关闭连接造成的：

2020/08/12 21:18:07 [error] 30217#0: *8105 upstream prematurely closed connection while reading response header from upstream, client: 127.0.0.1, server: test.xueersi.com, request: "GET /test HTTP/1.1", upstream: "http://127.0.0.1:8080/test", host: "test.xueersi.com"

  看到这里有个疑惑。curl命令执行时间为5秒，说明是5秒后Golang服务才断开连接的，我们不是设置了WriteTimeout=3秒吗？为什么3秒超时不断开，而是5秒后才断开？

WriteTimeout到底做了什么

  我们从这一行程序去切入寻找答案，c.rwc.SetWriteDeadline。这里的rwc类型为net.Conn，是一个接口。真正的对象是由l.Accept()返回的，而l是对象TCPListener。往下追踪可以发现创建的是net.TCPConn对象，而该对象继承了net.conn，net.conn又实现了net.Conn接口（注意大小写）。

type TCPConn struct {
	conn
}

type conn struct {
	fd *netFD
}

func (c *conn) SetReadDeadline(t time.Time) error {
	
	if err := c.fd.SetReadDeadline(t); err != nil {
		
	}
}

  再继续往下跟踪，调用链是这样的：

net.(c *conn).SetWriteDeadline()
    net.(fd *netFD).SetWriteDeadline()
        poll.(fd *FD).SetWriteDeadline()
            poll.setDead