i/o timeout ， 希望你不要踩到這個net/http包的坑
共 23309字，需瀏覽 47分鐘
·
2024-04-20 10:00
文章持續(xù)更新，可以微信搜一搜「golang小白成長記」第一時間閱讀，回復(fù)【教程】獲golang免費視頻教程。本文已經(jīng)收錄在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) //設(shè)置建立連接超時
20 if err != nil {
21 return nil, err
22 }
23 err = conn.SetDeadline(time.Now().Add(time.Second * 3)) //設(shè)置發(fā)送接受數(shù)據(jù)超時
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}
做的事情，比較簡單，就是循環(huán)去請求 http://www.baidu.com/ , 然后等待響應(yīng)。
看上去貌似沒啥問題吧。
代碼跑起來，也確實能正常收發(fā)消息。
但是這段代碼跑一段時間，就會出現(xiàn) i/o timeout 的報錯。
這其實是最近排查了的一個問題，發(fā)現(xiàn)這個坑可能比較容易踩上，我這邊對代碼做了簡化。
實際生產(chǎn)中發(fā)生的現(xiàn)象是，golang服務(wù)在發(fā)起http調(diào)用時，雖然http.Transport設(shè)置了3s超時，會偶發(fā)出現(xiàn)i/o timeout的報錯。
但是查看下游服務(wù)的時候，發(fā)現(xiàn)下游服務(wù)其實 100ms 就已經(jīng)返回了。
排查
就很奇怪了，明明服務(wù)端顯示處理耗時才100ms，且客戶端超時設(shè)的是3s, 怎么就出現(xiàn)超時報錯 i/o timeout 呢？
這里推測有兩個可能。
因為服務(wù)端打印的日志其實只是服務(wù)端應(yīng)用層打印的日志。但客戶端應(yīng)用層發(fā)出數(shù)據(jù)后，中間還經(jīng)過客戶端的傳輸層，網(wǎng)絡(luò)層，數(shù)據(jù)鏈路層和物理層，再經(jīng)過服務(wù)端的物理層，數(shù)據(jù)鏈路層，網(wǎng)絡(luò)層，傳輸層到服務(wù)端的應(yīng)用層。服務(wù)端應(yīng)用層處耗時100ms，再原路返回。那剩下的
3s-100ms可能是耗在了整個流程里的各個層上。比如網(wǎng)絡(luò)不好的情況下，傳輸層TCP使勁丟包重傳之類的原因。網(wǎng)絡(luò)沒問題，客戶端到服務(wù)端鏈路整個收發(fā)流程大概耗時就是
100ms左右?？蛻舳颂幚磉壿媶栴}導(dǎo)致超時。
一般遇到問題，大部分情況下都不會是底層網(wǎng)絡(luò)的問題，大膽懷疑是自己的問題就對了，不死心就抓個包看下。
分析下，從剛開始三次握手（畫了紅框的地方）。
到最后出現(xiàn)超時報錯 i/o timeout （畫了藍框的地方）。
從time那一列從7到10，確實間隔3s。而且看右下角的藍框，是51169端口發(fā)到80端口的一次Reset連接。
80端口是服務(wù)端的端口。換句話說就是客戶端3s超時主動斷開鏈接的。
但是再仔細看下第一行三次握手到最后客戶端超時主動斷開連接的中間，其實有非常多次HTTP請求。
回去看代碼設(shè)置超時的方式。
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) //設(shè)置建立連接超時
5 if err != nil {
6 return nil, err
7 }
8 err = conn.SetDeadline(time.Now().Add(time.Second * 3)) //設(shè)置發(fā)送接受數(shù)據(jù)超時
9 if err != nil {
10 return nil, err
11 }
12 return conn, nil
13 },
14 }
也就是說，這里的3s超時，其實是在建立連接之后開始算的，而不是單次調(diào)用開始算的超時。
看注釋里寫的是
SetDeadline sets the read and write deadlines associated with the connection.
超時原因
大家知道HTTP是應(yīng)用層協(xié)議，傳輸層用的是TCP協(xié)議。
HTTP協(xié)議從1.0以前，默認用的是短連接，每次發(fā)起請求都會建立TCP連接。收發(fā)數(shù)據(jù)。然后斷開連接。
TCP連接每次都是三次握手。每次斷開都要四次揮手。
其實沒必要每次都建立新連接，建立的連接不斷開就好了，每次發(fā)送數(shù)據(jù)都復(fù)用就好了。
于是乎，HTTP協(xié)議從1.1之后就默認使用長連接。具體相關(guān)信息可以看之前的 這篇文章。
那么golang標準庫里也兼容這種實現(xiàn)。
通過建立一個連接池，針對每個域名建立一個TCP長連接，比如http://baidu.com和http://golang.com 就是兩個不同的域名。
第一次訪問http://baidu.com 域名的時候會建立一個連接，用完之后放到空閑連接池里，下次再要訪問http://baidu.com 的時候會重新從連接池里把這個連接撈出來復(fù)用。
插個題外話：這也解釋了之前這篇文章里最后的疑問，為什么要強調(diào)是同一個域名：一個域名會建立一個連接，一個連接對應(yīng)一個讀goroutine和一個寫goroutine。正因為是同一個域名，所以最后才會泄漏
3個goroutine，如果不同域名的話，那就會泄漏1+2*N個協(xié)程，N就是域名數(shù)。
假設(shè)第一次請求要100ms，每次請求完http://baidu.com 后都放入連接池中，下次繼續(xù)復(fù)用，重復(fù)29次，耗時2900ms。
第30次請求的時候，連接從建立開始到服務(wù)返回前就已經(jīng)用了3000ms，剛好到設(shè)置的3s超時閾值，那么此時客戶端就會報超時 i/o timeout 。
雖然這時候服務(wù)端其實才花了100ms，但耐不住前面29次加起來的耗時已經(jīng)很長。
也就是說只要通過 http.Transport 設(shè)置了 err = conn.SetDeadline(time.Now().Add(time.Second * 3))，并且你用了長連接，哪怕服務(wù)端處理再快，客戶端設(shè)置的超時再長，總有一刻，你的程序會報超時錯誤。
正確姿勢
原本預(yù)期是給每次調(diào)用設(shè)置一個超時，而不是給整個連接設(shè)置超時。
另外，上面出現(xiàn)問題的原因是給長連接設(shè)置了超時，且長連接會復(fù)用。
基于這兩點，改一下代碼。
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) //設(shè)置建立連接超時
20 // if err != nil {
21 // return nil, err
22 // }
23 // err = conn.SetDeadline(time.Now().Add(time.Second * 3)) //設(shè)置發(fā)送接受數(shù)據(jù)超時
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, // 超時加在這里，是每次調(diào)用的超時
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}
看注釋會發(fā)現(xiàn)，改動的點有兩個
http.Transport里的建立連接時的一些超時設(shè)置干掉了。在發(fā)起http請求的時候會場景
http.Client，此時加入超時設(shè)置，這里的超時就可以理解為單次請求的超時了。同樣可以看下注釋
Timeout specifies a time limit for requests made by this Client.
到這里，代碼就改好了，實際生產(chǎn)中問題也就解決了。
實例代碼里，如果拿去跑的話，其實還會下面的錯
1Get http://www.baidu.com/: EOF
這個是因為調(diào)用得太猛了，http://www.baidu.com 那邊主動斷開的連接，可以理解為一個限流措施，目的是為了保護服務(wù)器，畢竟每個人都像這么搞，服務(wù)器是會炸的。。。
解決方案很簡單，每次HTTP調(diào)用中間加個sleep間隔時間就好。
到這里，其實問題已經(jīng)解決了，下面會在源碼層面分析出現(xiàn)問題的原因。對讀源碼不感興趣的朋友們可以不用接著往下看，直接拉到文章底部右下角，做點正能量的事情（點兩下）支持一下。（瘋狂暗示，拜托拜托，這對我真的很重要！）
源碼分析
用的go版本是1.12.7。
從發(fā)起一個網(wǎng)絡(luò)請求開始跟。
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 // 嘗試去獲取一個空閑連接，用于發(fā)起 http 連接
27 pconn, err := t.getConn(treq, cm)
28 // ...
29}
30
31// 重點關(guān)注這個函數(shù)，返回是一個長連接
32func (t *Transport) getConn(treq *transportRequest, cm connectMethod) (*persistConn, error) {
33 // 省略了大量邏輯，只關(guān)注下面兩點
34 // 有空閑連接就返回
35 pc := <-t.getIdleConnCh(cm)
36
37 // 沒有創(chuàng)建連接
38 pc, err := t.dialConn(ctx, cm)
39
40}
這里上面很多代碼，其實只是為了展示這部分代碼是怎么跟蹤下來的，方便大家去看源碼的時候去跟一下。
最后一個上面的代碼里有個 getConn 方法。在發(fā)起網(wǎng)絡(luò)請求的時候，會先取一個網(wǎng)絡(luò)連接，取連接有兩個來源。
如果有空閑連接，就拿空閑連接
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}沒有空閑連接，就創(chuàng)建長連接。
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}
當第一次發(fā)起一個http請求時，這時候肯定沒有空閑連接，會建立一個新連接。同時會創(chuàng)建一個讀goroutine和一個寫goroutine。
注意上面代碼里的t.dial(ctx, "tcp", cm.addr())，如果像文章開頭那樣設(shè)置了 http.Transport的
1Dial: func(netw, addr string) (net.Conn, error) {
2 conn, err := net.DialTimeout(netw, addr, time.Second*2) //設(shè)置建立連接超時
3 if err != nil {
4 return nil, err
5 }
6 err = conn.SetDeadline(time.Now().Add(time.Second * 3)) //設(shè)置發(fā)送接受數(shù)據(jù)超時
7 if err != nil {
8 return nil, err
9 }
10 return conn, nil
11},
那么這里就會在下面的dial里被執(zhí)行到
1func (t *Transport) dial(ctx context.Context, network, addr string) (net.Conn, error) {
2 // ...
3 c, err := t.Dial(network, addr)
4 // ...
5}
這里面調(diào)用的設(shè)置超時，會執(zhí)行到
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 // 設(shè)置一個定時器事件
21 rtf = netpollDeadline
22 // 并將事件注冊到定時器里
23 modtimer(&pd.rt, pd.rd, 0, rtf, pd, pd.rseq)
24}
上面的源碼，簡單來說就是，當?shù)谝淮握{(diào)用請求的，會建立個連接，這時候還會注冊一個定時器事件，假設(shè)時間設(shè)了3s，那么這個事件會在3s后發(fā)生，然后執(zhí)行注冊事件的邏輯。而這個注冊事件就是netpollDeadline。 注意這個netpollDeadline，待會會提到。
設(shè)置了超時事件，且超時事件是3s后之后，發(fā)生。再次期間正常收發(fā)數(shù)據(jù)。一切如常。
直到3s過后，這時候看讀goroutine，會等待網(wǎng)絡(luò)數(shù)據(jù)返回。
1/src/net/http/tansport.go:1642
2func (pc *persistConn) readLoop() {
3 //...
4 for alive {
5 _, err := pc.br.Peek(1) // 阻塞讀取服務(wù)端返回的數(shù)據(jù)
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，這個可以簡單認為是等待服務(wù)端數(shù)據(jù)返回。
1//go:linkname poll_runtime_pollWait internal/poll.runtime_pollWait
2func poll_runtime_pollWait(pd *pollDesc, mode int) int {
3
4 // 1.如果網(wǎng)絡(luò)正常返回數(shù)據(jù)就跳出
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}
整條鏈路跟下來，就是會一直等待數(shù)據(jù)，等待的結(jié)果只有兩個
有可以讀的數(shù)據(jù)
出現(xiàn)報錯
這里面的報錯，又有那么兩種
連接關(guān)閉
超時
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}
其中提到的超時，就是指這里面返回的數(shù)字2，會通過下面的函數(shù)，轉(zhuǎn)化為 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到點時執(zhí)行的邏輯。
1func timerproc(tb *timersBucket) {
2 // 計時器到設(shè)定時間點了，觸發(fā)之前注冊函數(shù)
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}
這里會設(shè)置pd.rd=-1，是指 poller descriptor.read deadline ，含義網(wǎng)絡(luò)輪詢器文件描述符的讀超時時間， 我們知道在linux里萬物皆文件，這里的文件其實是指這次網(wǎng)絡(luò)通訊中使用到的socket。
這時候再回去看發(fā)生超時的條件就是if (mode == 'r' && pd.rd < 0)。
至此。我們的代碼里就收到了 io timeout 的報錯。
總結(jié)
不要在
http.Transport中設(shè)置超時，那是連接的超時，不是請求的超時。否則可能會出現(xiàn)莫名io timeout報錯。請求的超時在創(chuàng)建
client里設(shè)置。
如果文章對你有幫助，看下文章底部右下角，做點正能量的事情（點兩下）支持一下。（瘋狂暗示，拜托拜托，這對我真的很重要！）
我是小白，我們下期見。
------------------- End -------------------
往期精彩文章推薦：
歡迎大家點贊，留言，轉(zhuǎn)發(fā)，轉(zhuǎn)載，感謝大家的相伴與支持
想加入Go學(xué)習(xí)群請在后臺回復(fù)【入群】
萬水千山總是情，點個【在看】行不行