i/o timeout ，希望你不要踩到这个net/http包的坑

Myth丶恋晨 2022-09-10 03:23 50阅读 0赞

> 文章持续更新，可以微信搜一搜「小白debug」第一时间阅读，回复【教程】获golang免费视频教程。本文已经收录在GitHub https://github.com/xiaobaiTech/golangFamily , 有大厂面试完整考点和成长路线，欢迎Star。

### 问题 ###

我们来看一段日常代码。

1package main
     2
     3import (
     4    "bytes"
     5    "encoding/json"
     6    "fmt"
     7    "io/ioutil"
     8    "net"
     9    "net/http"
    10    "time"
    11)
    12
    13var tr *http.Transport
    14
    15func init() {
    16    tr = &http.Transport{
    17        MaxIdleConns: 100,
    18        Dial: func(netw, addr string) (net.Conn, error) {
    19            conn, err := net.DialTimeout(netw, addr, time.Second*2) //设置建立连接超时
    20            if err != nil {
    21                return nil, err
    22            }
    23            err = conn.SetDeadline(time.Now().Add(time.Second * 3)) //设置发送接受数据超时
    24            if err != nil {
    25                return nil, err
    26            }
    27            return conn, nil
    28        },
    29    }
    30}
    31
    32func main() {
    33    for {
    34        _, err := Get("http://www.baidu.com/")
    35        if err != nil {
    36            fmt.Println(err)
    37            break
    38        }
    39    }
    40}
    41
    42
    43func Get(url string) ([]byte, error) {
    44    m := make(map[string]interface{})
    45    data, err := json.Marshal(m)
    46    if err != nil {
    47        return nil, err
    48    }
    49    body := bytes.NewReader(data)
    50    req, _ := http.NewRequest("Get", url, body)
    51    req.Header.Add("content-type", "application/json")
    52
    53    client := &http.Client{
    54        Transport: tr,
    55    }
    56    res, err := client.Do(req)
    57    if res != nil {
    58        defer res.Body.Close()
    59    }
    60    if err != nil {
    61        return nil, err
    62    }
    63    resBody, err := ioutil.ReadAll(res.Body)
    64    if err != nil {
    65        return nil, err
    66    }
    67    return resBody, nil
    68}

做的事情，比较简单，就是循环去请求 `http://www.baidu.com/` , 然后等待响应。

**看上去貌似没啥问题吧。**

代码跑起来，也**确实能正常收发消息**。

但是这段代码跑**一段时间**，就会出现 `i/o timeout` 的报错。

这其实是最近排查了的一个问题，发现这个坑可能比较容易踩上，我这边对代码做了简化。

实际生产中发生的**现象**是，`golang`服务在发起`http`调用时，虽然`http.Transport`设置了`3s`超时，会偶发出现`i/o timeout`的报错。

但是查看下游服务的时候，发现下游服务其实 `100ms` 就已经返回了。

### 排查 ###

![五层网络协议对应的消息体变化分析][1368885d6fe4fe5cf636c57d034116e9.png] 五层网络协议对应的消息体变化分析

就很奇怪了，明明服务端显示处理耗时才`100ms`，且客户端超时设的是`3s`, 怎么就出现超时报错 `i/o timeout` 呢？

这里推测有两个可能。

*  因为服务端打印的日志其实只是**服务端应用层**打印的日志。但客户端应用层发出数据后，中间还经过**客户端的传输层，网络层，数据链路层和物理层**，再经过**服务端的物理层，数据链路层，网络层，传输层到服务端的应用层**。服务端应用层处耗时**100ms**，再原路返回。那剩下的`3s-100ms`**可能是**耗在了整个流程里的各个层上。比如网络不好的情况下，传输层TCP使劲丢包重传之类的原因。
 *  网络没问题，客户端到服务端链路整个收发流程大概耗时就是`100ms`左右。客户端处理逻辑问题导致超时。

**一般遇到问题，大部分情况下都不会是底层网络的问题，大胆怀疑是自己的问题就对了**，不死心就抓个包看下。

![07f6be4c3ab58a6dc681c1691e2a3e8d.png][]

抓包结果

分析下，从刚开始三次握手（**画了红框的地方**）。

到最后出现超时报错 `i/o timeout` （**画了蓝框的地方**）。

从`time`那一列从`7`到`10`，确实间隔`3s`。而且看**右下角**的蓝框，是`51169`端口发到`80`端口的一次`Reset`连接。

`80`端口是服务端的端口。换句话说就是客户端`3s`超时**主动**断开链接的。

但是再仔细看下**第一行**三次握手到**最后**客户端超时主动断开连接的中间，其实有**非常多次HTTP请求**。

回去看代码设置超时的方式。

1    tr = &http.Transport{
     2        MaxIdleConns: 100,
     3        Dial: func(netw, addr string) (net.Conn, error) {
     4            conn, err := net.DialTimeout(netw, addr, time.Second*2) //设置建立连接超时
     5            if err != nil {
     6                return nil, err
     7            }
     8            err = conn.SetDeadline(time.Now().Add(time.Second * 3)) //设置发送接受数据超时
     9            if err != nil {
    10                return nil, err
    11            }
    12            return conn, nil
    13        },
    14    }

也就是说，这里的`3s`超时，其实是在**建立连接之后**开始算的，而不是**单次调用开始算的**超时。

看注释里写的是

> SetDeadline sets the read and write deadlines associated with the **connection**.

### 超时原因 ###

大家知道`HTTP`是应用层协议，传输层用的是`TCP`协议。

HTTP协议从`1.0`以前，默认用的是`短连接`，每次发起请求都会建立TCP连接。收发数据。然后断开连接。

TCP连接每次都是三次握手。每次断开都要四次挥手。

其实没必要每次都建立新连接，建立的连接不断开就好了，每次发送数据都复用就好了。

于是乎，HTTP协议从`1.1`之后就默认使用`长连接`。具体相关信息可以看之前的 [这篇文章][Link 1]。

那么`golang标准库`里也兼容这种实现。

通过建立一个连接池，针对`每个域名`建立一个TCP长连接，比如`http://baidu.com`和`http://golang.com` 就是两个不同的域名。

第一次访问`http://baidu.com` 域名的时候会建立一个连接，用完之后放到空闲连接池里，下次再要访问`http://baidu.com` 的时候会重新从连接池里把这个连接捞出来`复用`。

![复用长连接][e48f6abcf52818d52bc918c41d7f19fb.png] 复用长连接

> 插个题外话：这也解释了之前[这篇文章][Link 2]里最后的疑问，为什么要强调是同一个域名：一个域名会建立一个连接，一个连接对应**一个读goroutine和一个写goroutine**。正因为是同一个域名，所以最后才会泄漏`3`个goroutine，如果不同域名的话，那就会泄漏 `1+2*N` 个协程，`N`就是域名数。

假设第一次请求要`100ms`，每次请求完`http://baidu.com` 后都**放入**连接池中，下次继续复用，重复`29`次，耗时`2900ms`。

第`30`次请求的时候，连接从建立开始到服务返回前就已经用了`3000ms`，刚好到设置的**3s**超时阈值，那么此时客户端就会报超时 `i/o timeout` 。

虽然这时候服务端其实才花了`100ms`，但耐不住前面`29次`加起来的耗时已经很长。

也就是说只要通过 `http.Transport` 设置了 `err = conn.SetDeadline(time.Now().Add(time.Second * 3))`，并且你用了**长连接**，哪怕服务端处理再快，客户端设置的超时再长，总有一刻，你的程序会报超时错误。

### 正确姿势 ###

原本预期是给每次调用设置一个超时，而不是给整个连接设置超时。

另外，上面出现问题的原因是给长连接设置了超时，且长连接会复用。

基于这两点，改一下代码。

1package main
     2
     3import (
     4    "bytes"
     5    "encoding/json"
     6    "fmt"
     7    "io/ioutil"
     8    "net/http"
     9    "time"
    10)
    11
    12var tr *http.Transport
    13
    14func init() {
    15    tr = &http.Transport{
    16        MaxIdleConns: 100,
    17        // 下面的代码被干掉了
    18        //Dial: func(netw, addr string) (net.Conn, error) {
    19        //  conn, err := net.DialTimeout(netw, addr, time.Second*2) //设置建立连接超时
    20        //  if err != nil {
    21        //      return nil, err
    22        //  }
    23        //  err = conn.SetDeadline(time.Now().Add(time.Second * 3)) //设置发送接受数据超时
    24        //  if err != nil {
    25        //      return nil, err
    26        //  }
    27        //  return conn, nil
    28        //},
    29    }
    30}
    31
    32
    33func Get(url string) ([]byte, error) {
    34    m := make(map[string]interface{})
    35    data, err := json.Marshal(m)
    36    if err != nil {
    37        return nil, err
    38    }
    39    body := bytes.NewReader(data)
    40    req, _ := http.NewRequest("Get", url, body)
    41    req.Header.Add("content-type", "application/json")
    42
    43    client := &http.Client{
    44        Transport: tr,
    45        Timeout: 3*time.Second,  // 超时加在这里，是每次调用的超时
    46    }
    47    res, err := client.Do(req) 
    48    if res != nil {
    49        defer res.Body.Close()
    50    }
    51    if err != nil {
    52        return nil, err
    53    }
    54    resBody, err := ioutil.ReadAll(res.Body)
    55    if err != nil {
    56        return nil, err
    57    }
    58    return resBody, nil
    59}
    60
    61func main() {
    62    for {
    63        _, err := Get("http://www.baidu.com/")
    64        if err != nil {
    65            fmt.Println(err)
    66            break
    67        }
    68    }
    69}

看注释会发现，改动的点有两个

*  `http.Transport`里的建立连接时的一些超时设置干掉了。
 *  在发起http请求的时候会场景`http.Client`，此时加入超时设置，这里的超时就可以理解为单次请求的超时了。同样可以看下注释

> Timeout specifies a time limit for **requests** made by this Client.

到这里，代码就改好了，实际生产中问题也就解决了。

实例代码里，如果拿去跑的话，其实还会下面的错

1Get http://www.baidu.com/: EOF

这个是因为调用得太猛了，`http://www.baidu.com` 那边主动断开的连接，可以理解为一个限流措施，目的是为了保护服务器，**毕竟每个人都像这么搞，服务器是会炸的**。。。

解决方案很简单，每次HTTP调用中间加个`sleep`间隔时间就好。

到这里，其实问题已经解决了，下面会在源码层面分析出现问题的原因。对读源码不感兴趣的朋友们可以不用接着往下看，直接拉到文章底部**右下角**，做点正能量的事情（**点两下**）支持一下。（**疯狂暗示，拜托拜托，这对我真的很重要！**）

### 源码分析 ###

**用的go版本是1.12.7**。

从发起一个网络请求开始跟。

1res, err := client.Do(req)
     2func (c *Client) Do(req *Request) (*Response, error) {
     3    return c.do(req)
     4}
     5
     6func (c *Client) do(req *Request) {
     7    // ...
     8    if resp, didTimeout, err = c.send(req, deadline); err != nil {
     9    // ...
    10  }
    11    // ...  
    12}  
    13func send(ireq *Request, rt RoundTripper, deadline time.Time) {
    14    // ...    
    15    resp, err = rt.RoundTrip(req)
    16     // ...  
    17} 
    18
    19// 从这里进入 RoundTrip 逻辑
    20/src/net/http/roundtrip.go: 16
    21func (t *Transport) RoundTrip(req *Request) (*Response, error) {
    22    return t.roundTrip(req)
    23}
    24
    25func (t *Transport) roundTrip(req *Request) (*Response, error) {
    26    // 尝试去获取一个空闲连接，用于发起 http 连接
    27  pconn, err := t.getConn(treq, cm)
    28  // ...
    29}
    30
    31// 重点关注这个函数，返回是一个长连接
    32func (t *Transport) getConn(treq *transportRequest, cm connectMethod) (*persistConn, error) {
    33  // 省略了大量逻辑，只关注下面两点
    34    // 有空闲连接就返回
    35    pc := <-t.getIdleConnCh(cm)
    36
    37  // 没有创建连接
    38  pc, err := t.dialConn(ctx, cm)
    39
    40}

这里上面很多代码，其实只是为了展示这部分代码是怎么跟踪下来的，方便大家去看源码的时候去跟一下。

最后一个上面的代码里有个 `getConn` 方法。在发起网络请求的时候，会先取一个网络连接，取连接有两个来源。

*  如果有空闲连接，就拿空闲连接
    
        1/src/net/http/tansport.go:810
        2func (t *Transport) getIdleConnCh(cm connectMethod) chan *persistConn {
        3 // 返回放空闲连接的chan
        4 ch, ok := t.idleConnCh[key]
        5   // ...
        6 return ch
        7}
 *  没有空闲连接，就创建长连接。

1/src/net/http/tansport.go:1357
    2func (t *Transport) dialConn() {
    3  //...
    4  conn, err := t.dial(ctx, "tcp", cm.addr())
    5  // ...
    6  go pconn.readLoop()
    7  go pconn.writeLoop()
    8  // ...
    9}

当**第一次**发起一个http请求时，这时候肯定没有空闲连接，会建立一个新连接。同时会创建一个**读goroutine和一个写goroutine**。

![读写协程][af090a644bc6317301fbcde9a8b16440.png] 读写协程

注意上面代码里的`t.dial(ctx, "tcp", cm.addr())`，如果像文章开头那样设置了 `http.Transport`的

1Dial: func(netw, addr string) (net.Conn, error) {
     2   conn, err := net.DialTimeout(netw, addr, time.Second*2) //设置建立连接超时
     3   if err != nil {
     4      return nil, err
     5   }
     6   err = conn.SetDeadline(time.Now().Add(time.Second * 3)) //设置发送接受数据超时
     7   if err != nil {
     8      return nil, err
     9   }
    10   return conn, nil
    11},

那么这里就会在下面的`dial`里被执行到

1func (t *Transport) dial(ctx context.Context, network, addr string) (net.Conn, error) {
    2   // ...
    3  c, err := t.Dial(network, addr)
    4  // ...
    5}

这里面调用的设置超时，会执行到

1/src/net/net.go
     2func (c *conn) SetDeadline(t time.Time) error {
     3    //...
     4    c.fd.SetDeadline(t)
     5    //...
     6}
     7
     8//...
     9
    10func setDeadlineImpl(fd *FD, t time.Time, mode int) error {
    11    // ...
    12    runtime_pollSetDeadline(fd.pd.runtimeCtx, d, mode)
    13    return nil
    14}
    15
    16
    17//go:linkname poll_runtime_pollSetDeadline internal/poll.runtime_pollSetDeadline
    18func poll_runtime_pollSetDeadline(pd *pollDesc, d int64, mode int) {
    19    // ...
    20  // 设置一个定时器事件
    21  rtf = netpollDeadline
    22    // 并将事件注册到定时器里
    23  modtimer(&pd.rt, pd.rd, 0, rtf, pd, pd.rseq)
    24}

上面的源码，简单来说就是，当第一次调用请求的，会建立个连接，这时候还会注册一个**定时器事件**，假设时间设了`3s`，那么这个事件会在`3s`后发生，然后执行注册事件的逻辑。而这个注册事件就是`netpollDeadline`。 **注意这个`netpollDeadline`，待会会提到。**

![读写协程定时器事件][f607243afee29946bfacf31843d5d789.png] 读写协程定时器事件

设置了超时事件，且超时事件是3s后之后，发生。再次期间正常收发数据。一切如常。

直到`3s`过后，这时候看`读goroutine`，会等待网络数据返回。

1/src/net/http/tansport.go:1642
    2func (pc *persistConn) readLoop() {
    3    //...
    4    for alive {
    5        _, err := pc.br.Peek(1)  // 阻塞读取服务端返回的数据
    6    //...
    7}

然后就是一直跟代码。

1src/bufio/bufio.go: 129
     2func (b *Reader) Peek(n int) ([]byte, error) {
     3   // ...
     4   b.fill() 
     5   // ...   
     6}
     7
     8func (b *Reader) fill() {
     9    // ...
    10    n, err := b.rd.Read(b.buf[b.w:])
    11    // ...
    12}
    13
    14/src/net/http/transport.go: 1517
    15func (pc *persistConn) Read(p []byte) (n int, err error) {
    16    // ...
    17    n, err = pc.conn.Read(p)
    18    // ...
    19}
    20
    21// /src/net/net.go: 173
    22func (c *conn) Read(b []byte) (int, error) {
    23    // ...
    24    n, err := c.fd.Read(b)
    25    // ...
    26}
    27
    28func (fd *netFD) Read(p []byte) (n int, err error) {
    29    n, err = fd.pfd.Read(p)
    30    // ...
    31}
    32
    33/src/internal/poll/fd_unix.go: 
    34func (fd *FD) Read(p []byte) (int, error) {
    35    //...
    36  if err = fd.pd.waitRead(fd.isFile); err == nil {
    37    continue
    38  }
    39    // ...
    40}
    41
    42func (pd *pollDesc) waitRead(isFile bool) error {
    43    return pd.wait('r', isFile)
    44}
    45
    46func (pd *pollDesc) wait(mode int, isFile bool) error {
    47    // ...
    48  res := runtime_pollWait(pd.runtimeCtx, mode)
    49    return convertErr(res, isFile)
    50}

直到跟到 **runtime\_pollWait**，这个可以简单认为是**等待服务端数据返回**。

1//go:linkname poll_runtime_pollWait internal/poll.runtime_pollWait
     2func poll_runtime_pollWait(pd *pollDesc, mode int) int {
     3
     4    // 1.如果网络正常返回数据就跳出
     5  for !netpollblock(pd, int32(mode), false) {
     6    // 2.如果有出错情况也跳出
     7        err = netpollcheckerr(pd, int32(mode))
     8        if err != 0 {
     9            return err
    10        }
    11    }
    12    return 0
    13}

整条链路跟下来，就是会一直等待数据，等待的结果只有两个

*  有可以读的数据
 *  出现报错

这里面的**报错**，又有那么两种

*  连接关闭
 *  超时

1func netpollcheckerr(pd *pollDesc, mode int32) int {
    2    if pd.closing {
    3        return 1 // errClosing
    4    }
    5    if (mode == 'r' && pd.rd < 0) || (mode == 'w' && pd.wd < 0) {
    6        return 2 // errTimeout
    7    }
    8    return 0
    9}

其中提到的`超时`，就是指这里面返回的`数字2`，会通过下面的函数，转化为 `ErrTimeout`， 而 `ErrTimeout.Error()` 其实就是 `i/o timeout`。

1func convertErr(res int, isFile bool) error {
     2    switch res {
     3    case 0:
     4        return nil
     5    case 1:
     6        return errClosing(isFile)
     7    case 2:
     8        return ErrTimeout // ErrTimeout.Error() 就是 "i/o timeout"
     9    }
    10    println("unreachable: ", res)
    11    panic("unreachable")
    12}

那么问题来了。上面返回的超时错误，也就是**返回2的时候的条件是怎么满足的**？

1    if (mode == 'r' && pd.rd < 0) || (mode == 'w' && pd.wd < 0) {
    2        return 2 // errTimeout
    3    }

还记得刚刚提到的 `netpollDeadline`吗？

这里面放了定时器`3s`到点时执行的逻辑。

1func timerproc(tb *timersBucket) {
     2    // 计时器到设定时间点了，触发之前注册函数
     3    f(arg, seq) // 之前注册的是 netpollDeadline
     4}
     5
     6func netpollDeadline(arg interface{}, seq uintptr) {
     7    netpolldeadlineimpl(arg.(*pollDesc), seq, true, true)
     8}
     9
    10/src/runtime/netpoll.go: 428
    11func netpolldeadlineimpl(pd *pollDesc, seq uintptr, read, write bool) {
    12    //...
    13    if read {
    14        pd.rd = -1
    15        rg = netpollunblock(pd, 'r', false)
    16    }
    17    //...
    18}

这里会设置`pd.rd=-1`，是指 `poller descriptor.read deadline` ，含义**网络轮询器文件描述符**的**读超时时间**， 我们知道在linux里万物皆文件，这里的文件其实是指这次网络通讯中使用到的**socket**。

这时候再回去看**发生超时的条件**就是`if (mode == 'r' && pd.rd < 0)`。

至此。我们的代码里就收到了 `io timeout` 的报错。

### 总结 ###

*  不要在 `http.Transport`中设置超时，那是连接的超时，不是请求的超时。否则可能会出现莫名 `io timeout`报错。
 *  请求的超时在创建`client`里设置。

如果文章对你有帮助，看下文章底部右下角，做点正能量的事情（**点两下**）支持一下。（**疯狂暗示，拜托拜托，这对我真的很重要！**）

我是小白，我们下期见。

### 文章推荐： ###

*  [妙啊! 程序猿的第一本互联网黑话指南][Link 3]
 *  [程序员防猝死指南][Link 4]
 *  [我感觉，我可能要拿图灵奖了。。。][Link 5]
 *  [给大家丢脸了，用了三年golang，我还是没答对这道内存泄漏题][Link 2]
 *  [硬核！漫画图解HTTP知识点+面试题][Link 1]
 *  [TCP粘包 数据包：我只是犯了每个数据包都会犯的错 |硬核图解][Link 4]
 *  [硬核图解！30张图带你搞懂！路由器，集线器，交换机，网桥，光猫有啥区别？][30]

###### 别说了，一起在知识的海洋里呛水吧 ######

关注公众号:**【小白debug】**

[1368885d6fe4fe5cf636c57d034116e9.png]: /images/20220829/cf5c6d4e605546e7a7251b321ef36120.png
[07f6be4c3ab58a6dc681c1691e2a3e8d.png]: /images/20220829/468af94c3b474322a1dd3e6afa8214e5.png
[Link 1]: https://mp.weixin.qq.com/s?__biz=MzAwMDAxNjU4Mg%3D%3D&idx=1&mid=2247484204&scene=21&sn=0e83aabb2a48570b5bec563a777f4d26#wechat_redirect
[e48f6abcf52818d52bc918c41d7f19fb.png]: /images/20220829/6bc9adb621a34e6b8c2c75ce55261286.png
[Link 2]: https://mp.weixin.qq.com/s?__biz=MzAwMDAxNjU4Mg%3D%3D&idx=1&mid=2247483794&scene=21&sn=0b617bf9acffc17afa5b3278d3d32eef#wechat_redirect
[af090a644bc6317301fbcde9a8b16440.png]: /images/20220829/2256d664185c476caf9b8dee638f81ba.png
[f607243afee29946bfacf31843d5d789.png]: /images/20220829/ee05476350ed4343a562c5c70622dede.png
[Link 3]: https://mp.weixin.qq.com/s?__biz=MzAwMDAxNjU4Mg%3D%3D&idx=1&mid=2247484666&scene=21&sn=8934b34eed16f52160724759f91c50cb#wechat_redirect
[Link 4]: https://mp.weixin.qq.com/s?__biz=MzAwMDAxNjU4Mg%3D%3D&idx=1&mid=2247483874&scene=21&sn=fa24dbed4709e5bf3f876f2c38351b49#wechat_redirect
[Link 5]: https://mp.weixin.qq.com/s?__biz=MzAwMDAxNjU4Mg%3D%3D&idx=1&mid=2247484695&scene=21&sn=11c0505769ef91e8a7bcc8ee5c27559a#wechat_redirect
[30]: https://mp.weixin.qq.com/s?__biz=MzAwMDAxNjU4Mg%3D%3D&idx=1&mid=2247484640&scene=21&sn=9c6fcd4c5973278e401188f32b54be97#wechat_redirect