i/o タイムアウト、この net/http パッケージの罠に踏まないことを祈ります

質問

毎日のコードを見てみましょう。

 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 エラーが表示されます。

これは実は最近調査された問題で、この落とし穴に踏みやすい可能性があることがわかったので、ここでコードを簡略化しました。

実際の運用環境で発生する

現象 は、http.Transport# にもかかわらず、golang サービスが http 呼び出しを開始することです。 ##3s タイムアウトが設定されている場合、i/o timeout エラーが表示されることがあります。 しかし、ダウンストリーム サービスを確認したところ、実際にはダウンストリーム サービスが

100ms

で戻ってきたことがわかりました。

トラブルシューティング

5 層ネットワーク プロトコルに対応するメッセージ本文の変更の分析

非常に奇妙です、サーバー処理時間は 100ms のみで、クライアント タイムアウトは 3s に設定されているのに、タイムアウト エラー i/o timeout が表示されるのはなぜですか?

#ここには 2 つの可能性があります。

• サーバーによって出力されるログは、実際には

  サーバー アプリケーション層によって出力されるログのみであるためです。ただし、クライアント アプリケーション層がデータを送信した後、データは クライアントのトランスポート層、ネットワーク層、データリンク層、物理層 を通過し、さらに サーバーの物理層、データリンク層、ネットワークも通過します。サーバー側の層、トランスポート層からアプリケーション層まで。サーバー アプリケーション層で 100ms かかり、その後元のパスに戻ります。残りの 3 秒～100 ミリ秒 は、プロセス全体のさまざまなレイヤーで 無駄になる可能性があります。たとえば、ネットワークが良好でない場合、トランスポート層の TCP はパケットを激しく失い、再送信します。

• ネットワークに問題はありません。クライアントからサーバーまでの送受信プロセス全体には、おそらく

  100ms 程度かかります。クライアント処理ロジックの問題によりタイムアウトが発生します。

  
  

通常、問題が発生した場合、ほとんどの場合、それは基盤となるネットワークの問題ではありません。あなた自身の問題、あなたは正しいです。、諦めたくないなら、バッグを手に取って見てください。

パケット キャプチャ結果

分析後、3 回のハンドシェイクの最初から (

赤いボックスが表示されている場所)描かれています＃＃ ＃）。

到最后出现超时报错 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 以降、デフォルトで short connection を使用しており、リクエストが行われるたびに TCP 接続が確立されます。データを送受信します。その後、接続を解除します。

すべての TCP 接続は 3 ウェイ ハンドシェイクです。それぞれの切断には 4 つの波が必要です。

実際には、毎回新しい接続を確立する必要はなく、確立された接続は切断されない限り、データを送信するたびに再利用されます。

それ以来、HTTP プロトコルは 1.1 以降、デフォルトで 長い接続を使用するようになりました。具体的な情報については、この前の記事を参照してください。

となると、golang 標準ライブラリ もこの実装と互換性があります。

接続プールを確立することで、http://baidu.com や http:/ などの 各ドメイン名 に対して TCP ロング接続を確立します。 / golang.com は 2 つの異なるドメイン名です。

http://baidu.com に初めてアクセスすると、接続が確立され、使い果たされると、アイドル接続プールに配置されます。 http://baidu.com にアクセスすると、接続プール reuse からこの接続が取得されます。

長い接続を再利用する

余談を挿入します。これは、この記事の最後のステートメントについても説明しています。同じドメイン名であることを強調します。ドメイン名は接続を確立し、1 つの接続は 読み取りゴルーチンと書き込みゴルーチン に対応します。同じドメイン名なので最終的には 3 個のゴルーチンが漏洩しますが、異なるドメイン名であれば 1 2*N 個のゴルーチンが漏洩します、N はドメイン名の数です。

最初のリクエストに 100ms かかると仮定し、各リクエストの後に http://baidu.com を配置します。すべての を 接続プールに追加し、次回も再利用し続けます。これを 29 回繰り返し、2900ms かかります。

30 リクエストの時点で、接続は確立されてからサービスが返されるまでにすでに 3000ms かかっており、設定された # にちょうど到達しました。 ##3s タイムアウトしきい値を設定すると、クライアントはタイムアウト i/o タイムアウト を報告します。

この時点でサーバーは実際には

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。

读写协程

注意上面代码里的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，待会会提到。

读写协程定时器事件

设置了超时事件，且超时事件是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 == &#39;r&#39; && pd.rd < 0) || (mode == &#39;w&#39; && 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 == &#39;r&#39; && pd.rd < 0) || (mode == &#39;w&#39; && 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 で設定されます。

以上がi/o タイムアウト、この net/http パッケージの罠に踏まないことを祈りますの詳細内容です。詳細については、PHP 中国語 Web サイトの他の関連記事を参照してください。