记一次HTTP连接重用问题分析

最近新发现了一个开源项目叫pyroscope:一个开源持续Profiling平台。

image.png

之所以关注到这个开源项目跟我以前的一个想法有一些契合,所以就先照着官方文档,写了个样例试用

package main

import (
    "github.com/gin-gonic/gin"
    "github.com/pyroscope-io/pyroscope/pkg/agent/profiler"
)

func main() {
    profiler.Start(profiler.Config{
        ApplicationName: "backend.purchases",
        ServerAddress:   "http://localhost:4040",
    })

    r := gin.Default()
    r.GET("/ping", func(c *gin.Context) {
        c.JSON(200, gin.H{
            "message": "pong",
        })
    })
    r.Run()
}

先把服务跑起来再说,结果却发现Agent上送Profiler经常会有EOF错误,这让我觉得有点尴尬,看到Issues上有人提了这个问题,在好奇心驱使下,准备看看怎么回事

抓包分析

用wireshark抓包看了一下


image.png

发现竟然是服务端在先关闭连接,此时我还未看代码,直接上此类服务应该用长连接才对,翻看服务端代码也是常规写法

s := &http.Server{
    Addr:           ctrl.cfg.Server.ApiBindAddr,
    Handler:        mux,
    ReadTimeout:    10 * time.Second,
    WriteTimeout:   10 * time.Second,
    MaxHeaderBytes: 1 << 20,
    ErrorLog:       golog.New(w, "", 0),
}

Agent端了也是默认长连接的

&http.Client{
    Transport: &http.Transport{
        MaxConnsPerHost: cfg.UpstreamThreads,
    },
    Timeout: cfg.UpstreamRequestTimeout,
}

所以其实两端都是支持长连接的,但连接确实是首先由服务端关闭的,这不合理啊,回头再来看抓包信息,Agent发送了[FIN, ACK]以后,还发了一次POST请求,正常情况Server端应该回一个ACK,不过由于经过了[FIN]->[FIN, ACK]此时服务端已经处于FIN_WAIT_1状态了,正等对端回ACK和FIN,不过比较巧的是刚好Agent端此时发关了一个POST请求,此时服务端只能收数据,不能发送数据,所以服务端发回了一个RST


image.png

原因是什么?

现象分析完了,那为什么会出现这种情况呢?网上看到一些此类问题解决办法是客户端处理POST请求直接Close关掉连接,这个就没法复用连接了,而且场景不同,根本不应该这么暴力操作,还是要具体问题具体分析的。关注一个小细节,在Agent发起[SYN]建立连接到Server发起[FIN]关注连接时间间隔正好是10s,这个时间与Server的读写超时时间相同,而Agent的上送Profiler的默认时间间隔也是10s,这之间会不会有什么关系?因为理想情况至少客户端是应该复用这个连接的,直觉上应该是Agent端关闭连接才对的。果不其然,在server.go中找到了线索:

    // 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

服务端本意是想复用连接的,但是并没有设置IdleTimeout,但是有设置ReadTimeout为10s秒,这正好是Agent端上送Profiler的间隔时间,所以很快就破案了,真是好巧不巧的,这个时间点卡的可真准,其实一般情况服务端这么设置也没问题,因为长连接通常适用于并发调用,以Agent端的调用频率并不高,而且也没有并发,所以将服务端IdleTimeout设置为魔数30s,就没有再出现EOF的错误,然后我提了PR,很快就合入了主干。

总结

一开始上网搜解决方案,发现完全不是那么回事,果然是人云亦云,每个人给出的上下文不一样,解决方案自然有差别。其实用wireshark抓一下包就能找到线索,大胆猜测,小心求证,数据总不会骗人的,源码也静待剖析。

参考:

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,271评论 5 476
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,275评论 2 380
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,151评论 0 336
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,550评论 1 273
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,553评论 5 365
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,559评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,924评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,580评论 0 257
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,826评论 1 297
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,578评论 2 320
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,661评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,363评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,940评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,926评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,156评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,872评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,391评论 2 342

推荐阅读更多精彩内容