I am trying to time how long it takes to make concurrent requests. My timing results are about four times slower than what ab2 reports.
I've tried timing requests in two different ways, both of which lead to similar results (which are far off ab2's results). To give an example, ab2 will report the longest request to last 2 milliseconds on a local server, whereas this code will report up to 4.5 milliseconds. By the way, the whole codebase is available here.
How do I properly time a request in go?
Method 1: timing includes more than just the request
From this commit.
// Let's spawn all the requests, with their respective concurrency.
wg.Add(r.Repeat)
r.doneWg.Add(r.Repeat)
for rno := 1; rno <= r.Repeat; rno++ {
go func(no int, greq goreq.Request) {
r.ongoingReqs <- struct{}{} // Adding sentinel value to limit concurrency.
startTime := time.Now()
greq.Uri = r.URL.Generate()
gresp, err := greq.Do()
if err != nil {
log.Critical("could not send request to #%d %s: %s", no, r.URL, err)
} else if no < r.Repeat {
// We're always using the last response for the next batch of requests.
gresp.Body.Close()
}
<-r.ongoingReqs // We're done, let's make room for the next request.
resp := Response{Response: gresp, duration: time.Now().Sub(startTime)}
// Let's add that request to the list of completed requests.
r.doneChan <- &resp
runtime.Gosched()
}(rno, greq)
}
Method 2: using an internal function with a defer statement
From this commit.
// Let's spawn all the requests, with their respective concurrency.
wg.Add(r.Repeat)
r.doneWg.Add(r.Repeat)
for rno := 1; rno <= r.Repeat; rno++ {
go func(no int, greq goreq.Request) {
r.ongoingReqs <- struct{}{} // Adding sentinel value to limit concurrency.
greq.Uri = r.URL.Generate()
var duration time.Duration
gresp, err := func(dur *time.Duration) (gresp *goreq.Response, err error) {
defer func(startTime time.Time) { *dur = time.Now().Sub(startTime) }(time.Now())
return greq.Do()
}(&duration)
if err != nil {
log.Critical("could not send request to #%d %s: %s", no, r.URL, err)
} else if no < r.Repeat {
// We're always using the last response for the next batch of requests.
gresp.Body.Close()
}
<-r.ongoingReqs // We're done, let's make room for the next request.
resp := Response{Response: gresp, duration: duration}
// Let's add that request to the list of completed requests.
r.doneChan <- &resp
runtime.Gosched()
}(rno, greq)
}
I had a look at this question, which did not help.