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

BUG Ikiscoket panics and crashes server with `close of closed channel` #26

Closed samchouse closed 2 years ago

samchouse commented 2 years ago

Describe the bug Ikisocket panics and crashes the server

To Reproduce Code:

var GatewayClients = make(map[primitive.ObjectID]string)

func SetupSocketListeners(ctx *context.Context) {
    ikisocket.On(ikisocket.EventMessage, func(ep *ikisocket.EventPayload) {
        message := &struct {
            Token string `json:"token"`
        }{}
        if err := json.Unmarshal(ep.Data, message); err != nil {
            util.GatewayResponse(&gError{})

            ep.Kws.Close()
            return
        }

        // ...

        GatewayClients[usr.Id] = ep.SocketUUID
        ep.Kws.SetAttribute("userId", usr.Id)

        ep.Kws.Emit(util.GatewayResponse(&Message{}), ikisocket.TextMessage)

        ep.Kws.Broadcast(util.GatewayResponse(&Message{}), true, ikisocket.TextMessage)
    })

    ikisocket.On(ikisocket.EventError, func(ep *ikisocket.EventPayload) {
        util.GatewayResponse(&gError{})

        ep.Kws.Close()
    })

    ikisocket.On(ikisocket.EventDisconnect, func(ep *ikisocket.EventPayload) {
        userId, ok := ep.Kws.GetAttribute("userId").(primitive.ObjectID)
        if !ok {
            return
        }

        delete(GatewayClients, userId)
        ep.Kws.SetAttribute("userId", nil)

        ep.Kws.Broadcast(util.GatewayResponse(&Message{}), true, ikisocket.TextMessage)
    })

    ikisocket.On(ikisocket.EventClose, func(ep *ikisocket.EventPayload) {
        userId, ok := ep.Kws.GetAttribute("userId").(primitive.ObjectID)
        if !ok {
            return
        }

        delete(GatewayClients, userId)
        ep.Kws.SetAttribute("userId", nil)

        ep.Kws.Broadcast(util.GatewayResponse(&Message{}), true, ikisocket.TextMessage)
    })

Logs:

panic: close of closed channel

goroutine 261 [running]:
github.com/antoniodipinto/ikisocket.(*Websocket).disconnected(0xc000696af0, {0xec6de0, 0xc000463510})
        /home/xenfo/.asdf/installs/golang/1.19.1/packages/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:563 +0x65
github.com/antoniodipinto/ikisocket.(*Websocket).send(0xc000696af0, {0xecbc38, 0xc000798cc0})
        /home/xenfo/.asdf/installs/golang/1.19.1/packages/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:491 +0x265
created by github.com/antoniodipinto/ikisocket.(*Websocket).run
        /home/xenfo/.asdf/installs/golang/1.19.1/packages/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20220806220653-2e4f04aebe6a/ikisocket.go:507 +0x185

Expected behavior Ikisocket doesn't crash the server

Additional context This has only happened once, I was reloading the page and socket wasn't connecting because of this. Not exactly sure how it happened.

antoniodipinto commented 2 years ago

My suggestion here is to handle the panic with recover and at app level, especially if this only happened once. This will be helpful to understand which behavior triggers this panic Try also with Go version 1.19 instead of 1.19.1; here the reason from Fiber documentation:

Due to Fiber's usage of unsafe, the library may not always be compatible with the latest Go version. Fiber 2.29.0 has been tested with Go versions 1.14 to 1.19.
       // define the recover point of the application
    defer func() {
        if r := recover(); r != nil {
            logger.Error(r)
        }
    }()
samchouse commented 2 years ago

Alright thank you!

samchouse commented 2 years ago

It happened again and the recover block didn't work. I don't think it's Go 1.19.1 that's causing the issue, never had any issues with panics on 1.19.1 before I started using Ikisocket. Do I need to restart something to make it work?

package main

import (
    "fmt"
    "log"

    "server/internal/context"
    "server/internal/db"
    "server/internal/routes"
    "server/internal/util"
    "server/internal/util/gateway"

    "github.com/gofiber/fiber/v2"
    "github.com/gofiber/fiber/v2/middleware/cors"
    "github.com/gofiber/fiber/v2/middleware/logger"
    recoverMiddleware "github.com/gofiber/fiber/v2/middleware/recover"
    "go.uber.org/zap"
)

func main() {
    ctx := context.Init()
    defer ctx.DbCtx.Cancel()
    defer func() {
        if r := recover(); r != nil {
            ctx.Logger.Error("Recovered from panic", zap.Error(fmt.Errorf("%v", r)))
        }
    }()

    util.SetContext(ctx)

    db.InitMongo(ctx)
    db.InitRedis(ctx)

    util.Sync(ctx)

    app := fiber.New()

    corsConfig := cors.ConfigDefault
    corsConfig.AllowOrigins = ctx.Config.Frontend
    corsConfig.AllowCredentials = true

    // Middleware
    app.Use(cors.New(corsConfig))
    app.Use(logger.New())
    app.Use(recoverMiddleware.New())

    // Routes
    initRoutes(app, ctx)

    // Gateway
    gateway.SetupSocketListeners(ctx)

    log.Fatal(app.Listen(url))
}

Also could it be caused by the use of both the close event and the disconnect event? Maybe one runs before the other sometimes and removes something the other needs to run?

antoniodipinto commented 2 years ago

Just noticed one thing

ikisocket.On(ikisocket.EventError, func(ep *ikisocket.EventPayload) {
        util.GatewayResponse(&gError{})

        ep.Kws.Close() <-- This will panic if the error is a disconnection. Because you will close an already closed connection
    })

The "OnError" event is meant to be a passive event type. It would help if you did nothing active with the socket, like closing or sending messages.

samchouse commented 2 years ago

Ah ok, is there another place to handle these errors or at this point is the socket always dead?

antoniodipinto commented 2 years ago

If a websocket connection is dropped (by the client, by the server, by anything else), you cannot do anything other than log the error if you want.

If you want, you can handle the disconnection event, but also, in that case, you cannot handle anything since the connection is already dropped. Check here if you want more details about this: https://github.com/antoniodipinto/ikisocket/blob/master/ikisocket.go#L46

jibon57 commented 1 year ago

@antoniodipinto I'm also facing problem. Is there any way from library side to check if connection was stopped before running close? Will IsAlive() work here? Do you want to add any safeguard to prevent this type error?

jibon57 commented 1 year ago

Looks like problem is happening here:

panic: close of closed channel

goroutine 3564 [running]:
github.com/antoniodipinto/ikisocket.(*Websocket).disconnected(0xc00027f0a0, {0x1234440, 0xc000220ad0})
    /go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20230224142534-cb796a15fd08/ikisocket.go:562 +0x65
github.com/antoniodipinto/ikisocket.(*Websocket).send(0xc00027f0a0, {0x123f7d0, 0xc0007e8690})
    /go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20230224142534-cb796a15fd08/ikisocket.go:489 +0x265
created by github.com/antoniodipinto/ikisocket.(*Websocket).run
    /go/pkg/mod/github.com/antoniodipinto/ikisocket@v0.0.0-20230224142534-cb796a15fd08/ikisocket.go:505 +0x185

https://github.com/antoniodipinto/ikisocket/blob/cb796a15fd088a5b43224c2b4cf8fd4891927406/ikisocket.go#L562C9-L562C17

I think before checking IsAlive() better to wait few milliseconds?

antoniodipinto commented 1 year ago

Hi @jibon57 the isAlive function is linked to the socket connection. The error you posted is not linked to socket connection, the issue seems to be related to Go Channel being used while closed.

If you want to catch error like that in Go (not related to the library itself) please take a look here https://go.dev/ref/spec#Handling_panics

On the other side, the isAlive func returns a variable that is changed in the ping/pong function, so when ikisocket receives an error (from disconnection for example), that variable is updated to isAlive = false. There is no need to wait a few seconds there. More details here https://github.com/antoniodipinto/ikisocket/blob/master/ikisocket.go#L557

jibon57 commented 1 year ago

@antoniodipinto thanks for reply. Yes, I can understand that panic is happening because of closing channel which has been closed already. I'm using gofiber recovery middleware but that's not working as expected. For my case this panic is happening quite often now.

antoniodipinto commented 1 year ago

I don't know the usage of your code. What I can suggest is to check whether you are actively closing the connection from ikisocket.

On the other side, panic management from fiber, only cover errors 500 and everything related to an endpoint. You still need to handle panic before fiber starts something like that

         // define the recover point of the application
    defer func() {
        if r := recover(); r != nil {
            logger.Error(r)
        }
    }()

That is different from recover in app.use

jibon57 commented 1 year ago

Thank you @antoniodipinto. I'm using recovery here: https://github.com/mynaparrot/plugNmeet-server/blob/fe00752fab5b919fbd155bd5d6c64b8f195ab360/pkg/handler/router.go#L46

only calling closing connection here: https://github.com/mynaparrot/plugNmeet-server/blob/fe00752fab5b919fbd155bd5d6c64b8f195ab360/pkg/controllers/websocket_service.go#L94