grpc-go icon indicating copy to clipboard operation
grpc-go copied to clipboard

Flaky Test/AuthorityRevive in google.golang.org/grpc/xds/internal/xdsclient/tests

Open atollena opened this issue 7 months ago • 3 comments

https://github.com/grpc/grpc-go/actions/runs/9711071699/job/26803095072?pr=7364

--- FAIL: Test (14.05s)
    --- FAIL: Test/AuthorityRevive (0.00s)
        authority_test.go:76: Created new snapshot cache...
        tlogger.go:116: INFO server.go:685 [core] [Server #518]Server created  (t=+259.644µs)
        authority_test.go:76: Registered Aggregated Discovery Service (ADS)...
        authority_test.go:76: xDS management server serving at: 127.0.0.1:44757...
        authority_test.go:79: Created new snapshot cache...
        tlogger.go:116: INFO server.go:685 [core] [Server #519]Server created  (t=+316.09µs)
        authority_test.go:79: Registered Aggregated Discovery Service (ADS)...
        authority_test.go:79: xDS management server serving at: 127.0.0.1:41611...
        tlogger.go:116: INFO server.go:881 [core] [Server #518 ListenSocket #520]ListenSocket created  (t=+404.195µs)
        tlogger.go:116: INFO server.go:881 [core] [Server #519 ListenSocket #521]ListenSocket created  (t=+480.408µs)
        tlogger.go:116: INFO bootstrap.go:571 [xds] [xds-bootstrap] Bootstrap config for creating xds-client: &{xDSServers:[0xc00076abd0] cpcs:map[] serverListenerResourceNameTemplate: clientDefaultListenerResourceNameTemplate:%s authorities:map[test-authority1:0xc00076d830 test-authority2:0xc00076d860 test-authority3:0xc00076d890] node:{ID:4974a10e-6dfc-42ee-b520-e37a6fc2948f Cluster: Locality:{Region: Zone: SubZone:} Metadata:<nil> userAgentName:gRPC Go userAgentVersionType:{UserAgentVersion:1.66.0-dev} clientFeatures:[envoy.lb.does_not_support_overprovisioning xds.config.resource-in-sotw]} certProviderConfigs:map[]}  (t=+538.716µs)
        tlogger.go:116: INFO client_new.go:87 [xds] [xds-client 0xc0004ea0a0] Created client to xDS management server: 127.0.0.1:44757-insecure-  (t=+573.17µs)
        server.go:229: Created new resource snapshot...
        server.go:235: Updated snapshot cache with resource snapshot...
        tlogger.go:116: INFO clientconn.go:1687 [core] original dial target is: "127.0.0.1:44757"  (t=+847.172µs)
        tlogger.go:116: INFO clientconn.go:309 [core] [Channel #522]Channel created  (t=+875.374µs)
        tlogger.go:116: INFO clientconn.go:191 [core] [Channel #522]parsed dial target is: resolver.Target{URL:url.URL{Scheme:"dns", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/127.0.0.1:44757", RawPath:"", OmitHost:false, ForceQuery:false, RawQuery:"", Fragment:"", RawFragment:""}}  (t=+912.994µs)
        tlogger.go:116: INFO clientconn.go:192 [core] [Channel #522]Channel authority set to "127.0.0.1:44757"  (t=+935.887µs)
        tlogger.go:116: INFO resolver_wrapper.go:197 [core] [Channel #522]Resolver state updated: {
              "Addresses": [
                {
                  "Addr": "127.0.0.1:44757",
                  "ServerName": "",
                  "Attributes": null,
                  "BalancerAttributes": null,
                  "Metadata": null
                }
              ],
              "Endpoints": [
                {
                  "Addresses": [
                    {
                      "Addr": "127.0.0.1:44757",
                      "ServerName": "",
                      "Attributes": null,
                      "BalancerAttributes": null,
                      "Metadata": null
                    }
                  ],
                  "Attributes": null
                }
              ],
              "ServiceConfig": null,
              "Attributes": null
            } (resolver returned new addresses)  (t=+1.022228ms)
        tlogger.go:116: INFO balancer_wrapper.go:103 [core] [Channel #522]Channel switches to new LB policy "pick_first"  (t=+1.056141ms)
        tlogger.go:116: INFO clientconn.go:852 [core] [Channel #522 SubChannel #523]Subchannel created  (t=+1.096707ms)
        tlogger.go:116: INFO clientconn.go:539 [core] [Channel #522]Channel Connectivity change to CONNECTING  (t=+1.115833ms)
        tlogger.go:116: INFO clientconn.go:309 [core] [Channel #522]Channel exiting idle mode  (t=+1.137313ms)
        tlogger.go:116: INFO transport.go:237 [xds] [xds-client 0xc0004ea0a0] [127.0.0.1:44757] Created transport to server "127.0.0.1:44757"  (t=+1.165655ms)
        tlogger.go:116: INFO clientconn.go:1[213](https://github.com/grpc/grpc-go/actions/runs/9711071699/job/26803095072?pr=7364#step:8:214) [core] [Channel #522 SubChannel #523]Subchannel Connectivity change to CONNECTING  (t=+1.259239ms)
        tlogger.go:116: INFO clientconn.go:1329 [core] [Channel #522 SubChannel #523]Subchannel picks a new address "127.0.0.1:44757" to connect  (t=+1.285688ms)
        tlogger.go:116: INFO clientconn.go:1329 [core] [Channel #522 SubChannel #523]Subchannel picks a new address "127.0.0.1:44757" to connect  (t=+1.429717ms)
        authority_test.go:298: Unexpected new transport created to management server
        tlogger.go:116: WARNING transport.go:335 [xds] [xds-client 0xc0004ea0a0] [127.0.0.1:44757] Creating new ADS stream failed: rpc error: code = Canceled desc = received context error while waiting for new LB policy update: context canceled  (t=+1.926424ms)
        tlogger.go:116: INFO clientconn.go:539 [core] [Channel #522]Channel Connectivity change to SHUTDOWN  (t=+1.947954ms)
        tlogger.go:116: INFO resolver_wrapper.go:100 [core] [Channel #522]Closing the name resolver  (t=+1.969675ms)
        tlogger.go:116: INFO balancer_wrapper.go:135 [core] [Channel #522]ccBalancerWrapper: closing  (t=+1.989221ms)
        tlogger.go:116: INFO clientconn.go:1213 [core] [Channel #522 SubChannel #523]Subchannel Connectivity change to SHUTDOWN  (t=+2.015099ms)
        tlogger.go:116: INFO clientconn.go:1560 [core] [Channel #522 SubChannel #523]Subchannel deleted  (t=+2.035908ms)
        tlogger.go:116: INFO clientconn.go:309 [core] [Channel #522]Channel deleted  (t=+2.054984ms)
        tlogger.go:116: INFO clientimpl.go:100 [xds] [xds-client 0xc0004ea0a0] Shutdown  (t=+2.127708ms)
        tlogger.go:116: INFO server.go:817 [core] [Server #519 ListenSocket #521]ListenSocket deleted  (t=+2.179294ms)
        tlogger.go:116: INFO server.go:817 [core] [Server #518 ListenSocket #520]ListenSocket deleted  (t=+2.[217](https://github.com/grpc/grpc-go/actions/runs/9711071699/job/26803095072?pr=7364#step:8:218)455ms)

atollena avatar Jun 28 '24 12:06 atollena