Repository: grpc/grpc-go

Issue:
received context error while waiting for new LB policy update: context deadline exceeded
We're seeing an intermittent issue. This always happens randomly at app startup time, that prevents app from properly starting up

```
rpc error: code = DeadlineExceeded desc = received context error while waiting for new LB policy update: context deadline exceeded
```

how should we interpret this error? Does it signal an issue with connectivity, gRPC server/client configuration or something else entirely. Appreciate any feedback on this.


Discussion:
@eshitachandwani: Hey @mayurkale22 , only this error message doesn't provide much information about what could be causing it. The problem could be caused by a number of issues starting from slow network to some error in the application or issue with name resolution. To help identify the cause, you can enable debug logs using 
```
$ export GRPC_GO_LOG_VERBOSITY_LEVEL=99
$ export GRPC_GO_LOG_SEVERITY_LEVEL=info
```
and that will give us more idea about the root cause. @itzmanish: Hi @mayurkale22 are you using DNS resolver? 

I am also getting the same error on the latest GRPC client. 
grpc-go v1.67.3

I can see the resolver resolving 3 endpoints that point to my NLB and are correct. The only difference I can see is that it's using LB policy to "pick_first" instead of round-robin.@itzmanish: I have more information on this issue. I got it fixed for my usecase ***SOMEHOW***, not sure if this really fixed it or just mitigated it for the time being. 

In my setup I had a DNS endpoint resolving to multiple A address of NLB and my client was using `pick_first` loadbalancer for some reason (maybe it's default loadbalancer). I changed the loadbalancer to `round_robin` and I don't find the context deadline issue anymore. My guess is for some reason one of the NLB endpoint was taking longer or GRPC lib was not able update the resolver state for that endpoint. 

I am still poking around the library for the flow and how it creates a client connection. I will update here if I find anything else.@purnesh42H: @mayurkale22 could you provide more information in following format https://github.com/grpc/grpc-go/issues/new?template=bug.md with debugging enabled? 

Please specify if you are using a different load balancing policy or name resolver than the default one. Mention the grpc version you are on and if you are using `grpc.NewClient` or `grpc.Dial`



@purnesh42H: As per your other question of how to interpret `rpc error: code = DeadlineExceeded desc = received context error while waiting for new LB policy update: context deadline exceeded`

It can happen when either there is no picker to connect to backend or there was a valid picker but it has become invalid now (because balancer detected a change in backend availability). So, its more likely a connectivity issue since you mentioned it happens intermittently. Do you have single backend or multiple?

To give some background, Picker is used by gRPC to pick a SubConn (backend) to send an RPC. Balancer is expected to generate a new picker from its snapshot every time its internal state has changed. Balancer takes input from gRPC, manages SubConns, and collects and aggregates the connectivity states. It also generates and updates the Picker used by gRPC to pick SubConns (backends) for RPCs.
@dfawley: Note that there was a recent change to output this message instead of a more generic "deadline exceeded" error.

If this is happening at startup, then it's almost always going to be that we are still waiting for connections to be established.  Maybe the RPC has too short of a deadline?

If there were errors connecting, then those errors would be given to the RPC instead.

I wonder if we can further improve this error so that users don't feel confused by it and need to file issues to learn more.@github-actions: This issue is labeled as requiring an update from the reporter, and no update has been received after 6 days.  If no update is provided in the next 7 days, this issue will be automatically closed.@itzmanish: > My guess is for some reason one of the NLB endpoints was taking longer or GRPC lib was not able to update the resolver state for that endpoint.

@purnesh42H is my guess correct? I think in `pick_first` only one conn is made and if it gets a deadline exceeded the request fails. While in `roundrobin` multiple connections are made and a request is made using all of the connections, because this can only explain why my service is working correctly after switching to `roundrobin`.@purnesh42H: > is my guess correct? I think in pick_first only one conn is made and if it gets a deadline exceeded the request fails.

No. pick_first also handles failover. It will not give up after a single connection failure or deadline exceeded on a single backend. It will attempt to connect to the next backend in the resolved list.

> While in roundrobin multiple connections are made and a request is made using all of the connections, because this can only explain why my service is working correctly after switching to roundrobin.

Not really. roundrobin sends each request to a single backend at a time, determined by its round-robin order. It does maintain connections to multiple backends, but it doesn't send the same request to all of them.@arjan-bal: @itzmanish `pickfirst` tries one address at a time until it finds a healthy backend. `pickfirst` minimizes the number of active transports. `roudrobin` tries to create a transport with every backend at the same time. `roundrobin` reports ready as soon as a single backend is connected. If you have unhealthy backends in the front of the list of addresses produced by DNS, `pickfirst` will take more time than `roundrobin` to report ready. On the other hand, `roundrobin` will create more transports than `pickfirst`. 

If you want to fix the issues you're seeing with `pickfirst`, consider the following:
1. Increase the timeout for the context that is used to make RPCs.
2. If the backends are unreachable, use a [custom dialer](https://pkg.go.dev/google.golang.org/grpc#WithContextDialer) and set a reasonable timeout for establishing connections, e.g: use `net.Dialer{Timeout: 2 * time.Second}`. This should make `pickfirst` move to the next address in the list faster.@github-actions: This issue is labeled as requiring an update from the reporter, and no update has been received after 6 days.  If no update is provided in the next 7 days, this issue will be automatically closed.@itzmanish: Thanks @arjan-bal. That was the issue. Right now I moved to `round_robin` instead of a custom dialer. @arjan-bal: The error message was improved in #8035. Closing this issue assuming all queries have been answered. Please feel free to re-open if this is not the case.

Solution patch:
diff --git a/picker_wrapper.go b/picker_wrapper.go
index bdaa2130..a2d2a798 100644
--- a/picker_wrapper.go
+++ b/picker_wrapper.go
@@ -123,7 +123,7 @@ func (pw *pickerWrapper) pick(ctx context.Context, failfast bool, info balancer.
 				if lastPickErr != nil {
 					errStr = "latest balancer error: " + lastPickErr.Error()
 				} else {
-					errStr = fmt.Sprintf("received context error while waiting for new LB policy update: %s", ctx.Err().Error())
+					errStr = fmt.Sprintf("%v while waiting for connections to become ready", ctx.Err())
 				}
 				switch ctx.Err() {
 				case context.DeadlineExceeded:



Test patch:
diff --git a/internal/transport/proxy_ext_test.go b/internal/transport/proxy_ext_test.go
index e53b5060..4f5ece1e 100644
--- a/internal/transport/proxy_ext_test.go
+++ b/internal/transport/proxy_ext_test.go
@@ -38,6 +38,7 @@ import (
 	"google.golang.org/grpc/internal/testutils"
 	"google.golang.org/grpc/internal/testutils/proxyserver"
 	testgrpc "google.golang.org/grpc/interop/grpc_testing"
+	testpb "google.golang.org/grpc/interop/grpc_testing"
 	"google.golang.org/grpc/resolver"
 	"google.golang.org/grpc/resolver/manual"
 )
@@ -55,7 +56,7 @@ func Test(t *testing.T) {
 func startBackendServer(t *testing.T) *stubserver.StubServer {
 	t.Helper()
 	backend := &stubserver.StubServer{
-		EmptyCallF: func(context.Context, *testgrpc.Empty) (*testgrpc.Empty, error) { return &testgrpc.Empty{}, nil },
+		EmptyCallF: func(context.Context, *testpb.Empty) (*testpb.Empty, error) { return &testpb.Empty{}, nil },
 	}
 	if err := backend.StartServer(); err != nil {
 		t.Fatalf("failed to start backend: %v", err)
@@ -119,7 +120,7 @@ func (s) TestGRPCDialWithProxy(t *testing.T) {
 
 	// Send an empty RPC to the backend through the proxy.
 	client := testgrpc.NewTestServiceClient(conn)
-	if _, err := client.EmptyCall(ctx, &testgrpc.Empty{}); err != nil {
+	if _, err := client.EmptyCall(ctx, &testpb.Empty{}); err != nil {
 		t.Fatalf("EmptyCall failed: %v", err)
 	}
 
@@ -176,7 +177,7 @@ func (s) TestGRPCDialWithDNSAndProxy(t *testing.T) {
 
 	// Send an empty RPC to the backend through the proxy.
 	client := testgrpc.NewTestServiceClient(conn)
-	if _, err := client.EmptyCall(ctx, &testgrpc.Empty{}); err != nil {
+	if _, err := client.EmptyCall(ctx, &testpb.Empty{}); err != nil {
 		t.Fatalf("EmptyCall failed: %v", err)
 	}
 
@@ -235,7 +236,7 @@ func (s) TestNewClientWithProxy(t *testing.T) {
 
 	// Send an empty RPC to the backend through the proxy.
 	client := testgrpc.NewTestServiceClient(conn)
-	if _, err := client.EmptyCall(ctx, &testgrpc.Empty{}); err != nil {
+	if _, err := client.EmptyCall(ctx, &testpb.Empty{}); err != nil {
 		t.Fatalf("EmptyCall failed: %v", err)
 	}
 	if !proxyCalled {
@@ -295,7 +296,7 @@ func (s) TestNewClientWithProxyAndCustomResolver(t *testing.T) {
 
 	// Send an empty RPC to the backend through the proxy.
 	client := testgrpc.NewTestServiceClient(conn)
-	if _, err := client.EmptyCall(ctx, &testgrpc.Empty{}); err != nil {
+	if _, err := client.EmptyCall(ctx, &testpb.Empty{}); err != nil {
 		t.Fatalf("EmptyCall() failed: %v", err)
 	}
 
@@ -351,7 +352,7 @@ func (s) TestNewClientWithProxyAndTargetResolutionEnabled(t *testing.T) {
 
 	// Send an empty RPC to the backend through the proxy.
 	client := testgrpc.NewTestServiceClient(conn)
-	if _, err := client.EmptyCall(ctx, &testgrpc.Empty{}); err != nil {
+	if _, err := client.EmptyCall(ctx, &testpb.Empty{}); err != nil {
 		t.Fatalf("EmptyCall failed: %v", err)
 	}
 
@@ -400,7 +401,7 @@ func (s) TestNewClientWithNoProxy(t *testing.T) {
 
 	// Create a test service client and make an RPC call.
 	client := testgrpc.NewTestServiceClient(conn)
-	if _, err := client.EmptyCall(ctx, &testgrpc.Empty{}); err != nil {
+	if _, err := client.EmptyCall(ctx, &testpb.Empty{}); err != nil {
 		t.Fatalf("EmptyCall() failed: %v", err)
 	}
 }
@@ -449,7 +450,7 @@ func (s) TestNewClientWithContextDialer(t *testing.T) {
 	defer conn.Close()
 
 	client := testgrpc.NewTestServiceClient(conn)
-	if _, err := client.EmptyCall(ctx, &testgrpc.Empty{}); err != nil {
+	if _, err := client.EmptyCall(ctx, &testpb.Empty{}); err != nil {
 		t.Fatalf("EmptyCall() failed: %v", err)
 	}
 }
@@ -510,7 +511,7 @@ func (s) TestBasicAuthInNewClientWithProxy(t *testing.T) {
 
 	// Send an empty RPC to the backend through the proxy.
 	client := testgrpc.NewTestServiceClient(conn)
-	client.EmptyCall(ctx, &testgrpc.Empty{})
+	client.EmptyCall(ctx, &testpb.Empty{})
 
 	if !proxyCalled {
 		t.Fatalf("Proxy not connected")