search

grpc / grpc-go

The Go language implementation of gRPC. HTTP/2 based RPC
https://grpc.io
Apache License 2.0
21.08k stars 4.38k forks source link

Flaky test: 1/100k: UpdateAddresses_NoopIfCalledWithSameAddresses #5548

Open easwars opened 2 years ago

easwars commented 2 years ago

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

easwars commented 1 year ago

FAILED in 1 out of 100000 in google3.

Logs:

-----------------------------------------------------------------------------
=== RUN   Test
=== RUN   Test/UpdateAddresses_NoopIfCalledWithSameAddresses
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:105 [core] [Channel #1] Channel created  (t=+1.374868ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:1547 [core] [Channel #1] original dial target is: "whatever:///this-gets-overwritten"  (t=+1.650016ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:1554 [core] [Channel #1] parsed dial target is: {Scheme:whatever Authority: Endpoint:this-gets-overwritten URL:{Scheme:whatever Opaque: User: Host: Path:/this-gets-overwritten RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}  (t=+1.833276ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:263 [core] [Channel #1] Channel authority set to "this-gets-overwritten"  (t=+1.953338ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO resolver_conn_wrapper.go:175 [core] [Channel #1] Resolver state updated: {
          "Addresses": [
            {
              "Addr": "[::1]:37493",
              "ServerName": "",
              "Attributes": null,
              "BalancerAttributes": null,
              "Type": 0,
              "Metadata": null
            },
            {
              "Addr": "[::1]:46871",
              "ServerName": "",
              "Attributes": null,
              "BalancerAttributes": null,
              "Type": 0,
              "Metadata": null
            },
            {
              "Addr": "[::1]:44679",
              "ServerName": "",
              "Attributes": null,
              "BalancerAttributes": null,
              "Type": 0,
              "Metadata": null
            }
          ],
          "ServiceConfig": null,
          "Attributes": null
        } (resolver returned new addresses)  (t=+4.079417ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO balancer_conn_wrappers.go:274 [core] [Channel #1] Channel switches to new LB policy "state_recording_balancer"  (t=+4.322838ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:725 [core] [Channel #1 SubChannel #2] Subchannel created  (t=+4.513074ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:1100 [core] [Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING  (t=+4.693587ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:1211 [core] [Channel #1 SubChannel #2] Subchannel picks a new address "[::1]:37493" to connect  (t=+4.809815ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:418 [core] [Channel #1] Channel Connectivity change to CONNECTING  (t=+19.382625ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:1100 [core] [Channel #1 SubChannel #2] Subchannel Connectivity change to READY  (t=+21.513652ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:418 [core] [Channel #1] Channel Connectivity change to READY  (t=+21.930223ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:1100 [core] [Channel #1 SubChannel #2] Subchannel Connectivity change to IDLE  (t=+22.191346ms)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:418 [core] [Channel #1] Channel Connectivity change to IDLE  (t=+22.421348ms)
    [third_party/golang/grpc/clientconn_test.go:1011](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/clientconn_test.go?l=1011&ws=easwars/6060&snapshot=2): timed out waiting for server1 to be contacted
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:418 [core] [Channel #1] Channel Connectivity change to SHUTDOWN  (t=+5.008471674s)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:1100 [core] [Channel #1 SubChannel #2] Subchannel Connectivity change to SHUTDOWN  (t=+5.008634954s)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:1425 [core] [Channel #1 SubChannel #2] Subchannel deleted  (t=+5.008730413s)
    [third_party/golang/grpc/internal/grpctest/tlogger.go:116](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/internal/grpctest/tlogger.go?l=116&ws=easwars/6060&snapshot=2): INFO clientconn.go:1055 [core] [Channel #1] Channel deleted  (t=+5.008806245s)
    [third_party/golang/grpc/clientconn_test.go:963](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/clientconn_test.go?l=963&ws=easwars/6060&snapshot=2): accept tcp [::1]:46871: use of closed network connection
    [third_party/golang/grpc/clientconn_test.go:945](https://cs.corp.google.com/piper///depot/google3/third_party/golang/grpc/clientconn_test.go?l=945&ws=easwars/6060&snapshot=2): accept tcp [::1]:37493: use of closed network connection
--- FAIL: Test (5.02s)
    --- FAIL: Test/UpdateAddresses_NoopIfCalledWithSameAddresses (5.01s)