Skip to content
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

GSO fails on some platforms / interfaces #3911

Closed
zllovesuki opened this issue Jun 23, 2023 · 71 comments · Fixed by #4005
Closed

GSO fails on some platforms / interfaces #3911

zllovesuki opened this issue Jun 23, 2023 · 71 comments · Fixed by #4005
Labels
Milestone

Comments

@zllovesuki
Copy link
Contributor

zllovesuki commented Jun 23, 2023

I'm seeing a lot of INTERNAL_ERROR (local): write udp [::]:443->[REDACTED]:42830: sendmsg: invalid argument on the server side, causing the connection to be disconnected. They only happen when the clients are aarch64 (raspberry pi).

Could this be related to the GSO change?

@zllovesuki zllovesuki changed the title sendmsg: invalid argument on v0.16.0 sendmsg: invalid argument on v0.36.0 Jun 23, 2023
@marten-seemann
Copy link
Member

GSO would have been my first guess as well. I suspect that for some reason we manage to enable GSO, but don't correctly recognize that it was successfully enabled. This then causes the failure you're seeing because once enabled, the kernel expects the segment length message for the sendmsg to be set:

func appendUDPSegmentSizeMsg(b []byte, size uint16) []byte {
startLen := len(b)
const dataLen = 2 // payload is a uint16
b = append(b, make([]byte, unix.CmsgSpace(dataLen))...)
h := (*unix.Cmsghdr)(unsafe.Pointer(&b[startLen]))
h.Level = syscall.IPPROTO_UDP
h.Type = UDP_SEGMENT
h.SetLen(unix.CmsgLen(dataLen))
// UnixRights uses the private `data` method, but I *think* this achieves the same goal.
offset := startLen + unix.CmsgSpace(0)
*(*uint16)(unsafe.Pointer(&b[offset])) = size
return b
}

Can you try manually disabling GSO via the QUIC_GO_DISABLE_GSO environment variable?

func maybeSetGSO(rawConn syscall.RawConn) bool {
disable, _ := strconv.ParseBool(os.Getenv("QUIC_GO_DISABLE_GSO"))
if disable {
return false
}

This should make the failure go away.

If it's actually due to GSO, can you confirm if the syscall to enable it is successful in

var setErr error
if err := rawConn.Control(func(fd uintptr) {
setErr = unix.SetsockoptInt(int(fd), syscall.IPPROTO_UDP, UDP_SEGMENT, 1)
}); err != nil {
setErr = err
}


If my suspicion is correct, this would mean that we can't rely on the return value of the syscall that enables GSO. Maybe we need to instead read the value back using GetSockoptInt in maybeSetGSO?

@zllovesuki
Copy link
Contributor Author

zllovesuki commented Jun 23, 2023

It is indeed GSO:

With QUIC_GO_DISABLE_GSO on v0.36.0:

$ sudo k3s kubectl -n kube-system logs deployment/specter-tunnel -f
{"level":"info","ts":1687509533.946454,"caller":"client/client.go:150","msg":"Connected to specter server","id":8319038888190,"addr":"..."}
{"level":"info","ts":1687509534.009357,"caller":"client/client.go:366","msg":"Reusing existing client certificate","id":8319038888190,"identity":{"id":8319038888190,"token":"..."}}
{"level":"info","ts":1687509534.8210588,"caller":"client/client.go:150","msg":"Connected to specter server","id":8319038888190,"addr":"..."}
{"level":"info","ts":1687509535.0624511,"caller":"client/client.go:150","msg":"Connected to specter server","id":8319038888190,"addr":"..."}
{"level":"info","ts":1687509535.062558,"caller":"client/client.go:105","msg":"Waiting for RTT measurement...","id":8319038888190,"max":3}
{"level":"info","ts":1687509537.8524847,"caller":"client/client.go:465","msg":"Synchronizing tunnels in config file with specter","id":8319038888190,"tunnels":3}
// ...
{"level":"info","ts":1687509540.0839405,"caller":"client/client.go:734","msg":"Listening for tunnel traffic","id":8319038888190}
{"level":"info","ts":1687509540.0855958,"caller":"client/server.go:210","msg":"Local server started","id":8319038888190,"listen":"[::]:1180"}

Without QUIC_GO_DISABLE_GSO on v0.36.0:

$ sudo k3s kubectl -n kube-system logs deployment/specter-tunnel -f
{"level":"info","ts":1687509601.2167587,"caller":"client/client.go:150","msg":"Connected to specter server","id":8319038888190,"addr":"..."}
{"level":"info","ts":1687509601.2458448,"caller":"client/client.go:366","msg":"Reusing existing client certificate","id":8319038888190,"identity":{"id":8319038888190,"token":"..."}}
{"level":"info","ts":1687509601.846103,"caller":"client/client.go:150","msg":"Connected to specter server","id":8319038888190,"addr":"..."}
{"level":"info","ts":1687509602.3856218,"caller":"client/client.go:150","msg":"Connected to specter server","id":8319038888190,"addr":"..."}
{"level":"info","ts":1687509602.3857913,"caller":"client/client.go:105","msg":"Waiting for RTT measurement...","id":8319038888190,"max":3}
{"level":"info","ts":1687509604.3391526,"caller":"client/client.go:465","msg":"Synchronizing tunnels in config file with specter","id":8319038888190,"tunnels":3}
{"level":"error","ts":1687509604.3451564,"caller":"client/client.go:470","msg":"Failed to query available hostnames","id":8319038888190,"error":"twirp error internal: failed to do request: Post \"https://[REDACTED]:443/twirp/protocol.TunnelService/RegisteredHostnames\": INTERNAL_ERROR (local): write udp [::]:39575->[REDACTED]:443: sendmsg: invalid argument","stacktrace":"kon.nect.sh/specter/tun/client.(*Client).SyncConfigTunnels\n\t/app/tun/client/client.go:470\nkon.nect.sh/specter/tun/client.(*Client).Initialize\n\t/app/tun/client/client.go:109\nkon.nect.sh/specter/cmd/client.cmdTunnel\n\t/app/cmd/client/tunnel.go:115\ngithub.com/urfave/cli/v2.(*Command).Run\n\t/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:274\ngithub.com/urfave/cli/v2.(*Command).Run\n\t/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:267\ngithub.com/urfave/cli/v2.(*Command).Run\n\t/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:267\ngithub.com/urfave/cli/v2.(*App).RunContext\n\t/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/app.go:332\nmain.main\n\t/app/main.go:15\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:250"}

@zllovesuki
Copy link
Contributor Author

zllovesuki commented Jun 23, 2023

This is with debug printout (don't worry the version in the message, that's just my fork not having updated tags):

$ sudo k3s kubectl -n kube-system logs deployment/specter-tunnel -f
{"level":"info","ts":1687510239.739196,"caller":"quic-go@v0.28.2-0.20230622082411-87dbaf5cbef0/sys_conn_df_linux.go:58","msg":"!! DEBUG !! setErr: <nil>","subsystem":"unknown"}
// ...
{"level":"error","ts":1687510243.1822891,"caller":"client/client.go:521","msg":"Failed to publish tunnel","id":8319038888190,"hostname":"jenkins.box.s0c.net","target":"http://jenkins-service.devops-tools.svc.cluster.local:8080","endpoints":3,"error":"twirp error internal: failed to do request: Post \"https://[REDACTED]:443/twirp/protocol.TunnelService/PublishTunnel\": INTERNAL_ERROR (local): write udp [::]:54254->[REDACTED]:443: sendmsg: invalid argument","stacktrace":"kon.nect.sh/specter/tun/client.(*Client).SyncConfigTunnels\n\t/app/tun/client/client.go:521\nkon.nect.sh/specter/tun/client.(*Client).Initialize\n\t/app/tun/client/client.go:109\nkon.nect.sh/specter/cmd/client.cmdTunnel\n\t/app/cmd/client/tunnel.go:115\ngithub.com/urfave/cli/v2.(*Command).Run\n\t/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:274\ngithub.com/urfave/cli/v2.(*Command).Run\n\t/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:267\ngithub.com/urfave/cli/v2.(*Command).Run\n\t/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/command.go:267\ngithub.com/urfave/cli/v2.(*App).RunContext\n\t/go/pkg/mod/github.com/urfave/cli/v2@v2.25.7/app.go:332\nmain.main\n\t/app/main.go:15\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:250"}

Like so:

	var setErr error
	if err := rawConn.Control(func(fd uintptr) {
		setErr = unix.SetsockoptInt(int(fd), syscall.IPPROTO_UDP, UDP_SEGMENT, 1)
	}); err != nil {
		setErr = err
	}
	log.Printf("!! DEBUG !! setErr: %+v\n", setErr)
	if setErr != nil {
		log.Println("failed to enable GSO")
		return false
	}

@zllovesuki
Copy link
Contributor Author

GetsockoptInt won't work because it will read back the value correctly:

$ sudo k3s kubectl -n kube-system logs deployment/specter-tunnel -f
{"level":"info","ts":1687510849.0587795,"caller":"quic-go@v0.36.1-0.20230622083630-75a709765faa/sys_conn_df_linux.go:64","msg":"!! DEBUG !! GetsockoptInt: 1, err: <nil>","subsystem":"unknown"}

Like so:

	var setErr error
	if err := rawConn.Control(func(fd uintptr) {
		setErr = unix.SetsockoptInt(int(fd), syscall.IPPROTO_UDP, UDP_SEGMENT, 1)
	}); err != nil {
		setErr = err
	}
	if setErr != nil {
		log.Println("failed to enable GSO")
		return false
	}
	rawConn.Control(func(fd uintptr) {
		val, err := unix.GetsockoptInt(int(fd), syscall.IPPROTO_UDP, UDP_SEGMENT)
		log.Printf("!! DEBUG !! GetsockoptInt: %+v, err: %+v\n", val, err)
	})

@zllovesuki
Copy link
Contributor Author

Could this be the kernel not supporting GSO fully? On the client, they are running inside docker but on aarch64 hosts, also they are raspberry pi. On the server, the server complaining about invalid argument is also aarch64 but they are Ampere Altra, although in a VM.

@marten-seemann
Copy link
Member

Thank you! I would’ve expected the SetSockoptInt to fail in that case, but maybe that’s not how it works?

Any idea how we could determine if GSO is actually available? Seems like we can neither trust SetSockoptInt nor GetSockoptInt. And the „invalid argument“ error is also pretty unspecific, otherwise we could do some kind of error assertion.

@zllovesuki
Copy link
Contributor Author

I think the argument might be incorrect: https://github.com/torvalds/linux/blob/master/tools/testing/selftests/net/udpgso.c

The value is not 1 or 0 but the size it seems

@jfgiorgi
Copy link
Contributor

jfgiorgi commented Jun 23, 2023

we have the same issue with Chromebooks (Linux vm in Chromebook).
GSO breaks with IPv6 and works fine with IPv4.
Cloudflare quiche has the same issue (but we have not tested it as much as quic-go).

To test for GSO, quiche use "1350" instead of "1" but I've tried to change this in quic-go and the error is still there. (see detect_gso definition and calls)

@jfgiorgi
Copy link
Contributor

the issues seems to detect if GSO works ALSO with IPv6.

@marten-seemann
Copy link
Member

@jfgiorgi Does the error occur immediately, or only when DPLPMTUD kicks in and attempts to send a packet larger than 1350 bytes (maybe minus IP / UDP header?).

@kgersen
Copy link

kgersen commented Jun 23, 2023

immediately.

here an example with h3ctx (https://github.com/kgersen/h3ctx) with QUIC_GO_LOG_LEVEL set to DEBUG.

to reproduce: QUIC_GO_LOG_LEVEL=DEBUG go run main.go -6 -noh2

    ...
    downloading https://localhost:2222/10000000000
    HTTP3 dialing localhost:2222 -> [::1]:2222
    2023/06/23 20:52:50 Setting DF for IPv4 and IPv6.
    2023/06/23 20:52:50 Activating reading of ECN bits for IPv4 and IPv6.
    2023/06/23 20:52:50 Activating reading of packet info for IPv4 and IPv6.
    QUIC: connected to [::1]:2222 from [::]:44040 (ids=a6e73f9b-da30a13223924d2301b0c6fae1bf)
    2023/06/23 20:52:50 client Starting new connection to localhost ([::]:44040 -> [::1]:2222), source connection ID a6e73f9b, destination connection ID da30a13223924d2301b0c6fae1bf, version v1
    2023/06/23 20:52:50 Adding connection ID a6e73f9b.
    2023/06/23 20:52:50 Increased receive buffer size to 4096 kiB
    2023/06/23 20:52:50 client Not doing 0-RTT.
    2023/06/23 20:52:50 client -> Sending packet 0 (1232 bytes) for connection da30a13223924d2301b0c6fae1bf, Initial
    2023/06/23 20:52:50 client      Long Header{Type: Initial, DestConnectionID: da30a13223924d2301b0c6fae1bf, SrcConnectionID: a6e73f9b, Token: (empty), PacketNumber: 0, PacketNumberLen: 2, Length: 1204, Version: v1}
    2023/06/23 20:52:50 client      -> &wire.CryptoFrame{Offset: 0, Data length: 260, Offset + Data length: 260}
    2023/06/23 20:52:50 client Destroying connection with error: write udp [::]:44040->[::1]:2222: sendmsg: invalid argument
    2023/06/23 20:52:50 Removing connection ID a6e73f9b.
    2023/06/23 20:52:50 client Connection da30a13223924d2301b0c6fae1bf closed.
    closing local quic transport
    client error for https://localhost:2222/10000000000: Get "https://localhost:2222/10000000000": INTERNAL_ERROR (local): write udp [::]:44040->[::1]:2222: sendmsg: invalid argument
    
    server :2222 shuting down

h3ctx is a client and a server. in this mode, the client tries to connect and get sendmsg: invalid argument immediatly. Nothing is logged server side.

I don't know if this can help but you might want to take a look at how msquic solved this: microsoft/msquic#1360
They also have RSS and Receive Batching implemented which could be nice to have in quic-go

@zllovesuki
Copy link
Contributor Author

@marten-seemann can we recall the 0.36.0 release? Folks not knowing gso might explode may have their system explodes if they upgraded to 0.36.0 mistakenly

@marten-seemann
Copy link
Member

@marten-seemann can we recall the 0.36.0 release? Folks not knowing gso might explode may have their system explodes if they upgraded to 0.36.0 mistakenly

I'm considering it, unless we can figure out a patch within the next day or so. Alternatively, we could also flip the environment variable to QUIC_GO_ENABLE_GSO, so we don't have to recall all the other GSO-unrelated fixes.

cc @mholt @francislavoie, just so you're aware, you'll most likely receive another PR with a patch for Caddy soon.


I don't know if this can help but you might want to take a look at how msquic solved this: microsoft/msquic#1360

@kgersen The fallback is actually not the big problem. I'm fine falling back to a simple sendmsg on systems that don't support GSO for now. The problem is detecting if we're on such a system. Unfortunately, the kernel doesn't give us an error message that says "I don't like that UDP_SEGMENT message you gave me".


I think the argument might be incorrect: https://github.com/torvalds/linux/blob/master/tools/testing/selftests/net/udpgso.c

The value is not 1 or 0 but the size it seems

@zllovesuki Could you try setting the value to 1400 or so and see if that fixes the problem?


Does anyone have any pointer for me how to reproduce this? GSO works fine both on my Ubuntu machine (via Parallels), and on all the Linode cloud servers I have up and running. Ideally some cloud service where I can quickly spin up a machine to play around with.

@mholt
Copy link
Contributor

mholt commented Jun 23, 2023

Thanks for the ping. We'll hold the Caddy 2.7 stable release until a patch is ready. We're fine with either a fix or disabling it.

@marten-seemann marten-seemann pinned this issue Jun 23, 2023
@bt90
Copy link
Contributor

bt90 commented Jun 24, 2023

@marten-seemann Oracle offers aarch64 in their free tier

https://www.oracle.com/cloud/free/

@bt90
Copy link
Contributor

bt90 commented Jun 24, 2023

I wonder if this is in fact a kernel bug? Might be one of those aarch64 funzies that @marcan and the Asahi team keeps running into.

@kgersen
Copy link

kgersen commented Jun 24, 2023

@kgersen The fallback is actually not the big problem. I'm fine falling back to a simple sendmsg on systems that don't support GSO for now. The problem is detecting if we're on such a system. Unfortunately, the kernel doesn't give us an error message that says "I don't like that UDP_SEGMENT message you gave me".

So the fix they use is to actually test gso before using it an not just believe what the kernel returns.

@marten-seemann
Copy link
Member

Can you point me to where they test this?

@jfgiorgi
Copy link
Contributor

jfgiorgi commented Jun 24, 2023

here: https://github.com/microsoft/msquic/blob/main/src/platform/datapath_epoll.c#L473 (up to line 535)
They test GSO and then optionally also GRO.
problem I see here if that they use IPv4 lookback ...not sure they would detect the issue on our machines.

I've run the Linux kernel selftests on a machine with the issue and I can confirm, in our case, it's GSO+IPv6 the cultrip:

user@penguin:~/linux-source-5.10/tools/testing/selftests/net$ sudo ./in_netns.sh ./udpgso -6 -C -s
device mtu (orig): 65536
device mtu (test): 1500
ipv6 tx:1 gso:0 
ipv6 tx:1452 gso:0 
ipv6 tx:1453 gso:0 (fail)
ipv6 tx:1452 gso:1452 
./udpgso: send failed while expecting success

with -4 (Ipv4) all tests are ok.

@marten-seemann
Copy link
Member

@jfgiorgi Any chance I can spin up a machine like this myself? Would be really helpful if I could debug it myself.

@bt90
Copy link
Contributor

bt90 commented Jun 24, 2023

@marten-seemann Oracle offers aarch64 in their free tier

https://www.oracle.com/cloud/free/

You should be able to use the service for free 😉

@jfgiorgi
Copy link
Contributor

@jfgiorgi Any chance I can spin up a machine like this myself? Would be really helpful if I could debug it myself.

unfortunately it's not a VM in the cloud. it's a VM inside of physical device, a Chromebook.

the specs:
the hardware is an Intel I5-7Y57, running ChromeOS (Linux 5.4.247)
inside there is a VM in qemu running Linux 5.15.117
in which there is LXD container running Debian (with shared kernel so Linux 5.15.117).

We only have shell access to the inner LXD container so I don't know which layer is causing the issue.

@bt90
Copy link
Contributor

bt90 commented Jun 24, 2023

Seems like it's tied to IPv6 and VMs/containers?

I wonder if this patch is related?

https://patchwork.kernel.org/project/netdevbpf/patch/1610027418-30438-1-git-send-email-ayal@nvidia.com/

@marten-seemann
Copy link
Member

@marten-seemann Oracle offers aarch64 in their free tier
https://www.oracle.com/cloud/free/

You should be able to use the service for free 😉

I tried, and it doesn't work. This user interface is a total mess. Apparently they're "out of capacity" for the aarch64 machines, and they don't let me use the 250 bucks of "free credit" they gave me to play around with beefier machines. And for some reason I'm stuck in the upgrade process of my account, which would allow me to add my credit card. What should I say, Oracle...

Instead, I set up an aarch64 on AWS. However, everything works fine there, I can successfully enable GSO there.

I'm not sure how to continue debugging this. By now I've probably tested on > 10 machines, and every machine I set up works fine, no matter which architecture and which distribution I select.

the specs:
the hardware is an Intel I5-7Y57, running ChromeOS (Linux 5.4.247)
inside there is a VM in qemu running Linux 5.15.117
in which there is LXD container running Debian (with shared kernel so Linux 5.15.117).

I don't think I'll be able to recreate this... ;)

@jfgiorgi
Copy link
Contributor

There isn't much to debug. it's clearly a kernel/hardware issue on some machines/configuration not related to quic-go or even Go.
Even the kernel selftest fails.
At this point either spend more time trying to contact the people who made gso in Linux kernel or a Linux kernel/driver support group. may be there is a way to detect the issue (may be a cpu feature is missing or whatnot).
or do like msquic.
or switch gso to opt-in and let quic-go users do their own 'extra detection' when they encounter the issue.

The safest is like msquic: detect gso but don't trust the kernel so perform a test or catch the very first error and retry once without gso.

I'll take a look at Google's quiche and Chromium source later next week to see how they deal with this since our Chromebooks have the issue.

@marten-seemann
Copy link
Member

There's a few things I'd like to try out. As @zllovesuki noticed, the we shouldn't set the option to 1, but the actual packet size. Now what I'd like to experiment with is the following:

  1. What if we set this to a value that fits the initial packet size (~1280 bytes), but doesn't fit larger packet sizes, as PLPMTUD would attempt to send.
  2. Can we just set this value to something > 1500 bytes, or will this call the syscall to fail for Ethernet interfaces (which usually have a smaller MTU)?

here: https://github.com/microsoft/msquic/blob/main/src/platform/datapath_epoll.c#L473 (up to line 535)
They test GSO and then optionally also GRO.

We could implement something similar: Send a packet filled with random bytes in maybeSetGSO, and disable GSO if we get any error. This means that the first packet a newly started QUIC server receives will be random garbage, but we obviously need to be able to deal with that anyway (i.e. discard it).

@marten-seemann
Copy link
Member

Unfortunately, I don't have a Raspberry Pi with me at the moment. @zllovesuki, can you help us out here?

@jwhited
Copy link

jwhited commented Jul 30, 2023

You can get EINVAL when the split would result in more than 64 datagrams. I grepped for this value in quic-go and I don't see it being enforced, though I may have missed it.

See https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/net/ipv4/udp.c?h=v6.2&id=c9c3395d5e3dcc6daee66c6908354d47bf98cb0c#n933 and the usage of https://github.com/WireGuard/wireguard-go/pull/75/files?diff=unified&w=0#diff-8fba84ef516815198fc29ef62a2486ad0c8b49e02257af3c3b96171a1cbfdc87R451

@marten-seemann
Copy link
Member

That check is implicit. The minimum size of packets we send is 1200 bytes, and we stop adding new packets to a batch as soon as a packet is packed that's smaller than that. Since the size is limited to 64k, we can never have more than 64 packets.

@marten-seemann
Copy link
Member

Maybe the way we construct the cmsg doesn't work on all platforms? Just a wild guess, but it might be worth checking that the cmsg looks the same when generated in C vs. what we generate here in Go:

func appendUDPSegmentSizeMsg(b []byte, size uint16) []byte {
startLen := len(b)
const dataLen = 2 // payload is a uint16
b = append(b, make([]byte, unix.CmsgSpace(dataLen))...)
h := (*unix.Cmsghdr)(unsafe.Pointer(&b[startLen]))
h.Level = syscall.IPPROTO_UDP
h.Type = unix.UDP_SEGMENT
h.SetLen(unix.CmsgLen(dataLen))
// UnixRights uses the private `data` method, but I *think* this achieves the same goal.
offset := startLen + unix.CmsgSpace(0)
*(*uint16)(unsafe.Pointer(&b[offset])) = size
return b
}

@zllovesuki
Copy link
Contributor Author

@marten-seemann do you just need SSH access to a raspberry pi? Send me an email (address on profile) or we can chat over Signal to coordinate

@marten-seemann
Copy link
Member

@zllovesuki Thanks for offering. I might get back to you on this in a couple of days.

@jfgiorgi
Copy link
Contributor

I've reproduced this in C: https://gist.github.com/marten-seemann/36a2558b48d060d063ecb3b005f47320. It's useful to run this with ptrace to see the syscalls being made: strace -e trace=sendmsg -s 1000 ./your_program.

i've updated this C code to support both IPv4 & IPv6 : https://github.com/jfgiorgi/cgso

on our systems with the gso issue:

#IPv6
clang gsofallback.c && ./a.out 2001:4860:4860::8888
Sending with GSO to [2001:4860:4860::8888]:6121...
GSO failed. Attempting without GSO...
Message sent without GSO.

#IPv4
clang gsofallback.c && ./a.out 8.8.8.8
Sending with GSO to [::ffff:8.8.8.8]:6121...
Message sent with GSO.

it works if:
. no call to setsockopt is made (uncommeting the setsockopt lines make the fallback fails too)
. fallback if first message fails with UDP_SEGMENT in ancillary data

@jwhited
Copy link

jwhited commented Jul 31, 2023

it works if: . no call to setsockopt is made (uncommeting the setsockopt lines make the fallback fails too) . fallback if first message fails with UDP_SEGMENT in ancillary data

The UDP_SEGMENT sockopt is not a binary flag like UDP_GRO. It sets the split size for all datagrams without the need for an equivalent cmsg. So, setting it to 1 and mixing with cmsg seems unintentional if quic-go is still doing that.

@zllovesuki
Copy link
Contributor Author

zllovesuki commented Aug 29, 2023

I'm still seeing issues with GSO on arm64 and amd64 platform:

"error":"INTERNAL_ERROR (local): write udp [::]:443->[redacted]:51157: sendmsg: invalid argument"

amd64 is a linode vm, arm64 is an oracle vm

@bt90
Copy link
Contributor

bt90 commented Aug 30, 2023

Is there any container runtime involved?

@bt90
Copy link
Contributor

bt90 commented Aug 30, 2023

I wonder if the offset calculation is correct. The internal data method only accounts for cmsgAlignOf(SizeofCmsghdr) but we use CmsgSpace(0) which also applies the alignment for a zero datalength.

Wouldn't CmsgLen(0) be the safer choice?

@howardjohn
Copy link

This isn't a super helpful comment but I forgot to gather more info and tore down my environment. Figured I would comment something now instead of waiting - I will try to make this more useful though.

On a GCP c3 VM with completely out-of-the-box settings connecting to another C3 VM using the latest version of quic-go, I had to disable GSO or I got the invalid argument. The same code works on my local machine.

package main

import (
	"context"
	"crypto/rand"
	"crypto/rsa"
	"crypto/tls"
	"crypto/x509"
	"encoding/pem"
	"flag"
	"github.com/quic-go/quic-go"
	syscall "golang.org/x/sys/unix"
	"io"
	"log"
	"math/big"
	"net"
	"os"
	"os/signal"
	"sync"
	"time"
)

var (
	remote = flag.String("r", "127.0.0.1:8080", "remote addresses")
)

func main() {
	flag.Parse()

	go outbound()
	go inbound()
	WaitSignal()
}

func listenUDP(addr string) (*net.UDPConn, error) {
	udpAddr, err := net.ResolveUDPAddr("udp4", addr)
	if err != nil {
		return nil, err
	}
	return net.ListenUDP("udp4", udpAddr)
}

func dialUDP(addr string, tlsConf *tls.Config, conf *quic.Config) (quic.Connection, error) {
	udpConn, err := net.ListenUDP("udp4", nil)
	if err != nil {
		return nil, err
	}
	udpAddr, err := net.ResolveUDPAddr("udp4", addr)
	if err != nil {
		return nil, err
	}
	return quic.Dial(context.Background(), udpConn, udpAddr, tlsConf, conf)
}

func outbound() {
	listener, err := net.Listen("tcp", "0.0.0.0:15001")
	if err != nil {
		panic(err)
	}

	for {
		conn, err := listener.Accept()
		if err != nil {
			panic(err)
		}
		log.Println("accepted outbound connection")
		go proxyConn(conn, *remote, true)
	}
}
func inbound() {
	pc, err := listenUDP("0.0.0.0:15006")
	if err != nil {
		panic(err)
	}
	listener, err := quic.Listen(pc, generateTLSConfig(), &quic.Config{
		EnableDatagrams: true,
	})
	if err != nil {
		panic(err)
	}
	for {
		conn, err := listener.Accept(context.Background())
		if err != nil {
			panic(err)
		}
		log.Println("accepted inbound connection")
		_, port, _ := net.SplitHostPort(*remote)
		stream, err := conn.AcceptStream(context.Background())
		if err != nil {
			panic(err)
		}
		go proxyConn(stream, "127.0.0.1:"+port, false)
	}
}

func WaitSignal() {
	sigs := make(chan os.Signal, 1)
	signal.Notify(sigs, syscall.SIGINT, syscall.SIGTERM)
	<-sigs
}

func proxyConn(incoming io.ReadWriteCloser, dstIP string, useTLS bool) {
	var outgoing io.ReadWriteCloser
	if useTLS {
		c, err := dialUDP(dstIP, generateTLSConfig(), &quic.Config{EnableDatagrams: true})
		if err != nil {
			panic(err)
		}
		stream, err := c.OpenStream()
		if err != nil {
			panic(err)
		}
		outgoing = stream
	} else {
		c, err := net.Dial("tcp", dstIP)
		if err != nil {
			panic(err)
		}
		outgoing = c
	}

	log.Println("connected to upstream")
	t0 := time.Now()
	wg := sync.WaitGroup{}
	wg.Add(1)
	go func() {
		n, err := io.Copy(incoming, outgoing)
		log.Printf("upstream complete, wrote=%v, err=%v", n, err)
		incoming.Close()
		outgoing.Close()
		wg.Done()
	}()

	n, err := io.Copy(outgoing, incoming)
	log.Printf("downstream complete, wrote=%v, err=%v", n, err)
	incoming.Close()
	outgoing.Close()
	wg.Wait()
	log.Println("connection closed in ", time.Since(t0))
}

func generateTLSConfig() *tls.Config {
	key, err := rsa.GenerateKey(rand.Reader, 1024)
	if err != nil {
		panic(err)
	}
	template := x509.Certificate{SerialNumber: big.NewInt(1)}
	certDER, err := x509.CreateCertificate(rand.Reader, &template, &template, &key.PublicKey, key)
	if err != nil {
		panic(err)
	}
	keyPEM := pem.EncodeToMemory(&pem.Block{Type: "RSA PRIVATE KEY", Bytes: x509.MarshalPKCS1PrivateKey(key)})
	certPEM := pem.EncodeToMemory(&pem.Block{Type: "CERTIFICATE", Bytes: certDER})

	tlsCert, err := tls.X509KeyPair(certPEM, keyPEM)
	if err != nil {
		panic(err)
	}
	return &tls.Config{
		Certificates:       []tls.Certificate{tlsCert},
		InsecureSkipVerify: true,
	}
}

@marten-seemann
Copy link
Member

@howardjohn Not sure how to use your code, but I successfully tested quic-go on a GCP c3 machine, establishing a QUIC connection to google.com.

@wlynxg
Copy link
Contributor

wlynxg commented Nov 10, 2023

When I use quic echo, the same error still occurs, the information is as follows:

[root@Aliyun quic]# QUIC_GO_LOG_LEVEL=DEBUG go run main.go 
2023/11/10 22:14:36 Increased receive buffer size to 4096 kiB
2023/11/10 22:14:36 Increased send buffer size to 4096 kiB
2023/11/10 22:14:36 Setting DF for IPv4 and IPv6.
2023/11/10 22:14:36 Activating reading of ECN bits for IPv4 and IPv6.
2023/11/10 22:14:36 Activating reading of packet info for IPv4 and IPv6.
2023/11/10 22:14:36 client Starting new connection to localhost ([::]:47781 -> 127.0.0.1:4242), source connection ID (empty), destination connection ID dedb29535cb7debdda558e64e544722190fdd626, version v1
2023/11/10 22:14:36 Adding connection ID (empty).
2023/11/10 22:14:36 client Not doing 0-RTT. Has sealer: false, has params: false
2023/11/10 22:14:36 client -> Sending packet 0 (1252 bytes) for connection dedb29535cb7debdda558e64e544722190fdd626, Initial
2023/11/10 22:14:36 client      Long Header{Type: Initial, DestConnectionID: dedb29535cb7debdda558e64e544722190fdd626, SrcConnectionID: (empty), Token: (empty), PacketNumber: 0, PacketNumberLen: 2, Length: 1222, Version: v1}
2023/11/10 22:14:36 client      -> &wire.CryptoFrame{Offset: 0, Data length: 279, Offset + Data length: 279}
2023/11/10 22:14:36 client Destroying connection with error: write udp [::]:47781->127.0.0.1:4242: sendmsg: invalid argument
2023/11/10 22:14:36 Removing connection ID (empty).
2023/11/10 22:14:36 client Connection dedb29535cb7debdda558e64e544722190fdd626 closed.
panic: INTERNAL_ERROR (local): write udp [::]:47781->127.0.0.1:4242: sendmsg: invalid argument

goroutine 1 [running]:
main.main()
        /root/quic/main.go:29 +0x45
exit status 2

I added QUIC_GO_DISABLE_GSO=true and the problem still exists

[root@Aliyun quic]# QUIC_GO_DISABLE_GSO=true QUIC_GO_LOG_LEVEL=DEBUG go run main.go 
2023/11/10 22:14:27 Increased receive buffer size to 4096 kiB
2023/11/10 22:14:27 Increased send buffer size to 4096 kiB
2023/11/10 22:14:27 Setting DF for IPv4 and IPv6.
2023/11/10 22:14:27 Activating reading of ECN bits for IPv4 and IPv6.
2023/11/10 22:14:27 Activating reading of packet info for IPv4 and IPv6.
2023/11/10 22:14:27 client Starting new connection to localhost ([::]:52004 -> 127.0.0.1:4242), source connection ID (empty), destination connection ID 5ee5129391926792fbf5e57e0efbcd75, version v1
2023/11/10 22:14:27 Adding connection ID (empty).
2023/11/10 22:14:27 client Not doing 0-RTT. Has sealer: false, has params: false
2023/11/10 22:14:27 client -> Sending packet 0 (1252 bytes) for connection 5ee5129391926792fbf5e57e0efbcd75, Initial
2023/11/10 22:14:27 client      Long Header{Type: Initial, DestConnectionID: 5ee5129391926792fbf5e57e0efbcd75, SrcConnectionID: (empty), Token: (empty), PacketNumber: 0, PacketNumberLen: 2, Length: 1226, Version: v1}
2023/11/10 22:14:27 client      -> &wire.CryptoFrame{Offset: 0, Data length: 273, Offset + Data length: 273}
2023/11/10 22:14:27 client Destroying connection with error: write udp [::]:52004->127.0.0.1:4242: sendmsg: invalid argument
2023/11/10 22:14:27 Removing connection ID (empty).
2023/11/10 22:14:27 client Connection 5ee5129391926792fbf5e57e0efbcd75 closed.
panic: INTERNAL_ERROR (local): write udp [::]:52004->127.0.0.1:4242: sendmsg: invalid argument

goroutine 1 [running]:
main.main()
        /root/quic/main.go:29 +0x45
exit status 2

about my Linux:

[root@Aliyun quic]# uname -a
Linux Aliyun 3.10.0-957.21.3.el7.x86_64 #1 SMP Tue Jun 18 16:35:19 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
[root@Aliyun quic]# go version
go version go1.20 linux/amd64
[root@Aliyun quic]# cat go.mod
module gquic

go 1.20

require github.com/quic-go/quic-go v0.40.0

require (
        github.com/go-task/slim-sprig v0.0.0-20230315185526-52ccab3ef572 // indirect
        github.com/google/pprof v0.0.0-20210407192527-94a9f03dee38 // indirect
        github.com/onsi/ginkgo/v2 v2.9.5 // indirect
        github.com/quic-go/qtls-go1-20 v0.4.1 // indirect
        go.uber.org/mock v0.3.0 // indirect
        golang.org/x/crypto v0.4.0 // indirect
        golang.org/x/exp v0.0.0-20221205204356-47842c84f3db // indirect
        golang.org/x/mod v0.11.0 // indirect
        golang.org/x/net v0.10.0 // indirect
        golang.org/x/sys v0.8.0 // indirect
        golang.org/x/tools v0.9.1 // indirect
)

@otbutz
Copy link

otbutz commented Nov 10, 2023

Linux Aliyun 3.10.0-957.21.3.el7.x86_64

UDP GSO support was introduced in 4.18: https://kernelnewbies.org/Linux_4.18#Networking

@wlynxg
Copy link
Contributor

wlynxg commented Nov 10, 2023

Linux Aliyun 3.10.0-957.21.3.el7.x86_64

UDP GSO support was introduced in 4.18: https://kernelnewbies.org/Linux_4.18#Networking

Sorry, I didn't debug at first and came directly to this issue. I found that it was not just GSO that caused this problem. Using QUIC_GO_DISABLE_GSO=true was effective, but my linux did not support ECN, so I had to use QUIC_GO_DISABLE_ECN=true at the same time to solve this problem.

@zllovesuki
Copy link
Contributor Author

@marten-seemann do you think the invalid argument was coming from ECN related bug instead of GSO?

@marten-seemann
Copy link
Member

That would be my suspicion of QUIC_GO_DISABLE_ECN=true solved the problem.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.