Go服务中的502问题总结

问题引入

  服务端开发最常见的问题可能就是HTTP状态码异常了，常见的异常状态码包括404 Not Found，502 Bad Gateway，504 Gateway Time-out等。其中502状态码最常见并且最复杂，本文主要介绍了Go服务可能出现502状态码的几种情况。需要说明的是，本文所有的示例访问链路都是客户端→网关→Go服务，也就是说除了Go服务之外还需要搭建网关服务。

  目前大部分企业都是基于Nginx搭建的网关，而Nginx编译安装过程比较复杂，所以我们选择通过 Docker 方式部署并启动Nginx服务。部署方式如下：

//搜索nginx镜像
docker search nginx
//下载nginx镜像（下载最新版本latest）
docker pull nginx

//容器里Nginx默认配置文件在/etc/nginx目录
//-v目录映射，本地主机文件与容器文件建立映射关系
//-p 端口映射
//-d 后台模式运行，输出容器ID
docker run --name nginx -p 80:80 \
-v /xxx/nginx/nginx.conf:/etc/nginx/nginx.conf \
-v /xxx/nginx/conf.d:/etc/nginx/conf.d \
-v /xxx/nginx/logs:/var/log/nginx \
-d nginx:latest

  参考上面的说明，docker run命令用于运行容器。容器中Nginx服务的默认配置文件位于/etc/nginx目录，因此我们使用-v参数将本地配置文件映射到容器中的指定目录。其中，nginx.conf是Nginx的主配置文件（参考Nginx的默认配置模板）；conf.d目录下包含所有虚拟服务的配置；/var/log/nginx是Nginx服务日志文件的存放目录。

  新建Nginx虚拟服务配置，如下所示：

upstream  localhost {
    server x.x.x.x:8080;
}  // 网关Nginx会将所有请求转发到x.x.x.x:8080

server {
      listen 80;
      server_name _ ;
      location / {
          proxy_pass http://localhost;
      }
}

  当然，别忘了在主配置文件nginx.conf中引入conf.d目录下所有的虚拟服务配置，引入方式如下：

