Effect of concurrency over HTTP client

[JuanPabloAJ]

Hi,

I have some doubts related to the HTTP client.

I have an HTTP service that in the handler calls synchronously to another HTTP service (serviceA). (I will call it case 1).

func withoutGoroutine(w http.ResponseWriter, r *http.Request) {

  httpGetA()

  _, err := w.Write([]byte(``))
  if err != nil {
    log.Printf("%v", err)
  }
}

The same service has another handler, it does the same that case 1 with an additional asynchronous HTTP call to a different service (serviceB) using a different HTTP client (I will call it case 2).

func withGoroutine(w http.ResponseWriter, r *http.Request) {

  httpGetA()

  _, err := w.Write([]byte(``))
  if err != nil {
    log.Printf("%v", err)
  }

  go httpGetB()
}

I run some load tests over these handlers with these results

Case 1

    ab -n 500000 -c 50 0.0.0.0:8080/withoutgoroutine
    ...
    Percentage of the requests served within a certain time (ms)
      50%      3
      66%      4
      75%      4
      80%      4
      90%      5
      95%      7
      98%     10
      99%     11
     100%     38 (longest request)

Case 2

    ab -n 500000 -c 50 0.0.0.0:8080/withgoroutine
    ...
    Percentage of the requests served within a certain time (ms)
      50%      5
      66%      5
      75%      6
      80%      6
      90%      8
      95%     10
      98%     14
      99%     16
     100%     42 (longest request)

Why case 2 has slower responses?
I would expect the same response time.

To be sure about the problem is not the creation of goroutines, I created a third case: Case 1 with the creation of goroutines but without an HTTP call.

func withSleepyGoroutine(w http.ResponseWriter, r *http.Request) {

  httpGetA()

  _, err := w.Write([]byte(``))
  if err != nil {
    log.Printf("%v", err)
  }

  go func() {
    time.Sleep(1 * time.Millisecond)
  }()
}

In cases 2 and 3, the goroutines are created after the HTTP response is sent.

I made the load tests in different machines to dismiss a network issue.

The full source code is available in this Github repo.

juanpabloaj/go_http_with_concurrency

Thanks a lot for your help.

Regards

[ncw (Nick Craig-Wood)]

Try profiling the two cases.

If you are running an http server, the easiest way to do this is by adding the net/pprof hook

You can then use go tool pprof to discover all sorts of exciting things about your server.

[JuanPabloAJ]

@ncw thanks for your answer.

I added the gops agent to get profile and trace, for example like these images of Synchronization blocking profile:

But, I am not sure about which conclusions may I get from these.

Or also it opened more questions, for example over the same time of load tests, why in case 2 the time used by the runtime is twice?

Thanks again for your help.