Skip to content

test(tailnet): Add TestTransmitHang test with packet capture and logging #7414

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 7 commits into from

Conversation

mafredri
Copy link
Member

@mafredri mafredri commented May 4, 2023

This commit adds a test that occasionally triggers the issue in #7262. When triggered, the test takes e.g. ~30s to complete instead of 2s. The test also logs both from both tailnet.Conns into a log file and produces pcap files from each side.


Trigger by simply running go test ./tailnet -run=TestTransmitHang -v -count=1 until it takes longer than a few seconds. NOTE: I've been reproducing this in a Docker container.

To trigger this in dogfood, it may help to set export GOMAXPROCS=2. (I've also been able to trigger the issue on an M1 MacBook with this setting.)

To analyze the pcap files, you'll need Wireshark and ts-dissector.lua, start via wireshark -X lua_script:ts-dissector.lua tailnet-test-3304800396/send.pcap.

To further increase log verbosity, enable Tailscale debug flags before running the test, e.g. export TS_DEBUG_DISCO=true TS_DEBUG_DERP=true TS_DEBUG_NETSTACK=true.

To me there's no obvious indicators as to whats going wrong. First we see a bunch of TCP Dup Acks after which we're spinning our wheels in TCP Retransmission for ~30 seconds.

This issue can be reproduced using the currently bundled coder/tailscale#ed9307cf1b22 as well as coder/tailscale#main (at the time of writing).

We also have a few changes in our Tailscale fork which I've tried to revert like:

  • Initial probe plan delay
  • Disable of captive portal
  • Waiting for probes
  • Port map timeout
  • Probe timeout

However, even with all those changes reverted, we still run into this issue.

@mafredri mafredri force-pushed the mafredri/test-add-tailnet-transmit-hang-test branch from f674ac1 to 46052b4 Compare May 4, 2023 16:23
@mafredri mafredri force-pushed the mafredri/test-add-tailnet-transmit-hang-test branch from 46052b4 to 17bca06 Compare May 4, 2023 19:20
@mtojek
Copy link
Member

mtojek commented May 9, 2023

Good repro, Mathias!

It's fairly easy to show it on dogfood, but I managed to do it also on M1:

    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1199, "transmitted_kb": 76731}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1200, "transmitted_kb": 76795}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1201, "transmitted_kb": 76859}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1202, "transmitted_kb": 76923}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1203, "transmitted_kb": 76987}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1204, "transmitted_kb": 77051}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1205, "transmitted_kb": 77115}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1206, "transmitted_kb": 77179}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1207, "transmitted_kb": 77243}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1208, "transmitted_kb": 77307}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1209, "transmitted_kb": 77371}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1210, "transmitted_kb": 77435}
    t.go:81: 2023-05-09 08:26:25.204 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1211, "transmitted_kb": 77499}
    t.go:81: 2023-05-09 08:26:26.655 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:cbfe9620b0300fec
    t.go:81: 2023-05-09 08:26:26.655 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Ping, <nil>
    t.go:81: 2023-05-09 08:26:26.655 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:6b278661622edd55
    t.go:81: 2023-05-09 08:26:26.656 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Pong, <nil>
    t.go:81: 2023-05-09 08:26:26.659 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:6b278661622edd55
    t.go:81: 2023-05-09 08:26:26.659 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Ping, <nil>
    t.go:81: 2023-05-09 08:26:26.659 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:cbfe9620b0300fec
    t.go:81: 2023-05-09 08:26:26.659 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Pong, <nil>
    t.go:81: 2023-05-09 08:26:29.656 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:cbfe9620b0300fec
    t.go:81: 2023-05-09 08:26:29.656 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Ping, <nil>
    t.go:81: 2023-05-09 08:26:29.656 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:6b278661622edd55
    t.go:81: 2023-05-09 08:26:29.656 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Pong, <nil>
    t.go:81: 2023-05-09 08:26:29.660 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:6b278661622edd55
    t.go:81: 2023-05-09 08:26:29.660 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Ping, <nil>
    t.go:81: 2023-05-09 08:26:29.660 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:cbfe9620b0300fec
    t.go:81: 2023-05-09 08:26:29.660 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Pong, <nil>
    t.go:81: 2023-05-09 08:26:32.657 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:cbfe9620b0300fec
    t.go:81: 2023-05-09 08:26:32.657 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Ping, <nil>
    t.go:81: 2023-05-09 08:26:32.657 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:6b278661622edd55
    t.go:81: 2023-05-09 08:26:32.657 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Pong, <nil>
    t.go:81: 2023-05-09 08:26:32.660 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:6b278661622edd55
    t.go:81: 2023-05-09 08:26:32.660 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Ping, <nil>
    t.go:81: 2023-05-09 08:26:32.660 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:cbfe9620b0300fec
    t.go:81: 2023-05-09 08:26:32.660 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Pong, <nil>
    t.go:81: 2023-05-09 08:26:35.657 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:cbfe9620b0300fec
    t.go:81: 2023-05-09 08:26:35.657 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Ping, <nil>
    t.go:81: 2023-05-09 08:26:35.657 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:6b278661622edd55
    t.go:81: 2023-05-09 08:26:35.658 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Pong, <nil>
    t.go:81: 2023-05-09 08:26:35.660 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:6b278661622edd55
    t.go:81: 2023-05-09 08:26:35.660 [DEBUG]	(send.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Ping, <nil>
    t.go:81: 2023-05-09 08:26:35.660 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2094>	(*Conn).handleDiscoMessage	magicsock: disco: got disco-looking frame from d:cbfe9620b0300fec
    t.go:81: 2023-05-09 08:26:35.660 [DEBUG]	(recv.wgengine)	<tailscale.com/wgengine/magicsock/magicsock.go:2143>	(*Conn).handleDiscoMessage	magicsock: disco: disco.Parse = *disco.Pong, <nil>
    t.go:81: 2023-05-09 08:26:36.338 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1212, "transmitted_kb": 77563}
    t.go:81: 2023-05-09 08:26:36.338 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1213, "transmitted_kb": 77627}
    t.go:81: 2023-05-09 08:26:36.338 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1214, "transmitted_kb": 77691}
    t.go:81: 2023-05-09 08:26:36.338 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1215, "transmitted_kb": 77755}
    t.go:81: 2023-05-09 08:26:36.338 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1216, "transmitted_kb": 77819}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1217, "transmitted_kb": 77883}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1218, "transmitted_kb": 77947}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1219, "transmitted_kb": 78011}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1220, "transmitted_kb": 78075}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1221, "transmitted_kb": 78139}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1222, "transmitted_kb": 78203}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1223, "transmitted_kb": 78267}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1224, "transmitted_kb": 78331}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1225, "transmitted_kb": 78395}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1226, "transmitted_kb": 78459}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1227, "transmitted_kb": 78523}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1228, "transmitted_kb": 78587}
    t.go:81: 2023-05-09 08:26:36.339 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1229, "transmitted_kb": 78651}
    t.go:81: 2023-05-09 08:26:36.340 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1230, "transmitted_kb": 78715}
    t.go:81: 2023-05-09 08:26:36.340 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1231, "transmitted_kb": 78779}
    t.go:81: 2023-05-09 08:26:36.340 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1232, "transmitted_kb": 78843}
    t.go:81: 2023-05-09 08:26:36.340 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:292>	TestTransmitHang	write payload	{"num": 1233, "transmitted_kb": 78907}

I'm going to research this further.

@mtojek
Copy link
Member

mtojek commented May 9, 2023

I spent a day investigating this issue. In most cases, my research ended on the gVisor:

goroutine 23 [select]:
gvisor.dev/gvisor/pkg/tcpip/adapters/gonet.(*TCPConn).Write(0x1400080b080, {0x14001140000, 0xc0000, 0xc0000})
	/Users/mtojek/go/pkg/mod/gvisor.dev/gvisor@v0.0.0-20221203005347-703fd9b7fbc0/pkg/tcpip/adapters/gonet/gonet.go:401 +0x248
github.com/coder/coder/tailnet_test.TestTransmitHang(0x14000384000)
	/Users/mtojek/code/coder/tailnet/conn_test.go:293 +0xf0c
testing.tRunner(0x14000384000, 0x101d4f8f8)
	/opt/homebrew/Cellar/go/1.20.1/libexec/src/testing/testing.go:1576 +0x104
created by testing.(*T).Run
	/opt/homebrew/Cellar/go/1.20.1/libexec/src/testing/testing.go:1629 +0x370

goroutine 1106 [chan receive]:
github.com/tailscale/wireguard-go/device.(*Peer).RoutineSequentialReceiver(0x140000e2600, 0x1)
	/Users/mtojek/go/pkg/mod/github.com/tailscale/wireguard-go@v0.0.0-20221219190806-4fa124729667/device/receive.go:437 +0x124
created by github.com/tailscale/wireguard-go/device.(*Peer).Start
	/Users/mtojek/go/pkg/mod/github.com/tailscale/wireguard-go@v0.0.0-20221219190806-4fa124729667/device/peer.go:199 +0x2c0

I tried a few more things:

  1. strace:
strace -E TS_DEBUG_DISCO=true -E TS_DEBUG_DERP=true -E TS_DEBUG_NETSTACK=true -E GOMAXPROCS=2 -f -e trace=network go test ./tailnet -run=TestTransmitHang -v -count=1 2>&1 | grep -v SIG | egrep -v "write payload|write done"

