Golang: 在启用了 idleConn 的情况下，通过代理立即关闭 http2 客户端连接。

huangapple
go评论73阅读模式
英文:

Golang: http2 client immediately close connections via proxy while idleConn was enabled

问题

0x00 TL;DR

我正在使用Go实现一个HTTP客户端，并使用Squid作为转发代理将请求发送到远程服务器。当使用代理的HTTP/1.1或不使用代理的HTTP/1.1、HTTP/2时，一切都很顺利。然而，当使用代理的HTTP/2客户端时，大多数连接会立即关闭，只有一两个连接保持打开。

不确定是我的代码有问题还是其他原因。HTTP传输中启用了idleConn配置。提前感谢您的帮助。

0x01 环境

代码

package main

import (
	"context"
	"crypto/tls"
	"fmt"
	"io"
	"io/ioutil"
	"net"
	"net/http"
	"net/url"
	"sync"
	"time"
)

const (
	proxyURL = "http://{{proxy-ip}}:3128"
)

func main() {
	wg := &sync.WaitGroup{}

	wg.Add(1)
	go func() {
		doSendRequests()
		wg.Done()
	}()

	wg.Wait()
}

func doSendRequests() {
	//client := newHTTPClient(nil)
	client := newHTTPClient(proxy)

	round := 0
	for {
		round += 1
		for i := 0; i < 5; i++ {
			go func(r int) {
				start := time.Now()
				var err error
				defer func() {
					duration := time.Since(start)
					fmt.Printf("Round: %d, A: %v, duration: %v\n", r, err, duration)
				}()
				req := newRequest("https://www.google.com")
				resp, err := client.Do(req)
				if err == nil {
					io.Copy(ioutil.Discard, resp.Body)
					resp.Body.Close()
				} else {
					fmt.Printf("A: %v\n", err)
				}
			}(round)
		}

		time.Sleep(100 * time.Second)
	}
}

type TLSDialer struct {
	net.Dialer
}

var (
	config = &tls.Config{InsecureSkipVerify: true}
)

func (dialer *TLSDialer) DialContext(ctx context.Context, network, addr string) (net.Conn, error) {
	return tls.DialWithDialer(&dialer.Dialer, network, addr, config)
}

var (
	DefaultDialer = net.Dialer{
		Timeout:   30 * time.Second,
		KeepAlive: 30 * time.Second,
		DualStack: true,
	}

	DefaultTLSDialer = TLSDialer{DefaultDialer}
)

func proxy(req *http.Request) (*url.URL, error) {
	uri, err := url.Parse(proxyURL)
	if err != nil {
		return nil, nil
	}
	return uri, nil
}

func newHTTPClient(proxy func(*http.Request) (*url.URL, error)) *http.Client {
	t := &http.Transport{
		DialContext:           (&DefaultDialer).DialContext,
		DisableKeepAlives:     false,
		DisableCompression:    false,
		ForceAttemptHTTP2:     true,
		MaxIdleConns:          5000,
		MaxIdleConnsPerHost:   1000,
		IdleConnTimeout:       0 * time.Second,
		ExpectContinueTimeout: 1 * time.Second,
	}

	if proxy == nil {
		t.DialTLSContext = (&DefaultTLSDialer).DialContext
	} else {
		t.Proxy = proxy
		t.TLSClientConfig = &tls.Config{
			InsecureSkipVerify: true,
		}
	}

	return &http.Client{Transport: t}
}

func newRequest(uri string) *http.Request {
	ctx, _ := context.WithTimeout(context.Background(), 60*time.Second)
	req, _ := http.NewRequestWithContext(ctx, "GET", uri, nil)

	return req
}

环境

go 1.15.3

GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/ec2-user/.cache/go-build"
GOENV="/home/ec2-user/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/ec2-user/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/ec2-user/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build200120630=/tmp/go-build -gno-record-gcc-switches"

uname -a

Linux ip-10-53-74-64.ec2.internal 4.14.243-185.433.amzn2.x86_64 #1 SMP Mon Aug 9 05:55:52 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

squid 4.15

0x02 现象

如我在摘要中所述，当我使用代理的HTTP/1.1或不使用代理的HTTP/1.1、HTTP/2时，一切都很顺利。然而，当使用代理的HTTP/2客户端时，连接将会创建与请求一样多的连接，然后关闭其他连接，只保留一个或两个连接。我使用Wireshark捕获了数据包，并发现连接最初是从客户端关闭的，所以可能与代理端无关，不确定。

不使用代理

// www.google.com
Every 0.5s: netstat -anop | grep '172.217'

