Gin: Route handlers are not asynchronous

[AliRezaBeitari]

Description

Route handlers are not asynchronous and and when I use goroutines, it crashes because of some wrong memory address access.

How to reproduce

To test this, I wrote a simple route for /ping which will wait for 5 seconds for the first request and next requests should be handled immediately; but it doesn't!

package main

import (
    "time"

    "github.com/gin-gonic/gin"
)

func main() {
    ok := false

    r := gin.Default()
    r.GET("/ping", func(c *gin.Context) {
        if !ok {
            ok = true
            time.Sleep(5 * time.Second) // 5 Seconds
        }

        c.JSON(200, gin.H{
            "message": "pong",
        })
    })
    r.Run() // listen and serve on 0.0.0.0:8080 (for windows "localhost:8080")
}

And also when I use goroutines, this will happend:

package main

import (
    "time"

    "github.com/gin-gonic/gin"
)

func main() {
    ok := false

    r := gin.Default()
    r.GET("/ping", func(c *gin.Context) {
        context := c.Copy()

        go func() {
            if !ok {
                ok = true
                time.Sleep(5 * time.Second) // 5 Seconds
            }

            context.JSON(200, gin.H{
                "message": "pong",
            })
        }()
    })
    r.Run() // listen and serve on 0.0.0.0:8080 (for windows "localhost:8080")
}

Errors:

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x1544052]

goroutine 21 [running]:
github.com/gin-gonic/gin.(*responseWriter).Header(0xc000312300, 0x154f5b5)
    <autogenerated>:1 +0x32
github.com/gin-gonic/gin/render.writeContentType(0x37a0ed8, 0xc000312300, 0x1a1ddd0, 0x1, 0x1)
    /Users/*******/go/src/github.com/gin-gonic/gin/render/render.go:36 +0x35
github.com/gin-gonic/gin/render.WriteJSON(0x37a0ed8, 0xc000312300, 0x15c60c0, 0xc000229770, 0x15f4e00, 0x37a0ed8)
    /Users/*******/go/src/github.com/gin-gonic/gin/render/json.go:68 +0x5d
github.com/gin-gonic/gin/render.JSON.Render(...)
    /Users/*******/go/src/github.com/gin-gonic/gin/render/json.go:55
github.com/gin-gonic/gin.(*Context).Render(0xc000312300, 0xc8, 0x1703bc0, 0xc0002d12e0)
    /Users/*******/go/src/github.com/gin-gonic/gin/context.go:865 +0x149
github.com/gin-gonic/gin.(*Context).JSON(...)
    /Users/*******/go/src/github.com/gin-gonic/gin/context.go:908
main.main.func1.1(0xc000302608, 0xc000312300)
    /Users/*******/Desktop/test_go_gin/main.go:22 +0xdc
created by main.main.func1
    /Users/*******/Desktop/test_go_gin/main.go:16 +0x65
exit status 2

I know the copy version of gin.Context is read-only and it seems context.JSON is the problem, but I don't know how to handle it?

Expectations

The first request should response after 5 seconds and next requests should be handled immediately; but they don't!

Actual result

It gives the errors above.

Environment

• go version: go1.15 darwin/amd64
• gin version (or commit ref): 3100b7cb05a8072b76d31686d8a7b4f9b12df4be
• operating system: Darwin MacBook-Pro.local 19.6.0 Darwin Kernel Version 19.6.0: Thu Jun 18 20:49:00 PDT 2020; root:xnu-6153.141.1~1/RELEASE_X86_64 x86_64

[Sata51]

As suggested in https://github.com/gin-gonic/gin/issues/1317#issuecomment-381393671 you can rewrite your code using a channel like this :

r.GET("/ping", func(c *gin.Context) {
    result := make(chan gin.H)
    go func(context *gin.Context) {
        if !ok {
            ok = true
            time.Sleep(5 * time.Second) // 5 Seconds
        }

        result <- gin.H{
            "message": "pong",
            "requestedPath": context.Request.URL.Path,
        }
    }(c.Copy())
    c.JSON(http.StatusOK, <-result)
})

[AliRezaBeitari]

As suggested in #1317 (comment) you can rewrite your code using a channel like this :

r.GET("/ping", func(c *gin.Context) {
    result := make(chan gin.H)
    go func(context *gin.Context) {
        if !ok {
            ok = true
            time.Sleep(5 * time.Second) // 5 Seconds
        }

        result <- gin.H{
            "message": "pong",
            "requestedPath": context.Request.URL.Path,
        }
    }(c.Copy())
    c.JSON(http.StatusOK, <-result)
})

Well, the main problem I had was not be able to handle heavy operations (in this case time.Sleep) concurrently.

The above code still blocks all request until the first one has finished!

[Sata51]

By adding logs like this

func main() {
    ok := false
    counter := 0

    r := gin.Default()
    r.GET("/ping", func(c *gin.Context) {
        counter++
        start := time.Now()
        logrus.WithFields(logrus.Fields{
            "request": counter,
        }).Info("Start")
        result := make(chan gin.H)
        go func(context *gin.Context, counterValue int) {
            if !ok {
                ok = true
                time.Sleep(5 * time.Second) // 5 Seconds
            }

            logrus.WithFields(logrus.Fields{
                "request": counterValue,
                "time":    time.Since(start),
            }).Info("done")
            result <- gin.H{
                "message":       "pong",
                "requestedPath": context.Request.URL.Path,
            }
        }(c.Copy(), counter)
        c.JSON(http.StatusOK, <-result)
    })
    r.Run() // listen and serve on 0.0.0.0:8080 (for windows "localhost:8080")
}

I have this result

INFO[0002] Start                                         request=1
INFO[0004] Start                                         request=2
INFO[0004] done                                          fields.time="83.772µs" request=2
[GIN] 2020/09/17 - 02:20:14 | 200 |     220.529µs |             ::1 | GET      "/ping"
INFO[0007] done                                          fields.time=5.001391386s request=1
[GIN] 2020/09/17 - 02:20:16 | 200 |  5.001501751s |             ::1 | GET      "/ping"

The heavy treatment is only proceeded into the first request. The second is answered directly

[AliRezaBeitari]

@Sata51 yes you were right. I was testing it in Chrome and it seems Chrome itself will wait for the first request to finish and makes the second request if the route is exactly the same. When I tested it on 2 different browsers, it worked!

Thank you so much.

[Sata51]

To add to this response, if you have multiple task to run you can use sync.WaitGroup like this :

r.GET("/ping", func(c *gin.Context) {
        var (
            wg    sync.WaitGroup
            data1 = "not done"
            data2 = "not done"
            data3 = "not done"
        )

        wg.Add(3)

        go func() {
            //Do some stuff
            time.Sleep(3 * time.Second)
            data1 = "done"
            wg.Done()
        }()
        go func() {
            //Do some stuff
            time.Sleep(2 * time.Second)
            data2 = "done"
            wg.Done()
        }()
        go func() {
            //Do some stuff
            time.Sleep(1 * time.Second)
            data3 = "done"
            wg.Done()
        }()

        wg.Wait()
        c.JSON(http.StatusOK, gin.H{
            "data1": data1,
            "data2": data2,
            "data3": data3,
        })
    })

And if it is a long init task you can do something like this :

func pingWithInit() gin.HandlerFunc{
   inited := false
   time.Sleep(10 * time.Second)
   inited = true
  return func(c *gin.Context){
    c.JSON(http.StatusOK, gin.H{
            "inited": inited,
        })
  }
}

and the handler registration is r.GET("/ping", pingWithInit()). This will lock the registration of the handler until it's done.

Also, to avoid using goroutine and boolean to wait only for the first call, you can use sync.Once

Hope it helps