--- FAIL: Test (23.36s)
--- FAIL: Test/RingHash_AggregateClusterFallBackFromRingHashToLogicalDnsAtStartup (10.01s)
tlogger.go:116: INFO server.go:685 [core] [Server #409]Server created (t=+276.144µs)
stubserver.go:288: Started test service backend at "127.0.0.1:44079"
tlogger.go:116: INFO server.go:881 [core] [Server #409 ListenSocket #410]ListenSocket created (t=+423.177µs)
tlogger.go:116: INFO restartable_listener.go:84 [testutils] Stopping restartable listener "127.0.0.1:34327" (t=+762.212µs)
ringhash_balancer_test.go:438: Created new snapshot cache...
tlogger.go:116: INFO server.go:685 [core] [Server #411]Server created (t=+1.204154ms)
ringhash_balancer_test.go:438: Registered Aggregated Discovery Service (ADS)...
ringhash_balancer_test.go:438: xDS management server serving at: 127.0.0.1:35659...
tlogger.go:116: INFO server.go:881 [core] [Server #411 ListenSocket #412]ListenSocket created (t=+1.870166ms)
server.go:[229](https://github.com/grpc/grpc-go/actions/runs/12684369727/job/35352925778?pr=7992#step:8:230): Created new resource snapshot...
server.go:235: Updated snapshot cache with resource snapshot...
tlogger.go:116: INFO clientconn.go:1674 [core] original dial target is: "xds:///test.server" (t=+3.552713ms)
tlogger.go:116: INFO clientconn.go:314 [core] [Channel #413]Channel created (t=+3.622452ms)
tlogger.go:116: INFO clientconn.go:193 [core] [Channel #413]parsed dial target is: resolver.Target{URL:url.URL{Scheme:"xds", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/test.server", RawPath:"", OmitHost:false, ForceQuery:false, RawQuery:"", Fragment:"", RawFragment:""}} (t=+3.73948ms)
tlogger.go:116: INFO clientconn.go:194 [core] [Channel #413]Channel authority set to "test.server" (t=+3.798049ms)
tlogger.go:116: INFO xds_resolver.go:100 [xds] [xds-resolver 0xc000785320] Creating resolver for target: xds:///test.server (t=+4.049948ms)
tlogger.go:116: INFO client_refcounted.go:76 [xds] [xds-client 0xc000389a40] Created client with name "xds:///test.server" and bootstrap configuration:
{
"xds_servers": [
{
"server_uri": "passthrough:///127.0.0.1:35659",
"channel_creds": [
{
"type": "insecure"
}
]
}
],
"certificate_providers": {
"client-side-certificate-provider-instance": {
"plugin_name": "file_watcher",
"config": {
"certificate_file": "/tmp/testClientSideXDS35[230](https://github.com/grpc/grpc-go/actions/runs/12684369727/job/35352925778?pr=7992#step:8:231)94675/cert.pem",
"private_key_file": "/tmp/testClientSideXDS3523094675/key.pem",
"ca_certificate_file": "/tmp/testClientSideXDS3523094675/ca.pem",
"refresh_interval": "600s"
}
},
"server-side-certificate-provider-instance": {
"plugin_name": "file_watcher",
"config": {
"certificate_file": "/tmp/testServerSideXDS420696777/cert.pem",
"private_key_file": "/tmp/testServerSideXDS420696777/key.pem",
"ca_certificate_file": "/tmp/testServerSideXDS420696777/ca.pem",
"refresh_interval": "600s"
}
}
},
"server_listener_resource_name_template": "grpc/server?xds.resource.listening_address=%s",
"client_default_listener_resource_name_template": "%s",
"node": {
"id": "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed",
"locality": {}
}
} (t=+5.461273ms)
tlogger.go:116: INFO client_refcounted.go:81 [xds] xDS node ID: 9deb4ef4-9391-4307-b8ba-e560cb9cc3ed (t=+5.576247ms)
tlogger.go:116: INFO clientconn.go:1674 [core] original dial target is: "passthrough:///127.0.0.1:35659" (t=+5.729802ms)
tlogger.go:116: INFO clientconn.go:314 [core] [Channel #414]Channel created (t=+5.829618ms)
tlogger.go:116: INFO clientconn.go:193 [core] [Channel #414]parsed dial target is: resolver.Target{URL:url.URL{Scheme:"passthrough", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/127.0.0.1:35659", RawPath:"", OmitHost:false, ForceQuery:false, RawQuery:"", Fragment:"", RawFragment:""}} (t=+5.969428ms)
tlogger.go:116: INFO clientconn.go:194 [core] [Channel #414]Channel authority set to "127.0.0.1:35659" (t=+6.044247ms)
tlogger.go:116: INFO resolver_wrapper.go:200 [core] [Channel #414]Resolver state updated: {
"Addresses": [
{
"Addr": "127.0.0.1:35659",
"ServerName": "",
"Attributes": null,
"BalancerAttributes": null,
"Metadata": null
}
],
"Endpoints": [
{
"Addresses": [
{
"Addr": "127.0.0.1:35659",
"ServerName": "",
"Attributes": null,
"BalancerAttributes": null,
"Metadata": null
}
],
"Attributes": null
}
],
"ServiceConfig": null,
"Attributes": null
} (resolver returned new addresses) (t=+6.435836ms)
tlogger.go:116: INFO balancer_wrapper.go:117 [core] [Channel #414]Channel switches to new LB policy "pick_first" (t=+6.641057ms)
tlogger.go:116: INFO clientconn.go:544 [core] [Channel #414]Channel Connectivity change to CONNECTING (t=+6.738749ms)
tlogger.go:116: INFO clientconn.go:858 [core] [Channel #414 SubChannel #415]Subchannel created (t=+6.848183ms)
tlogger.go:116: INFO clientconn.go:1219 [core] [Channel #414 SubChannel #415]Subchannel Connectivity change to CONNECTING (t=+6.952096ms)
tlogger.go:116: INFO clientconn.go:1339 [core] [Channel #414 SubChannel #415]Subchannel picks a new address "127.0.0.1:35659" to connect (t=+7.016496ms)
tlogger.go:116: INFO clientconn.go:314 [core] [Channel #414]Channel exiting idle mode (t=+7.827194ms)
tlogger.go:116: INFO clientconn.go:314 [core] [Channel #413]Channel exiting idle mode (t=+8.216047ms)
tlogger.go:116: INFO clientconn.go:1219 [core] [Channel #414 SubChannel #415]Subchannel Connectivity change to READY (t=+10.783082ms)
tlogger.go:116: INFO clientconn.go:544 [core] [Channel #414]Channel Connectivity change to READY (t=+11.036874ms)
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.listener.v3.Listener[test.server] and known map[]. Diff [test.server]
logging.go:30: respond type.googleapis.com/envoy.config.listener.v3.Listener[test.server] version "" with version "1"
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.listener.v3.Listener[test.server] and known map[test.server:{}]. Diff []
logging.go:30: open watch 1 for type.googleapis.com/envoy.config.listener.v3.Listener[test.server] from nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed", version "1"
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.route.v3.RouteConfiguration[new_route] and known map[]. Diff [new_route]
logging.go:30: respond type.googleapis.com/envoy.config.route.v3.RouteConfiguration[new_route] version "" with version "1"
tlogger.go:116: INFO xds_resolver.go:284 [xds] [xds-resolver 0xc000785320] For Listener resource "test.server" and RouteConfiguration resource "new_route", generated service config: {
"loadBalancingConfig": [
{
"xds_cluster_manager_experimental": {
"children": {
"cluster:aggregate_cluster": {
"childPolicy": [
{
"cds_experimental": {
"cluster": "aggregate_cluster"
}
}
]
}
}
}
}
]
} (t=+14.317477ms)
tlogger.go:116: INFO resolver_wrapper.go:200 [core] [Channel #413]Resolver state updated: {
"Addresses": null,
"Endpoints": [],
"ServiceConfig": {
"Config": {
"Config": null,
"Methods": {}
},
"Err": null
},
"Attributes": {
"\u003c%!p(resolver.csKeyType=grpc.internal.resolver.configSelector)\u003e": "\u003c0xc0006f60a0\u003e",
"\u003c%!p(xdsclient.clientKeyType=grpc.xds.internal.client.Client)\u003e": "\u003c0xc000739c40\u003e"
}
} (service config updated) (t=+14.696121ms)
tlogger.go:116: INFO balancer_wrapper.go:117 [core] [Channel #413]Channel switches to new LB policy "xds_cluster_manager_experimental" (t=+14.779026ms)
tlogger.go:116: INFO clustermanager.go:59 [xds] [xds-cluster-manager-lb 0xc000160cc0] Created (t=+14.828808ms)
tlogger.go:116: INFO balancergroup.go:299 [xds] [xds-cluster-manager-lb 0xc000160cc0] Adding child policy of type "cds_experimental" for child "cluster:aggregate_cluster" (t=+14.879082ms)
tlogger.go:116: INFO balancergroup.go:102 [xds] [xds-cluster-manager-lb 0xc000160cc0] Creating child policy of type "cds_experimental" for child "cluster:aggregate_cluster" (t=+14.918615ms)
tlogger.go:116: INFO cdsbalancer.go:109 [xds] [cds-lb 0xc000247520] Created (t=+14.966885ms)
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.route.v3.RouteConfiguration[new_route] and known map[new_route:{}]. Diff []
logging.go:30: open watch 2 for type.googleapis.com/envoy.config.route.v3.RouteConfiguration[new_route] from nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed", version "1"
tlogger.go:116: INFO cdsbalancer.go:121 [xds] [cds-lb 0xc000247520] xDS credentials in use: false (t=+15.364675ms)
tlogger.go:116: INFO cdsbalancer.go:290 [xds] [cds-lb 0xc000247520] Received balancer config update: {
"LoadBalancingConfig": null,
"Cluster": "aggregate_cluster"
} (t=+15.460233ms)
tlogger.go:116: INFO balancerstateaggregator.go:191 [xds] [xds-cluster-manager-lb 0xc000160cc0] Child pickers: map[cluster:aggregate_cluster:picker:0xc00077a670,state:CONNECTING,stateToAggregate:CONNECTING] (t=+15.634617ms)
tlogger.go:116: INFO clientconn.go:544 [core] [Channel #413]Channel Connectivity change to CONNECTING (t=+15.713023ms)
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster] and known map[]. Diff [aggregate_cluster]
logging.go:30: respond type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster] version "" with version "1"
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster] and known map[aggregate_cluster:{}]. Diff []
logging.go:30: open watch 3 for type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster] from nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed", version "1"
tlogger.go:116: INFO cdsbalancer.go:414 [xds] [cds-lb 0xc000247520] Received Cluster resource: {
"ClusterType": 2,
"ClusterName": "aggregate_cluster",
"EDSServiceName": "",
"LRSServerConfig": null,
"SecurityCfg": null,
"MaxRequests": null,
"DNSHostName": "",
"PrioritizedClusterNames": [
"eds_cluster",
"logical_dns_cluster"
],
"LBPolicy": [
{
"ring_hash_experimental": {
"minRingSize": 1024,
"maxRingSize": 8388608
}
}
],
"OutlierDetection": null,
"Raw": {
"type_url": "type.googleapis.com/envoy.config.cluster.v3.Cluster",
"value": "ChFhZ2dyZWdhdGVfY2x1c3RlcjACsgKKAQoYZW52b3kuY2x1c3RlcnMuYWdncmVnYXRlEm4KSHR5cGUuZ29vZ2xlYXBpcy5jb20vZW52b3kuZXh0ZW5zaW9ucy5jbHVzdGVycy5hZ2dyZWdhdGUudjMuQ2x1c3RlckNvbmZpZxIiCgtlZHNfY2x1c3RlcgoTbG9naWNhbF9kbnNfY2x1c3Rlcg=="
},
"TelemetryLabels": {
"csm.service_name": "unknown",
"csm.service_namespace_name": "unknown"
}
} (t=+16.746595ms)
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster eds_cluster] and known map[aggregate_cluster:{}]. Diff [eds_cluster]
logging.go:30: respond type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster eds_cluster] version "1" with version "1"
tlogger.go:116: INFO cdsbalancer.go:414 [xds] [cds-lb 0xc000247520] Received Cluster resource: {
"ClusterType": 0,
"ClusterName": "eds_cluster",
"EDSServiceName": "eds_cluster",
"LRSServerConfig": null,
"SecurityCfg": null,
"MaxRequests": null,
"DNSHostName": "",
"PrioritizedClusterNames": null,
"LBPolicy": [
{
"xds_wrr_locality_experimental": {
"childPolicy": [
{
"round_robin": {}
}
]
}
}
],
"OutlierDetection": null,
"Raw": {
"type_url": "type.googleapis.com/envoy.config.cluster.v3.Cluster",
"value": "CgtlZHNfY2x1c3RlchoRCgIaABILZWRzX2NsdXN0ZXIQAw=="
},
"TelemetryLabels": {
"csm.service_name": "unknown",
"csm.service_namespace_name": "unknown"
}
} (t=+18.182486ms)
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster eds_cluster logical_dns_cluster] and known map[aggregate_cluster:{} eds_cluster:{}]. Diff [logical_dns_cluster]
logging.go:30: respond type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster eds_cluster logical_dns_cluster] version "1" with version "1"
tlogger.go:116: INFO cdsbalancer.go:414 [xds] [cds-lb 0xc000247520] Received Cluster resource: {
"ClusterType": 1,
"ClusterName": "logical_dns_cluster",
"EDSServiceName": "",
"LRSServerConfig": null,
"SecurityCfg": null,
"MaxRequests": null,
"DNSHostName": "server.example.com:443",
"PrioritizedClusterNames": null,
"LBPolicy": [
{
"xds_wrr_locality_experimental": {
"childPolicy": [
{
"round_robin": {}
}
]
}
}
],
"OutlierDetection": null,
"Raw": {
"type_url": "type.googleapis.com/envoy.config.cluster.v3.Cluster",
"value": "ChNsb2dpY2FsX2Ruc19jbHVzdGVyigIhEh8SHQobChkKFxISc2VydmVyLmV4YW1wbGUuY29tGLsDEAI="
},
"TelemetryLabels": {
"csm.service_name": "unknown",
"csm.service_namespace_name": "unknown"
}
} (t=+19.145708ms)
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster eds_cluster logical_dns_cluster] and known map[aggregate_cluster:{} eds_cluster:{} logical_dns_cluster:{}]. Diff []
logging.go:30: open watch 4 for type.googleapis.com/envoy.config.cluster.v3.Cluster[aggregate_cluster eds_cluster logical_dns_cluster] from nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed", version "1"
tlogger.go:116: INFO clusterresolver.go:85 [xds] [xds-cluster-resolver-lb 0xc0008cea80] Created (t=+19.61966ms)
tlogger.go:116: INFO cdsbalancer.go:455 [xds] [cds-lb 0xc000247520] Created child policy 0xc0008cea80 of type cluster_resolver_experimental (t=+19.708395ms)
ringhash_balancer_test.go:460: rpc EmptyCall() failed: rpc error: code = DeadlineExceeded desc = received context error while waiting for new LB policy update: context deadline exceeded
tlogger.go:116: INFO clientconn.go:544 [core] [Channel #413]Channel Connectivity change to SHUTDOWN (t=+10.008614258s)
tlogger.go:116: INFO resolver_wrapper.go:100 [core] [Channel #413]Closing the name resolver (t=+10.008656096s)
tlogger.go:116: INFO balancer_wrapper.go:155 [core] [Channel #413]ccBalancerWrapper: closing (t=+10.008718722s)
tlogger.go:116: INFO watch_service.go:56 [xds] [xds-resolver 0xc000785320] Canceling watch on Listener resource "test.server" (t=+10.008880952s)
tlogger.go:116: INFO watch_service.go:91 [xds] [xds-resolver 0xc000785320] Canceling watch on RouteConfiguration resource "new_route" (t=+10.00908305s)
tlogger.go:116: INFO clusterresolver.go:355 [xds] [xds-cluster-resolver-lb 0xc0008cea80] Shutdown (t=+10.00918091s)
tlogger.go:116: WARNING ads_stream.go:514 [xds] [xds-client 0xc000389a40] [xds-channel 0xc00064c120] [ads-stream 0xc0006f0800] ADS stream closed: rpc error: code = Canceled desc = context canceled (t=+10.009[232](https://github.com/grpc/grpc-go/actions/runs/12684369727/job/35352925778?pr=7992#step:8:233)788s)
tlogger.go:116: INFO cdsbalancer.go:380 [xds] [cds-lb 0xc000247520] Shutdown (t=+10.009283252s)
tlogger.go:116: INFO ads_stream.go:178 [xds] [xds-client 0xc000389a40] [xds-channel 0xc00064c120] [ads-stream 0xc0006f0800] Stopping ADS stream (t=+10.009327324s)
logging.go:30: nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed" requested type.googleapis.com/envoy.config.cluster.v3.Cluster[eds_cluster logical_dns_cluster] and known map[aggregate_cluster:{} eds_cluster:{} logical_dns_cluster:{}]. Diff []
tlogger.go:116: INFO clientconn.go:544 [core] [Channel #414]Channel Connectivity change to SHUTDOWN (t=+10.009384731s)
logging.go:30: open watch 5 for type.googleapis.com/envoy.config.cluster.v3.Cluster[eds_cluster logical_dns_cluster] from nodeID "9deb4ef4-9391-4307-b8ba-e560cb9cc3ed", version "1"
tlogger.go:116: INFO resolver_wrapper.go:100 [core] [Channel #414]Closing the name resolver (t=+10.009489346s)
tlogger.go:116: INFO clustermanager.go:197 [xds] [xds-cluster-manager-lb 0xc000160cc0] Shutdown (t=+10.009563402s)
tlogger.go:116: INFO balancer_wrapper.go:155 [core] [Channel #414]ccBalancerWrapper: closing (t=+10.009610319s)
tlogger.go:116: INFO clientconn.go:1219 [core] [Channel #414 SubChannel #415]Subchannel Connectivity change to SHUTDOWN (t=+10.009743041s)
tlogger.go:116: INFO clientconn.go:1547 [core] [Channel #414 SubChannel #415]Subchannel deleted (t=+10.009789337s)
tlogger.go:116: INFO clientconn.go:314 [core] [Channel #414]Channel deleted (t=+10.010027204s)
tlogger.go:116: INFO channel.go:145 [xds] [xds-client 0xc000389a40] [xds-channel 0xc00064c120] Shutdown (t=+10.010089721s)
tlogger.go:116: INFO clientimpl.go:185 [xds] [xds-client 0xc000389a40] Shutdown (t=+10.010159192s)
tlogger.go:116: INFO xds_resolver.go:253 [xds] [xds-resolver 0xc000785320] Shutdown (t=+10.01019071s)
tlogger.go:116: INFO clientconn.go:314 [core] [Channel #413]Channel deleted (t=+10.010[238](https://github.com/grpc/grpc-go/actions/runs/12684369727/job/35352925778?pr=7992#step:8:239)539s)
tlogger.go:116: INFO server.go:817 [core] [Server #411 ListenSocket #412]ListenSocket deleted (t=+10.010355049s)
tlogger.go:116: INFO server.go:817 [core] [Server #409 ListenSocket #410]ListenSocket deleted (t=+10.010458542s)
FAIL