Sat Nov 27 04:26:22 2021

tcp        0      0 10.53.74.64:44106       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.35/0/0)
tcp        0      0 10.53.74.64:44378       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.44/0/0)
tcp        0      0 10.53.74.64:44084       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.60/0/0)
tcp        0      0 10.53.74.64:44374       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.43/0/0)
tcp        0      0 10.53.74.64:44220       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.52/0/0)

使用代理和HTTP/1.1

Every 0.5s: netstat -anop | grep ":3128"

Sun Dec  5 13:09:44 2021

tcp        0      0 10.53.74.64:58370       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.70/0/0)
tcp        0      0 10.53.74.64:58366       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.70/0/0)
tcp        0      0 10.53.74.64:58374       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.70/0/0)
tcp        0      0 10.53.74.64:58368       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.69/0/0)
tcp        0      0 10.53.74.64:58372       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.70/0/0)

使用代理和HTTP2

如下所示，其他连接在建立后不久就被关闭了，并且在http传输中启用了idleConn配置。

Sun Dec  5 13:19:35 UTC 2021
tcp        0    284 10.53.74.64:58414       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.20/0/0)
tcp        0    284 10.53.74.64:58416       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.19/0/0)
tcp        0    284 10.53.74.64:58410       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.19/0/0)
tcp        0    284 10.53.74.64:58412       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.19/0/0)
tcp        0    284 10.53.74.64:58418       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.19/0/0)

Sun Dec  5 13:19:35 UTC 2021
tcp        0     89 10.53.74.64:58414       {{proxy-ip}}:3128     FIN_WAIT1   -                    on (0.14/0/0)
tcp        0     89 10.53.74.64:58416       {{proxy-ip}}:3128     FIN_WAIT1   -                    on (0.14/0/0)
tcp        0    365 10.53.74.64:58410       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.14/0/0)
tcp        0     89 10.53.74.64:58412       {{proxy-ip}}:3128     FIN_WAIT1   -                    on (0.14/0/0)
tcp        0     89 10.53.74.64:58418       {{proxy-ip}}:3128     FIN_WAIT1   -                    on (0.14/0/0)

Sun Dec  5 13:19:35 UTC 2021
tcp        0      0 10.53.74.64:58414       {{proxy-ip}}:3128     TIME_WAIT   -                    timewait (59.99/0/0)
tcp        0      0 10.53.74.64:58416       {{proxy-ip}}:3128     TIME_WAIT   -                    timewait (59.99/0/0)
tcp        0     31 10.53.74.64:58410       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.26/0/0)
tcp        0      0 10.53.74.64:58412       {{proxy-ip}}:3128     TIME_WAIT   -                    timewait (59.99/0/0)
tcp        0      0 10.53.74.64:58418       {{proxy-ip}}:3128     TIME_WAIT   -                    timewait (59.99/0/0)

这个问题可以在最新的golang 1.17.4中复现（截至目前：2021-12-05）。有没有人能提供一种解决这个问题的方法？谢谢。

EDIT1：所有请求都没有错误。

EDIT2：我在Golang仓库上提了一个问题，如果有人感兴趣：
https://github.com/golang/go/issues/50000

英文:

0x00 TL;DR

I'm using Go to implement an http client and squid as a forward proxy to send requests to remote servers. Things goes well when using http/1.1 via proxy or http/1.1, http2 without proxy, however, while using http2 client via proxy, most of the connections were closed immediately and only one or two were kept.

Not sure it's my bad code or what. The idleConn configuration was enabled on the http transport. Thanks in advance.

0x01 Environments

Code

package main

import (
	&quot;context&quot;
	&quot;crypto/tls&quot;
	&quot;fmt&quot;
	&quot;io&quot;
	&quot;io/ioutil&quot;
	&quot;net&quot;
	&quot;net/http&quot;
	&quot;net/url&quot;
	&quot;sync&quot;
	&quot;time&quot;
)

const (
	proxyURL = &quot;http://{{proxy-ip}}:3128&quot;
)

func main() {
	wg := &amp;sync.WaitGroup{}

	wg.Add(1)
	go func() {
		doSendRequests()
		wg.Done()
	}()

	wg.Wait()
}

