Bishnu
Bishnu

Reputation: 423

Context timeout not working as expected in golang

Helo All,

New to golang and was debugging timeout issues in a production environment. Before making a call to the server we add a timeout of 50ms to context and fire a server call. If the response is not received within 50 ms we expect the application to move on and not wait for the response.

But while debugging, I capture the duration between we fire a server call and the response received (or error out), to my surprise the value at the time is much higher than 50 ms.

Client syntax -

    ctx, cancel := context.WithTimeout(ctx, e.opts.Timeout)
    defer cancel()
    fireServerCall(ctx)
..
..

def fireServerCall(ctx context:Context){
  startTime:=time.Now()
  //call to the server
  res, err:=callToServer(ctx)
  if err!=nil{
   //capture failure latency
   return ....
  }
   //capture success latency
   return ....
}

Has anyone ever faced any similar issue? Is this expected behaviour? How did you handle such cases?

Am I doing something incorrectly? Suggestions are welcome :)

Edit:

I am passing context in my original code but forgot to mention it here, just added it. That mean, I am passing the same context on which my client is waiting for server to respond within 50 ms.

Upvotes: 1

Views: 8147

Answers (1)

Nikscorp
Nikscorp

Reputation: 440

  1. You should pass created context to fireServerCall and callToServer functions
  2. callToServer should consider passed context and monitor ctx.Done() channel to stop its execution accordingly

Answering to comment by @Bishnu:

Don't think this is needed. Did a test and even without passing ctx to callToServer() it works. The behaviour is not as expected under high load. Can you kindly share some document/test what you have pointed here?

Context timeout just can't work without context passing and checking its Done() channel. Context is not some kind of magic — simplifying it is just a struct with done channel which is closed by calling cancel function or when timeout occurs. Monitoring this channel — is responsibility of the innermost function that accepts it.

Example:

package main

import (
    "context"
    "fmt"
    "time"
)

func callToServer(ctx context.Context) {
    now := time.Now()
    select {
    case <-ctx.Done(): // context cancelled via cancel or deadline
    case <-time.After(1 * time.Second): // emulate external call
    }
    fmt.Printf("callToServer: %v\n", time.Since(now))
}

func callToServerContextAgnostic(ctx context.Context) {
    now := time.Now()
    select {
    case <-time.After(2 * time.Second): // emulate external call
    }
    fmt.Printf("callToServerContextAgnostic: %v\n", time.Since(now))
}

func main() {
    ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond)
    defer cancel()
    callToServer(ctx)

    ctx2, cancel2 := context.WithTimeout(context.Background(), 100*time.Millisecond)
    defer cancel2()
    callToServerContextAgnostic(ctx2)
}

Results:

callToServer: 100ms
callToServerContextAgnostic: 2s

You can launch it on Go Playground: https://go.dev/play/p/tIxjHxUzYfh

Note that many of the clients (from standard or third party libraries) monitors Done channel by themselves.

For example standard HTTP client:

    c := &http.Client{} // client for all requests

    ctx, cancel := context.WithTimeout(context.Background(), time.Duration(time.Millisecond*100))
    defer cancel()

    req, err := http.NewRequestWithContext(ctx, http.MethodGet, "http://google.com", nil)
    if err != nil {
        log.Fatal(err)
    }

    resp, err := c.Do(req) // will monitor `Done` channel for you

Some docs and articles:

Upvotes: 3

Related Questions