18

We have a API server written in go that is based on gin-gonic. We've noticed something odd that has led us to believe that it is processing requests serially rather than the expected parallel operation. Consider this log file:

[GIN] 2016/04/05 - 17:24:37 | 200 |    5.738742ms | 64.... |   POST    /api/v2/d/
[GIN] 2016/04/05 - 17:24:40 | 200 |  3.262816256s | 64.... |   POST    /api/v2/d/
[GIN] 2016/04/05 - 17:24:42 | 200 |    3.563779ms | 64.... |   POST    /api/v2/d/
[GIN] 2016/04/05 - 17:24:43 | 200 |     105.429µs | 64.... |   POST    /api/v2/d/
[GIN] 2016/04/05 - 17:24:43 | 200 |     808.824µs | 64.... |   POST    /api/v2/d/

Watching the log in real time, the last 3 entries are not displayed until the second call finishes. These five calls are made to the API within 5 milliseconds of each other. We expect that the calls should be processed in parallel. This implies that all the calls should complete by 17:24:40, not 17:24:43. IE: That the server spawns a new thread/goroutine when the connection is made to process the request. If that is not the case does anyone have any suggestions for a package that does work that way.

This is our first project with gin-gonic and I'm wondering if there is some configuration parameter that needs to be set. Any ideas/suggestions are appreciated.

Zoyd
  • 3,449
  • 1
  • 18
  • 27
mlewis54
  • 2,372
  • 6
  • 36
  • 58

1 Answers1

8

To answer your root question; The stdlib http.Serve (doc) func farms the request out to a goroutine after the initial connection accept and some connection work.

Conceptual Rambling:

Go has primitives that are designed to provide strong concurrency capability, but concurrency is not the same as parallelism.

If you have more than one processor core, and if your GOMAXPROCS environment is set to be more than 1, then you may see some parallelism in addition to concurrency, assuming the appropriate goroutines.

As of Go 1.5 the default setting for GOMAXPROCS is the number of CPU cores. Prior versions of Go default the GOMAXPROCS setting to 1.

William Kennedy had a good write up about the differences a couple years ago: http://www.goinggo.net/2014/01/concurrency-goroutines-and-gomaxprocs.html

John Weldon
  • 39,849
  • 11
  • 94
  • 127
  • 8
    I fully understand the concepts of concurrency and parallelism in go and us go routines in a number of areas. My question has nothing to do with that. It was asking if gin-gonic handles requests in a synchronous fashion or it was async (boiling it all down). I am looking for help more with gin-gonic than with go. Now it's possible that the answer is that I have to use a go routine with gin-gonic but I'm not familiar enough with gin-gonic to know if that's the case. – mlewis54 Apr 05 '16 at 19:47
  • Got it. Well, we can review the gin-gonic code to see if it's using goroutines or not. – John Weldon Apr 05 '16 at 19:48
  • PS: I have 22 cores on the server and nothing else running so I am not running out of processors. Actually, the issue may be further up the line in net/http. Does it support async operations and process multiple requests at the same time? – mlewis54 Apr 05 '16 at 19:49
  • 3
    gin-gonic is just a web framework that uses a (fast) router, but the actual http requests are ultimately handled by the Go http.Server.Serve function – John Weldon Apr 05 '16 at 20:07
  • 1
    So based on your answer to the root question it seems that in fact multiple requests can be serviced at the same time (until we run out of cores). So I'm back to the puzzling issue: Why do the connections seem to be executed sequentially? I double checked to make sure that GOMAXPROCS isn't set anywhere. It isn't (by me anyway). I started with a 1.6 clean install so there's no legacy code. I'm stuck. – mlewis54 Apr 05 '16 at 20:22
  • Yeah; more complicated question than I initially realized.. It seems like parallelism related questions can be quite hard to track down. – John Weldon Apr 05 '16 at 20:24
  • The logger (by requirement) would process events serially. gin-gonic does handle requests concurrently (I don't know any Go mux that doesn't). How are you testing this? What are you testing with. – elithrar Apr 06 '16 at 04:49
  • 1
    @elithrar Thanks for the input. I have a go program which launches 5 requests as go routines (from another server). It was while watching the logs that I saw the odd timing and seemed to bear up when the results returned to the callers. There is one "fat" call that takes 1.5 - 4 seconds to run and some of the other calls seem to stack up behind them. I then tried it in Javascript with posts and callbacks. Same behavior. – mlewis54 Apr 06 '16 at 15:09
  • It sounds like a side-effect of your testing methodology, the logging, etc. Without seeing your program it's hard to know for sure, but Go's HTTP server is "concurrent by default", as is Gin/gorilla mux/Goji/etc. – elithrar Apr 06 '16 at 16:00
  • 1
    @elithrar Okay I think I will write a quick net/http server and see if the same behavior appears. Using gin-gonic, the caller and logger on the server agree that the calls are not happening concurrently. – mlewis54 Apr 06 '16 at 17:30
  • @mlewis54 Did you manage to dig down what was the issue? – sphoenix Feb 03 '21 at 07:01
  • 2
    @sphoenix I was able to eliminate the GIN-GONIC and NET/HTTP modules. They were indeed running concurrently. It appeared to be something in the front end code that was making the call to a PHP program that was issuing the API call. However, it's been a while so I may be forgetting some of the details. – mlewis54 Feb 06 '21 at 19:03