v055n: Crash when stopping WireGuard in Simple mode #1632
Comments
|
Can you share the crash logs, please? Instructions: #1533 (comment) |
ignoramous
changed the title
|
Thanks. Apart from a string of ARM Memory Tagging related crashes (#962), the crash you're seeing when stopping WireGuard specifically is due to an issue fixed in ...
08-02 19:31:14.119 9581 7856 I GoLog : wgproxy.go:653: D proxy: wg: wg28 tun: closing...
08-02 19:31:14.119 9581 7856 I GoLog : base.go:110: I proxy: base: stopped
08-02 19:31:14.119 9581 7856 I GoLog : tunnel.go:168: I tun: <<< disconnect >>>; err0(<nil>); err1(<nil>); svc(0)
08-02 19:31:14.119 9581 7856 D VpnLifecycle: onProxiesStopped; clear the handshake times
08-02 19:31:14.120 9581 7856 I GoLog : fdbased.go:443: VV ns: tun(6): WritePackets (to tun): written(1)/total(1)
...
08-02 19:31:14.121 9581 7834 E GoLog : wgproxy.go:577: W wg: wg28 tun: read closed
08-02 19:31:14.122 9581 9656 I GoLog : wgnet.go:159: I wg: dial: tcp: #0 [2001:bc8:710:750::]:443
...
08-02 19:31:14.125 9581 0 E Go : panic: send on closed channel
08-02 19:31:14.125 9581 0 E Go :
08-02 19:31:14.125 9581 0 E Go : goroutine 1489 [running, locked to thread]:
08-02 19:31:14.126 9581 0 E Go : github.com/celzero/firestack/intra/ipn.(*wgtun).WriteNotify(0x400694a870)
08-02 19:31:14.126 9581 0 E Go : >/home/jitpack/build/intra/ipn/wgproxy.go:634 +0xe8
08-02 19:31:14.126 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/link/channel.(*queue).Write(0x4006b474c0, 0x40069ac280)
08-02 19:31:14.126 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/link/channel/channel.go:100 +0x164
08-02 19:31:14.126 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/link/channel.(*Endpoint).WritePackets(0x40002a01e0, {{0x40001224f0, 0x1, 0x1}})
08-02 19:31:14.126 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/link/channel/channel.go:260 +0x6c
08-02 19:31:14.126 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/stack.(*delegatingQueueingDiscipline).WritePacket(0x40069d5a30, 0x40069ac280)
08-02 19:31:14.126 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/stack/nic.go:156 +0xa4
08-02 19:31:14.126 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/stack.(*nic).writeRawPacket(0x4000ce8008, 0x40069ac280)
08-02 19:31:14.126 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/stack/nic.go:411 +0x5c
08-02 19:31:14.126 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/stack.(*nic).writePacket(0x4000ce8008, 0x40069ac280)
08-02 19:31:14.126 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/stack/nic.go:393 +0x40
08-02 19:31:14.126 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/stack.(*nic).WritePacket(0x4000ce8008, 0x4000484d80, 0x40069ac280)
08-02 19:31:14.126 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/stack/nic.go:354 +0x124
08-02 19:31:14.126 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/network/ipv4.(*endpoint).writePacketPostRouting(0x4006ad4908, 0x4000484d80, 0x40069ac280, 0x0?)
...
08-02 19:31:14.126 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/network/ipv4/ipv4.go:605 +0x418
08-02 19:31:14.126 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/network/ipv4.(*endpoint).writePacket(0x4006ad4908, 0x4000484d80, 0x40069ac280)
08-02 19:31:14.126 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/network/ipv4/ipv4.go:555 +0x17c
08-02 19:31:14.126 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/network/ipv4.(*endpoint).WritePacket(0x4006ad4908, 0x4000484d80, {0x800?, 0x0?, 0x0?, 0x0?}, 0x40069ac280)
08-02 19:31:14.126 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/network/ipv4/ipv4.go:523 +0x9c
08-02 19:31:14.127 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/stack.(*Route).WritePacket(0x4000484d80, {0x3c21000a?, 0x0?, 0x0?, 0x0?}, 0x40069ac280)
08-02 19:31:14.127 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/stack/route.go:500 +0x80
08-02 19:31:14.127 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.sendTCP(0x4000484d80, {{0xf675, {{0xa, 0x0, 0x21, 0x3c, 0x0, 0x0, 0x0, 0x0, ...}, ...}, ...}, ...}, ...)
08-02 19:31:14.127 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/connect.go:917 +0x1c0
08-02 19:31:14.127 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*Endpoint).sendTCP(0x40006f4e08, 0x75e2c004c4?, {{0xf675, {{0xa, 0x0, 0x21, 0x3c, 0x0, 0x0, 0x0, ...}, ...}, ...}, ...}, ...)
08-02 19:31:14.127 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/connect.go:815 +0x90
08-02 19:31:14.127 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*Endpoint).sendRaw(0x40006f4e08, 0x40069ac280, 0x11, 0x2cd7ed4e, 0xe54079ef, 0x1000)
08-02 19:31:14.127 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/connect.go:990 +0x258
08-02 19:31:14.127 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*sender).sendSegmentFromPacketBuffer(0x4000b0fc08, 0x40068dc3c0, 0x11, 0x2cd7ed4e)
08-02 19:31:14.127 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/snd.go:1752 +0xdc
08-02 19:31:14.127 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*sender).sendSegment(0x4000b0fc08, 0x40067d6300)
08-02 19:31:14.127 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/snd.go:1713 +0x1a0
08-02 19:31:14.127 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*sender).maybeSendSegment(0x4000b0fc08, 0x40067d6300, 0x40006175e8?, 0xe2ec62b4?)
08-02 19:31:14.127 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/snd.go:920 +0x1f4
08-02 19:31:14.127 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*sender).sendData(0x4000b0fc08)
08-02 19:31:14.128 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/snd.go:1037 +0x1d0
08-02 19:31:14.128 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*Endpoint).sendData(0x40006f4e08?, 0x3c21000a?)
08-02 19:31:14.128 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/connect.go:1015 +0x40
08-02 19:31:14.128 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*Endpoint).shutdownLocked(0x40006f4e08, 0x400012e000?)
08-02 19:31:14.128 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/endpoint.go:2580 +0x490
08-02 19:31:14.128 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*Endpoint).closeLocked(0x40006f4e08)
08-02 19:31:14.128 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/endpoint.go:1100 +0xa0
08-02 19:31:14.128 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*Endpoint).Close(0x40006f4e08)
08-02 19:31:14.128 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/transport/tcp/endpoint.go:1070 +0x30
08-02 19:31:14.128 9581 0 E Go : gvisor.dev/gvisor/pkg/tcpip/adapters/gonet.(*TCPConn).Close(...)
08-02 19:31:14.128 9581 0 E Go : >/tmp/gomobile-work-574208690/pkg/mod/gvisor.dev/gvisor@v0.0.0-20240524213522-f2b01a6e47ff/pkg/tcpip/adapters/gonet/gonet.go:418
...
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/intra/core.CloseConn({0x4000617840?, 0x400669b020?, 0x4000891850?})
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/intra/core/closer.go:102 +0xe0
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/intra/core.(*cm).Clear(0x400669b080)
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/intra/core/connmap.go:226 +0x2b0
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/intra.closeconns({0x75e323c018?, 0x400669b080?}, {0x0?, 0x0, 0x0?})
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/intra/common.go:215 +0x3c
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/intra.(*tcpHandler).CloseConns(0x0?, {0x0?, 0x4000132080?, 0x4000812000?})
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/intra/tcp.go:145 +0x3c
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/intra/netstack.(*gconnhandler).CloseConns(0x400669b1a0, {0x0?, 0x4000122020?})
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/intra/netstack/hdl.go:69 +0xa8
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/intra/netstack.(*gconnhandler).Close(0x400669b1a0)
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/intra/netstack/hdl.go:86 +0x30
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/tunnel.(*gtunnel).Disconnect.func1()
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/tunnel/tunnel.go:214 +0x48
08-02 19:31:14.128 9581 0 E Go : sync.(*Once).doSlow(0x4000817740?, 0x2?)
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/golang/go/src/sync/once.go:74 +0x100
08-02 19:31:14.128 9581 0 E Go : sync.(*Once).Do(...)
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/golang/go/src/sync/once.go:65
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/tunnel.(*gtunnel).Disconnect(0x40001680e0?)
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/tunnel/tunnel.go:209 +0x44
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/intra.(*rtunnel).Disconnect.func1()
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/intra/tunnel.go:170 +0x200
08-02 19:31:14.128 9581 0 E Go : sync.(*Once).doSlow(0x75fffffcf3?, 0x4000124a50?)
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/golang/go/src/sync/once.go:74 +0x100
08-02 19:31:14.128 9581 0 E Go : sync.(*Once).Do(...)
08-02 19:31:14.128 12880 5604 V NativeCrypto: SSL shutdown failed: ssl=0xb40000778fcb06d8: I/O error during system call, Broken pipe
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/golang/go/src/sync/once.go:65
08-02 19:31:14.128 9581 0 E Go : github.com/celzero/firestack/intra.(*rtunnel).Disconnect(0x75e365ca70?)
08-02 19:31:14.128 9581 0 E Go : >/home/jitpack/build/intra/tunnel.go:160 +0xd4
08-02 19:31:14.128 9581 0 E Go : main.proxyintra_Tunnel_Disconnect(0xfffffc01?)
08-02 19:31:14.128 9581 0 E Go : >/tmp/gomobile-work-574208690/src/gobind/go_intramain.go:946 +0x84 |
|
Awesome thank you! I will delete my logs if you don't mind |
Sure. Hopefully, with improvements (and UI changes) we've made to our crash & logs collector (#1455) in |
|
Btw, I also saw a couple "connection was refused" TCP errors1 (which is an unrecoverable error, and one we have been unable to root-cause). Are you running Rethink in Block connections without VPN mode? And if so, do you notice that Rethink completely fails connecting over TCP after a point (ie, when you hit these "connection was refused" errors) and that you've to Footnotes
|
|
Is this a timestamp from today, 2nd of August, right? This mode was not turned on for at least a week or so. |
The next time you see this happen, take a note of what the final status of the connection from those apps ends up being (the final status may only be visible in the footer of the bottomsheet that comes up when you tap on the entries in the Network Log UI after the connection has timed-out or ended, which is usually anywhere between 15seconds to 2mins, and varies from app to app). If the final status shows "connection was refused" (this happens only for TCP connections), the network engine has entered this unrecoverable scenario and we don't know why it happens. Except the fact that it has happens fairly consistently once every few days when Block connections without VPN is turned ON (and the only way to recover was to either pause then unpause the app OR stop then start the app). This happens regardless of WireGuard or any other proxy is in use or not. |
|
AFAIU, nothing here shows the final status of the connection: 
|
Not all connections will have final status (but most should). This is due to edge cases where the network engine shuts down without sending one, like on crash or when abruptly stopped or where the database drops writes/updates due to backpressure / load etc. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Steps to reproduce:
The app crashes while the VPN is still activated and it doesn't work.
The text was updated successfully, but these errors were encountered: