antoniodipinto / ikisocket

🧬 WebSocket wrapper with event management for Fiber https://github.com/gofiber/fiber. Based on Fiber WebSocket and inspired by Socket.io
MIT License
123 stars 21 forks source link

Request for investigation | Server shuts down with exit code 2 #23

Closed talksik closed 2 years ago

talksik commented 2 years ago

Sorry for bugging you here again :(

Essentially, I find that if I run the server locally, and I continuously connect and disconnect and use it for a decent amount of time with two clients disconnecting and connecting over and over again with multiple connections to the server, there is a problem where it shuts down with this message let's say after like 10 minutes of all of it working.

exit status 2

I am not sure that this happens in my digital ocean hosted version but locally, and my bet is that it has to do with go routines not being cleaned up on socket disconnections and reaching 1000 go routines. Here is the stack trace.

This is long, but just want to make sure I am verbose enough as I don't understand the stack trace in the terminal:

`bufio.(Reader).fill(0x140004c8900) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:106 +0x100 bufio.(Reader).Peek(0x140004c8900, 0x2) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:144 +0x64 github.com/fasthttp/websocket.(Conn).read(0x140006a0c60, 0x1027a8744?) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:371 +0x2c github.com/fasthttp/websocket.(Conn).advanceFrame(0x140006a0c60) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:809 +0x68 github.com/fasthttp/websocket.(Conn).NextReader(0x140006a0c60) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:1009 +0xb0 github.com/fasthttp/websocket.(Conn).ReadMessage(0x1400028bf78?) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:1093 +0x20 github.com/antoniodipinto/ikisocket.(Websocket).read(0x140006ae3f0, {0x102ae9330, 0x1400013c740}) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:526 +0x130 created by github.com/antoniodipinto/ikisocket.(Websocket).run /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:506 +0x134

goroutine 1939 [select]: github.com/antoniodipinto/ikisocket.(Websocket).pong(0x140006ae460, {0x102ae9330, 0x1400013c800}) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:451 +0xe0 created by github.com/antoniodipinto/ikisocket.(Websocket).run /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:505 +0xc4

goroutine 1292 [select]: github.com/antoniodipinto/ikisocket.(Websocket).send(0x140005b81c0, {0x102ae9330, 0x140006b41c0}) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:472 +0x90 created by github.com/antoniodipinto/ikisocket.(Websocket).run /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:507 +0x1a4

goroutine 1294 [select]: github.com/antoniodipinto/ikisocket.(Websocket).pong(0x140005b8230, {0x102ae9330, 0x140006b42c0}) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:451 +0xe0 created by github.com/antoniodipinto/ikisocket.(Websocket).run /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:505 +0xc4

goroutine 291 [IO wait]: internal/poll.runtime_pollWait(0x129d407a8, 0x72) /opt/homebrew/Cellar/go/1.18.5/libexec/src/runtime/netpoll.go:302 +0xa4 internal/poll.(pollDesc).wait(0x1400027a280?, 0x14000399000?, 0x0) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_poll_runtime.go:83 +0x2c internal/poll.(pollDesc).waitRead(...) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_poll_runtime.go:88 internal/poll.(FD).Read(0x1400027a280, {0x14000399000, 0x1000, 0x1000}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_unix.go:167 +0x1e4 net.(netFD).Read(0x1400027a280, {0x14000399000?, 0x140000c7bf8?, 0x1029a8d20?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/net/fd_posix.go:55 +0x2c net.(conn).Read(0x14000110038, {0x14000399000?, 0x140000c7c18?, 0x1029a1024?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/net/net.go:183 +0x38 bufio.(Reader).fill(0x140000b1020) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:106 +0x100 bufio.(Reader).Peek(0x140000b1020, 0x1) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:144 +0x64 github.com/valyala/fasthttp.(Server).serveConn(0x140000c06c0, {0x102ae9cf0?, 0x14000110038}) /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2125 +0x4a8 github.com/valyala/fasthttp.(workerPool).workerFunc(0x140000bac80, 0x1400051c160) /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/workerpool.go:224 +0x70 github.com/valyala/fasthttp.(workerPool).getCh.func1() /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/workerpool.go:196 +0x3c created by github.com/valyala/fasthttp.(*workerPool).getCh /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/workerpool.go:195 +0x22c

goroutine 1928 [IO wait]: internal/poll.runtime_pollWait(0x129d403e8, 0x72) /opt/homebrew/Cellar/go/1.18.5/libexec/src/runtime/netpoll.go:302 +0xa4 internal/poll.(pollDesc).wait(0x14000506280?, 0x140003c7000?, 0x0) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_poll_runtime.go:83 +0x2c internal/poll.(pollDesc).waitRead(...) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_poll_runtime.go:88 internal/poll.(FD).Read(0x14000506280, {0x140003c7000, 0x1000, 0x1000}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_unix.go:167 +0x1e4 net.(netFD).Read(0x14000506280, {0x140003c7000?, 0x102f25d28?, 0x5d?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/net/fd_posix.go:55 +0x2c net.(conn).Read(0x14000010050, {0x140003c7000?, 0x129d404d8?, 0x0?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/net/net.go:183 +0x38 bufio.(Reader).Read(0x1400031d5c0, {0x1400069bc00, 0x400, 0x14000602380?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:236 +0x1e4 github.com/valyala/fasthttp.(hijackConn).Read(0x0?, {0x1400069bc00?, 0x1400040b4f8?, 0x1029b1c88?}) /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2493 +0x30 bufio.(Reader).fill(0x140004c8540) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:106 +0x100 bufio.(Reader).Peek(0x140004c8540, 0x2) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:144 +0x64 github.com/fasthttp/websocket.(Conn).read(0x140006a09a0, 0x1027a8744?) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:371 +0x2c github.com/fasthttp/websocket.(Conn).advanceFrame(0x140006a09a0) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:809 +0x68 github.com/fasthttp/websocket.(Conn).NextReader(0x140006a09a0) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:1009 +0xb0 github.com/fasthttp/websocket.(Conn).ReadMessage(0x1400040b778?) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:1093 +0x20 github.com/antoniodipinto/ikisocket.(Websocket).read(0x140006ae310, {0x102ae9330, 0x1400013c500}) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:526 +0x130 created by github.com/antoniodipinto/ikisocket.(*Websocket).run /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:506 +0x134

goroutine 1345 [IO wait]: internal/poll.runtime_pollWait(0x129c8b8c8, 0x72) /opt/homebrew/Cellar/go/1.18.5/libexec/src/runtime/netpoll.go:302 +0xa4 internal/poll.(pollDesc).wait(0x14000162580?, 0x14000460000?, 0x0) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_poll_runtime.go:83 +0x2c internal/poll.(pollDesc).waitRead(...) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_poll_runtime.go:88 internal/poll.(FD).Read(0x14000162580, {0x14000460000, 0x1000, 0x1000}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_unix.go:167 +0x1e4 net.(netFD).Read(0x14000162580, {0x14000460000?, 0x140000c3bf8?, 0x1029a8d20?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/net/fd_posix.go:55 +0x2c net.(conn).Read(0x14000426080, {0x14000460000?, 0x140000c3c18?, 0x1029a1024?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/net/net.go:183 +0x38 bufio.(Reader).fill(0x1400030f980) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:106 +0x100 bufio.(Reader).Peek(0x1400030f980, 0x1) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:144 +0x64 github.com/valyala/fasthttp.(Server).serveConn(0x140000c06c0, {0x102ae9cf0?, 0x14000426080}) /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2125 +0x4a8 github.com/valyala/fasthttp.(workerPool).workerFunc(0x140000bac80, 0x1400044e100) /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/workerpool.go:224 +0x70 github.com/valyala/fasthttp.(workerPool).getCh.func1() /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/workerpool.go:196 +0x3c created by github.com/valyala/fasthttp.(*workerPool).getCh /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/workerpool.go:195 +0x22c

goroutine 1963 [chan receive]: github.com/antoniodipinto/ikisocket.(Websocket).run(0x140001202a0) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:509 +0x1b4 github.com/antoniodipinto/ikisocket.New.func1(0x140002f2750) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:272 +0x2d0 github.com/gofiber/websocket/v2.New.func2.4(0x102ae9be8?) /Users/arjun.patel/go/pkg/mod/github.com/gofiber/websocket/v2@v2.0.24/websocket.go:109 +0x80 github.com/fasthttp/websocket.(FastHTTPUpgrader).Upgrade.func1({0x102ae9be8, 0x140002f2840}) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/server_fasthttp.go:201 +0x164 github.com/valyala/fasthttp.hijackConnHandler(0xb0?, {0x102ae7008?, 0x1400012b5c0}, {0x102ae9cf0, 0x140000100c0}, 0x140000c06c0, 0x14000618400) /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2448 +0x60 created by github.com/valyala/fasthttp.(*Server).serveConn /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2403 +0x15e8

goroutine 1922 [chan receive]: github.com/antoniodipinto/ikisocket.(Websocket).run(0x140006ae2a0) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:509 +0x1b4 github.com/antoniodipinto/ikisocket.New.func1(0x140002ddf50) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:272 +0x2d0 github.com/gofiber/websocket/v2.New.func2.4(0x102ae9be8?) /Users/arjun.patel/go/pkg/mod/github.com/gofiber/websocket/v2@v2.0.24/websocket.go:109 +0x80 github.com/fasthttp/websocket.(FastHTTPUpgrader).Upgrade.func1({0x102ae9be8, 0x140003a75c0}) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/server_fasthttp.go:201 +0x164 github.com/valyala/fasthttp.hijackConnHandler(0x0?, {0x102ae7008?, 0x140006a4060}, {0x102ae9cf0, 0x14000010020}, 0x140000c06c0, 0x1400013c2c0) /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2448 +0x60 created by github.com/valyala/fasthttp.(*Server).serveConn /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2403 +0x15e8

goroutine 1926 [chan receive]: github.com/antoniodipinto/ikisocket.(Websocket).run(0x140006ae310) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:509 +0x1b4 github.com/antoniodipinto/ikisocket.New.func1(0x14000302f30) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:272 +0x2d0 github.com/gofiber/websocket/v2.New.func2.4(0x102ae9be8?) /Users/arjun.patel/go/pkg/mod/github.com/gofiber/websocket/v2@v2.0.24/websocket.go:109 +0x80 github.com/fasthttp/websocket.(FastHTTPUpgrader).Upgrade.func1({0x102ae9be8, 0x14000303020}) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/server_fasthttp.go:201 +0x164 github.com/valyala/fasthttp.hijackConnHandler(0x80?, {0x102ae7008?, 0x1400031d5c0}, {0x102ae9cf0, 0x14000010050}, 0x140000c06c0, 0x1400013c400) /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2448 +0x60 created by github.com/valyala/fasthttp.(*Server).serveConn /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2403 +0x15e8

goroutine 1792 [IO wait]: internal/poll.runtime_pollWait(0x129d405c8, 0x72) /opt/homebrew/Cellar/go/1.18.5/libexec/src/runtime/netpoll.go:302 +0xa4 internal/poll.(pollDesc).wait(0x14000506000?, 0x140000bd000?, 0x0) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_poll_runtime.go:83 +0x2c internal/poll.(pollDesc).waitRead(...) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_poll_runtime.go:88 internal/poll.(FD).Read(0x14000506000, {0x140000bd000, 0x1000, 0x1000}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/internal/poll/fd_unix.go:167 +0x1e4 net.(netFD).Read(0x14000506000, {0x140000bd000?, 0x102f25878?, 0x10277a15d?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/net/fd_posix.go:55 +0x2c net.(conn).Read(0x14000010008, {0x140000bd000?, 0x102f25878?, 0x1400040dc5d?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/net/net.go:183 +0x38 bufio.(Reader).Read(0x14000285260, {0x1400069b400, 0x400, 0x30000007d?}) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:236 +0x1e4 github.com/valyala/fasthttp.(hijackConn).Read(0x1400040dcc8?, {0x1400069b400?, 0x1308?, 0x102ab8340?}) /Users/arjun.patel/go/pkg/mod/github.com/valyala/fasthttp@v1.38.0/server.go:2493 +0x30 bufio.(Reader).fill(0x140004c8180) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:106 +0x100 bufio.(Reader).Peek(0x140004c8180, 0x2) /opt/homebrew/Cellar/go/1.18.5/libexec/src/bufio/bufio.go:144 +0x64 github.com/fasthttp/websocket.(Conn).read(0x140006a06e0, 0x1027a8744?) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:371 +0x2c github.com/fasthttp/websocket.(Conn).advanceFrame(0x140006a06e0) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:809 +0x68 github.com/fasthttp/websocket.(Conn).NextReader(0x140006a06e0) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:1009 +0xb0 github.com/fasthttp/websocket.(Conn).ReadMessage(0x1400040df78?) /Users/arjun.patel/go/pkg/mod/github.com/fasthttp/websocket@v1.5.0/conn.go:1093 +0x20 github.com/antoniodipinto/ikisocket.(Websocket).read(0x140006ae230, {0x102ae9330, 0x1400013c240}) /Users/arjun.patel/go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:526 +0x130`

Environments: this happens running with go run main.go and in a docker container.

talksik commented 2 years ago

There is more to the stack trace, but I assume this will be enough?

talksik commented 2 years ago

Here is the same app deployed on digital ocean, hasn't restarted once in the past few days from what I can tell:

image

Although maybe this dashboard view of digital ocean app is not taking into account the docker restarts that happen within

antoniodipinto commented 2 years ago

Can you log internally into your app if the service restarts and also in on your server? As you mentioned, I don't think Digital Oceans logs docker container restarts

talksik commented 2 years ago

Thanks @antoniodipinto ! I actually found the problem: essentially, I was not putting a mutex on a shared map in memory and so two connections were trying to write something in memory simultaneously.