Sure, here's the trace:
--
DEBUG: (wg1) 2023/03/22 23:46:39 peer(Suxf…6dEI) - Routine: sequential sender -
stopped
panic: As4 called on IP zero value
goroutine 70 [running]:
net/netip.Addr.As4({{0xc0048b1200?, 0xc00058bb28?}, 0x0?})
/opt/go1.20.2.linux-arm64/src/net/netip/netip.go:690 +0x174
golang.zx2c4.com/wireguard/conn.setSrcControl(0xc00931b018, 0xc006301640)
/home/lsc36/wireguard-go/conn/sticky_linux.go:95 +0x280
golang.zx2c4.com/wireguard/conn.(*StdNetBind).send4(0xc0003b6000,
0xffffa9d04200?, 0xc0000b8230, {0x24e6e8?, 0xc006301640?}, {0xc000533800, 0x1,
0xba250?})
/home/lsc36/wireguard-go/conn/bind_std.go:346 +0x178
golang.zx2c4.com/wireguard/conn.(*StdNetBind).Send(0xc0003b6000, {0xc000533800,
0x1, 0x80}, {0x24e6e8, 0xc006301640})
/home/lsc36/wireguard-go/conn/bind_std.go:332 +0x1d8
golang.zx2c4.com/wireguard/device.(*Peer).SendBuffers(0xc0000be380,
{0xc000533800?, 0x1, 0x80})
/home/lsc36/wireguard-go/device/peer.go:126 +0x190
golang.zx2c4.com/wireguard/device.(*Peer).RoutineSequentialSender(0xc0000be380,
0x80)
/home/lsc36/wireguard-go/device/send.go:519 +0x45c
created by golang.zx2c4.com/wireguard/device.(*Peer).Start
/home/lsc36/wireguard-go/device/peer.go:198 +0x304
--
The offending call `ep.SrcIP().As4()` (sticky_linux.go:95) is only
reached when `ep.SrcIP().Is4() && ep.SrcIP().IsValid()` is true, yet it
panicked saying it was being called against a zero value. That's why I
suspected it's a data race in the first place.
On 3/24/23 01:00, Jordan Whited wrote:
> SC, thank you for reporting. Do you happen to have a stack trace from
> one of the panics?
>
> On Thu, Mar 23, 2023 at 2:01 AM lsc <l...@lv6.tw> wrote:
>>
>> Hi,
>>
>> Not sure if this is the correct place for bug reports, hope it's okay :)
>>
>> I found my wireguard-go server (built from current ToT 1417a47) always
>> panicking when I ran speedtest on a client via the server. I rebuilt the
>> server with data race detector (`go build -race`) and got the following
>> trace:
>>
>> ==================
>> WARNING: DATA RACE
>> Read at 0x00c00043b2f8 by goroutine 49:
>> golang.zx2c4.com/wireguard/conn.setSrcControl()
>> /home/lsc36/wireguard-go/conn/sticky_linux.go:76 +0x8c
>> golang.zx2c4.com/wireguard/conn.(*StdNetBind).send4()
>> /home/lsc36/wireguard-go/conn/bind_std.go:346 +0x174
>> golang.zx2c4.com/wireguard/conn.(*StdNetBind).Send()
>> /home/lsc36/wireguard-go/conn/bind_std.go:332 +0x1d4
>> golang.zx2c4.com/wireguard/device.(*Peer).SendBuffers()
>> /home/lsc36/wireguard-go/device/peer.go:126 +0x18c
>> golang.zx2c4.com/wireguard/device.(*Peer).RoutineSequentialSender()
>> /home/lsc36/wireguard-go/device/send.go:519 +0x458
>> golang.zx2c4.com/wireguard/device.(*Peer).Start.func2()
>> /home/lsc36/wireguard-go/device/peer.go:198 +0x40
>>
>> Previous write at 0x00c00043b2f8 by goroutine 47:
>> golang.zx2c4.com/wireguard/conn.(*StdNetEndpoint).ClearSrc()
>> /home/lsc36/wireguard-go/conn/bind_std.go:100 +0x48
>> golang.zx2c4.com/wireguard/conn.getSrcFromControl()
>> /home/lsc36/wireguard-go/conn/sticky_linux.go:18 +0x3c
>> golang.zx2c4.com/wireguard/conn.(*StdNetBind).makeReceiveIPv4.func1()
>> /home/lsc36/wireguard-go/conn/bind_std.go:232 +0x350
>> golang.zx2c4.com/wireguard/device.(*Device).RoutineReceiveIncoming()
>> /home/lsc36/wireguard-go/device/receive.go:107 +0x3ac
>> golang.zx2c4.com/wireguard/device.(*Device).BindUpdate.func3()
>> /home/lsc36/wireguard-go/device/device.go:530 +0x4c
>>
>> Goroutine 49 (running) created at:
>> golang.zx2c4.com/wireguard/device.(*Peer).Start()
>> /home/lsc36/wireguard-go/device/peer.go:198 +0x300
>> golang.zx2c4.com/wireguard/device.(*ipcSetPeer).handlePostConfig()
>> /home/lsc36/wireguard-go/device/uapi.go:268 +0x164
>> golang.zx2c4.com/wireguard/device.(*Device).IpcSetOperation()
>> /home/lsc36/wireguard-go/device/uapi.go:160 +0x35c
>> golang.zx2c4.com/wireguard/device.(*Device).IpcHandle()
>> /home/lsc36/wireguard-go/device/uapi.go:428 +0x248
>> main.main.func4.1()
>> /home/lsc36/wireguard-go/main.go:245 +0x4c
>>
>> Goroutine 47 (running) created at:
>> golang.zx2c4.com/wireguard/device.(*Device).BindUpdate()
>> /home/lsc36/wireguard-go/device/device.go:530 +0x4b8
>> golang.zx2c4.com/wireguard/device.(*Device).handleDeviceLine()
>> /home/lsc36/wireguard-go/device/uapi.go:223 +0x45c
>> golang.zx2c4.com/wireguard/device.(*Device).IpcSetOperation()
>> /home/lsc36/wireguard-go/device/uapi.go:183 +0x210
>> golang.zx2c4.com/wireguard/device.(*Device).IpcHandle()
>> /home/lsc36/wireguard-go/device/uapi.go:428 +0x248
>> main.main.func4.1()
>> /home/lsc36/wireguard-go/main.go:245 +0x4c
>> ==================
>>
>> The bug looks introduced by a recent commit 9e2f386 "conn, device, tun:
>> implement vectorized I/O on Linux". Without much knowledge to the
>> codebase, it seems to me that Endpoint is supposed to be guarded by the
>> RWMutex embedded in Peer, yet the change introduced a write without
>> locking the mutex (`ep.ClearSrc()` called from sticky_linux.go:18).
>>
>> In addition, I found it weird that Endpoint objects are reused via
>> `endpointPool`. The docstring suggests "Endpoints are immutable, so we
>> can re-use them" but that doesn't seem true.
>>
>> Added authors/reviewers of 9e2f386 to cc. Would you take a look?
>>
>> Regards,
>> SC
>>
