The Go language implementation of gRPC. HTTP/2 based RPC

Overview

gRPC-Go

Build Status GoDoc GoReportCard

The Go implementation of gRPC: A high performance, open source, general RPC framework that puts mobile and HTTP/2 first. For more information see the Go gRPC docs, or jump directly into the quick start.

Prerequisites

Installation

With Go module support (Go 1.11+), simply add the following import

import "google.golang.org/grpc"

to your code, and then go [build|run|test] will automatically fetch the necessary dependencies.

Otherwise, to install the grpc-go package, run the following command:

$ go get -u google.golang.org/grpc

Note: If you are trying to access grpc-go from China, see the FAQ below.

Learn more

FAQ

I/O Timeout Errors

The golang.org domain may be blocked from some countries. go get usually produces an error like the following when this happens:

$ go get -u google.golang.org/grpc
package google.golang.org/grpc: unrecognized import path "google.golang.org/grpc" (https fetch: Get https://google.golang.org/grpc?go-get=1: dial tcp 216.239.37.1:443: i/o timeout)

To build Go code, there are several options:

  • Set up a VPN and access google.golang.org through that.

  • Without Go module support: git clone the repo manually:

    git clone https://github.com/grpc/grpc-go.git $GOPATH/src/google.golang.org/grpc

    You will need to do the same for all of grpc's dependencies in golang.org, e.g. golang.org/x/net.

  • With Go module support: it is possible to use the replace feature of go mod to create aliases for golang.org packages. In your project's directory:

    go mod edit -replace=google.golang.org/grpc=github.com/grpc/[email protected]
    go mod tidy
    go mod vendor
    go build -mod=vendor

    Again, this will need to be done for all transitive dependencies hosted on golang.org as well. For details, refer to golang/go issue #28652.

Compiling error, undefined: grpc.SupportPackageIsVersion

If you are using Go modules:

Ensure your gRPC-Go version is required at the appropriate version in the same module containing the generated .pb.go files. For example, SupportPackageIsVersion6 needs v1.27.0, so in your go.mod file:

module <your module name>

require (
    google.golang.org/grpc v1.27.0
)

If you are not using Go modules:

Update the proto package, gRPC package, and rebuild the .proto files:

go get -u github.com/golang/protobuf/{proto,protoc-gen-go}
go get -u google.golang.org/grpc
protoc --go_out=plugins=grpc:. *.proto

How to turn on logging

The default logger is controlled by environment variables. Turn everything on like this:

$ export GRPC_GO_LOG_VERBOSITY_LEVEL=99
$ export GRPC_GO_LOG_SEVERITY_LEVEL=info

The RPC failed with error "code = Unavailable desc = transport is closing"

This error means the connection the RPC is using was closed, and there are many possible reasons, including:

  1. mis-configured transport credentials, connection failed on handshaking
  2. bytes disrupted, possibly by a proxy in between
  3. server shutdown
  4. Keepalive parameters caused connection shutdown, for example if you have configured your server to terminate connections regularly to trigger DNS lookups. If this is the case, you may want to increase your MaxConnectionAgeGrace, to allow longer RPC calls to finish.

It can be tricky to debug this because the error happens on the client side but the root cause of the connection being closed is on the server side. Turn on logging on both client and server, and see if there are any transport errors.

Issues
  • protoc-gen-go-grpc: API for service registration

    protoc-gen-go-grpc: API for service registration

    There were some changes in #3657 that make it harder to develop gRPC services and harder to find new unimplemented methods - I wanted to start a discussion around the new default and figure out why the change was made. I do understand this is in an unreleased version, so I figured a discussion would be better than a bug report or feature request.

    From my perspective, this is a number of steps backwards for reasons I will outline below.

    When implementing a gRPC service in Go, I often start with a blank slate - the service has been defined in proto files, the go and gRPC protobuf definitions have been generated, all that's left to do is write the code. I often use something like the following so the compiler will help me along, telling me about missing methods, incorrect signatures, things like that.

    package chat
    func init() {
    	// Ensure that Server implements the ChatIngestServer interface
    	var server *Server = nil
    	var _ pb.ChatIngestServer = server
    }
    

    This can alternatively be done with var _ pb.ChatIngestServer = &Server{} but that theoretically leaves a little bit more memory around at runtime.

    After this, I add all the missing methods myself (returning the unimplemented status) and start adding implementations to them until I have a concrete implementation for all the methods.

    Problems with the new approach

    • As soon as you embed the Unimplemented implementation, the Go compiler gets a lot less useful - it will no longer tell you about missing methods and because Go interfaces are implicit, if you make a mistake in implementing a method (like misspelling a method name), you will not find out until runtime. Additionally, because these are public methods, if they're attached to a public struct (like the commonly used Server), they may not be detected as an unused method.
    • If protos and generated files are updated, you will not know about any missing methods until runtime. Personally, I would prefer to know if I have not fully implemented a service at compile time rather than waiting until clients are running against it.
    • IDE hinting is worse with the new changes - IDEs will generally not recommend a method stub for an unimplemented method if it's provided by an embedded struct because even though it's technically implemented, it does not have a working implementation.

    I generally prefer compile time guarantees that all methods are implemented over runtime checks.

    Benefits of the new approach

    • Protos and generated files can be updated without requiring updates to server implementations.

    Proposal

    By default, the option requireUnimplementedServers should default to false. This option is more valuable when dealing with external protobufs which are not versioned (maybe there should be a recommendation to embed the unimplemented struct in this instance) and makes it harder to catch mistakes if you are developing a canonical implementation of a service which should implement all the available methods.

    At least for me, the problems with the new approach vastly outweigh the benefits I've seen so far.

    Type: Question P1 
    opened by belak 86
  • Support serving web content from the same port

    Support serving web content from the same port

    https://github.com/grpc/grpc-common/blob/master/PROTOCOL-HTTP2.md#appendix-a---grpc-for-protobuf says grpc protobuf mapping uses service names as paths. Would it be possible to serve web content from other urls?

    I see TLS side does alpn, so that's an easy place to hook up.

    Any thoughts about non-TLS? e.g. a service running on localhost. Of course that would mean needing to do a http/1 upgrade negotiation, as then the port could not default to http/2.

    Use case 1: host a web application and its api on the same port.

    Use case 2: serve a health check response.

    Use case 3: serve a "nothing to see here" html page.

    Use case 4: serve a /robots.txt file.

    opened by tv42 70
  • Go 1.7 uses import

    Go 1.7 uses import "context"

    If you're using the new "context" library, then gRPC servers can't match the server to the interface, because it has the wrong type of context.

    Compiling bin/linux.x86_64/wlserver

    asci/cs/tools/whitelist/wlserver

    ./wlserver.go:767: cannot use wls (type _Server) as type WhitelistProto.GoogleWhitelistServer in argument to WhitelistProto.RegisterGoogleWhitelistServer: *Server does not implement WhitelistProto.GoogleWhitelistServer (wrong type for Delete method) have Delete(context.Context, *WhitelistProto.DeleteRequest) (_WhitelistProto.DeleteReply, error) want Delete(context.Context, _WhitelistProto.DeleteRequest) (_WhitelistProto.DeleteReply, error)

    Type: API Change P3 Status: Blocked 
    opened by puellanivis 67
  • Connection latency significantly affects throughput

    Connection latency significantly affects throughput

    I am working on a system that uses GRPC to send 1MB blobs between clients and servers and have observed some poor throughput when connection latency is high (180ms round trip is typical between Australia and the USA).

    The same throughput issues are not present when I take GRPC out of the equation. I have prepared a self-contained program that reproduces the problem on a local machine by simulating latency at the net.Listener level. It can run either using GRPC or just plain HTTP/2 POST requests. In each case the payload and latency are the same, but—as you can see from the data below—GRPC becomes several orders of magnitude slower as latency increases.

    The program and related files: https://gist.github.com/adg/641d04ef335782648502cb32a03b2b07

    The output of a typical run:

    $ ./run.sh 
    Duration	Latency	Proto
    
    6.977221ms	0s	GRPC
    4.833989ms	0s	GRPC
    4.714891ms	0s	GRPC
    3.884165ms	0s	GRPC
    5.254322ms	0s	GRPC
    
    8.507352ms	0s	HTTP/2.0
    936.436µs	0s	HTTP/2.0
    453.471µs	0s	HTTP/2.0
    252.786µs	0s	HTTP/2.0
    265.955µs	0s	HTTP/2.0
    
    107.32663ms	1ms	GRPC
    102.51629ms	1ms	GRPC
    100.235617ms	1ms	GRPC
    100.444982ms	1ms	GRPC
    100.881221ms	1ms	GRPC
    
    12.423725ms	1ms	HTTP/2.0
    3.02918ms	1ms	HTTP/2.0
    2.775928ms	1ms	HTTP/2.0
    4.161895ms	1ms	HTTP/2.0
    2.951534ms	1ms	HTTP/2.0
    
    195.731175ms	2ms	GRPC
    190.571784ms	2ms	GRPC
    188.810298ms	2ms	GRPC
    190.593822ms	2ms	GRPC
    190.015888ms	2ms	GRPC
    
    19.18046ms	2ms	HTTP/2.0
    4.663983ms	2ms	HTTP/2.0
    5.45113ms	2ms	HTTP/2.0
    5.56255ms	2ms	HTTP/2.0
    5.582744ms	2ms	HTTP/2.0
    
    378.653747ms	4ms	GRPC
    362.14625ms	4ms	GRPC
    357.95833ms	4ms	GRPC
    364.525646ms	4ms	GRPC
    364.954077ms	4ms	GRPC
    
    33.666184ms	4ms	HTTP/2.0
    8.68926ms	4ms	HTTP/2.0
    10.658349ms	4ms	HTTP/2.0
    10.741361ms	4ms	HTTP/2.0
    10.188444ms	4ms	HTTP/2.0
    
    719.696194ms	8ms	GRPC
    699.807568ms	8ms	GRPC
    703.794127ms	8ms	GRPC
    702.610461ms	8ms	GRPC
    710.592955ms	8ms	GRPC
    
    55.66933ms	8ms	HTTP/2.0
    18.449093ms	8ms	HTTP/2.0
    17.080567ms	8ms	HTTP/2.0
    20.597944ms	8ms	HTTP/2.0
    17.318133ms	8ms	HTTP/2.0
    
    1.415272339s	16ms	GRPC
    1.350923577s	16ms	GRPC
    1.355653965s	16ms	GRPC
    1.338834603s	16ms	GRPC
    1.358419144s	16ms	GRPC
    
    102.133898ms	16ms	HTTP/2.0
    39.144638ms	16ms	HTTP/2.0
    40.82348ms	16ms	HTTP/2.0
    35.133498ms	16ms	HTTP/2.0
    39.516466ms	16ms	HTTP/2.0
    
    2.630821843s	32ms	GRPC
    2.46741086s	32ms	GRPC
    2.507019279s	32ms	GRPC
    2.476177935s	32ms	GRPC
    2.49266693s	32ms	GRPC
    
    179.271675ms	32ms	HTTP/2.0
    72.575954ms	32ms	HTTP/2.0
    67.23265ms	32ms	HTTP/2.0
    70.651455ms	32ms	HTTP/2.0
    67.579124ms	32ms	HTTP/2.0
    

    I theorize that there is something wrong with GRPC's flow control mechanism, but that's just a guess.

    P1 Type: Performance 
    opened by adg 66
  • Failed HTTP/2 Parsing StatusCode.Unavailable when calling Streaming RPCs from Golang Server

    Failed HTTP/2 Parsing StatusCode.Unavailable when calling Streaming RPCs from Golang Server

    Please answer these questions before submitting your issue.

    This is a continuation of https://github.com/grpc/grpc/issues/11586 which I am opening here for better visibility from the grpc-go devs.

    What version of gRPC are you using?

    We are using python grpcio==1.3.5 and grpc-go==v1.4.x. We've also reproduced this on python grpcio==1.4.0

    What version of Go are you using (go version)?

    We're using go version 1.8.1

    What operating system (Linux, Windows, …) and version?

    Ubuntu 14.04

    What did you do?

    If possible, provide a recipe for reproducing the error. Happens inconsistently, every so often a streaming RPC will fail with the following error: <_Rendezvous of RPC that terminated with (StatusCode.UNAVAILABLE, Failed parsing HTTP/2)>

    Some grpc logs: E0629 13:45:52.222804121 27606 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:45:52.222827355 27606 completion_queue.c:226] Operation failed: tag=0x7f10bbd9ca60, error={"created":"@1498769152.222798356","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:45:52.222838571 27606 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:45:52.222846339 27606 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cad0, error={"created":"@1498769152.222799406","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:45:52.223925299 27603 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:45:52.223942312 27603 completion_queue.c:226] Operation failed: tag=0x7f10bbd9c9f0, error={"created":"@1498769152.223918465","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:45:52.223949262 27603 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:45:52.223979616 27603 completion_queue.c:226] Operation failed: tag=0x7f10bbd9c980, error={"created":"@1498769152.223919439","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:45:52.224009309 27603 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:45:52.224017226 27603 completion_queue.c:226] Operation failed: tag=0x7f10bbd9c830, error={"created":"@1498769152.223920475","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:45:52.224391810 27609 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:45:52.224403941 27609 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cc20, error={"created":"@1498769152.224387963","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:52:37.556768181 28157 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:52:37.556831045 28157 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cb40, error={"created":"@1498769557.556750425","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:52:37.557441154 28161 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:52:37.557504078 28161 completion_queue.c:226] Operation failed: tag=0x7f10bbd9c830, error={"created":"@1498769557.557416763","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:52:37.557563746 28161 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:52:37.557608834 28161 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cc20, error={"created":"@1498769557.557420283","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:52:37.557649360 28161 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:52:37.557694897 28161 completion_queue.c:226] Operation failed: tag=0x7f10bbd9c980, error={"created":"@1498769557.557423433","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:52:37.558510258 28166 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:52:37.558572634 28166 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cd70, error={"created":"@1498769557.558490789","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:52:37.558610179 28166 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:52:37.558644492 28166 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cec0, error={"created":"@1498769557.558494483","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 13:52:37.559833158 28167 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 13:52:37.559901218 28167 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cad0, error={"created":"@1498769557.559815450","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:11:46.635698278 29153 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:11:46.635812439 29153 completion_queue.c:226] Operation failed: tag=0x7f108afcb1a0, error={"created":"@1498770706.635668871","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:11:46.635887056 29153 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:11:46.635944586 29153 completion_queue.c:226] Operation failed: tag=0x7f108afcb210, error={"created":"@1498770706.635675260","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:11:46.636461489 29155 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:11:46.636525366 29155 completion_queue.c:226] Operation failed: tag=0x7f108afcb130, error={"created":"@1498770706.636440110","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:11:46.636556141 29155 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:11:46.636585820 29155 completion_queue.c:226] Operation failed: tag=0x7f108afcb360, error={"created":"@1498770706.636443702","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:11:46.637721291 29163 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:11:46.637791752 29163 completion_queue.c:226] Operation failed: tag=0x7f108afcb0c0, error={"created":"@1498770706.637702529","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:11:46.637836300 29163 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:11:46.637872014 29163 completion_queue.c:226] Operation failed: tag=0x7f108afcb2f0, error={"created":"@1498770706.637706809","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:11:46.641194536 29163 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:11:46.641241298 29163 completion_queue.c:226] Operation failed: tag=0x7f108afcb050, error={"created":"@1498770706.641178364","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:28:37.539497986 29251 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:28:37.539555939 29251 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cc90, error={"created":"@1498771717.539483236","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:28:37.540536617 29265 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:28:37.540601626 29265 completion_queue.c:226] Operation failed: tag=0x7f10bbd9c910, error={"created":"@1498771717.540517372","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:28:37.540647559 29265 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:28:37.540679773 29265 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cd70, error={"created":"@1498771717.540521809","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:28:37.541893786 29265 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:28:37.541943420 29265 completion_queue.c:226] Operation failed: tag=0x7f10bbd9ce50, error={"created":"@1498771717.541871189","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:28:37.541982533 29265 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:28:37.542009741 29265 completion_queue.c:226] Operation failed: tag=0x7f10bbd9c830, error={"created":"@1498771717.541874944","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:28:37.542044730 29265 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:28:37.542080406 29265 completion_queue.c:226] Operation failed: tag=0x7f10bbd9c980, error={"created":"@1498771717.541878692","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} E0629 14:28:37.543488271 29265 channel_connectivity.c:138] watch_completion_error: "Cancelled" E0629 14:28:37.543534201 29265 completion_queue.c:226] Operation failed: tag=0x7f10bbd9cad0, error={"created":"@1498771717.543473445","description":"Timed out waiting for connection state change","file":"src/core/ext/filters/client_channel/channel_connectivity.c","file_line":145} <_Rendezvous of RPC that terminated with (StatusCode.UNAVAILABLE, Failed parsing HTTP/2)>

    What did you expect to see?

    The streaming RPC to succeed.

    What did you see instead?

    The streaming RPC failed

    Status: Requires Reporter Clarification Type: Bug 
    opened by kahuang 54
  • ClientConn is inflexible for client-side LB

    ClientConn is inflexible for client-side LB

    Client side LB was being discussed here: https://groups.google.com/forum/#!searchin/grpc-io/loadbalancing/grpc-io/yqB8sNNHeoo/0Mfu4b2cdaUJ

    We've been considering using GRPC for our new MicroService stack. We are using Etcd+SkyDNS for DNS SRV based service discovery and would like to leverage that for RR-like RPC load balancing between backends.

    However, it seems that the current ClientConn is fairly "single-homed". I thought about implementing an LbClientConn that would aggregate multiple ClientConn, but all the auto-generated code takes ClientConn structure and not a swappable interface.

    Are you planning on doing client-side LB anytime soon? Or maybe ideas or hints on how to make an early stab at it?

    opened by mwitkow 51
  • Instrumentation hooks

    Instrumentation hooks

    We're currently experimenting with GRPC and wondering how we'll monitor the client code/server code dispatch using Prometheus metrics (should look familiar ;)

    I've been looking for a place in the grpc-go to be able to hook up gathering of ServiceName, MethodName, bytes, latency data, and found none.

    Reading upon the thread in #131 about RPC interceptors, it is suggested to add the instrumentation in our Application Code (a.k.a. the code implementing the auto-generated Proto interfaces). I see the point about not cluttering grpc-go implementation and being implementation agnostic.

    However, adding instrumentation into Application Code means that either we need to: a) add a lot of repeatable code inside Application Code to handle instrumentation b) use the callFoo pattern described in #131 proposed [only applicable to Client] c) add a thin implementation of each Proto-generated interface that wraps the "real" Proto-generated method calls with metrics [only applicable to Client]

    There are downsides to each solution though: a) leads to a lot of clutter and errors related to copy pasting, and some of these will be omitted or badly done b) means that we loose the best (IMHO) feature of Proto-generated interfaces: the "natural" syntax that allows for easy mocking in unit tests (through injection of the Proto-generated Interface), and is only applicable on the Client-side c) is very tedious because each time we re-generate the Proto (add a method or a service) we need to go and manually copy paste some boiler plate. This would be a huge drag on our coding workflow, since we really want to rely on Proto-generate code as much as possible. And also is only applicable on the Client-side.

    I think that cleanest solution would be a pluggable set of callbacks on pre-call/post-call on client/server that would grant access to ServiceName, MethodName and RpcContext (provided the latter stats about bytes transferred/start time of the call). This would allow people to plug an instrumentation mechanism of their choice (statsd, grafana, Prometheus), and shouldn't have any impact on performance that interceptors described in #131 could have had (the double serialization/deserialization).

    Having seen how amazingly useful RPC instrumentation was inside Google, I'm sure you've been thinking about solving this in gRPC, and I'm curious to know what you're planning :)

    opened by mwitkow 45
  • Access to TLS client certificate

    Access to TLS client certificate

    I can't see any way for an RPC method to authenticate a client based on a TLS certificate.

    An example program where an RPC method echoes the client TLS certificate would be great.

    opened by tv42 44
  • Document how to use ServeHTTP

    Document how to use ServeHTTP

    Now that #75 is fixed (via #514), let's add examples on how to use ServeHTTP. The examples were removed from earlier versions of #514 to reduce the size of that change.

    First, I'd like to get #545 submitted, to clean up the testdata files, before fixing this issue would otherwise make it worse.

    /cc @iamqizhao

    Type: Documentation 
    opened by bradfitz 34
  • Unexpected transport closing: too many pings from client

    Unexpected transport closing: too many pings from client

    What version of gRPC are you using?

    583a6303969ea5075e9bd1dc4b75805dfe66989a

    What version of Go are you using (go version)?

    1.10

    What operating system (Linux, Windows, …) and version?

    Linux AMD64, Kernel 4.10

    What did you do?

    When I have the server configured with GZIP compression as so:

    gzcp := grpc.NewGZIPCompressor()
    grpcServer := grpc.NewServer(grpc.RPCCompressor(gzcp))
    

    Then when serving thousands of concurrent requests a second, clients will occasionally be disconnected with

    rpc error: code = Unavailable desc = transport is closing
    

    I see no errors from the server, and the both the client and server are far from overloaded (<10% CPU usage etc). Not all clients are affected at once, it will just be one connection which gets this error.

    While trying to debug this, I disabled GZIP compression so I could use more easily look at packet captures. I am unable to reproduce this error once the GZIP compressor is no longer in use.

    This issue is mostly to ask what the best way to proceed with diagnosing the problem is, or if there are any reasons why having a compressor would change the behavior of the system (aside from CPU usage which I don't think is a problem).

    P1 Type: Bug 
    opened by immesys 33
  • cmd/protoc-gen-go-grpc: add code generator

    cmd/protoc-gen-go-grpc: add code generator

    Add a code generator for gRPC services.

    No tests included here. A followup PR updates code generation to use this generator, which acts as a test of the generator as well.

    Type: Feature no release notes 
    opened by neild 30
  • xds: drop localities with zero weight at the xdsClient layer

    xds: drop localities with zero weight at the xdsClient layer

    Fixes https://github.com/grpc/grpc-go/issues/5453

    This PR moves the logic of dropping localities, in a received EDS response with weight 0, to the xdsClient. This allows the LB policy implementations to function with the assumption that they would only receive localities with non-zero weights as part of any updates from the xdsClient. This mirrors C-core behavior.

    RELEASE NOTES: none

    Type: Internal Cleanup 
    opened by easwars 0
  • balancer: fix connectivity state aggregation algorithm to follow the spec

    balancer: fix connectivity state aggregation algorithm to follow the spec

    The connectivity state aggregation algorithm as specified in the spec is as follows:

    The policy sets the channel's connectivity state by aggregating the states of the subchannels:
    
    - If any one subchannel is in READY state, the channel's state is READY.
    - Otherwise, if there is any subchannel in state CONNECTING, the channel's state is CONNECTING.
    - Otherwise, if there is any subchannel in state IDLE, the channel's state is IDLE.
    - Otherwise, if all subchannels are in state TRANSIENT_FAILURE, the channel's state is TRANSIENT_FAILURE.
    
    Note that when a given subchannel reports TRANSIENT_FAILURE, it is considered to still be in
    TRANSIENT_FAILURE until it successfully reconnects and reports READY. In particular, we ignore 
    the transition from TRANSIENT_FAILURE to CONNECTING.
    

    In our existing implementation, we were giving more precedence to TRANSIENT_FAILURE than IDLE. This was not causing any issue so far since this algorithm was only being used by the round_robin LB policy where IDLE is a fleeting state (the policy triggers a connection attempt whenever the subConn enters IDLE). We plan to use this connectivity state aggregation algorithm in the weightedtarget LB policy, where IDLE is not a fleeting state and needs to be prioritized over TRANSIENT_FAILURE.

    Also, this algorithm does not take care of suppressing connectivity state changes from TRANSIENT_FAILURE to non-READY states. This is currently taken care by the LB policy implementations and will continue to remain that way.

    Fixes https://github.com/grpc/grpc-go/issues/5458

    RELEASE NOTES:

    • balancer: give more precedence to IDLE over TRANSIENT_FAILURE when aggregating connectivity state
    Type: Bug 
    opened by easwars 0
  • balancer: existing LB policies must update picker synchronously

    balancer: existing LB policies must update picker synchronously

    https://github.com/grpc/grpc-go/issues/5211 talks about delaying picker updates in LB policies which have child policies, until the configs have been propagated to all the children. It also talks about auditing existing code to ensure that existing LB policy implementations update their pickers synchronously upon receipt of a config update.

    We will use this issue to ensure that we have audited all existing LB policy implementations, and update docs to indicate the same.

    • [ ] cds_experimental
    • [ ] xds_cluster_impl_experimental
    • [ ] xds_cluster_manager_experimental
    • [ ] cluster_resolver_experimental
    • [ ] outlier_detection_experimental
    • [ ] priority_experimental
    • [ ] ring_hash_experimental
    • [ ] round_robin
    • [ ] pick_first
    • [ ] grpclb
    • [ ] rls_experimental
    • [ ] weighted_round_robin
    • [ ] weighted_target_experimental
    • [ ] update documentation to indicate that LB policies must update their pickers synchronously upon receipt of config udpate
    P1 Type: Bug 
    opened by easwars 0
  • Flaky test: ControlChannelConnectivityStateMonitoring

    Flaky test: ControlChannelConnectivityStateMonitoring

    Test error log:
    --- FAIL: Test (9.95s)
        --- FAIL: Test/ControlChannelConnectivityStateMonitoring (5.02s)
            tlogger.go:116: INFO server.go:598 [core] [Server #525] Server created  (t=+533.807µs)
            fake_rls_server.go:53: Started fake RLS server at "127.0.0.1:35475"
            balancer_test.go:763: Registered child policy with name "test-child-policyTest/ControlChannelConnectivityStateMonitoring"
            tlogger.go:116: INFO server.go:598 [core] [Server #526] Server created  (t=+1.244216ms)
            balancer_test.go:772: Started TestService backend at: "127.0.0.1:38063"
            tlogger.go:116: INFO config.go:144 [rls] Received JSON service config: {
                  "routeLookupConfig": {
                    "grpc_keybuilders": [
                      {
                        "names": [
                          {
                            "service": "grpc.testing.TestService"
                          }
                        ],
                        "headers": [
                          {
                            "key": "k1",
                            "names": [
                              "n1"
                            ]
                          },
                          {
                            "key": "k2",
                            "names": [
                              "n2"
                            ]
                          }
                        ]
                      }
                    ],
                    "lookup_service": "127.0.0.1:35475",
                    "lookup_service_timeout": "5s",
                    "max_age": "0.100s",
                    "cache_size_bytes": "1024"
                  },
                  "routeLookupChannelServiceConfig": {
                    "loadBalancingConfig": [
                      {
                        "pick_first": {}
                      }
                    ]
                  },
                  "childPolicy": [
                    {
                      "test-child-policyTest/ControlChannelConnectivityStateMonitoring": {}
                    }
                  ],
                  "childPolicyConfigTargetFieldName": "Backend"
                }  (t=+2.370632ms)
            tlogger.go:116: INFO server.go:786 [core] [Server #525 ListenSocket #527] ListenSocket created  (t=+3.815951ms)
            tlogger.go:116: INFO server.go:786 [core] [Server #526 ListenSocket #528] ListenSocket created  (t=+7.234996ms)
            tlogger.go:116: INFO clientconn.go:105 [core] [Channel #529] Channel created  (t=+8.666116ms)
            tlogger.go:116: INFO clientconn.go:1579 [core] [Channel #529] original dial target is: "rls-e2e:///"  (t=+8.798917ms)
            tlogger.go:116: INFO clientconn.go:1586 [core] [Channel #529] parsed dial target is: {Scheme:rls-e2e Authority: Endpoint: URL:{Scheme:rls-e2e Opaque: User: Host: Path:/ RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}  (t=+8.961119ms)
            tlogger.go:116: INFO clientconn.go:263 [core] [Channel #529] Channel authority set to ""  (t=+9.104421ms)
            tlogger.go:116: INFO resolver_conn_wrapper.go:175 [core] [Channel #529] Resolver state updated: {
                  "Addresses": null,
                  "ServiceConfig": {
                    "Config": {
                      "Config": null,
                      "LB": null,
                      "Methods": {}
                    },
                    "Err": null
                  },
                  "Attributes": null
                } (service config updated)  (t=+9.363025ms)
            tlogger.go:116: INFO balancer_conn_wrappers.go:271 [core] [Channel #529] Channel switches to new LB policy "rls_experimental"  (t=+9.625628ms)
            tlogger.go:116: INFO balancer.go:260 [rls] [rls-experimental-lb 0x4000336600] Creating control channel to RLS server at: 127.0.0.1:35475  (t=+10.007133ms)
            tlogger.go:116: INFO control_channel.go:127 [rls] [rls-control-channel 0x4000238000] Disabling service config from the name resolver and instead using: {"loadBalancingConfig": [{"pick_first": {}}]}  (t=+15.280104ms)
            tlogger.go:116: INFO clientconn.go:105 [core] [Channel #530] Channel created  (t=+15.543207ms)
            tlogger.go:116: INFO clientconn.go:1579 [core] [Channel #530] original dial target is: "127.0.0.1:35475"  (t=+16.076014ms)
            tlogger.go:116: INFO clientconn.go:1584 [core] [Channel #530] dial target "127.0.0.1:35475" parse failed: parse "127.0.0.1:35475": first path segment in URL cannot contain colon  (t=+16.279217ms)
            tlogger.go:116: INFO clientconn.go:1599 [core] [Channel #530] fallback to scheme "passthrough"  (t=+16.411719ms)
            tlogger.go:116: INFO clientconn.go:1607 [core] [Channel #530] parsed dial target is: {Scheme:passthrough Authority: Endpoint:127.0.0.1:35475 URL:{Scheme:passthrough Opaque: User: Host: Path:/127.0.0.1:35475 RawPath: ForceQuery:false RawQuery: Fragment: RawFragment:}}  (t=+16.616622ms)
            tlogger.go:116: INFO clientconn.go:263 [core] [Channel #530] Channel authority set to "127.0.0.1:35475"  (t=+16.813024ms)
            tlogger.go:116: INFO resolver_conn_wrapper.go:175 [core] [Channel #530] Resolver state updated: {
                  "Addresses": [
                    {
                      "Addr": "127.0.0.1:35475",
                      "ServerName": "",
                      "Attributes": null,
                      "BalancerAttributes": null,
                      "Type": 0,
                      "Metadata": null
                    }
                  ],
                  "ServiceConfig": null,
                  "Attributes": null
                } (resolver returned new addresses)  (t=+17.124028ms)
            tlogger.go:116: INFO clientconn.go:631 [core] [Channel #530] ignoring service config from resolver (<nil>) and applying the default because service config is disabled  (t=+17.322831ms)
            tlogger.go:116: INFO balancer_conn_wrappers.go:271 [core] [Channel #530] Channel switches to new LB policy "pick_first"  (t=+17.552034ms)
            tlogger.go:116: INFO clientconn.go:725 [core] [Channel #530 SubChannel #531] Subchannel created  (t=+17.804538ms)
            tlogger.go:116: INFO control_channel.go:83 [rls] [rls-control-channel 0x4000238000] Control channel created to RLS server at: 127.0.0.1:35475  (t=+18.030441ms)
            tlogger.go:116: INFO balancer.go:282 [rls] [rls-experimental-lb 0x4000336600] Child policy changed to "test-child-policyTest/ControlChannelConnectivityStateMonitoring"  (t=+18.174542ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:IDLE Picker:0x40003e6780}  (t=+18.329945ms)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS"
                }  (t=+18.698049ms)
            tlogger.go:116: INFO picker_wrapper.go:161 [core] blockingPicker: the picked transport is not ready, loop back to repick  (t=+26.99106ms)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #530 SubChannel #531] Subchannel Connectivity change to CONNECTING  (t=+27.139[46](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:47)2ms)
            tlogger.go:116: INFO clientconn.go:1212 [core] [Channel #530 SubChannel #531] Subchannel picks a new address "127.0.0.1:35[47](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:48)5" to connect  (t=+27.354365ms)
            tlogger.go:116: INFO control_channel.go:135 [rls] [rls-control-channel 0x4000238000] Starting connectivity state monitoring goroutine  (t=+27.554168ms)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #530] Channel Connectivity change to CONNECTING  (t=+28.981587ms)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #530 SubChannel #531] Subchannel Connectivity change to READY  (t=+29.108088ms)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #530] Channel Connectivity change to READY  (t=+29.326591ms)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x40003e6780] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:} with targets [127.0.0.1:38063], headerData "", err: <nil>  (t=+30.70601ms)
            tlogger.go:116: INFO child_policy.go:84 [rls] [rls-child-policy-wrapper 127.0.0.1:38063 0x40002338c0] Created  (t=+30.837111ms)
            tlogger.go:116: INFO balancergroup.go:100 [rls] [rls-experimental-lb 0x4000336600] Creating child policy of type test-child-policyTest/ControlChannelConnectivityStateMonitoring  (t=+30.933613ms)
            tlogger.go:116: INFO balancer.go:571 [rls] [rls-experimental-lb 0x4000336600] Child policy "127.0.0.1:38063" added to BalancerGroup  (t=+31.042614ms)
            tlogger.go:116: INFO balancer.go:368 [rls] [rls-experimental-lb 0x4000336600] Pushing new state to child policy "127.0.0.1:38063": {ResolverState:{Addresses:[] ServiceConfig:0x4000258120 Attributes:<nil>} BalancerConfig:0x4000233a10}  (t=+31.223817ms)
            tlogger.go:116: INFO clientconn.go:725 [core] [Channel #529 SubChannel #534] Subchannel created  (t=+31.336218ms)
            tlogger.go:116: INFO balancergroup.go:499 [rls] [rls-experimental-lb 0x4000336600] Balancer state update from locality 127.0.0.1:38063, new state: {ConnectivityState:IDLE Picker:0x4000233b30}  (t=+31.437519ms)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x40003e6780] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:}  (t=+31.540721ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:CONNECTING Picker:0x400027f200}  (t=+31.630222ms)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #529] Channel Connectivity change to CONNECTING  (t=+31.700523ms)
            tlogger.go:116: INFO balancer.go:546 [rls] [rls-experimental-lb 0x4000336600] Child policy "127.0.0.1:38063" has new state 0x400000c900  (t=+31.828125ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:IDLE Picker:0x400027f380}  (t=+31.902726ms)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #529] Channel Connectivity change to IDLE  (t=+31.968727ms)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #529 SubChannel #534] Subchannel Connectivity change to CONNECTING  (t=+32.102228ms)
            tlogger.go:116: INFO clientconn.go:1212 [core] [Channel #529 SubChannel #534] Subchannel picks a new address "127.0.0.1:38063" to connect  (t=+32.22793ms)
            tlogger.go:116: INFO balancergroup.go:499 [rls] [rls-experimental-lb 0x4000336600] Balancer state update from locality 127.0.0.1:38063, new state: {ConnectivityState:CONNECTING Picker:0x4000233ec0}  (t=+32.519734ms)
            tlogger.go:116: INFO balancer.go:546 [rls] [rls-experimental-lb 0x4000336600] Child policy "127.0.0.1:38063" has new state 0x400000c978  (t=+32.629335ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:CONNECTING Picker:0x400027f6e0}  (t=+32.705236ms)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #529] Channel Connectivity change to CONNECTING  (t=+32.779337ms)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #529 SubChannel #534] Subchannel Connectivity change to READY  (t=+33.5756[48](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:49)ms)
            tlogger.go:116: INFO balancergroup.go:[49](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:50)9 [rls] [rls-experimental-lb 0x4000336600] Balancer state update from locality 127.0.0.1:38063, new state: {ConnectivityState:READY Picker:0x40003fb020}  (t=+33.71105ms)
            tlogger.go:116: INFO balancer.go:546 [rls] [rls-experimental-lb 0x4000336600] Child policy "127.0.0.1:38063" has new state 0x400000cae0  (t=+33.822051ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x400027ff80}  (t=+33.899352ms)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #529] Channel Connectivity change to READY  (t=+33.971053ms)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #530 SubChannel #531] Subchannel Connectivity change to IDLE  (t=+36.00568ms)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #530] Channel Connectivity change to IDLE  (t=+36.857092ms)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS"
                }  (t=+136.815426ms)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #530 SubChannel #531] Subchannel Connectivity change to CONNECTING  (t=+137.14733ms)
            tlogger.go:116: INFO clientconn.go:1212 [core] [Channel #530 SubChannel #531] Subchannel picks a new address "127.0.0.1:35475" to connect  (t=+137.403834ms)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #530] Channel Connectivity change to CONNECTING  (t=+137.940641ms)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #530 SubChannel #531] Subchannel Connectivity change to TRANSIENT_FAILURE  (t=+139.230458ms)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #530] Channel Connectivity change to TRANSIENT_FAILURE  (t=+139.426061ms)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x400027ff80] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:} with targets [], headerData "", err: rpc error: code = Unavailable desc = connection closed before server preface received  (t=+139.838966ms)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x400027ff80] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:}  (t=+140.034069ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x400037cc60}  (t=+140.201471ms)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS",
                  "keyMap": {
                    "k1": "v1"
                  }
                }  (t=+140.85168ms)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x400037cc60] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1} with targets [], headerData "", err: rpc error: code = Unavailable desc = connection closed before server preface received  (t=+141.174984ms)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x400037cc60] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1}  (t=+141.326186ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x400037d440}  (t=+141.468488ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x400037d740}  (t=+241.705526ms)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS",
                  "keyMap": {
                    "k1": "v1"
                  }
                }  (t=+242.295734ms)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x400037d740] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1} with targets [], headerData "", err: rpc error: code = Unavailable desc = connection closed before server preface received  (t=+242.541337ms)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x400037d740] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1}  (t=+242.631438ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x4000436240}  (t=+242.732639ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x4000436360}  (t=+343.807488ms)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS",
                  "keyMap": {
                    "k1": "v1"
                  }
                }  (t=+443.834123ms)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x4000436360] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1} with targets [], headerData "", err: rpc error: code = Unavailable desc = connection closed before server preface received  (t=+444.066627ms)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x4000436360] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1}  (t=+444.177428ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x4000184d80}  (t=+444.279129ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x40004364e0}  (t=+544.806971ms)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS",
                  "keyMap": {
                    "k1": "v1"
                  }
                }  (t=+545.557281ms)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x40004364e0] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1} with targets [], headerData "", err: rpc error: code = Unavailable desc = connection closed before server preface received  (t=+545.925886ms)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x40004364e0] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1}  (t=+546.073688ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x4000436fc0}  (t=+546.23079ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x40004370e0}  (t=+646.479828ms)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS",
                  "keyMap": {
                    "k1": "v1"
                  }
                }  (t=+746.686065ms)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x40004370e0] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1} with targets [], headerData "", err: rpc error: code = Unavailable desc = connection closed before server preface received  (t=+746.982869ms)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x40004370e0] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1}  (t=+747.081671ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x4000185[50](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:51)0}  (t=+747.180172ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x4000185680}  (t=+848.289921ms)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS",
                  "keyMap": {
                    "k1": "v1"
                  }
                }  (t=+947.545946ms)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x4000185680] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1} with targets [], headerData "", err: rpc error: code = Unavailable desc = connection closed before server preface received  (t=+947.9227[51](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:52)ms)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x4000185680] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1}  (t=+948.073253ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x4000437e60}  (t=+948.230755ms)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x400009e360}  (t=+1.048285991s)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS",
                  "keyMap": {
                    "k1": "v1"
                  }
                }  (t=+1.048[52](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:53)7294s)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x4000437e60] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1} with targets [], headerData "", err: rpc error: code = Unavailable desc = connection closed before server preface received  (t=+1.048758597s)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x4000437e60] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1}  (t=+1.048846198s)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x4000185bc0}  (t=+1.048937099s)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #[53](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:54)0 SubChannel #531] Subchannel Connectivity change to IDLE  (t=+1.139600009s)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #530] Channel Connectivity change to IDLE  (t=+1.139817412s)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x40003e6d20}  (t=+1.149314239s)
            tlogger.go:116: INFO control_channel.go:212 [rls] [rls-control-channel 0x4000238000] Sending RLS request {
                  "targetType": "grpc",
                  "reason": "REASON_MISS",
                  "keyMap": {
                    "k1": "v1"
                  }
                }  (t=+1.149895947s)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #530 SubChannel #531] Subchannel Connectivity change to CONNECTING  (t=+1.15014715s)
            tlogger.go:116: INFO clientconn.go:1212 [core] [Channel #530 SubChannel #531] Subchannel picks a new address "127.0.0.1:3[54](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:55)75" to connect  (t=+1.150298252s)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #530] Channel Connectivity change to CONNECTING  (t=+1.150720058s)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #530 SubChannel #531] Subchannel Connectivity change to READY  (t=+1.152216278s)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #530] Channel Connectivity change to READY  (t=+1.152507182s)
            tlogger.go:116: INFO control_channel.go:170 [rls] [rls-control-channel 0x4000238000] Connectivity state is READY  (t=+1.152615883s)
            tlogger.go:116: INFO picker.go:305 [rls] [rls-picker 0x40003e6d20] Received RLS response for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1} with targets [127.0.0.1:38063], headerData "", err: <nil>  (t=+1.1[55](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:56)632723s)
            tlogger.go:116: INFO picker.go:311 [rls] [rls-picker 0x40003e6d20] Removing pending request entry for key {path:/grpc.testing.TestService/EmptyCall keys:k1=v1}  (t=+1.155747825s)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x4000336600] New balancer.State: {ConnectivityState:READY Picker:0x400009f080}  (t=+1.155842226s)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x400016a800] New balancer.State: {ConnectivityState:READY Picker:0x4000185ec0}  (t=+1.395396623s)
            tlogger.go:116: INFO balancer.go:441 [rls] [rls-experimental-lb 0x400016aa00] New balancer.State: {ConnectivityState:READY Picker:0x40003e7[56](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:57)0}  (t=+1.515330324s)
            balancer_test.go:824: Timed out waiting for resetBackoffDone
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #529] Channel Connectivity change to SHUTDOWN  (t=+5.011408384s)
            tlogger.go:116: INFO control_channel.go:188 [rls] [rls-control-channel 0x4000238000] Closing control channel  (t=+5.011648387s)
            tlogger.go:116: INFO clientconn.go:418 [core] [Channel #530] Channel Connectivity change to SHUTDOWN  (t=+5.011755188s)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #530 SubChannel #531] Subchannel Connectivity change to SHUTDOWN  (t=+5.01187389s)
            tlogger.go:116: INFO clientconn.go:14[57](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:58) [core] [Channel #530 SubChannel #531] Subchannel deleted  (t=+5.011980691s)
            tlogger.go:116: INFO clientconn.go:1056 [core] [Channel #530] Channel deleted  (t=+5.012052792s)
            tlogger.go:116: INFO clientconn.go:1101 [core] [Channel #529 SubChannel #534] Subchannel Connectivity change to SHUTDOWN  (t=+5.012199794s)
            tlogger.go:116: INFO clientconn.go:1457 [core] [Channel #529 SubChannel #534] Subchannel deleted  (t=+5.012307396s)
            tlogger.go:116: INFO clientconn.go:1056 [core] [Channel #529] Channel deleted  (t=+5.012382997s)
            tlogger.go:116: INFO server.go:737 [core] [Server #526 ListenSocket #528] ListenSocket deleted  (t=+5.012814403s)
            tlogger.go:116: INFO server.go:737 [core] [Server #525 ListenSocket #527] ListenSocket deleted  (t=+5.01308[63](https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true#step:8:64)06s)
    FAIL
    FAIL	google.golang.org/grpc/balancer/rls
    

    https://github.com/grpc/grpc-go/runs/7033783730?check_suite_focus=true

    P2 Type: Testing 
    opened by easwars 0
  • Flaky test: EDS_TwoLocalities

    Flaky test: EDS_TwoLocalities

    https://github.com/grpc/grpc-go/runs/7028911480?check_suite_focus=true

    Test log:
    --- FAIL: Test (4.47s)
        --- FAIL: Test/EDS_TwoLocalities (1.17s)
            tlogger.go:116: INFO clusterresolver.go:81 [xds] [xds-cluster-resolver-lb 0xc00017e380] Created  (t=+67.003µs)
            tlogger.go:116: INFO clusterresolver.go:159 [xds] [xds-cluster-resolver-lb 0xc00017e380] Receive update from resolver, balancer config: {
                  "discoveryMechanisms": [
                    {
                      "cluster": "test-cluster-name",
                      "outlierDetection": {}
                    }
                  ]
                }  (t=+273.214µs)
            tlogger.go:116: INFO resource_resolver.go:257 [xds] [xds-cluster-resolver-lb 0xc00017e380] EDS watch started on test-cluster-name  (t=+371.219µs)
            tlogger.go:116: INFO clusterresolver.go:191 [xds] [xds-cluster-resolver-lb 0xc00017e380] resource update: [
                  {}
                ]  (t=+457.023µs)
            tlogger.go:116: INFO balancer.go:66 [xds] [priority-lb 0xc00025e070] Created  (t=+567.129µs)
            tlogger.go:116: INFO configbuilder.go:311 [xds] xds lb policy is "round_robin", building config with weighted_target + round_robin  (t=+621.332µs)
            tlogger.go:116: INFO clusterresolver.go:223 [xds] [xds-cluster-resolver-lb 0xc00017e380] build balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"I\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+1.509678ms)
            tlogger.go:116: INFO balancer.go:108 [xds] [priority-lb 0xc00025e070] Received update from resolver, balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"I\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+1.843895ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: , priority-0-0,   (t=+2.460727ms)
            balancer.go:147: testClientConn: UpdateState({CONNECTING 0xc00025a7a0})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+2.545131ms)
            tlogger.go:116: INFO balancergroup.go:100 [xds] [priority-lb 0xc00025e070] Creating child policy of type xds_cluster_impl_experimental  (t=+2.586333ms)
            tlogger.go:116: INFO clusterimpl.go:73 [xds] [xds-cluster-impl-lb 0xc0004086c0] Created  (t=+2.732641ms)
            tlogger.go:116: INFO clusterimpl.go:224 [xds] [xds-cluster-impl-lb 0xc0004086c0] Received update from resolver, balancer config: {
                  "cluster": "test-cluster-name",
                  "childPolicy": [
                    {
                      "weighted_target_experimental": {
                        "targets": {
                          "{\"subZone\":\"I\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          }
                        }
                      }
                    }
                  ]
                }  (t=+2.950552ms)
            tlogger.go:116: INFO weightedtarget.go:59 [xds] [weighted-target-lb 0xc00037cba0] Created  (t=+3.034357ms)
            tlogger.go:116: INFO weightedtarget.go:84 [xds] [weighted-target-lb 0xc00037cba0] Received update from resolver, balancer config: {
                  "targets": {
                    "{\"subZone\":\"I\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    }
                  }
                }  (t=+3.139362ms)
            tlogger.go:116: INFO balancergroup.go:100 [xds] [weighted-target-lb 0xc00037cba0] Creating child policy of type round_robin  (t=+3.195765ms)
            balancer.go:113: testClientConn: NewSubConn([{
                  "Addr": "0.0.0.0:0",
                  "ServerName": "",
                  "Attributes": {},
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }], {CredsBundle:<nil> HealthCheckEnabled:true}) => sc0
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[]}  (t=+3.373674ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"I"}, new state: {ConnectivityState:CONNECTING Picker:0xc00025add0}  (t=+3.419477ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc00025add0,state:CONNECTING,stateToAggregate:CONNECTING]  (t=+3.47628ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0xc0002e68c0}  (t=+3.569484ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"I"}, new state: {ConnectivityState:CONNECTING Picker:0xc00025add0}  (t=+3.67679ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc00025add0,state:CONNECTING,stateToAggregate:CONNECTING]  (t=+3.781395ms)
            tlogger.go:116: INFO clusterresolver.go:191 [xds] [xds-cluster-resolver-lb 0xc00017e380] resource update: [
                  {}
                ]  (t=+3.837198ms)
            tlogger.go:116: INFO configbuilder.go:311 [xds] xds lb policy is "round_robin", building config with weighted_target + round_robin  (t=+3.883701ms)
            tlogger.go:116: INFO clusterresolver.go:223 [xds] [xds-cluster-resolver-lb 0xc00017e380] build balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"I\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+4.821249ms)
            tlogger.go:116: INFO balancer.go:108 [xds] [priority-lb 0xc00025e070] Received update from resolver, balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"I\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+5.211569ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+5.334876ms)
            balancer.go:147: testClientConn: UpdateState({CONNECTING 0xc0002e68c0})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+5.40758ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0xc0002e6af0}  (t=+5.466683ms)
            tlogger.go:116: INFO clusterimpl.go:224 [xds] [xds-cluster-impl-lb 0xc0004086c0] Received update from resolver, balancer config: {
                  "cluster": "test-cluster-name",
                  "childPolicy": [
                    {
                      "weighted_target_experimental": {
                        "targets": {
                          "{\"subZone\":\"I\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          },
                          "{\"subZone\":\"II\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          }
                        }
                      }
                    }
                  ]
                }  (t=+5.708395ms)
            tlogger.go:116: INFO weightedtarget.go:84 [xds] [weighted-target-lb 0xc00037cba0] Received update from resolver, balancer config: {
                  "targets": {
                    "{\"subZone\":\"I\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    },
                    "{\"subZone\":\"II\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    }
                  }
                }  (t=+5.873804ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[]}  (t=+5.953808ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"I"}, new state: {ConnectivityState:CONNECTING Picker:0xc00025ba30}  (t=+5.99701ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc00025ba30,state:CONNECTING,stateToAggregate:CONNECTING]  (t=+6.049513ms)
            tlogger.go:116: INFO balancergroup.go:100 [xds] [weighted-target-lb 0xc00037cba0] Creating child policy of type round_robin  (t=+6.143018ms)
            balancer.go:113: testClientConn: NewSubConn([{
                  "Addr": "1.1.1.1:1",
                  "ServerName": "",
                  "Attributes": {},
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }], {CredsBundle:<nil> HealthCheckEnabled:true}) => sc1
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[]}  (t=+6.299526ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"II"}, new state: {ConnectivityState:CONNECTING Picker:0xc00025bcf0}  (t=+6.341228ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc00025ba30,state:CONNECTING,stateToAggregate:CONNECTING {"subZone":"II"}:weight:1,picker:0xc00025bcf0,state:CONNECTING,stateToAggregate:CONNECTING]  (t=+6.401831ms)
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+6.483835ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00037cd40:{{
                  "Addr": "0.0.0.0:0",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+6.603241ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"I"}, new state: {ConnectivityState:READY Picker:0xc0004d65d0}  (t=+6.663945ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc0004d65d0,state:READY,stateToAggregate:READY {"subZone":"II"}:weight:1,picker:0xc00025bcf0,state:CONNECTING,stateToAggregate:CONNECTING]  (t=+6.729048ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"II"}, new state: {ConnectivityState:CONNECTING Picker:0xc00025bcf0}  (t=+6.788751ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc0004d65d0,state:READY,stateToAggregate:READY {"subZone":"II"}:weight:1,picker:0xc00025bcf0,state:CONNECTING,stateToAggregate:CONNECTING]  (t=+6.847154ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00037d6c0:{{
                  "Addr": "1.1.1.1:1",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+6.95216ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"II"}, new state: {ConnectivityState:READY Picker:0xc0004d6870}  (t=+7.000362ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc0004d65d0,state:READY,stateToAggregate:READY {"subZone":"II"}:weight:1,picker:0xc0004d6870,state:READY,stateToAggregate:READY]  (t=+7.058865ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0xc0002e7220}  (t=+7.14927ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0xc0002e7270}  (t=+7.211573ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+7.269276ms)
            balancer.go:147: testClientConn: UpdateState({CONNECTING 0xc0002e7220})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+7.367781ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+7.405383ms)
            balancer.go:147: testClientConn: UpdateState({CONNECTING 0xc0002e7270})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+7.461986ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc0002e72c0}  (t=+7.552691ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc0002e7310}  (t=+7.611294ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+7.666197ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc0002e72c0})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+7.737ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+7.776602ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc0002e7310})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+7.831105ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc0002e7360}  (t=+7.972612ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+8.032616ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc0002e7360})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+8.103719ms)
            tlogger.go:116: INFO clusterresolver.go:191 [xds] [xds-cluster-resolver-lb 0xc00017e380] resource update: [
                  {}
                ]  (t=+8.262127ms)
            tlogger.go:116: INFO configbuilder.go:311 [xds] xds lb policy is "round_robin", building config with weighted_target + round_robin  (t=+8.325331ms)
            tlogger.go:116: INFO clusterresolver.go:223 [xds] [xds-cluster-resolver-lb 0xc00017e380] build balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"I\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"III\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+9.47369ms)
            tlogger.go:116: INFO balancer.go:108 [xds] [priority-lb 0xc00025e070] Received update from resolver, balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"I\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"III\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+9.950215ms)
            tlogger.go:116: INFO clusterimpl.go:224 [xds] [xds-cluster-impl-lb 0xc0004086c0] Received update from resolver, balancer config: {
                  "cluster": "test-cluster-name",
                  "childPolicy": [
                    {
                      "weighted_target_experimental": {
                        "targets": {
                          "{\"subZone\":\"I\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          },
                          "{\"subZone\":\"II\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          },
                          "{\"subZone\":\"III\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          }
                        }
                      }
                    }
                  ]
                }  (t=+10.387637ms)
            tlogger.go:116: INFO weightedtarget.go:84 [xds] [weighted-target-lb 0xc00037cba0] Received update from resolver, balancer config: {
                  "targets": {
                    "{\"subZone\":\"I\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    },
                    "{\"subZone\":\"II\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    },
                    "{\"subZone\":\"III\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    }
                  }
                }  (t=+10.657251ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00037cd40:{{
                  "Addr": "0.0.0.0:0",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+10.81726ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"I"}, new state: {ConnectivityState:READY Picker:0xc0004d7b60}  (t=+10.872363ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc0004d7b60,state:READY,stateToAggregate:READY {"subZone":"II"}:weight:1,picker:0xc0004d6870,state:READY,stateToAggregate:READY]  (t=+10.943466ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00003c460}  (t=+11.02407ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00037d6c0:{{
                  "Addr": "1.1.1.1:1",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+11.156877ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"II"}, new state: {ConnectivityState:READY Picker:0xc0004d7d40}  (t=+11.21148ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc0004d7b60,state:READY,stateToAggregate:READY {"subZone":"II"}:weight:1,picker:0xc0004d7d40,state:READY,stateToAggregate:READY]  (t=+11.272683ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00003c4b0}  (t=+11.347387ms)
            tlogger.go:116: INFO balancergroup.go:100 [xds] [weighted-target-lb 0xc00037cba0] Creating child policy of type round_robin  (t=+11.40219ms)
            balancer.go:113: testClientConn: NewSubConn([{
                  "Addr": "2.2.2.2:2",
                  "ServerName": "",
                  "Attributes": {},
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }], {CredsBundle:<nil> HealthCheckEnabled:true}) => sc2
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[]}  (t=+11.5906ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"III"}, new state: {ConnectivityState:CONNECTING Picker:0xc000177630}  (t=+11.635802ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc0004d7b60,state:READY,stateToAggregate:READY {"subZone":"II"}:weight:1,picker:0xc0004d7d40,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc000177630,state:CONNECTING,stateToAggregate:CONNECTING]  (t=+11.711506ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc0002e7d60}  (t=+11.811911ms)
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+11.899816ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+11.959519ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc0002e7d60})
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"III"}, new state: {ConnectivityState:CONNECTING Picker:0xc000177630}  (t=+12.037123ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc0004d7b60,state:READY,stateToAggregate:READY {"subZone":"II"}:weight:1,picker:0xc0004d7d40,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc000177630,state:CONNECTING,stateToAggregate:CONNECTING]  (t=+12.143228ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00007ecc0:{{
                  "Addr": "2.2.2.2:2",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+12.294636ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"III"}, new state: {ConnectivityState:READY Picker:0xc0004bc480}  (t=+12.342739ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"I"}:weight:1,picker:0xc0004d7b60,state:READY,stateToAggregate:READY {"subZone":"II"}:weight:1,picker:0xc0004d7d40,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc0004bc480,state:READY,stateToAggregate:READY]  (t=+12.410742ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00011c870}  (t=+12.465545ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00011c8c0}  (t=+12.515948ms)
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+12.637254ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+12.684556ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc00011c870})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+12.74996ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+12.892167ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc00011c8c0})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+12.957971ms)
            tlogger.go:116: INFO clusterresolver.go:191 [xds] [xds-cluster-resolver-lb 0xc00017e380] resource update: [
                  {}
                ]  (t=+13.123779ms)
            tlogger.go:116: INFO configbuilder.go:311 [xds] xds lb policy is "round_robin", building config with weighted_target + round_robin  (t=+13.173782ms)
            tlogger.go:116: INFO clusterresolver.go:223 [xds] [xds-cluster-resolver-lb 0xc00017e380] build balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"III\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+14.041727ms)
            tlogger.go:116: INFO balancer.go:108 [xds] [priority-lb 0xc00025e070] Received update from resolver, balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"III\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+14.384744ms)
            tlogger.go:116: INFO clusterimpl.go:224 [xds] [xds-cluster-impl-lb 0xc0004086c0] Received update from resolver, balancer config: {
                  "cluster": "test-cluster-name",
                  "childPolicy": [
                    {
                      "weighted_target_experimental": {
                        "targets": {
                          "{\"subZone\":\"II\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          },
                          "{\"subZone\":\"III\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          }
                        }
                      }
                    }
                  ]
                }  (t=+14.640958ms)
            tlogger.go:116: INFO weightedtarget.go:84 [xds] [weighted-target-lb 0xc00037cba0] Received update from resolver, balancer config: {
                  "targets": {
                    "{\"subZone\":\"II\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    },
                    "{\"subZone\":\"III\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    }
                  }
                }  (t=+14.806566ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00007ecc0:{{
                  "Addr": "2.2.2.2:2",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+14.953974ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"III"}, new state: {ConnectivityState:READY Picker:0xc0002e4ea0}  (t=+15.008177ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:1,picker:0xc0004d7d40,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc0002e4ea0,state:READY,stateToAggregate:READY]  (t=+15.07378ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00037d6c0:{{
                  "Addr": "1.1.1.1:1",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+15.180886ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"II"}, new state: {ConnectivityState:READY Picker:0xc0002e50e0}  (t=+15.230988ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:1,picker:0xc0002e50e0,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc0002e4ea0,state:READY,stateToAggregate:READY]  (t=+15.290091ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:1,picker:0xc0002e50e0,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc0002e4ea0,state:READY,stateToAggregate:READY]  (t=+15.352995ms)
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+15.407597ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00003ceb0}  (t=+15.4636ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00003cf00}  (t=+15.519403ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00003cf50}  (t=+15.567906ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+15.613808ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc00003ceb0})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+15.665211ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+15.697712ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc00003cf00})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+15.760716ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+15.795018ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc00003cf50})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+15.84532ms)
            balancer.go:129: testClientConn: RemoveSubConn(sc0)
            tlogger.go:116: INFO clusterresolver.go:191 [xds] [xds-cluster-resolver-lb 0xc00017e380] resource update: [
                  {}
                ]  (t=+115.48068ms)
            tlogger.go:116: INFO configbuilder.go:311 [xds] xds lb policy is "round_robin", building config with weighted_target + round_robin  (t=+115.551584ms)
            tlogger.go:116: INFO clusterresolver.go:223 [xds] [xds-cluster-resolver-lb 0xc00017e380] build balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"III\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+116.535835ms)
            tlogger.go:116: INFO balancer.go:108 [xds] [priority-lb 0xc00025e070] Received update from resolver, balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"III\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+117.012559ms)
            tlogger.go:116: INFO clusterimpl.go:224 [xds] [xds-cluster-impl-lb 0xc0004086c0] Received update from resolver, balancer config: {
                  "cluster": "test-cluster-name",
                  "childPolicy": [
                    {
                      "weighted_target_experimental": {
                        "targets": {
                          "{\"subZone\":\"II\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          },
                          "{\"subZone\":\"III\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          }
                        }
                      }
                    }
                  ]
                }  (t=+117.305875ms)
            tlogger.go:116: INFO weightedtarget.go:84 [xds] [weighted-target-lb 0xc00037cba0] Received update from resolver, balancer config: {
                  "targets": {
                    "{\"subZone\":\"II\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    },
                    "{\"subZone\":\"III\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    }
                  }
                }  (t=+117.489284ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00037d6c0:{{
                  "Addr": "1.1.1.1:1",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+117.640692ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"II"}, new state: {ConnectivityState:READY Picker:0xc0001fb5f0}  (t=+117.706795ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:1,picker:0xc0001fb5f0,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc0002e4ea0,state:READY,stateToAggregate:READY]  (t=+117.779199ms)
            balancer.go:113: testClientConn: NewSubConn([{
                  "Addr": "3.3.3.3:3",
                  "ServerName": "",
                  "Attributes": {},
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }], {CredsBundle:<nil> HealthCheckEnabled:true}) => sc3
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00007ecc0:{{
                  "Addr": "2.2.2.2:2",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+118.009111ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"III"}, new state: {ConnectivityState:READY Picker:0xc0001fb8c0}  (t=+118.061114ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:1,picker:0xc0001fb5f0,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc0001fb8c0,state:READY,stateToAggregate:READY]  (t=+118.126217ms)
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+118.19072ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc0003e4b40}  (t=+118.260424ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc0003e4b90}  (t=+118.314927ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+118.37243ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc0003e4b40})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+118.434433ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+118.476935ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc0003e4b90})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+118.529238ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"III"}, new state: {ConnectivityState:READY Picker:0xc0001fb8c0}  (t=+118.585841ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:1,picker:0xc0001fb5f0,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc0001fb8c0,state:READY,stateToAggregate:READY]  (t=+118.652344ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00007ecc0:{{
                  "Addr": "2.2.2.2:2",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }} 0xc00007fb40:{{
                  "Addr": "3.3.3.3:3",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+118.820953ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"III"}, new state: {ConnectivityState:READY Picker:0xc0001fbf20}  (t=+118.875956ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:1,picker:0xc0001fb5f0,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc0001fbf20,state:READY,stateToAggregate:READY]  (t=+118.933959ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc0003e4e60}  (t=+118.989762ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc0003e4eb0}  (t=+119.039564ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+119.203073ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc0003e4e60})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+119.263876ms)
            tlogger.go:116: WARNING balancer_priority.go:87 [xds] ciu, cn, cu: priority-0-0, priority-0-0, priority-0-0  (t=+119.295278ms)
            balancer.go:147: testClientConn: UpdateState({READY 0xc0003e4eb0})
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+119.34608ms)
            tlogger.go:116: INFO clusterresolver.go:191 [xds] [xds-cluster-resolver-lb 0xc00017e380] resource update: [
                  {}
                ]  (t=+119.579992ms)
            tlogger.go:116: INFO configbuilder.go:311 [xds] xds lb policy is "round_robin", building config with weighted_target + round_robin  (t=+119.630695ms)
            tlogger.go:116: INFO clusterresolver.go:223 [xds] [xds-cluster-resolver-lb 0xc00017e380] build balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 2,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"III\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+120.543242ms)
            tlogger.go:116: INFO balancer.go:108 [xds] [priority-lb 0xc00025e070] Received update from resolver, balancer config: {
                  "children": {
                    "priority-0-0": {
                      "config": [
                        {
                          "xds_cluster_impl_experimental": {
                            "cluster": "test-cluster-name",
                            "childPolicy": [
                              {
                                "weighted_target_experimental": {
                                  "targets": {
                                    "{\"subZone\":\"II\"}": {
                                      "weight": 2,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    },
                                    "{\"subZone\":\"III\"}": {
                                      "weight": 1,
                                      "childPolicy": [
                                        {
                                          "round_robin": {}
                                        }
                                      ]
                                    }
                                  }
                                }
                              }
                            ]
                          }
                        }
                      ],
                      "ignoreReresolutionRequests": true
                    }
                  },
                  "priorities": [
                    "priority-0-0"
                  ]
                }  (t=+120.906361ms)
            tlogger.go:116: INFO clusterimpl.go:224 [xds] [xds-cluster-impl-lb 0xc0004086c0] Received update from resolver, balancer config: {
                  "cluster": "test-cluster-name",
                  "childPolicy": [
                    {
                      "weighted_target_experimental": {
                        "targets": {
                          "{\"subZone\":\"II\"}": {
                            "weight": 2,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          },
                          "{\"subZone\":\"III\"}": {
                            "weight": 1,
                            "childPolicy": [
                              {
                                "round_robin": {}
                              }
                            ]
                          }
                        }
                      }
                    }
                  ]
                }  (t=+121.172975ms)
            tlogger.go:116: INFO weightedtarget.go:84 [xds] [weighted-target-lb 0xc00037cba0] Received update from resolver, balancer config: {
                  "targets": {
                    "{\"subZone\":\"II\"}": {
                      "weight": 2,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    },
                    "{\"subZone\":\"III\"}": {
                      "weight": 1,
                      "childPolicy": [
                        {
                          "round_robin": {}
                        }
                      ]
                    }
                  }
                }  (t=+122.059721ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00037d6c0:{{
                  "Addr": "1.1.1.1:1",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+122.211429ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"II"}, new state: {ConnectivityState:READY Picker:0xc00031e4b0}  (t=+122.270532ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:2,picker:0xc00031e4b0,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc0001fbf20,state:READY,stateToAggregate:READY]  (t=+122.336735ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00003cfa0}  (t=+123.682105ms)
            tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0xc00007ecc0:{{
                  "Addr": "2.2.2.2:2",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }} 0xc00007fb40:{{
                  "Addr": "3.3.3.3:3",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": {},
                  "Type": 0,
                  "Metadata": null
                }}]}  (t=+125.117679ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [weighted-target-lb 0xc00037cba0] Balancer state update from locality {"subZone":"III"}, new state: {ConnectivityState:READY Picker:0xc00031f0b0}  (t=+125.190983ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:2,picker:0xc00031e4b0,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc00031f0b0,state:READY,stateToAggregate:READY]  (t=+125.261187ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00003d040}  (t=+125.349191ms)
            tlogger.go:116: INFO aggregator.go:201 [xds] [weighted-target-lb 0xc00037cba0] Child pickers with config: map[{"subZone":"II"}:weight:2,picker:0xc00031e4b0,state:READY,stateToAggregate:READY {"subZone":"III"}:weight:1,picker:0xc00031f0b0,state:READY,stateToAggregate:READY]  (t=+125.426195ms)
            tlogger.go:116: INFO balancergroup.go:499 [xds] [priority-lb 0xc00025e070] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc00003d130}  (t=+125.587003ms)
            tlogger.go:116: INFO balancer_priority.go:92 [xds] [priority-lb 0xc00025e070] switching to ("priority-0-0", 0) in syncPriority  (t=+125.669908ms)
            eds_impl_test.go:296: timeout waiting for picker with expected behavior, error from previous picker: <nil>
            tlogger.go:116: INFO resource_resolver.go:274 [xds] [xds-cluster-resolver-lb 0xc00017e380] EDS watch canceled on test-cluster-name  (t=+1.1204[188](https://github.com/grpc/grpc-go/runs/7028911480?check_suite_focus=true#step:8:189)24s)
            balancer.go:129: testClientConn: RemoveSubConn(sc2)
            balancer.go:129: testClientConn: RemoveSubConn(sc3)
            balancer.go:129: testClientConn: RemoveSubConn(sc1)
            tlogger.go:116: INFO clusterimpl.go:336 [xds] [xds-cluster-impl-lb 0xc0004086c0] Shutdown  (t=+1.1[205](https://github.com/grpc/grpc-go/runs/7028911480?check_suite_focus=true#step:8:206)89133s)
            balancer.go:129: testClientConn: RemoveSubConn(sc3)
            balancer.go:129: testClientConn: RemoveSubConn(sc1)
            balancer.go:129: testClientConn: RemoveSubConn(sc2)
            tlogger.go:116: INFO clusterresolver.go:311 [xds] [xds-cluster-resolver-lb 0xc00017e380] Shutdown  (t=+1.1[207](https://github.com/grpc/grpc-go/runs/7028911480?check_suite_focus=true#step:8:208)0[343](https://github.com/grpc/grpc-go/runs/7028911480?check_suite_focus=true#step:8:344)9s)
    FAIL
    FAIL	google.golang.org/grpc/xds/internal/balancer/clusterresolver	8.[544](https://github.com/grpc/grpc-go/runs/7028911480?check_suite_focus=true#step:8:545)s
    
    P2 Type: Testing 
    opened by easwars 0
Releases(v1.47.0)
  • v1.47.0(May 31, 2022)

    New Features

    • xds: add support for RBAC metadata invert matchers (#5345)

    Bug Fixes

    • client: fix a context leaked if a connection to an address is lost before it is fully established (#5337)
      • Special Thanks: @carzil
    • client: fix potential panic during RPC retries (#5323)
    • xds/client: fix a potential concurrent map read/write in load reporting (#5331)
    • client/SubConn: do not recreate addrConn if UpdateAddresses is called with the same addresses (#5373)
    • xds/eds: resources containing duplicate localities with the same priority will be rejected (#5303)
    • server: return Canceled or DeadlineExceeded status code when writing headers to a stream that is already closed (#5292)
      • Special Thanks: @idiamond-stripe

    Behavior Changes

    • xds/priority: start the init timer when a child switches to Connecting from non-failure states (#5334)
    • server: respond with HTTP Status 405 and gRPC status INTERNAL if the method sent to server is not POST (#5364)

    Documentation

    • server: clarify documentation around setting and sending headers and ServerStream errors (#5302)
    Source code(tar.gz)
    Source code(zip)
  • v1.46.2(May 13, 2022)

  • v1.46.0(Apr 22, 2022)

    New Features

    • server: Support setting TCP_USER_TIMEOUT on grpc.Server connections using keepalive.ServerParameters.Time (#5219)
      • Special Thanks: @bonnefoa
    • client: perform graceful switching of LB policies in the ClientConn by default (#5285)
    • all: improve logging by including channelz identifier in log messages (#5192)

    API Changes

    • grpc: delete WithBalancerName() API, deprecated over 4 years ago in #1697 (#5232)
    • balancer: change BuildOptions.ChannelzParentID to an opaque identifier instead of int (#5192)
      • Note: the balancer package is labeled as EXPERIMENTAL, and we don't believe users were using this field.

    Behavior Changes

    • client: change connectivity state to TransientFailure in pick_first LB policy when all addresses are removed (#5274)
      • This is a minor change that brings grpc-go's behavior in line with the intended behavior and how C and Java behave.
    • metadata: add client-side validation of HTTP-invalid metadata before attempting to send (#4886)
      • Special Thanks: @Patrick0308

    Bug Fixes

    • metadata: make a copy of the value slices in FromContext() functions so that modifications won't be made to the original copy (#5267)
    • client: handle invalid service configs by applying the default, if applicable (#5238)
    • xds: the xds client will now apply a 1 second backoff before recreating ADS or LRS streams (#5280)

    Dependencies

    • Upgrade security/authorization module dependencies to https://github.com/google/cel-go v0.10.1 and others (#5243)
      • Special Thanks: @TristonianJones
    Source code(tar.gz)
    Source code(zip)
  • v1.45.0(Mar 9, 2022)

    Bug Fixes

    • xds/clusterresolver: pass cluster name to DNS child policy to be used in creds handshake (#5119)
    • reflection: support dynamic messages (#5180)
      • Special Thanks: @codebutler

    Performance Improvements

    • wrr: improve randomWRR performance (#5067)
      • Special Thanks: @huangchong94

    Behavior Changes

    • server: convert context errors returned by service handlers to status with the correct status code (Canceled or DeadlineExceeded), instead of Unknown (#5156)

    New Features

    • reflection: add NewServer(ServerOptions) for creating a reflection server with advanced customizations (#5197)
    • xds: support federation (#5128)
    • xds/resource: accept Self as LDS's RDS config source and CDS's EDS config source (#5152)
    • xds/bootstrap: add plugin system for credentials specified in bootstrap file (#5136)
    Source code(tar.gz)
    Source code(zip)
  • v1.44.0(Jan 25, 2022)

    New Features

    • balancer: add RLS load balancing policy (#5046)
    • xds: add RLS Cluster Specifier Plugin (#5004)
    • insecure: remove experimental notice (#5069)

    Bug Fixes

    • internal/balancergroup: eliminate race in exitIdle (#5012)
    • authz: fix regex expression match (#5035)

    Documentation

    • grpc: minor improvement on WithInsecure() document (#5068)
      • Special Thanks: @shitian-ni
    • attributes: document that some value types (e.g. maps) must implement Equal (#5109)
    • dialoptions.go: Fix WithBlock godoc (#5073)
      • Special Thanks: @sgreene570
    • grpclog.DepthLoggerV2: Correct comment: formats like fmt.Println (#5038)
      • Special Thanks: @evanj
    Source code(tar.gz)
    Source code(zip)
  • cmd/protoc-gen-go-grpc/v1.2.0(Dec 21, 2021)

    New Features

    • Add protoc and protoc-gen-go-grpc versions to top comment

    Bug Fixes

    • update google.golang.org/protobuf to v1.27.1 to fix package name generation on macOS
      • NOTE: this includes a behavior change in the protobuf package: https://github.com/protocolbuffers/protobuf-go/releases/tag/v1.26.0#user-content-v1.26-require-import-path
    Source code(tar.gz)
    Source code(zip)
    protoc-gen-go-grpc.v1.2.0.darwin.amd64.tar.gz(3.83 MB)
    protoc-gen-go-grpc.v1.2.0.linux.386.tar.gz(3.79 MB)
    protoc-gen-go-grpc.v1.2.0.linux.amd64.tar.gz(3.89 MB)
    protoc-gen-go-grpc.v1.2.0.windows.386.tar.gz(3.89 MB)
    protoc-gen-go-grpc.v1.2.0.windows.amd64.tar.gz(3.96 MB)
  • v1.43.0(Dec 14, 2021)

    API Changes

    • grpc: stabilize WithConnectParams DialOption (#4915)
      • Special Thanks: @hypnoglow

    Behavior Changes

    • status: support wrapped errors in FromContextError (#4977)
      • Special Thanks: @bestbeforetoday
    • config: remove the environment variable to disable retry support (#4922)

    New Features

    • balancer: new field Authority in BuildOptions for server name to use in the authentication handshake with a remote load balancer (#4969)

    Bug Fixes

    • xds/resolver: fix possible ClientConn leak upon resolver initialization failure (#4900)
    • client: fix nil panic in rare race conditions with the pick first LB policy (#4971)
    • xds: improve RPC error messages when xDS connection errors occur (#5032, #5054)
    • transport: do not create stream object in the face of illegal stream IDs (#4873)
      • Special Thanks: @uds5501

    Documentation

    • client: clarify errors to indicate whether compressed or uncompressed messages exceeded size limits (#4918)
      • Special Thanks: @uds5501
    Source code(tar.gz)
    Source code(zip)
  • v1.41.1(Dec 1, 2021)

    • creds/google: add NewDefaultCredentialsWithOptions() to support custom per-RPC creds (#4767, #4830)
    • pickfirst: check b.sc before calling Connect (#4971)
    Source code(tar.gz)
    Source code(zip)
  • v1.40.1(Dec 1, 2021)

  • v1.42.0(Nov 2, 2021)

    Behavior Changes

    • grpc: Dial("unix://relative-path") no longer works (#4817)
      • use "unix://absolute-path" or "unix:relative-path" instead in accordance with our documentation
    • xds/csds: use new field GenericXdsConfig instead of PerXdsConfig (#4898)
    • transport: server transport will reject requests with connection header (#4803)

    New Features

    • grpc: support grpc.WithAuthority when secure credentials are used (#4817)
    • creds/google: add NewDefaultCredentialsWithOptions() to support custom per-RPC creds (#4767, #4830)
    • authz: create file watcher interceptor for gRPC SDK API (#4760)
    • attributes: add Equal method (#4855)
    • resolver: add AddressMap and State.BalancerAttributes (#4855)
    • resolver: Add URL field to Target to store parsed dial target (#4817)
    • grpclb: add a target_name field to lb config to specify target when used as a child policy (#4847)
    • grpclog: support formatting log output as JSON (#4854)

    Bug Fixes

    • server: add missing conn.Close if the connection dies before reading the HTTP/2 preface (#4837)
    • grpclb: recover if addresses are received after an empty server list was received previously (#4879)
    • authz: support empty principals and fix rbac authenticated matcher (#4883)
    • xds/rds: NACK the RDS response if it contains unknown cluster specifier (#4788)
    • xds/priority: do not switch to low priority when high priority is in Idle (e.g. ringhash) (#4889)

    Documentation

    • grpc: stabilize WithDefaultServiceConfig and improve godoc (#4888)
    • status: clarify FromError docstring (#4880)
    • examples: add example illustrating the use of unix abstract sockets (#4848)
    • examples: update load balancing example to use loadBalancingConfig (#4887)
    • doc: promote WithDisableRetry to stable; clarify retry is enabled by default (#4901)

    API Changes

    • credentials: Mark TransportCredentials.OverrideServerName method as deprecated (#4817)
    Source code(tar.gz)
    Source code(zip)
  • v1.41.0(Sep 24, 2021)

    API Changes

    • xds: Promote xds server and creds APIs to stable (#4753)
    • balancer: add ExitIdle interface to instruct the balancer to attempt to leave the IDLE state by connecting SubConns if appropriate. (#4673)
      • NOTICE: This method will be required by the Balancer interface in the future

    Behavior Changes

    • xds: update xdsclient to keep valid resources from the response even if it has invalid responses and is NACK'ed (see gRFC 260) (#4743)
    • balancer: SubConns no longer automatically reconnect after READY; instead they transition to IDLE on connection loss (#4613)

    New Features

    • xds: add support for RINGHASH lb-policy and affinity (#4741)
    • xds: add support for retry policy in VirtualHosts and Routes (#4738)
    • stats: support stats for all retry attempts; support transparent retry (#4749)
    • authz: create interceptors for gRPC security policy API (#4664)

    Bug Fixes

    • transport: fix race in transport stream accessing s.recvCompress (#4641)
    • client: fix transparent retries when per-RPC credentials are in use (#4785)
    • server: fix bug that net.Conn is leaked if the connection is closed (io.EOF) immediately with no traffic (#4633)
    • oauth: Allow access to Google API regional endpoints via Google Default Credentials (#4713)
    Source code(tar.gz)
    Source code(zip)
  • v1.40.0(Aug 12, 2021)

    Behavior Changes

    • balancer: client channel no longer connects to idle subchannels that are returned by the pickers; LB policy should call SubConn.Connect instead. (#4579)
      • This change is in line with existing documentation stating the balancer must call Connect on idle SubConns in order for them to connect, and is preparation for an upcoming change that transitions SubConns to the idle state when connections are lost. See https://pkg.go.dev/google.golang.org/grpc/balancer#SubConn for more details.

    Bug Fixes

    • transport: fail RPCs without HTTP status 200 (OK), according to the gRPC spec (#4474)
      • Special Thanks: @JNProtzman
    • binarylog: fail the Write() method if proto marshaling fails (#4582)
      • Special Thanks: @Jille
    • binarylog: exit the flusher goroutine upon closing the bufferedSink (#4583)
      • Special Thanks: @Jille

    New Features

    • metadata: add Delete method to MD to encapsulate lowercasing (#4549)
      • Special Thanks: @konradreiche
    • xds/cds: support logical DNS cluster and aggregated cluster (#4594)
    • stats: add stats.Begin.IsClientStream and IsServerStream to indicate the type of RPC invoked (#4533)
      • Special Thanks: @leviska

    Performance Improvements

    • server: improve performance when multiple interceptors are used (#4524)
      • Special Thanks: @amenzhinsky
    Source code(tar.gz)
    Source code(zip)
  • v1.39.1(Aug 5, 2021)

    • server: fix bug that net.Conn is leaked if the connection is closed (io.EOF) immediately with no traffic (#4642)
    • transport: fix race in transport stream accessing s.recvCompress (#4627)
    Source code(tar.gz)
    Source code(zip)
  • v1.39.0(Jun 29, 2021)

    Behavior Changes

    • csds: return empty response if xds client is not set (#4505)
    • metadata: convert keys to lowercase in FromContext() (#4416)

    New Features

    • xds: add GetServiceInfo to GRPCServer (#4507)
      • Special Thanks: @amenzhinsky
    • xds: add test-only injection of xds config to client and server (#4476)
    • server: allow PreparedMsgs to work for server streams (#3480)
      • Special Thanks: @eafzali

    Performance Improvements

    • transport: remove decodeState from client & server to reduce allocations (#4423)
      • Special Thanks: @JNProtzman

    Bug Fixes

    • server: return UNIMPLEMENTED on receipt of malformed method name (#4464)
    • xds/rds: use 100 as default weighted cluster totalWeight instead of 0 (#4439)
      • Special Thanks: @alpha-baby
    • transport: unblock read throttling when controlbuf exits (#4447)
    • client: fix status code to return Unavailable for servers shutting down instead of Unknown (#4561)

    Documentation

    • doc: fix broken benchmark dashboard link in README.md (#4503)
      • Special Thanks: @laststem
    • example: improve hello world server with starting msg (#4468)
      • Special Thanks: @dkkb
    • client: Clarify that WaitForReady will block for CONNECTING channels (#4477)
      • Special Thanks: @evanj
    Source code(tar.gz)
    Source code(zip)
  • v1.38.1(Jun 29, 2021)

  • v1.38.0(May 19, 2021)

    API Changes

    • reflection: accept interface instead of grpc.Server struct in Register() (#4340)
    • resolver: add error return value from ClientConn.UpdateState (#4270)

    Behavior Changes

    • client: do not poll name resolver when errors or bad updates are reported (#4270)
    • transport: InTapHandle may return RPC status errors; no longer RST_STREAMs (#4365)

    New Features

    • client: propagate connection error causes to RPC status (#4311, #4316)
    • xds: support inline RDS resource from LDS response (#4299)
    • xds: server side support is now experimentally available
    • server: add ForceServerCodec() to set a custom encoding.Codec on the server (#4205)
      • Special Thanks: @ash2k

    Performance Improvements

    • metadata: reduce memory footprint in FromOutgoingContext (#4360)
      • Special Thanks: @irfansharif

    Bug Fixes

    • xds/balancergroup: fix rare memory leak after closing ClientConn (#4308)

    Documentation

    • examples: update xds examples for PSM security (#4256)
    • grpc: improve docs on StreamDesc (#4397)
    Source code(tar.gz)
    Source code(zip)
  • v1.37.1(May 11, 2021)

    • client: fix rare panic when shutting down client while receiving the first name resolver update (#4398)
    • client: fix leaked addrConn struct when addresses are updated (#4347)
    • xds/resolver: prevent panic when two LDS updates are receives without RDS in between (#4327)
    Source code(tar.gz)
    Source code(zip)
  • v1.37.0(Apr 7, 2021)

    API Changes

    • balancer: Add UpdateAddresses() to balancer.ClientConn interface (#4215)
      • NOTICE: balancer.SubConn.UpdateAddresses() is now deprecated and will be REMOVED in gRPC-Go 1.39

    Behavior Changes

    • balancer/base: keep address attributes for pickers (#4253)
      • Special Thanks: @longXboy

    New Features

    • xds: add support for csds (#4226, #4217, #4243)
    • admin: create admin package for conveniently registering standard admin services (#4274)
    • xds: add support for HTTP filters (gRFC A39) (#4206, #4221)
    • xds: implement fault injection HTTP filter (A33) (#4236)
    • xds: enable timeout, circuit breaking, and fault injection by default (#4286)
    • xds: implement a priority based load balancer (#4070)
    • xds/creds: support all SAN matchers on client-side (#4246)

    Bug Fixes

    • xds: add env var protection for client-side security (#4247)
    • circuit breaking: update picker inline when there's a counter update (#4212)
    • server: fail RPCs without POST HTTP method (#4241)
    Source code(tar.gz)
    Source code(zip)
  • v1.36.1(Mar 25, 2021)

  • v1.35.1(Mar 12, 2021)

  • v1.34.2(Mar 12, 2021)

  • v1.36.0(Feb 24, 2021)

    New Features

    • xds bootstrap: support config content in env variable (#4153)

    Bug Fixes

    • encoding/proto: do not panic when types do not match (#4218)

    Documentation

    • status: document nil error handling of FromError (#4196)
      • Special Thanks: @gauravgahlot
    Source code(tar.gz)
    Source code(zip)
  • v1.35.0(Jan 14, 2021)

    Behavior Changes

    • roundrobin: strip attributes from addresses (#4024)
    • balancer: set RPC metadata in address attributes, instead of Metadata field (#4041)

    New Features

    • support unix-abstract schema (#4079)
      • Special Thanks: @resec
    • xds: implement experimental RouteAction timeout support (#4116)
    • xds: Implement experimental circuit breaking support. (#4050)

    Bug Fixes

    • xds: server_features should be a child of xds_servers and not a sibling (#4087)
    • xds: NACK more invalid RDS responses (#4120)
    Source code(tar.gz)
    Source code(zip)
  • v1.34.1(Jan 11, 2021)

    • xds client: Updated v3 type for http connection manager (#4137)
    • lrs: use JSON for locality's String representation (#4135)
    • eds/lrs: handle nil when LRS is disabled (#4086)
    • client: fix "unix" scheme handling for some corner cases (#4021)
    Source code(tar.gz)
    Source code(zip)
  • v1.33.3(Jan 11, 2021)

    • xds client: Updated v3 type for http connection manager (#4137)
    • lrs: use JSON for locality's String representation (#4135)
    • eds/lrs: handle nil when LRS is disabled (#4086)
    Source code(tar.gz)
    Source code(zip)
  • v1.34.0(Dec 2, 2020)

    New Features

    • client: implement support for "unix" resolver scheme (#3890)
    • rds: allow case_insensitive path matching (#3997)
    • credentials/insecure: implement insecure credentials. (#3964)
    • lrs: handle multiple clusters in LRS stream (#3935)

    Performance Improvements

    • encoding/proto: simplify & optimize proto codec (#3958)

    Bug Fixes

    • internal/transport: fix a bug causing -bin metadata to be incorrectly encoded (#3985)
      • Special Thanks: @dntj
    • grpclb: consider IDLE SubConns as connecting (#4031)
    • grpclb: send custom user-agent (#4011)
    • client: use "localhost:port" as authority if target is ":port" (#4017)
    • credentials: fix PerRPCCredentials w/RequireTransportSecurity and security levels (#3995)

    Documentation

    • Documentation: fix outgoing metadata example code (#3979)
      • Special Thanks: @aaronjheng
    • Remove experimental comment from client interceptors (#3948)
      • Special Thanks: @hypnoglow
    • Documentation: update keepalive.md to add why (#3993)
    Source code(tar.gz)
    Source code(zip)
  • v1.33.2(Nov 6, 2020)

    • protobuf: update all generated code to google.golang.org/protobuf (#3932)
    • xdsclient: populate error details for NACK (#3975)
    • internal/credentials: fix a bug and add one more helper function SPIFFEIDFromCert (#3929)
    Source code(tar.gz)
    Source code(zip)
  • cmd/protoc-gen-go-grpc/v1.0.1(Oct 23, 2020)

    Bug Fixes

    • use grpc.ServiceRegistrar instead of *grpc.Server in Register<Service>Server functions
    • fix method name in interceptor info
      • Special Thanks: @ofpiyush

    Extra thanks to @sagikazarmark for setting up automation to attach binaries for Linux, Mac, and Windows to our releases.

    Source code(tar.gz)
    Source code(zip)
    protoc-gen-go-grpc.v1.0.1.darwin.amd64.tar.gz(4.04 MB)
    protoc-gen-go-grpc.v1.0.1.linux.386.tar.gz(4.02 MB)
    protoc-gen-go-grpc.v1.0.1.linux.amd64.tar.gz(4.09 MB)
    protoc-gen-go-grpc.v1.0.1.windows.386.tar.gz(4.04 MB)
    protoc-gen-go-grpc.v1.0.1.windows.amd64.tar.gz(4.12 MB)
  • v1.33.1(Oct 20, 2020)

    API Changes

    • connectivity: remove unused, experimental Reporter interface (#3875)

    New Features

    • xds bootstrap: support insecure and make Creds required (#3881)
    • xds: add bootstrap support for certificate providers. (#3901)
    • lrs: add a layer for clusters in load store (#3880)
    • credentials/xds: implementation of client-side xDS credentials. (#3888)

    Bug Fixes

    • http2_client: fix reader segfault on PROTOCOL_ERRORs (#3926)
      • Special Thanks: @sorah
    • internal/transport: handle h2 errcode on header decoding (#3872)
      • Special Thanks: @tz70s
    • xds: exit from run() goroutine when resolver is closed. (#3882)
    • credentials/alts: ClientAuthorizationCheck to case-fold compare of peer SA (#3792)
      • Special Thanks: @AntonNep
    • service reflection: include transitive closure for a file (#3851)
    • stats: include message header in stats.InPayload.WireLength (#3886)
      • Special Thanks: @xstephen95x
    • binarylog: export Sink (#3879)
    • service reflection: include transitive closure for a file (#3851)
    Source code(tar.gz)
    Source code(zip)
Owner
grpc
A high performance, open source, general-purpose RPC framework
grpc
Hprose is a cross-language RPC. This project is Hprose for Golang.

Hprose 3.0 for Golang Introduction Hprose is a High Performance Remote Object Service Engine. It is a modern, lightweight, cross-language, cross-platf

Hprose 1.2k Jun 17, 2022
A Go library for master-less peer-to-peer autodiscovery and RPC between HTTP services

sleuth sleuth is a Go library that provides master-less peer-to-peer autodiscovery and RPC between HTTP services that reside on the same network. It w

null 352 Jun 21, 2022
Take control of your data, connect with anything, and expose it anywhere through protocols such as HTTP, GraphQL, and gRPC.

Semaphore Chat: Discord Documentation: Github pages Go package documentation: GoDev Take control of your data, connect with anything, and expose it an

Jexia.com 74 May 22, 2022
Simple, fast and scalable golang rpc library for high load

gorpc Simple, fast and scalable golang RPC library for high load and microservices. Gorpc provides the following features useful for highly loaded pro

Aliaksandr Valialkin 651 Jun 20, 2022
The jsonrpc package helps implement of JSON-RPC 2.0

jsonrpc About Simple, Poetic, Pithy. No reflect package. But reflect package is used only when invoke the debug handler. Support GAE/Go Standard Envir

Osamu TONOMORI 166 Jun 23, 2022
Distributed Lab 2: RPC in Go

Distributed Lab 2: RPC in Go Using the lab sheet There are two ways to use the lab sheet, you can either: create a new repo from this template - this

null 0 Oct 18, 2021
An implementation of a distributed access-control server that is based on Google Zanzibar

An implementation of a distributed access-control server that is based on Google Zanzibar - "Google's Consistent, Global Authorization System".

authorizer.tech 61 May 16, 2022
Golang implementation of the Raft consensus protocol

raft raft is a Go library that manages a replicated log and can be used with an FSM to manage replicated state machines. It is a library for providing

HashiCorp 6.2k Jun 29, 2022
Simplified distributed locking implementation using Redis

redislock Simplified distributed locking implementation using Redis. For more information, please see examples. Examples import ( "fmt" "time"

Black Square Media 721 Jun 20, 2022
The pure golang implementation of nanomsg (version 1, frozen)

mangos NOTE: This is the legacy version of mangos (v1). Users are encouraged to use mangos v2 instead if possible. No further development is taking pl

nanomsg 1.5k Jun 22, 2022
A Golang implementation of the Umee network, a decentralized universal capital facility in the Cosmos ecosystem.

Umee A Golang implementation of the Umee network, a decentralized universal capital facility in the Cosmos ecosystem. Umee is a Universal Capital Faci

null 139 Jun 27, 2022
Golang implementation of distributed mutex on Azure lease blobs

Distributed Mutex on Azure Lease Blobs This package implements distributed lock available for multiple processes. Possible use-cases include exclusive

YouScan 10 Jan 7, 2022
implementation of some distributed system techniques

Distributed Systems These applications were built with the objective of studding a distributed systems using the most recent technics. The main ideia

Rafael A. C 6 Feb 18, 2022
An implementation of a distributed KV store backed by Raft tolerant of node failures and network partitions 🚣

barge A simple implementation of a consistent, distributed Key:Value store which uses the Raft Concensus Algorithm. This project launches a cluster of

Shehjad Khan 0 Nov 24, 2021
A naive implementation of Raft consensus algorithm.

This implementation is used to learn/understand the Raft consensus algorithm. The code implements the behaviors shown in Figure 2 of the Raft paper wi

Martin 0 Dec 3, 2021
A spinlock implementation for Go.

A spinlock implementation for Go.

Hiroto Funakoshi 0 Dec 20, 2021
This is my implementation of Raft consensus algorithm that I did for own learning.

This is my implementation of Raft consensus algorithm that I did for own learning. Please follow the link to learn more about raft consensus algorithm https://raft.github.io. And Soon, I will be developing same algorithm in Java as well

Umar Tahir 1 Jan 12, 2022
Lockgate is a cross-platform locking library for Go with distributed locks using Kubernetes or lockgate HTTP lock server as well as the OS file locks support.

Lockgate Lockgate is a locking library for Go. Classical interface: 2 types of locks: shared and exclusive; 2 modes of locking: blocking and non-block

werf 230 Jun 16, 2022