(also -e bind,listen,socket,setsockopt to limit msgs)

  1. Extra envknobs: TS_DEBUG_NETLINK=1 and TS_DISABLE_UPNP=1, but no difference in output or behavior?

  2. SetWriteDeadline:

    t.go:81: 2023-05-09 14:02:51.069 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:297>	TestTransmitHang	write done
    t.go:81: 2023-05-09 14:02:51.069 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:295>	TestTransmitHang	write payload	{"num": 269, "transmitted_kb": 17214}
    t.go:81: 2023-05-09 14:02:51.069 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:297>	TestTransmitHang	write done
    t.go:81: 2023-05-09 14:02:51.069 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:295>	TestTransmitHang	write payload	{"num": 270, "transmitted_kb": 17278}
    t.go:81: 2023-05-09 14:02:51.069 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:297>	TestTransmitHang	write done
    t.go:81: 2023-05-09 14:02:51.069 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:295>	TestTransmitHang	write payload	{"num": 271, "transmitted_kb": 17342}
    t.go:81: 2023-05-09 14:02:51.069 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:297>	TestTransmitHang	write done
    t.go:81: 2023-05-09 14:02:51.069 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:295>	TestTransmitHang	write payload	{"num": 272, "transmitted_kb": 17406}
    t.go:81: 2023-05-09 14:02:51.070 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:297>	TestTransmitHang	write done
    t.go:81: 2023-05-09 14:02:51.070 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:295>	TestTransmitHang	write payload	{"num": 273, "transmitted_kb": 17470}
    t.go:81: 2023-05-09 14:02:51.070 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:297>	TestTransmitHang	write done
    t.go:81: 2023-05-09 14:02:51.070 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:295>	TestTransmitHang	write payload	{"num": 274, "transmitted_kb": 17534}
    t.go:81: 2023-05-09 14:02:52.752 [DEBUG]	<github.com/coder/coder/tailnet_test/conn_test.go:297>	TestTransmitHang	write done
    conn_test.go:298:
        	Error Trace:	/home/coder/coder/tailnet/conn_test.go:298
        	Error:      	Received unexpected error:
        	            	write tcp [fd7a:115c:a1e0:44c1:95b7:c48b:1dfc:bc88]:47220->[fd7a:115c:a1e0:46d6:8369:9615:74c2:eb84]:35565: i/o timeout
        	Test:       	TestTransmitHang

I think that @mafredri's test proves that it doesn't look like a bug in Coder's source code, but rather in coder/wireguard-go, coder/tailscale, or gvisor (the last one is the scariest). Maybe we should strip the entire tailnet wrapping logic, start with a plain project with gvisor and taiscale, and try to implement TestTransmitHang there?

@kylecarbs
Copy link
Member

I'm able to reproduce this in Tailscale's tsnet package:

diff --git a/tsnet/tsnet_test.go b/tsnet/tsnet_test.go
index 5ab27099..30b5c07e 100644
--- a/tsnet/tsnet_test.go
+++ b/tsnet/tsnet_test.go
@@ -261,25 +261,25 @@ func TestConn(t *testing.T) {
 	if err != nil {
 		t.Fatal(err)
 	}
-
-	want := "hello"
-	if _, err := io.WriteString(w, want); err != nil {
-		t.Fatal(err)
+	defer r.Close()
+	go io.Copy(io.Discard, r)
+
+	t.Log("writing")
+	payload := []byte(strings.Repeat("hello world\n", 65536/12))
+	size := 0
+	for i := 0; i < 1024*2; i++ {
+		t.Logf("write payload %d: %d bytes", i, size/1024)
+		n, err := w.Write(payload)
+		if err != nil {
+			t.Fatal(err)
+		}
+		size += n
 	}
 
-	got := make([]byte, len(want))
-	if _, err := io.ReadAtLeast(r, got, len(got)); err != nil {
+	err = w.Close()
+	if err != nil {
 		t.Fatal(err)
 	}
-	t.Logf("got: %q", got)
-	if string(got) != want {
-		t.Errorf("got %q, want %q", got, want)
-	}
-
-	_, err = s2.Dial(ctx, "tcp", fmt.Sprintf("%s:8082", s1ip)) // some random port
-	if err == nil {
-		t.Fatalf("unexpected success; should have seen a connection refused error")
-	}
 }
 
 func TestLoopbackLocalAPI(t *testing.T) {

@github-actions
Copy link

This Pull Request is becoming stale. In order to minimize WIP, prevent merge conflicts and keep the tracker readable, I'm going close to this PR in 3 days if there isn't more activity.

@github-actions github-actions bot added the stale This issue is like stale bread. label May 21, 2023
@mafredri mafredri removed the stale This issue is like stale bread. label May 22, 2023
mafredri added 2 commits May 24, 2023 17:30
This commit adds a test that occasionally triggers the issue in #7262.
When triggered, the test takes e.g. ~30s to complete instead of 2s. The
test also logs both from both `tailnet.Conn`s into a log file and
produces pcap files from each side.
@mafredri mafredri force-pushed the mafredri/test-add-tailnet-transmit-hang-test branch from 17bca06 to 2573049 Compare May 24, 2023 17:34
@github-actions github-actions bot added the stale This issue is like stale bread. label Jun 2, 2023
@github-actions github-actions bot closed this Jun 7, 2023
@github-actions github-actions bot deleted the mafredri/test-add-tailnet-transmit-hang-test branch November 26, 2023 00:11
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
stale This issue is like stale bread.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants