go net: TCP连接错误地在Windows上重复消息

iqjalb3h  于 5个月前  发布在  Go
关注(0)|答案(4)|浏览(165)

你使用的Go版本是什么( go version )?

$ go version
go version go1.20.1 windows/amd64

这个问题在最新版本的发布中是否重现?

是的。

你正在使用的操作系统和处理器架构是什么( go env )?

go env 输出

$ go env
PS C:\Users\jack\dev\golang-windows-dupreads> go env
set GO111MODULE=
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\jack\AppData\Local\go-build
set GOENV=C:\Users\jack\AppData\Roaming\go\env
set GOEXE=.exe
set GOEXPERIMENT=
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=C:\Users\jack\go\pkg\mod
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=C:\Users\jack\go
set GOPRIVATE=
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=C:\Program Files\Go
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=C:\Program Files\Go\pkg\tool\windows_amd64
set GOVCS=
set GOVERSION=go1.20.1
set GCCGO=gccgo
set GOAMD64=v1
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=0
set GOMOD=C:\Users\jack\dev\golang-windows-dupreads\go.mod
set GOWORK=
set CGO_CFLAGS=-O2 -g
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-O2 -g
set CGO_FFLAGS=-O2 -g
set CGO_LDFLAGS=-O2 -g
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -fno-caret-diagnostics -Qunused-arguments -Wl,--no-gc-sections -fmessage-length=0 -fdebug-prefix-map=C:\Users\jack\AppData\Local\Temp\go-build129281977=/tmp/go-build -gno-record-gcc-switches
PS C:\Users\jack\dev\golang-windows-dupreads>

你做了什么?

  1. 在本地主机上创建一个TCP服务器。
  2. 连接到该服务器。
  3. 将客户端连接 Package 在一个记录所有 Write 数据的 Package 器中,将服务器连接 Package 在一个记录所有 Read 数据的 Package 器中。
  4. 以非常特殊的方式读取和写入大量数据(详细信息如下)。
  5. 比较写入的内容和读取的内容。

你期望看到什么?

客户端发送的字节和服务器接收的字节之间应该没有不同。

你看到的是什么?

在大约2.7MB之后,会收到一块重复的数据。

细节

这个问题最初是在 https://github.com/jackc/pgx 的测试中遇到的。pgx需要非阻塞IO(参见 #36973#15735 )。在使用TLS时也需要支持这种非阻塞IO。由于当前Go中尚不存在所需的功能,因此它有一个内部包 nbconn ,该包以一种支持非阻塞IO甚至在TLS上的方式 Package 了许多复杂的代码。
其中一个测试在Windows上始终遇到问题,但在Linux或Mac上没有问题。鉴于复杂的代码,很容易假设问题出在那个 nbconn 包上。然而,经过数小时的调试后,我相信我已经排除了这个问题。我有一个可复现的测试用例,为客户端和服务器创建了一个 net.Conn ,并记录了客户端到服务器流中的所有写入和读取内容。TLS连接和nbconn连接位于/使用这些记录连接之上。记录的连接观察到重复的数据(这显然会破坏TLS连接)。
考虑到重复的数据在TLS连接下方被观察到,我不认为这个问题存在于pgx或tls包中。更有可能的问题在于网络包、Go运行时或Windows本身。
我在 https://github.com/jackc/golang-windows-dupreads 有一个测试用例。它总是在Windows上失败,但在其他平台上成功。我已经尽可能地减少了测试,但不幸的是,我无法在不使用 nbconntls 生成的特殊读写模式的情况下重现它。
以下是测试的核心部分。它在本地主机上创建一个服务器并建立连接。然后将两个连接都 Package 在记录器中。接下来执行一些活动。最后,检查写入的字节和读取的字节是否匹配:

func TestRepeatedMessage(t *testing.T) {
	// Make a connected pair of TCP connections.
	tcpClientConn, tcpServerConn, err := makeTCPConns()
	if err != nil {
		t.Errorf("makeTCPConns failed: %v", err)
	}

	// Wrap the connections in recording connections.
	recordedClientConn, recordedServerConn := makeRecordedConns(tcpClientConn, tcpServerConn)

	// Establish a TLS connection from the client to the server.
	clientConn, serverConn, err := makeTSLConnection(recordedClientConn, recordedServerConn)
	if err != nil {
		t.Errorf("makeTLSConnection failed: %v", err)
	}
	defer clientConn.Close()
	defer serverConn.Close()

	// This message size should be large enough to block a Write until the other side Reads some of it. Both the server
	// and the client try to Write a large message without reading.
	const messageSize = 4 * 1024 * 1024

	// The server writes a large message before reading.
	errChan := make(chan error, 1)
	go func() {
		remoteWriteBuf := make([]byte, messageSize)
		_, err := serverConn.Write(remoteWriteBuf)
		if err != nil {
			errChan <- err
			return
		}

		readBuf := make([]byte, messageSize)
		_, err = io.ReadFull(serverConn, readBuf)
		errChan <- err
	}()

	// This Write will always succeed due to the nbconn wrapper buffering all writes. This is necessary to prevent the
	// TLS connection from being broken by a temporarily failing write.
	writeBuf := make([]byte, messageSize)
	n, err := clientConn.Write(writeBuf)
	if err != nil {
		t.Errorf("clientConn.Write failed: %v", err)
	}
	if messageSize != n {
		t.Errorf("clientConn.Write wrote wrong number of bytes: %d instead of %d", n, messageSize)
	}

	readBuf := make([]byte, messageSize)
	// This Read is what will actually flush the previous Write. Since the server goroutine above also writes a large
	// message before reading this means that both sides are writing enough bytes to block until the other side reads.
	// This will deadlock unless the internal non-blocking and buffering logic is working.
	_, err = io.ReadFull(clientConn, readBuf)
	if err != nil {
		t.Errorf("io.ReadFull(clientConn, readBuf) failed: %v", err)
	}

	err = <-errChan
	if err != nil {
		t.Errorf("serverConn goroutine encountered an error: %v", err)
	}

	// Now compare what was written by the client connection and what was read by the server connection.
	recordedServerConn.readLock.Lock()
	defer recordedServerConn.readLock.Unlock()
	readLog := recordedServerConn.readLog

	recordedClientConn.writeLock.Lock()
	defer recordedClientConn.writeLock.Unlock()
	writeLog := recordedClientConn.writeLog

	if readLog.Len() != writeLog.Len() {
		t.Errorf("readLog.Len(): %d, writeLog.Len(): %d\n", readLog.Len(), writeLog.Len())
	}

	for i := 0; i < readLog.Len(); i++ {
		if readLog.Bytes()[i] != writeLog.Bytes()[i] {
			t.Errorf("mismatch at: %d", i)
			t.Logf("readLog.Bytes()[i-20 : i+20]  %v", readLog.Bytes()[i-20:i+20])
			t.Logf("writeLog.Bytes()[i-20 : i+20] %v", writeLog.Bytes()[i-20:i+20])
			firstOccuranceOfMismatchDataIndex := bytes.Index(writeLog.Bytes(), readLog.Bytes()[i:i+100])
			if firstOccuranceOfMismatchDataIndex < i {
				t.Logf("mismatch data appears earlier in stream at %d which is %d bytes earlier", firstOccuranceOfMismatchDataIndex, i-firstOccuranceOfMismatchDataIndex)
			}
			break
		}
	}
}

使用 go test 运行

PS C:\Users\jack\dev\golang-windows-dupreads> go test
--- FAIL: TestRepeatedMessage (0.14s)
    nbconn_test.go:229: serverConn goroutine encountered an error: local error: tls: bad record MAC
    nbconn_test.go:242: readLog.Len(): 2799033, writeLog.Len(): 4200393
    nbconn_test.go:247: mismatch at: 2766292
    nbconn_test.go:248: readLog.Bytes()[i-20 : i+20]  [33 53 47 198 118 85 105 211 192 151 29 220 243 125 77 23 3 3 64 17 75 110 182 199 210 112 201 152 118 93 91 4 251 122 27 61 92 41 94 214]
    nbconn_test.go:249: writeLog.Bytes()[i-20 : i+20] [33 53 47 198 118 85 105 211 192 151 29 220 243 125 77 23 3 3 64 17 94 72 252 16 226 122 111 94 77 211 208 12 105 22 3 27 13 109 105 190]
    nbconn_test.go:252: mismatch data appears earlier in stream at 2749886 which is 16406 bytes earlier
FAIL
exit status 1
FAIL    dupreads        0.350s

观察结果:

  1. 不匹配/重复消息总是提前16406字节出现。这似乎是tls包发出的Writes的大小。
  2. 错误从未在2.7MB之前发生。
  3. 在测试此问题时,我在Windows和Mac之间来回切换时观察到,Windows似乎具有更大的TCP缓冲区或窗口。也就是说,你可以在写入阻塞之前向连接写入更多字节。这导致这个测试在不同的平台上生成不同的读写模式。
9avjhtql

9avjhtql1#

你能给我们展示一个完整的独立程序或测试,以演示这个问题吗?
虽然任何事情都是可能的,但在网络包中出现这种类型的问题的可能性相当小。

qf9go6mv

qf9go6mv4#

自从Go 1.19.6版本发布以来,We在Linux上开始出现零星的tls: bad record MAC问题,这与打开到EPP服务器的长期TLS连接有关。看起来它发生在TLS握手过程中。
这个问题似乎仅限于一个远程操作员(GoDaddy),在我们部署Go 1.19.5和Go 1.19.6之间,他们那边没有(公开)的更改。
这是Go 1.19.6(一个1.20版本的回溯)中唯一的crypto/tls CL,但没有立即明显的关系可以联系到增加的alertBadRecordMAC错误: 00b256e
顺便说一下,这些tls.Conn是通过SSH代理拨号的(需要IP允许列表)。

相关问题