首页   注册   登录
V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
The Go Programming Language
http://golang.org/
Go Playground
Go Projects
Revel Web Framework
beego
拉钩
V2EX  ›  Go

Golang 中 http.Get 的耗时比 curl 耗时大很多是什么原因?

  •  
  •   rayhy · 11 天前 · 2078 次点击

    可能这个问题比较小白,大家轻喷

    我用 Golang 中http库的Get函数写个简单的下载网页的工具,发现下载网页时间很长,比 curl 长很多:

    截图

    Golang 代码:

    
    // Fetch prints the content found at a URL.
    package main
    
    import (
    	"time"
    	"fmt"
    	"io"
    	"net/http"
    	"os"
    	"strings"
    )
    
    func main() {
    
    	for _, url := range os.Args[1:] {
    		start := time.Now()
    		if !(strings.HasPrefix(url, "https://") || strings.HasPrefix(url, "http://")) {
    			url = "http://" + url
    		}
    
    		resp, err := http.Get(url)
    		if err != nil {
    			fmt.Fprintf(os.Stderr, "fetch: %v\n", err)
    			os.Exit(1)
    		}
    		fmt.Printf("[\033[0;31m%d\033[0m] %v\n", resp.StatusCode, resp.Request.URL)
    
    		// Test download cost.
    		//fmt.Println("Download cost:", time.Since(start))
    
    		if _, err := io.Copy(os.Stdout, resp.Body); err != nil {
    			fmt.Fprintf(os.Stderr, "\033[0;31mERROR\033[0m %v\n", err)
    			os.Exit(1)
    		}
    		fmt.Println("Total cost:", time.Since(start))
    	}
    }
    
    

    看到这么大的差距,我以为是io.Copy可能出了点问题,就在io.Copy前添了一个时间测试,结果:

    Download cost: 21.651425s
    Total cost: 21.656501s
    

    可以看到时间主要是花在http.Get这里了。

    我多次测试后都可以复现(包含测试不同网站),Google 也没有什么结果,搜索关键词都不知道怎么设置。。

    这究竟是啥原因啊?

    25 回复  |  直到 2018-12-07 08:49:49 +08:00
        1
    ucanuup   11 天前
    帮你试了下,我这儿无法复现。
    go version go1.11.2
        2
    katsusan   11 天前
    可以抓包看是建立连接之前的处理太长还是数据传输的花费时间长,我这里测试没问题。

    ```
    ➜ testing-ground go run httpget.go http://httpbin.org/get
    Get cost:496.770582ms
    [200] http://httpbin.org/get
    {
    "args": {},
    "headers": {
    "Accept-Encoding": "gzip",
    "Connection": "close",
    "Host": "httpbin.org",
    "User-Agent": "Go-http-client/1.1"
    },
    "origin": "124.79.234.173",
    "url": "http://httpbin.org/get"
    }
    Total cost: 497.479966ms
    ```
        3
    rayhy   11 天前
    @ucanuup 啊谢谢!我还能复现。我感觉肯定不是 golang 的原因,想不通哪出问题了。连个测试的方向我都想不出来(总不能是学校路由器针对 golang 的 user-agent 吧)。
    补充一下:
    我的版本是 go version go1.11 linux/amd64
    curl 测试的那行代码是
    start=$(date +'%s') && curl httpbin.org/get && echo "It took $(($(date +'%s') - $start)) seconds"
        4
    topbandit   11 天前
    strace 和抓包看看
        5
    icexin   11 天前
    用 httptrace 包看一下在哪里耗时了 https://godoc.org/net/http/httptrace#WithClientTrace
        6
    xivisi   11 天前
    @rayhy
    curl 好像只获取连接的第一个界面的文本。
    你的保存网页是不是,图片、CSS JS 之类的也下载下来了?
        7
    webluoye   11 天前
    没复现,go 1.11 Total cost: 501.175936ms
    用 http.Client 自己包装一个测试下看那个步骤耗时比较多。
        8
    zeyexe   11 天前   ♥ 1
    可能和 resolver 有关
        9
    icexin   11 天前   ♥ 1
    或者不想手写 httptrace 的话,试一下 github.com/davecheney/httpstat,这个是用 net/http 加 net/http/httptrace 做的工具,可以详细展示各个阶段的耗时。

    ➜ httpstat http://httpbin.org/get

    Connected to 52.86.186.182:80

    HTTP/1.1 200 OK
    Server: gunicorn/19.9.0
    Access-Control-Allow-Credentials: true
    Access-Control-Allow-Origin: *
    Content-Length: 231
    Content-Type: application/json
    Date: Wed, 05 Dec 2018 09:49:00 GMT
    Via: 1.1 vegur
    Connection: keep-alive

    Body discarded

    DNS Lookup TCP Connection Server Processing Content Transfer
    [ 612ms | 375ms | 237ms | 0ms ]
    | | | |
    namelookup:612ms | | |
    connect:988ms | |
    starttransfer:1225ms |
    total:1225ms
        10
    rayhy   11 天前
    @icexin
    @webluoye
    @katsusan
    谢谢!我测试一下,看看是哪里的问题
        11
    rayhy   10 天前
    @icexin
    @webluoye
    @katsusan
    @xivisi
    @topbandit
    @ucanuup
    又用 @icexin 提到的工具`httpstat`测试了下,发现时间主要花在 DNS Lookup 阶段:
    https://s1.ax1x.com/2018/12/05/FlsTEj.png
    可以看到 windows 下执行就是正常时间, wsl 下执行时间 DNS Lookup 阶段就花了很多时间。我分别用 Get-NetIPConfiguration 和 cat /etc/resolv.conf 看了下,wsl 和 windows 的 DNS 服务器都是 223.5.5.5 223.6.6.6
    用的是同一个 DNS。

    还是没有解决问题,同在 wsl 下,curl 和 go 的 http.Get 差别还是很大,理论上它俩是一个 DNS 服务器啊。
    https://imgchr.com/i/FlsIbQ
        12
    rayhy   10 天前
    忘记说环境了,我是 windows10,出现差异的是 wsl(Linux 4.4.0-17134-Microsoft )环境,在 windows 下 powershell 里是没问题的。
        13
    icexin   10 天前   ♥ 9
    可能是 dns cache 的问题,看下 net 下的文档 https://godoc.org/net#hdr-Name_Resolution
    类 unix 系统默认是纯 go 的实现走 dns 协议 Lookup,windows 默认是走系统调用,可能有 cache 加速。
    你在 wsl 下加上 export GODEBUG=netdns=cgo 强制走系统查询试试

    The method for resolving domain names, whether indirectly with functions like Dial or directly with functions like LookupHost and LookupAddr, varies by operating system.

    On Unix systems, the resolver has two options for resolving names. It can use a pure Go resolver that sends DNS requests directly to the servers listed in /etc/resolv.conf, or it can use a cgo-based resolver that calls C library routines such as getaddrinfo and getnameinfo.

    By default the pure Go resolver is used, because a blocked DNS request consumes only a goroutine, while a blocked C call consumes an operating system thread. When cgo is available, the cgo-based resolver is used instead under a variety of conditions: on systems that do not let programs make direct DNS requests (OS X), when the LOCALDOMAIN environment variable is present (even if empty), when the RES_OPTIONS or HOSTALIASES environment variable is non-empty, when the ASR_CONFIG environment variable is non-empty (OpenBSD only), when /etc/resolv.conf or /etc/nsswitch.conf specify the use of features that the Go resolver does not implement, and when the name being looked up ends in .local or is an mDNS name.

    The resolver decision can be overridden by setting the netdns value of the GODEBUG environment variable (see package runtime) to go or cgo, as in:

    export GODEBUG=netdns=go # force pure Go resolver
    export GODEBUG=netdns=cgo # force cgo resolver
    The decision can also be forced while building the Go source tree by setting the netgo or netcgo build tag.

    A numeric netdns setting, as in GODEBUG=netdns=1, causes the resolver to print debugging information about its decisions. To force a particular resolver while also printing debugging information, join the two settings by a plus sign, as in GODEBUG=netdns=go+1.

    On Plan 9, the resolver always accesses /net/cs and /net/dns.

    On Windows, the resolver always uses C library functions, such as GetAddrInfo and DnsQuery.
        14
    rayhy   10 天前
    在 wsl 里分别执行了 3 条命令,截取了部分结果:

    $dig @223.6.6.6
    > ;; Query time: 287 msec

    $ ./httpstat
    > Connected to 34.196.224.14:80
    > namelookup:15450ms

    $ curl -v
    > * Connected to httpbin.org (52.3.53.115) port 80 (#0)
    > It took 1 seconds


    仿佛有些头绪了。。。。
        15
    rayhy   10 天前   ♥ 1
    @icexin 感谢!完全解决!
    export GODEBUG=netdns=cgo
    > namelookup:154ms
    export GODEBUG=netdns=go
    > namelookup:15484ms
    看来 curl 和 go 区别应该就在这。 @zeyexe 在#8 已经提到了,刚看我还没搞懂,现在才明白 @zeyexe 说的是啥。
        16
    mritd   10 天前 via iPhone
    @icexin #13 又给我普及知识了^_^
        17
    JaguarJack   10 天前 via iPhone
    长知识了,我要收藏起来
        18
    itstudying   10 天前
    @icexin #13 学习了
        19
    iyaozhen   10 天前 via Android
    涨姿势了。这才是论坛的意义呀
        20
    XIVN1987   10 天前
    @icexin
    厉害了,,膜拜
        21
    webluoye   10 天前
    涨知识
        22
    coolmenu   10 天前 via iPhone
    大概猜到 dns 解析的问题,不过细节却是不知道,涨知识了
        23
    js2854   10 天前 via Android
    歪个楼,查看程序运行时间用 time 命令就好了,不需要取开始时间结束时间相减
        24
    rayhy   10 天前
    @js2854,谢谢,又发现了一个新命令。我试了一下,`/usr/bin/time -p`更适合我这个情况。
        25
    rayhy   9 天前 via Android
    又开了个帖子解释了下为啥 go dns 查询这么慢
    https://www.v2ex.com/t/515096#reply1
    关于   ·   FAQ   ·   API   ·   我们的愿景   ·   广告投放   ·   感谢   ·   实用小工具   ·   2213 人在线   最高记录 4019   ·  
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.1 · 28ms · UTC 10:00 · PVG 18:00 · LAX 02:00 · JFK 05:00
    ♥ Do have faith in what you're doing.
    沪ICP备16043287号-1