func doSendRequests() {
	//client := newHTTPClient(nil)
	client := newHTTPClient(proxy)

	round := 0
	for {
		round += 1
		for i := 0; i &lt; 5; i++ {
			go func(r int) {
				start := time.Now()
				var err error
				defer func() {
					duration := time.Since(start)
					fmt.Printf(&quot;Round: %d, A: %v, duration: %v\n&quot;, r, err, duration)
				}()
				req := newRequest(&quot;https://www.google.com&quot;)
				resp, err := client.Do(req)
				if err == nil {
					io.Copy(ioutil.Discard, resp.Body)
					resp.Body.Close()
				} else {
					fmt.Printf(&quot;A: %v\n&quot;, err)
				}
			}(round)
		}

		time.Sleep(100 * time.Second)
	}
}

type TLSDialer struct {
	net.Dialer
}

var (
	config = &amp;tls.Config{InsecureSkipVerify: true}
)

func (dialer *TLSDialer) DialContext(ctx context.Context, network, addr string) (net.Conn, error) {
	return tls.DialWithDialer(&amp;dialer.Dialer, network, addr, config)
}

var (
	DefaultDialer = net.Dialer{
		Timeout:   30 * time.Second,
		KeepAlive: 30 * time.Second,
		DualStack: true,
	}

	DefaultTLSDialer = TLSDialer{DefaultDialer}
)

func proxy(req *http.Request) (*url.URL, error) {
	uri, err := url.Parse(proxyURL)
	if err != nil {
		return nil, nil
	}
	return uri, nil
}

func newHTTPClient(proxy func(*http.Request) (*url.URL, error)) *http.Client {
	t := &amp;http.Transport{
		DialContext:           (&amp;DefaultDialer).DialContext,
		DisableKeepAlives:     false,
		DisableCompression:    false,
		ForceAttemptHTTP2:     true,
		MaxIdleConns:          5000,
		MaxIdleConnsPerHost:   1000,
		IdleConnTimeout:       0 * time.Second,
		ExpectContinueTimeout: 1 * time.Second,
	}

	if proxy == nil {
		t.DialTLSContext = (&amp;DefaultTLSDialer).DialContext
	} else {
		t.Proxy = proxy
		t.TLSClientConfig = &amp;tls.Config{
			InsecureSkipVerify: true,
		}
	}

	return &amp;http.Client{Transport: t}
}

func newRequest(uri string) *http.Request {
	ctx, _ := context.WithTimeout(context.Background(), 60*time.Second)
	req, _ := http.NewRequestWithContext(ctx, &quot;GET&quot;, uri, nil)

	return req
}

Env

go 1.15.3

GO111MODULE=&quot;&quot;
GOARCH=&quot;amd64&quot;
GOBIN=&quot;&quot;
GOCACHE=&quot;/home/ec2-user/.cache/go-build&quot;
GOENV=&quot;/home/ec2-user/.config/go/env&quot;
GOEXE=&quot;&quot;
GOFLAGS=&quot;&quot;
GOHOSTARCH=&quot;amd64&quot;
GOHOSTOS=&quot;linux&quot;
GOINSECURE=&quot;&quot;
GOMODCACHE=&quot;/home/ec2-user/go/pkg/mod&quot;
GONOPROXY=&quot;&quot;
GONOSUMDB=&quot;&quot;
GOOS=&quot;linux&quot;
GOPATH=&quot;/home/ec2-user/go&quot;
GOPRIVATE=&quot;&quot;
GOPROXY=&quot;https://proxy.golang.org,direct&quot;
GOROOT=&quot;/usr/local/go&quot;
GOSUMDB=&quot;sum.golang.org&quot;
GOTMPDIR=&quot;&quot;
GOTOOLDIR=&quot;/usr/local/go/pkg/tool/linux_amd64&quot;
GCCGO=&quot;gccgo&quot;
AR=&quot;ar&quot;
CC=&quot;gcc&quot;
CXX=&quot;g++&quot;
CGO_ENABLED=&quot;1&quot;
GOMOD=&quot;&quot;
CGO_CFLAGS=&quot;-g -O2&quot;
CGO_CPPFLAGS=&quot;&quot;
CGO_CXXFLAGS=&quot;-g -O2&quot;
CGO_FFLAGS=&quot;-g -O2&quot;
CGO_LDFLAGS=&quot;-g -O2&quot;
PKG_CONFIG=&quot;pkg-config&quot;
GOGCCFLAGS=&quot;-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build200120630=/tmp/go-build -gno-record-gcc-switches&quot;

uname -a

Linux ip-10-53-74-64.ec2.internal 4.14.243-185.433.amzn2.x86_64 #1 SMP Mon Aug 9 05:55:52 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

squid 4.15

0x02 Phenomenon

As I mentioned in the summary, everything goes well when I'm using http/1.1 via proxy or http/1.1, http2 without proxy. However, when using http2 client via proxy, the connections will be created as many as the requests, then close others and leave only one or two connections. I capture packages with Wireshark and found that the connections were closed from the client-side initially, so it may do not matter with the proxy-side, not sure about this.

without proxy

// www.google.com
Every 0.5s: netstat -anop | grep &#39;172.217&#39;

Sat Nov 27 04:26:22 2021

tcp        0	  0 10.53.74.64:44106       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.35/0/0)
tcp        0	  0 10.53.74.64:44378       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.44/0/0)
tcp        0	  0 10.53.74.64:44084       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.60/0/0)
tcp        0	  0 10.53.74.64:44374       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.43/0/0)
tcp        0	  0 10.53.74.64:44220       172.217.0.36:443        ESTABLISHED 3110/main            keepalive (25.52/0/0)

with proxy and http/1.1

Every 0.5s: netstat -anop | grep &quot;:3128&quot;

Sun Dec  5 13:09:44 2021

tcp        0      0 10.53.74.64:58370       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.70/0/0)
tcp        0      0 10.53.74.64:58366       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.70/0/0)
tcp        0      0 10.53.74.64:58374       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.70/0/0)
tcp        0      0 10.53.74.64:58368       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.69/0/0)
tcp        0      0 10.53.74.64:58372       {{proxy-ip}}:3128     ESTABLISHED 26322/main           keepalive (23.70/0/0)

with proxy and http2

As shown below, the other connections were closed soon after ESTABLISHED and the idleConn configuration was enabled on the http transport.

Sun Dec  5 13:19:35 UTC 2021
tcp        0    284 10.53.74.64:58414       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.20/0/0)
tcp        0    284 10.53.74.64:58416       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.19/0/0)
tcp        0    284 10.53.74.64:58410       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.19/0/0)
tcp        0    284 10.53.74.64:58412       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.19/0/0)
tcp        0    284 10.53.74.64:58418       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.19/0/0)

Sun Dec  5 13:19:35 UTC 2021
tcp        0     89 10.53.74.64:58414       {{proxy-ip}}:3128     FIN_WAIT1   -                    on (0.14/0/0)
tcp        0     89 10.53.74.64:58416       {{proxy-ip}}:3128     FIN_WAIT1   -                    on (0.14/0/0)
tcp        0    365 10.53.74.64:58410       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.14/0/0)
tcp        0     89 10.53.74.64:58412       {{proxy-ip}}:3128     FIN_WAIT1   -                    on (0.14/0/0)
tcp        0     89 10.53.74.64:58418       {{proxy-ip}}:3128     FIN_WAIT1   -                    on (0.14/0/0)

Sun Dec  5 13:19:35 UTC 2021
tcp        0      0 10.53.74.64:58414       {{proxy-ip}}:3128     TIME_WAIT   -                    timewait (59.99/0/0)
tcp        0      0 10.53.74.64:58416       {{proxy-ip}}:3128     TIME_WAIT   -                    timewait (59.99/0/0)
tcp        0     31 10.53.74.64:58410       {{proxy-ip}}:3128     ESTABLISHED 34301/main           on (0.26/0/0)
tcp        0      0 10.53.74.64:58412       {{proxy-ip}}:3128     TIME_WAIT   -                    timewait (59.99/0/0)
tcp        0      0 10.53.74.64:58418       {{proxy-ip}}:3128     TIME_WAIT   -                    timewait (59.99/0/0)

This could be reproduced by the latest golang 1.17.4(by now: 2021-12-05). Is there anyone who could offer a way to figure out why would this happen? Thanks.

EDIT1: all the requests done without errors.

EDIT2: I had open an issue on Golang repo, in case anyone interested:
https://github.com/golang/go/issues/50000

答案1

得分: 0

我终于弄清楚了，一切都按预期工作，所以与 net/http2 无关。

更多详细信息，请参考此问题：https://github.com/golang/go/issues/50000。

英文:

Finally, I figure it out and everything is working as expected, so it's nothing to do with net/http2.

For more details, please refer to this issue: https://github.com/golang/go/issues/50000.

huangapple
  • 本文由 发表于 2021年12月5日 21:49:53
  • 转载请务必保留本文链接：https://go.coder-hub.com/70234961.html
  • go
  • proxy
  • squid
匿名

发表评论

匿名网友

:?: :razz: :sad: :evil: :!: :smile: :oops: :grin: :eek: :shock: :???: :cool: :lol: :mad: :twisted: :roll: :wink: :idea: :arrow: :neutral: :cry: :mrgreen:

确定