include /etc/nginx/conf.d/*.conf;

Go服务超时为什么是502

  根据HTTP状态码的定义，服务超时的状态码不应该是504吗？为什么我们却说Go服务超时会导致出现502状态码呢？很简单，我们可以模拟Go服务超时的情况，测试一下这时候的状态码到底是502还是504。Go语言的标准库还是比较完善的，基于net/http库只需要几行代码就能创建并启动一个HTTP服务，代码如下：

func main() {
    server := &http.Server{
        Addr: "0.0.0.0:8080",
        // 设置HTTP请求的超时时间为3s
        WriteTimeout: time.Second * 3,
    }
    // 注册请求处理方法
    http.HandleFunc("/ping", func(w http.ResponseWriter, r *http.Request) {
        // 模拟请求超时
        time.Sleep(time.Second * 5)
        w.Write([]byte(r.URL.Path + " > ping response"))
    })
    //启动HTTP服务
    err := server.ListenAndServe()
    ……
}

  参考上面的代码，WriteTimeout用于设置 HTTP 请求的超时时间，函数 http.HandleFunc 用于注册请求处理方法。注意，我们通过函数 time.Sleep 使协程休眠 5s，模拟请求处理超时情况。编译并运行上面的 Go 程序，通过 curl 命令发起 HTTP 请求，结果如下：

time curl  --request POST 'http://127.0.0.1/ping' -v

< HTTP/1.1 502 Bad Gateway
……
// 耗时 0.01s user 0.01s system 0% cpu 5.049 total

  参考上面的运行结果，客户端收到的是502状态码，并且请求处理耗时为5.049s。这里有两个问题。

1. 为什么Go服务超时返回的是502状态码？
2. 明明我们设置的请求超时时间为3s，为什么实际的请求处理耗时却是5.049s？

  502状态码的含义是Bad Gateway，看上去好像是网关错误，其实不是。实际上，502状态码通常是由网关Nginx与上游服务之间的TCP连接异常导致的，或者是上游服务直接返回了502状态码。怎么判断是哪种情况呢？只需查看Nginx的错误日志。如果是网关Nginx与上游服务之间的TCP连接异常导致的502状态码，Nginx一定会记录错误日志。比如针对上面的502状态码问题，查看Nginx的错误日志，如下所示：

[error] upstream prematurely closed connection while reading response header from upstream ……

  参考上面的日志，可以清楚地看到，该502状态码产生的原因是，当网关等待从上游服务读取响应头时，上游服务过早地关闭了连接。也就是说，Go服务在检测到请求超时后，直接关闭了TCP连接，所以才导致网关返回了502状态码。

  还有一个问题，请求超时时间为3s，为什么5s后Go服务才关闭连接呢？这就需要了解WriteTimeout超时功能的实现逻辑了。

  参考图1，当Go服务接收到客户端请求时，首先根据WriteTimeout添加定时器，该定时器的作用是超时后设置与客户端的连接为已超时（注意只是设置一个标识位），所以即使请求处理时间已超过WriteTimeout，Go服务依然还在默默地处理请求。当Go服务处理完该HTTP请求准备向客户端返回数据时，检测到与客户端的连接为已超时，于是便关闭了与客户端的TCP连接，从而导致网关返回了502状态码。

panic异常

  panic异常是如何导致502状态码呢？我们先写一个简单的程序验证一下，代码如下所示：

func main() {
    server := &http.Server{
        Addr: "0.0.0.0:8080",
    }
    http.HandleFunc("/ping", func(w http.ResponseWriter, r *http.Request) {
        panic("panic test")
        w.Write([]byte(r.URL.Path + " > ping response"))
    })
    _ = server.ListenAndServe()
}

  在上面的代码中，我们在HTTP请求处理函数中抛出了panic异常。编译上面的程序，并通过curl命令发起HTTP请求，结果如下所示：

$ curl  --request POST 'http://127.0.0.1/ping' -v
< HTTP/1.1 502 Bad Gateway

  由上面的结果可知，客户端确实收到了502状态码，并且多次执行curl命令的结果都是一样的。另外，如果你这时候查看控制台，你会发现Go服务并没有退出（panic异常可能会导致Go服务退出），但是控制台输出了以下日志：

2023/11/08 20:37:17 http: panic serving xxxx:56850: panic test
goroutine 6 [running]:
net/http.(*conn).serve.func1()
        /go1.18/src/net/http/server.go:1825
panic({0x1217b00, 0x12c8430})
        /go1.18/src/runtime/panic.go:844
main.main.func1({0xc00011ba3b?, 0xffffffffffffffff?}, 0x0?)
        /main.go:15

  参考上面的输出结果，Go服务没有退出，说明一定有函数recover捕获了异常，并输出了协程调用栈，可是既然都捕获panic异常了，为什么网关返回的还是502呢？我们可以查看网关的错误日志，如下所示：

[error] upstream prematurely closed connection while reading response header 
from upstream

  参考上面的错误日志，网关Nginx在等待上游Go服务返回HTTP响应时，上游Go服务过早地关闭了TCP连接。为什么呢？估计是Go服务在处理HTTP请求时，使用函数recover捕获了异常，并关闭了TCP连接。是这样吗？我们简单看一下Go语言底层处理HTTP请求的逻辑，如下所示：

func (c *conn) serve(ctx context.Context) {
    defer func() {
        if err := recover(); err != nil && err != ErrAbortHandler {
            ……
            c.server.logf("http: panic serving %v: %v\n%s", c.remoteAddr, err, buf)
            c.close()
        }
    }()
}

  参考上面的代码，针对TCP连接，Go语言都会创建新的协程来处理从该连接接收到的HTTP请求，并且使用了函数recover来捕获panic异常。可以看到，当发生了panic之后，Go语言一方面输出了协程调用栈来帮助开发者排查问题，另一方面直接关闭了TCP连接，这也是网关Nginx返回502状态码的根本原因。

  最后，panic异常对Go服务的可用性影响非常大，极端情况下甚至会导致Go服务退出。所以，在项目开发过程中，我们应该尽可能避免发生panic异常，这就需要我们对常见的panic异常有一些了解，比如空指针异常、数组/切片索引越界、操作未初始化的散列表、并发操作散列表、类型断言等
。

长连接为什么会导致502

  长连接也会导致502状态码吗？不一定，准确地说，应该是当长连接使用不当时有可能会导致502状态码。我们可以通过具体的示例来验证。

  首先需要说明的是，网关Nginx在代理HTTP请求时默认使用的是短连接，想要使用长连接需要修改网关Nginx的配置，如下所示：

upstream  localhost {
    server x.x.x.x:8080 max_fails=1 fail_timeout=10;
    keepalive 16;
}
server {
      location / {
          proxy_http_version 1.1;
          proxy_set_header Connection "";
       proxy_pass http://localhost;
      }
}

  参考上面的配置，proxy_http_version用于设置网关Nginx在代理HTTP请求时采用的HTTP版本，proxy_set_header用于设置网关Nginx在代理HTTP请求的请求头，keepalive用于设置空闲长连接的数目。可以看到，我们这里采用了1.1版本的HTTP协议，请求头Connection为空，并且最大空闲长连接数目为16，这时候网关Nginx在代理HTTP请求时使用的就是长连接了。在使用长连接之后，抓包结果如下所示：

// 建立TCP连接
17:30:22 IP x.x.x.x.64137 > x.x.x.x.8080: Flags [S], length 0
17:30:22 IP x.x.x.x.8080 > x.x.x.x.64137: Flags [S.], length 0
17:30:22 IP x.x.x.x.64137 > x.x.x.x.8080: Flags [.], length 0
// 第一个HTTP请求
17:30:22 IP x.x.x.x.64137 > x.x.x.x.8080: Flags [P.], length 77: HTTP: GET /ping HTTP/1.1
17:30:22 IP x.x.x.x.8080 > x.x.x.x.64137: Flags [.], length 0
17:30:22 IP x.x.x.x.8080 > x.x.x.x.64137: Flags [P.], length 138: HTTP: HTTP/1.1 200 OK
// 第二个HTTP请求
17:30:25 IP x.x.x.x.64137 > x.x.x.x.8080: Flags [P.], length 77: HTTP: GET /ping HTTP/1.1
17:30:25 IP x.x.x.x.8080 > x.x.x.x.64137: Flags [.], length 0
17:30:25 IP x.x.x.x.8080 > x.x.x.x.64137: Flags [P.], length 138: HTTP: HTTP/1.1 200 OK

  参考上面的抓包结果，当客户端第一次发起HTTP请求时，同样需要建立TCP连接。不同的是，当客户端收到第一个HTTP请求的响应时，没有关闭TCP连接。这样一来，当客户端第二次发起HTTP请求时，就能够复用该TCP连接，从而提高传输效率。

  接下来回到我们最初的问题，为什么长连接会导致502状态码。我们先思考一个问题，假设客户端基于长连接来传输HTTP请求，并且客户端在发起第一个HTTP请求之后，一直没有发起第二个HTTP请求。这时候服务端需要一直维护这个长连接吗？当然不是，毕竟维护长连接是需要消耗系统资源的。所以我们通常会关闭长时间不使用的长连接（称之为空闲长连接）。

  也就是说，空闲长连接通常都会有一个超时时间，比如60秒，其含义是当一个长连接处于空闲状态的时间超过60秒之后，我们应该关闭该长连接。网关Nginx、Go语言都是这么实现的，并且他们都提供了专门的配置，供我们设置空闲长连接的超时时间，如下所示：

// 网关Nginx
Syntax: keepalive_timeout timeout;
Default:    keepalive_timeout 60s;
Context:    upstream
Sets a timeout during which an idle keepalive connection to an upstream server will stay open.
// Go语言
type Server struct {
    // IdleTimeout is the maximum amount of time to wait for the next request
    // when keep-alives are enabled. If IdleTimeout is zero, the value of
    // ReadTimeout is used. If both are zero, there is no timeout.
    IdleTimeout time.Duration
}

  参考上面的配置，在Nginx中，我们可以使用keepalive_timeout来设置空闲长连接的超时时间，注意其默认值是60秒。在Go语言中，我们可以使用IdleTimeout来设置空闲长连接的超时时间，注意如果IdleTimeout等于0，则使用ReadTimeout，当这两个值都等于0时，空闲长连接将永远不会超时（也就是说，此时Go服务将永远不会主动关闭空闲长连接）。

  为什么要介绍空闲长连接的超时时间呢？思考一下，如果Go服务设置的IdleTimeout小于网关Nginx设置的keepalive_timeout，会出现什么情况呢？Go服务有可能先于网关Nginx关闭这个长连接！要知道，网关Nginx是作为客户端向Go服务发起HTTP请求的，如果在Go服务关闭长连接的同时，网关Nginx恰好又发起了一个HTTP请求呢？由于Go服务已经关闭了长连接，所以Go服务所在节点会直接返回一个RST包（参考TCP协议，RST用于重置连接）。对于网关Nginx来说，这就意味着转发HTTP请求出错了（错误信息是"Connection reset by peer"）。于是，网关Nginx就会向客户端返回一个502状态码。这一过程如图2所示：

  参考图2，图中假设Go服务设置的IdleTimeout等于10秒，并且网关Nginx设置的keepalive_timeout等于60秒（默认值）。整个流程比较简单，这里就不再赘述了。
最后，当使用长连接时，服务重启也有可能会引起502。毕竟老的Go服务在退出时，首先会关闭监听的套接字以及空闲长连接，然后在处理完当前所有的HTTP请求（同时关闭对应的TCP连接）之后才会退出。与上面的事例类似，当老的Go服务在关闭空闲长连接时，网关Nginx可能恰好又发起了一个HTTP请求，这时就有可能出现 502状态码。

总结

  HTTP状态码异常是Go服务开发者经常会遇到的问题，而其中以502状态码最为常见并且最复杂。希望读者在以后遇到类似问题时，能够从容应对。