.SetTimeout() option breaks functionality, results in showing the duration of HTTP request wrong.

[roku-on-it]

When creating a resty client using .SetTimeout(100 * time.Millisecond) and sending a GET request. the response returns context deadline exceeded error as if it took more than 100 ms but it didn't, the response takes around 60 milliseconds.

However, if I don't specify any timeout merely by not using .SetTimeout() function it works as expected and resp.Time() shows that response took 60 ms.

---

var client = resty.New().SetBaseURL("https://checkip.amazonaws.com").SetTimeout(100 * time.Millisecond)
var counter int

func main() {

    app := fiber.New()

    app.Get("/", func(c *fiber.Ctx) error {
        counter++
        resp, err := client.R().Get("/")
        if err != nil {
            color.Red("Error Response #%d took: %v", counter, resp.Time())
        } else {
            color.Blue("Success Response #%d took: %v", counter, resp.Time())
        }

        return nil
    })

    app.Listen(":3000")
}

• Scenario: Sending 4 requests one after another.

• Expected behavior: The first request to take around 300 ms and log error, and the remaining 3 requests to take around 60 ms and log success.

• Actual Behaviour: All 4 requests result in an error of context deadline exceeded even the ones that didn't took more than 100 ms.

  ---

var client = resty.New().SetBaseURL("https://checkip.amazonaws.com").SetTimeout(100 * time.Millisecond)

So sending requests with the client above, using the SetTimeout option, results in resp.Time() to return 100 ms no matter the actual response time and end up returning an error:

But sending requests without using SetTimeout option results in resp.Time() to show that it took around 60 ms

var client = resty.New().SetBaseURL("https://checkip.amazonaws.com")

Disclaimer: I am not sure if this behaviour is caused by net/http package. I've tried to read the source code of both net/http and resty but couldn't identify if there is a problem.

[roku-on-it]

I have also tried setting the timeout to 250 ms thinking that 100 ms may be a little short time span. Now it shows as if every request took 250 ms.

But setting a higher value works as expected. Results when I set the timeout to be 350 ms. But I still think there is something wrong, why would it take 250 ms every time I send a request when I set the timeout to be 250 ms, but it takes 60 ms if I don't use the SetTimeout setting or set a rather high value?

[jeevatkm]

@roku-on-it Interesting; thanks for reaching out. Do you mind directly trying out your test programs with the net/http client? I'm curious because resty SetTimeout uses this https://pkg.go.dev/net/http#Client.Timeout

Based on your feedback, I will manage timeout(s) at the Resty end on v3.0.0 onwards instead of the default one.

[roku-on-it]

const baseUrl = "https://httpbin.org/get"

var counter int
var httpClient = &http.Client{
    Timeout: 200 * time.Millisecond,
}

func main() {
    app := fiber.New()

    app.Get("/", func(c *fiber.Ctx) error {
        counter++
        now := time.Now()

        _, err := httpClient.Get(baseUrl)

        if err != nil {
            color.Red("Error Response #%d took: %v", counter, time.Since(now))
        } else {
            color.Blue("Success Response #%d took: %v", counter, time.Since(now))
        }

        return nil
    })

    app.Listen(":3000")
}

I had some problems with AWS so I changed url to httpbin to reproduce. I guess this is Timeout problem is caused by net/http itself. With the timeout option set to 200, ms it always exceeds. I believe it's normal for first request to take more time because of DNS resolving, the requests after that takes shorter.

And this is the result when I set the timeout to 500, it worked like in the first example where I set the timeout to be a little longer.

[roku-on-it]

However, I must address that I am not sure if this is a bug. I don't know the internals of net/http. Maybe it works the way it's supposed to but breaks because of the Timeout option that I pass in. Because 100 or 200 ms is not a realistic timeout for most web applications. But still, it's weird why it would behave like this.

[jeevatkm]

@roku-on-it Thanks for confirming with net/http. Let me think about whether it's better to stop using http.Client.Timeout in favor of context.