grpc-go
grpc-go copied to clipboard
Published
20 hours ago •
grpc
grpc
Flaky test: 145/10k: OutlierDetectionXDSDefaultOn
https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595
--- FAIL: Test (24.46s)
--- FAIL: Test/OutlierDetectionXDSDefaultOn (10.07s)
tlogger.go:116: INFO server.go:132 [xds-e2e] Created new snapshot cache... (t=+104.105µs)
tlogger.go:116: INFO server.go:667 [core] [Server #841] Server created (t=+810.243µs)
tlogger.go:116: INFO server.go:158 [xds-e2e] Registered Aggregated Discovery Service (ADS)... (t=+1.027254ms)
tlogger.go:116: INFO server.go:177 [xds-e2e] xDS management server serving at: 127.0.0.1:43269... (t=+1.14126ms)
tlogger.go:116: INFO server.go:855 [core] [Server #841 ListenSocket #842] ListenSocket created (t=+2.788148ms)
tlogger.go:116: INFO server.go:667 [core] [Server #843] Server created (t=+3.897406ms)
stubserver.go:230: Started test service backend at "127.0.0.1:39293"
tlogger.go:116: INFO server.go:855 [core] [Server #843 ListenSocket #844] ListenSocket created (t=+4.194522ms)
tlogger.go:116: INFO server.go:667 [core] [Server #845] Server created (t=+5.200876ms)
stubserver.go:230: Started test service backend at "127.0.0.1:46753"
tlogger.go:116: INFO server.go:855 [core] [Server #845 ListenSocket #846] ListenSocket created (t=+5.47429ms)
tlogger.go:116: INFO server.go:667 [core] [Server #847] Server created (t=+6.260632ms)
stubserver.go:230: Started test service backend at "127.0.0.1:45485"
tlogger.go:116: INFO server.go:855 [core] [Server #847 ListenSocket #848] ListenSocket created (t=+6.551547ms)
tlogger.go:116: INFO server.go:220 [xds-e2e] Created new resource snapshot... (t=+7.248684ms)
tlogger.go:116: INFO server.go:226 [xds-e2e] Updated snapshot cache with resource snapshot... (t=+7.35349ms)
tlogger.go:116: INFO clientconn.go:318 [core] [Channel #849] Channel created (t=+7.466996ms)
tlogger.go:116: INFO clientconn.go:1825 [core] [Channel #849] original dial target is: "xds:///my-service-client-side-xds" (t=+8.071128ms)
tlogger.go:116: INFO clientconn.go:1832 [core] [Channel #849] parsed dial target is: {URL:{Scheme:xds Opaque: User: Host: Path:/my-service-client-side-xds RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}} (t=+8.232836ms)
tlogger.go:116: INFO clientconn.go:1987 [core] [Channel #849] Channel authority set to "my-service-client-side-xds" (t=+8.336542ms)
tlogger.go:116: INFO xds_resolver.go:83 [xds] [xds-resolver 0x4000244620] Creating resolver for target: {URL:{Scheme:xds Opaque: User: Host: Path:/my-service-client-side-xds RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}} (t=+8.67086ms)
tlogger.go:116: INFO client_new.go:80 [xds] [xds-client 0x4000881950] Created client to xDS management server: 127.0.0.1:43269-insecure-xds_v3 (t=+10.772171ms)
tlogger.go:116: INFO clientconn.go:318 [core] [Channel #850] Channel created (t=+10.981582ms)
tlogger.go:116: INFO clientconn.go:1825 [core] [Channel #850] original dial target is: "127.0.0.1:43269" (t=+11.187993ms)
tlogger.go:116: INFO clientconn.go:1830 [core] [Channel #850] dial target "127.0.0.1:43269" parse failed: parse "127.0.0.1:43269": first path segment in URL cannot contain colon (t=+11.408905ms)
tlogger.go:116: INFO clientconn.go:1846 [core] [Channel #850] fallback to scheme "passthrough" (t=+11.51651ms)
tlogger.go:116: INFO clientconn.go:1854 [core] [Channel #850] parsed dial target is: {URL:{Scheme:passthrough Opaque: User: Host: Path:/127.0.0.1:43269 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}} (t=+11.663218ms)
tlogger.go:116: INFO clientconn.go:1987 [core] [Channel #850] Channel authority set to "127.0.0.1:43269" (t=+12.057439ms)
tlogger.go:116: INFO resolver_conn_wrapper.go:246 [core] [Channel #850] Resolver state updated: {
"Addresses": [
{
"Addr": "127.0.0.1:43269",
"ServerName": "",
"Attributes": null,
"BalancerAttributes": null,
"Metadata": null
}
],
"Endpoints": [
{
"Addresses": [
{
"Addr": "127.0.0.1:43269",
"ServerName": "",
"Attributes": null,
"BalancerAttributes": null,
"Metadata": null
}
],
"Attributes": null
}
],
"ServiceConfig": null,
"Attributes": null
} (resolver returned new addresses) (t=+12.44866ms)
tlogger.go:116: INFO balancer_conn_wrappers.go:180 [core] [Channel #850] Channel switches to new LB policy "pick_first" (t=+12.794978ms)
tlogger.go:116: INFO clientconn.go:956 [core] [Channel #850 SubChannel #851] Subchannel created (t=+13.120595ms)
tlogger.go:116: INFO clientconn.go:592 [core] [Channel #850] Channel Connectivity change to CONNECTING (t=+13.299705ms)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #850 SubChannel #851] Subchannel Connectivity change to CONNECTING (t=+13.570019ms)
tlogger.go:116: INFO clientconn.go:1453 [core] [Channel #850 SubChannel #851] Subchannel picks a new address "127.0.0.1:43269" to connect (t=+13.724527ms)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #850 SubChannel #851] Subchannel Connectivity change to READY (t=+15.244908ms)
tlogger.go:116: INFO clientconn.go:592 [core] [Channel #850] Channel Connectivity change to READY (t=+15.396616ms)
tlogger.go:116: INFO transport.go:238 [xds] [xds-client 0x4000881950] [127.0.0.1:43269] Created transport to server "127.0.0.1:43269" (t=+16.566578ms)
tlogger.go:116: INFO transport.go:347 [xds] [xds-client 0x4000881950] [127.0.0.1:43269] ADS stream created (t=+16.79159ms)
tlogger.go:116: INFO xds_resolver.go:143 [xds] [xds-resolver 0x4000244620] Watch started on resource name my-service-client-side-xds with xds-client 0x40005f3a90 (t=+17.661536ms)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.listener.v3.Listener[my-service-client-side-xds] and known map[]. Diff [my-service-client-side-xds] (t=+17.877648ms)
tlogger.go:116: INFO simple.go:428 [xds-e2e] respond type.googleapis.com/envoy.config.listener.v3.Listener[my-service-client-side-xds] version "" with version "1" (t=+18.024755ms)
tlogger.go:116: INFO watch_service.go:94 [xds] [xds-resolver 0x4000244620] received LDS update: {
"RouteConfigName": "route-my-service-client-side-xds",
"InlineRouteConfig": null,
"MaxStreamDuration": 0,
"HTTPFilters": [
{
"Name": "router",
"Filter": {},
"Config": {
"FilterConfig": null
}
}
],
"InboundListenerCfg": null,
"Raw": {
"type_url": "type.googleapis.com/envoy.config.listener.v3.Listener",
"value": "ChpteS1zZXJ2aWNlLWNsaWVudC1zaWRlLXhkcxqpAhqTAgotZW52b3kuZmlsdGVycy5uZXR3b3JrLmh0dHBfY29ubmVjdGlvbl9tYW5hZ2VyIuEBCmV0eXBlLmdvb2dsZWFwaXMuY29tL2Vudm95LmV4dGVuc2lvbnMuZmlsdGVycy5uZXR3b3JrLmh0dHBfY29ubmVjdGlvbl9tYW5hZ2VyLnYzLkh0dHBDb25uZWN0aW9uTWFuYWdlchJ4Kk4KBnJvdXRlciJECkJ0eXBlLmdvb2dsZWFwaXMuY29tL2Vudm95LmV4dGVuc2lvbnMuZmlsdGVycy5odHRwLnJvdXRlci52My5Sb3V0ZXIaJgoCGgASIHJvdXRlLW15LXNlcnZpY2UtY2xpZW50LXNpZGUteGRzOhFmaWx0ZXItY2hhaW4tbmFtZZoB5AEK4QEKZXR5cGUuZ29vZ2xlYXBpcy5jb20vZW52b3kuZXh0ZW5zaW9ucy5maWx0ZXJzLm5ldHdvcmsuaHR0cF9jb25uZWN0aW9uX21hbmFnZXIudjMuSHR0cENvbm5lY3Rpb25NYW5hZ2VyEngqTgoGcm91dGVyIkQKQnR5cGUuZ29vZ2xlYXBpcy5jb20vZW52b3kuZXh0ZW5zaW9ucy5maWx0ZXJzLmh0dHAucm91dGVyLnYzLlJvdXRlchomCgIaABIgcm91dGUtbXktc2VydmljZS1jbGllbnQtc2lkZS14ZHM="
}
}, err: <nil> (t=+19.520035ms)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.listener.v3.Listener[my-service-client-side-xds] and known map[my-service-client-side-xds:{}]. Diff [] (t=+20.344478ms)
tlogger.go:116: INFO simple.go:380 [xds-e2e] open watch 1 for type.googleapis.com/envoy.config.listener.v3.Listener[my-service-client-side-xds] from nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14", version "1" (t=+20.469085ms)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.route.v3.RouteConfiguration[route-my-service-client-side-xds] and known map[]. Diff [route-my-service-client-side-xds] (t=+20.676596ms)
tlogger.go:116: INFO simple.go:428 [xds-e2e] respond type.googleapis.com/envoy.config.route.v3.RouteConfiguration[route-my-service-client-side-xds] version "" with version "1" (t=+20.783502ms)
tlogger.go:116: INFO watch_service.go:176 [xds] [xds-resolver 0x4000244620] received RDS update: {
"VirtualHosts": [
{
"Domains": [
"my-service-client-side-xds"
],
"Routes": [
{
"Path": null,
"Prefix": "/",
"Regex": null,
"CaseInsensitive": false,
"Headers": null,
"Fraction": null,
"HashPolicies": null,
"MaxStreamDuration": null,
"HTTPFilterConfigOverride": null,
"RetryConfig": null,
"ActionType": 1,
"WeightedClusters": {
"cluster-my-service-client-side-xds": {
"Weight": 100,
"HTTPFilterConfigOverride": null
}
},
"ClusterSpecifierPlugin": ""
}
],
"HTTPFilterConfigOverride": null,
"RetryConfig": null
}
],
"ClusterSpecifierPlugins": {},
"Raw": {
"type_url": "type.googleapis.com/envoy.config.route.v3.RouteConfiguration",
"value": "CiByb3V0ZS1teS1zZXJ2aWNlLWNsaWVudC1zaWRlLXhkcxJREhpteS1zZXJ2aWNlLWNsaWVudC1zaWRlLXhkcxozCgMKAS8SLBoqCigKImNsdXN0ZXItbXktc2VydmljZS1jbGllbnQtc2lkZS14ZHMSAghk"
}
}, err: <nil> (t=+21.862159ms)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.route.v3.RouteConfiguration[route-my-service-client-side-xds] and known map[route-my-service-client-side-xds:{}]. Diff [] (t=+22.26808ms)
tlogger.go:116: INFO simple.go:380 [xds-e2e] open watch 2 for type.googleapis.com/envoy.config.route.v3.RouteConfiguration[route-my-service-client-side-xds] from nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14", version "1" (t=+23.444343ms)
tlogger.go:116: INFO xds_resolver.go:223 [xds] [xds-resolver 0x4000244620] Received update on resource my-service-client-side-xds from xds-client 0x40005f3a90, generated service config: {
"loadBalancingConfig": [
{
"xds_cluster_manager_experimental": {
"children": {
"cluster:cluster-my-service-client-side-xds": {
"childPolicy": [
{
"cds_experimental": {
"cluster": "cluster-my-service-client-side-xds"
}
}
]
}
}
}
}
]
} (t=+23.667355ms)
tlogger.go:116: INFO resolver_conn_wrapper.go:246 [core] [Channel #849] Resolver state updated: {
"Addresses": null,
"Endpoints": [],
"ServiceConfig": {
"Config": {
"Config": null,
"LB": null,
"Methods": {}
},
"Err": null
},
"Attributes": {
"\u003c%!p(resolver.csKeyType=grpc.internal.resolver.configSelector)\u003e": "\u003c0x40006ce8c0\u003e",
"\u003c%!p(xdsclient.clientKeyType=grpc.xds.internal.client.Client)\u003e": "\u003c0x40005f3a90\u003e"
}
} (service config updated) (t=+24.764113ms)
tlogger.go:116: INFO balancer_conn_wrappers.go:180 [core] [Channel #849] Channel switches to new LB policy "xds_cluster_manager_experimental" (t=+24.982024ms)
tlogger.go:116: INFO clustermanager.go:58 [xds] [xds-cluster-manager-lb 0x40005d05c0] Created (t=+25.130732ms)
tlogger.go:116: INFO clustermanager.go:131 [xds] [xds-cluster-manager-lb 0x40005d05c0] update with config {
"LoadBalancingConfig": null,
"Children": {
"cluster:cluster-my-service-client-side-xds": {
"ChildPolicy": [
{
"cds_experimental": {
"LoadBalancingConfig": null,
"Cluster": "cluster-my-service-client-side-xds"
}
}
]
}
}
}, resolver state {Addresses:[] Endpoints:[] ServiceConfig:0x40005d04a0 Attributes:{"<%!p(resolver.csKeyType=grpc.internal.resolver.configSelector)>": "<0x40006ce8c0>" , "<%!p(xdsclient.clientKeyType=grpc.xds.internal.client.Client)>": "<0x40005f3a90>" }} (t=+25.83627ms)
tlogger.go:116: INFO balancergroup.go:316 [xds] [xds-cluster-manager-lb 0x40005d05c0] Adding child policy of type "cds_experimental" for locality "cluster:cluster-my-service-client-side-xds" (t=+27.16504ms)
tlogger.go:116: INFO balancergroup.go:100 [xds] [xds-cluster-manager-lb 0x40005d05c0] Creating child policy of type "cds_experimental" for locality "cluster:cluster-my-service-client-side-xds" (t=+27.270846ms)
tlogger.go:116: INFO cdsbalancer.go:99 [xds] [cds-lb 0x40008bac00] Created (t=+27.376951ms)
tlogger.go:116: INFO cdsbalancer.go:110 [xds] [cds-lb 0x40008bac00] xDS credentials in use: false (t=+27.72787ms)
tlogger.go:116: INFO cdsbalancer.go:499 [xds] [cds-lb 0x40008bac00] Received balancer config update: {
"LoadBalancingConfig": null,
"Cluster": "cluster-my-service-client-side-xds"
} (t=+27.91298ms)
tlogger.go:116: INFO cluster_handler.go:190 [xds] [cds-lb 0x40008bac00] CDS watch started on cluster-my-service-client-side-xds (t=+28.2974ms)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.cluster.v3.Cluster[cluster-my-service-client-side-xds] and known map[]. Diff [cluster-my-service-client-side-xds] (t=+28.911433ms)
tlogger.go:116: INFO simple.go:428 [xds-e2e] respond type.googleapis.com/envoy.config.cluster.v3.Cluster[cluster-my-service-client-side-xds] version "" with version "1" (t=+29.065641ms)
tlogger.go:116: INFO cdsbalancer.go:290 [xds] [cds-lb 0x40008bac00] Received Cluster resource contains content: [
{
"ClusterType": 0,
"ClusterName": "cluster-my-service-client-side-xds",
"EDSServiceName": "endpoints-my-service-client-side-xds",
"LRSServerConfig": 0,
"SecurityCfg": null,
"MaxRequests": null,
"DNSHostName": "",
"PrioritizedClusterNames": null,
"LBPolicy": [
{
"xds_wrr_locality_experimental": {
"childPolicy": [
{
"round_robin": {}
}
]
}
}
],
"OutlierDetection": {
"interval": "0.050s",
"successRateEjection": {
"stdevFactor": 1,
"minimumHosts": 1,
"requestVolume": 8
}
},
"Raw": {
"type_url": "type.googleapis.com/envoy.config.cluster.v3.Cluster",
"value": "CiJjbHVzdGVyLW15LXNlcnZpY2UtY2xpZW50LXNpZGUteGRzGioKAhoAEiRlbmRwb2ludHMtbXktc2VydmljZS1jbGllbnQtc2lkZS14ZHOaARMSBRCA4esXOgIIAUICCAhKAggBEAM="
}
}
], security config: null (t=+29.910186ms)
tlogger.go:116: INFO clusterresolver.go:86 [xds] [xds-cluster-resolver-lb 0x400045a4e0] Created (t=+30.053593ms)
tlogger.go:116: INFO cdsbalancer.go:316 [xds] [cds-lb 0x40008bac00] Created child policy 0x400045a4e0 of type cluster_resolver_experimental (t=+30.160099ms)
tlogger.go:116: INFO clusterresolver.go:190 [xds] [xds-cluster-resolver-lb 0x400045a4e0] Received new balancer config: {
"discoveryMechanisms": [
{
"cluster": "cluster-my-service-client-side-xds",
"edsServiceName": "endpoints-my-service-client-side-xds",
"outlierDetection": {
"interval": "0.050s",
"successRateEjection": {
"stdevFactor": 1,
"minimumHosts": 1,
"requestVolume": 8
}
}
}
],
"xdsLbPolicy": [
{
"xds_wrr_locality_experimental": {
"childPolicy": [
{
"round_robin": {}
}
]
}
}
]
} (t=+30.805533ms)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.cluster.v3.Cluster[cluster-my-service-client-side-xds] and known map[cluster-my-service-client-side-xds:{}]. Diff [] (t=+31.602275ms)
tlogger.go:116: INFO simple.go:380 [xds-e2e] open watch 3 for type.googleapis.com/envoy.config.cluster.v3.Cluster[cluster-my-service-client-side-xds] from nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14", version "1" (t=+31.719882ms)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment[endpoints-my-service-client-side-xds] and known map[]. Diff [endpoints-my-service-client-side-xds] (t=+31.865189ms)
tlogger.go:116: INFO simple.go:428 [xds-e2e] respond type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment[endpoints-my-service-client-side-xds] version "" with version "1" (t=+31.964894ms)
tlogger.go:116: INFO balancer.go:76 [xds] [priority-lb 0x40003d35e0] Created (t=+33.333467ms)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment[endpoints-my-service-client-side-xds] and known map[endpoints-my-service-client-side-xds:{}]. Diff [] (t=+33.905997ms)
tlogger.go:116: INFO simple.go:380 [xds-e2e] open watch 4 for type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment[endpoints-my-service-client-side-xds] from nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14", version "1" (t=+36.809651ms)
tlogger.go:116: INFO clusterresolver.go:248 [xds] [xds-cluster-resolver-lb 0x400045a4e0] Built child policy config: {
"children": {
"priority-0-0": {
"config": [
{
"outlier_detection_experimental": {
"interval": "0.050s",
"baseEjectionTime": "30s",
"maxEjectionTime": "300s",
"maxEjectionPercent": 10,
"successRateEjection": {
"stdevFactor": 1,
"enforcementPercentage": 100,
"minimumHosts": 1,
"requestVolume": 8
},
"childPolicy": [
{
"xds_cluster_impl_experimental": {
"cluster": "cluster-my-service-client-side-xds",
"edsServiceName": "endpoints-my-service-client-side-xds",
"childPolicy": [
{
"xds_wrr_locality_experimental": {
"childPolicy": [
{
"round_robin": {}
}
]
}
}
]
}
}
]
}
}
],
"ignoreReresolutionRequests": true
}
},
"priorities": [
"priority-0-0"
]
} (t=+37.089066ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [xds-cluster-manager-lb 0x40005d05c0] Balancer state update from locality cluster:cluster-my-service-client-side-xds, new state: {ConnectivityState:CONNECTING Picker:0x40009c6fc0} (t=+37.798104ms)
tlogger.go:116: INFO balancerstateaggregator.go:255 [xds] [xds-cluster-manager-lb 0x40005d05c0] Child pickers: map[cluster:cluster-my-service-client-side-xds:picker:0x40009c6fc0,state:CONNECTING,stateToAggregate:CONNECTING] (t=+37.959812ms)
tlogger.go:116: INFO clientconn.go:592 [core] [Channel #849] Channel Connectivity change to CONNECTING (t=+38.082219ms)
tlogger.go:116: INFO balancergroup.go:316 [xds] [priority-lb 0x40003d35e0] Adding child policy of type "outlier_detection_experimental" for locality "priority-0-0" (t=+38.188724ms)
tlogger.go:116: INFO balancergroup.go:100 [xds] [priority-lb 0x40003d35e0] Creating child policy of type "outlier_detection_experimental" for locality "priority-0-0" (t=+38.3[234](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:235)32ms)
tlogger.go:116: INFO balancer.go:77 [xds] [outlier-detection-lb 0x4000136600] Created (t=+38.444038ms)
tlogger.go:116: INFO clusterimpl.go:74 [xds] [xds-cluster-impl-lb 0x400067ea00] Created (t=+38.638748ms)
tlogger.go:116: INFO clusterimpl.go:213 [xds] [xds-cluster-impl-lb 0x400067ea00] Received update from resolver, balancer config: {
"cluster": "cluster-my-service-client-side-xds",
"edsServiceName": "endpoints-my-service-client-side-xds",
"childPolicy": [
{
"xds_wrr_locality_experimental": {
"childPolicy": [
{
"round_robin": {}
}
]
}
}
]
} (t=+38.879161ms)
tlogger.go:116: INFO weightedtarget.go:66 [xds] [weighted-target-lb 0x40005d1200] Created (t=+48.252258ms)
tlogger.go:116: INFO balancer.go:88 [xds] [wrrlocality-lb 0x4000460570] Created (t=+49.718536ms)
tlogger.go:116: INFO weightedtarget.go:91 [xds] [weighted-target-lb 0x40005d1200] Received update from resolver, balancer config: {
"targets": {
"{\"region\":\"region-1\",\"zone\":\"zone-1\",\"subZone\":\"subzone-1\"}": {
"weight": 1,
"childPolicy": [
{
"round_robin": {}
}
]
}
}
} (t=+50.275565ms)
tlogger.go:116: INFO balancergroup.go:316 [xds] [weighted-target-lb 0x40005d1200] Adding child policy of type "round_robin" for locality "{\"region\":\"region-1\",\"zone\":\"zone-1\",\"subZone\":\"subzone-1\"}" (t=+50.512378ms)
tlogger.go:116: INFO balancergroup.go:100 [xds] [weighted-target-lb 0x40005d1200] Creating child policy of type "round_robin" for locality "{\"region\":\"region-1\",\"zone\":\"zone-1\",\"subZone\":\"subzone-1\"}" (t=+50.632284ms)
tlogger.go:116: INFO clientconn.go:956 [core] [Channel #849 SubChannel #854] Subchannel created (t=+50.900098ms)
tlogger.go:116: INFO clientconn.go:956 [core] [Channel #849 SubChannel #855] Subchannel created (t=+51.[235](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:236)216ms)
tlogger.go:116: INFO clientconn.go:956 [core] [Channel #849 SubChannel #856] Subchannel created (t=+51.48973ms)
tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[]} (t=+51.724342ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [weighted-target-lb 0x40005d1200] Balancer state update from locality {"region":"region-1","zone":"zone-1","subZone":"subzone-1"}, new state: {ConnectivityState:CONNECTING Picker:0x40009c7e30} (t=+51.849749ms)
tlogger.go:116: INFO aggregator.go:252 [xds] [weighted-target-lb 0x40005d1200] Child pickers with config: map[{"region":"region-1","zone":"zone-1","subZone":"subzone-1"}:weight:1,picker:0x40009c7e30,state:CONNECTING,stateToAggregate:CONNECTING] (t=+52.0[236](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:237)58ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [priority-lb 0x40003d35e0] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0x40008fc0a8} (t=+52.355976ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [xds-cluster-manager-lb 0x40005d05c0] Balancer state update from locality cluster:cluster-my-service-client-side-xds, new state: {ConnectivityState:CONNECTING Picker:0x40008fc0a8} (t=+52.504683ms)
tlogger.go:116: INFO balancerstateaggregator.go:255 [xds] [xds-cluster-manager-lb 0x40005d05c0] Child pickers: map[cluster:cluster-my-service-client-side-xds:picker:0x40008fc0a8,state:CONNECTING,stateToAggregate:CONNECTING] (t=+52.615589ms)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #849 SubChannel #854] Subchannel Connectivity change to CONNECTING (t=+52.8191ms)
tlogger.go:116: INFO clientconn.go:1453 [core] [Channel #849 SubChannel #854] Subchannel picks a new address "localhost:39293" to connect (t=+53.329027ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [weighted-target-lb 0x40005d1200] Balancer state update from locality {"region":"region-1","zone":"zone-1","subZone":"subzone-1"}, new state: {ConnectivityState:CONNECTING Picker:0x40009c7e30} (t=+53.594941ms)
tlogger.go:116: INFO aggregator.go:252 [xds] [weighted-target-lb 0x40005d1200] Child pickers with config: map[{"region":"region-1","zone":"zone-1","subZone":"subzone-1"}:weight:1,picker:0x40009c7e30,state:CONNECTING,stateToAggregate:CONNECTING] (t=+53.985862ms)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #849 SubChannel #856] Subchannel Connectivity change to CONNECTING (t=+54.591194ms)
tlogger.go:116: INFO clientconn.go:1453 [core] [Channel #849 SubChannel #856] Subchannel picks a new address "localhost:45485" to connect (t=+59.736267ms)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #849 SubChannel #855] Subchannel Connectivity change to CONNECTING (t=+59.870374ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [priority-lb 0x40003d35e0] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0x40008fc198} (t=+61.747473ms)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #849 SubChannel #854] Subchannel Connectivity change to READY (t=+61.922983ms)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #849 SubChannel #856] Subchannel Connectivity change to READY (t=+62.195797ms)
tlogger.go:116: INFO clientconn.go:1453 [core] [Channel #849 SubChannel #855] Subchannel picks a new address "localhost:46753" to connect (t=+62.399208ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [weighted-target-lb 0x40005d1200] Balancer state update from locality {"region":"region-1","zone":"zone-1","subZone":"subzone-1"}, new state: {ConnectivityState:CONNECTING Picker:0x40009c7e30} (t=+62.566417ms)
tlogger.go:116: INFO aggregator.go:252 [xds] [weighted-target-lb 0x40005d1200] Child pickers with config: map[{"region":"region-1","zone":"zone-1","subZone":"subzone-1"}:weight:1,picker:0x40009c7e30,state:CONNECTING,stateToAggregate:CONNECTING] (t=+62.718625ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [weighted-target-lb 0x40005d1200] Balancer state update from locality {"region":"region-1","zone":"zone-1","subZone":"subzone-1"}, new state: {ConnectivityState:CONNECTING Picker:0x40009c7e30} (t=+62.847932ms)
tlogger.go:116: INFO aggregator.go:252 [xds] [weighted-target-lb 0x40005d1200] Child pickers with config: map[{"region":"region-1","zone":"zone-1","subZone":"subzone-1"}:weight:1,picker:0x40009c7e30,state:CONNECTING,stateToAggregate:CONNECTING] (t=+62.947537ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [priority-lb 0x40003d35e0] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0x40006ae1c8} (t=+63.106546ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [priority-lb 0x40003d35e0] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0x40006ae1f8} (t=+63.19205ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [xds-cluster-manager-lb 0x40005d05c0] Balancer state update from locality cluster:cluster-my-service-client-side-xds, new state: {ConnectivityState:CONNECTING Picker:0x40008fc198} (t=+63.264654ms)
tlogger.go:116: INFO balancerstateaggregator.go:255 [xds] [xds-cluster-manager-lb 0x40005d05c0] Child pickers: map[cluster:cluster-my-service-client-side-xds:picker:0x40008fc198,state:CONNECTING,stateToAggregate:CONNECTING] (t=+63.403561ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [xds-cluster-manager-lb 0x40005d05c0] Balancer state update from locality cluster:cluster-my-service-client-side-xds, new state: {ConnectivityState:CONNECTING Picker:0x40006ae1c8} (t=+63.522768ms)
tlogger.go:116: INFO balancerstateaggregator.go:255 [xds] [xds-cluster-manager-lb 0x40005d05c0] Child pickers: map[cluster:cluster-my-service-client-side-xds:picker:0x40006ae1c8,state:CONNECTING,stateToAggregate:CONNECTING] (t=+63.609372ms)
tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0x40005d16e0:{{Addr: "localhost:39293", ServerName: "", BalancerAttributes: {"<%!p(weightedroundrobin.attributeKey={})>": "Weight: 1" , "<%!p(hierarchy.pathKeyType=grpc.internal.address.hierarchical_path)>": "<0x4000ac6bd0>" , "<%!p(internal.localityKeyType=grpc.xds.internal.address.locality)>": "<%!p(internal.LocalityID={region-1 zone-1 subzone-1})>" , "<%!p(wrrlocality.attributeKey={})>": "Locality Weight: 1" }}}]} (t=+64.013194ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [weighted-target-lb 0x40005d1200] Balancer state update from locality {"region":"region-1","zone":"zone-1","subZone":"subzone-1"}, new state: {ConnectivityState:READY Picker:0x40005d26a0} (t=+64.1259ms)
tlogger.go:116: INFO aggregator.go:252 [xds] [weighted-target-lb 0x40005d1200] Child pickers with config: map[{"region":"region-1","zone":"zone-1","subZone":"subzone-1"}:weight:1,picker:0x40005d26a0,state:READY,stateToAggregate:READY] (t=+64.227805ms)
tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0x40005d16e0:{{Addr: "localhost:39293", ServerName: "", BalancerAttributes: {"<%!p(hierarchy.pathKeyType=grpc.internal.address.hierarchical_path)>": "<0x4000ac6bd0>" , "<%!p(internal.localityKeyType=grpc.xds.internal.address.locality)>": "<%!p(internal.LocalityID={region-1 zone-1 subzone-1})>" , "<%!p(wrrlocality.attributeKey={})>": "Locality Weight: 1" , "<%!p(weightedroundrobin.attributeKey={})>": "Weight: 1" }}} 0x40005d1b20:{{Addr: "localhost:45485", ServerName: "", BalancerAttributes: {"<%!p(internal.localityKeyType=grpc.xds.internal.address.locality)>": "<%!p(internal.LocalityID={region-1 zone-1 subzone-1})>" , "<%!p(wrrlocality.attributeKey={})>": "Locality Weight: 1" , "<%!p(weightedroundrobin.attributeKey={})>": "Weight: 1" , "<%!p(hierarchy.pathKeyType=grpc.internal.address.hierarchical_path)>": "<0x4000ac6c10>" }}}]} (t=+64.562123ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [weighted-target-lb 0x40005d1200] Balancer state update from locality {"region":"region-1","zone":"zone-1","subZone":"subzone-1"}, new state: {ConnectivityState:READY Picker:0x40005d28a0} (t=+64.667328ms)
tlogger.go:116: INFO aggregator.go:252 [xds] [weighted-target-lb 0x40005d1200] Child pickers with config: map[{"region":"region-1","zone":"zone-1","subZone":"subzone-1"}:weight:1,picker:0x40005d28a0,state:READY,stateToAggregate:READY] (t=+64.770434ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [priority-lb 0x40003d35e0] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0x40006ae480} (t=+64.899441ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [priority-lb 0x40003d35e0] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0x40006ae4b0} (t=+64.980345ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [xds-cluster-manager-lb 0x40005d05c0] Balancer state update from locality cluster:cluster-my-service-client-side-xds, new state: {ConnectivityState:CONNECTING Picker:0x40006ae1f8} (t=+65.08405ms)
tlogger.go:116: INFO balancerstateaggregator.go:255 [xds] [xds-cluster-manager-lb 0x40005d05c0] Child pickers: map[cluster:cluster-my-service-client-side-xds:picker:0x40006ae1f8,state:CONNECTING,stateToAggregate:CONNECTING] (t=+65.177955ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [xds-cluster-manager-lb 0x40005d05c0] Balancer state update from locality cluster:cluster-my-service-client-side-xds, new state: {ConnectivityState:READY Picker:0x40006ae480} (t=+65.279261ms)
tlogger.go:116: INFO balancerstateaggregator.go:255 [xds] [xds-cluster-manager-lb 0x40005d05c0] Child pickers: map[cluster:cluster-my-service-client-side-xds:picker:0x40006ae480,state:READY,stateToAggregate:READY] (t=+65.363165ms)
tlogger.go:116: INFO clientconn.go:592 [core] [Channel #849] Channel Connectivity change to READY (t=+65.44947ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [xds-cluster-manager-lb 0x40005d05c0] Balancer state update from locality cluster:cluster-my-service-client-side-xds, new state: {ConnectivityState:READY Picker:0x40006ae4b0} (t=+65.542875ms)
tlogger.go:116: INFO balancerstateaggregator.go:255 [xds] [xds-cluster-manager-lb 0x40005d05c0] Child pickers: map[cluster:cluster-my-service-client-side-xds:picker:0x40006ae4b0,state:READY,stateToAggregate:READY] (t=+65.626779ms)
tlogger.go:116: INFO balancer.go:843 [xds] [Channel #849] SuccessRate algorithm detected outlier: [[{Addr: "localhost:45485", ServerName: "", Attributes: {"<%!p(internal.handshakeClusterNameKey={})>": "cluster-my-service-client-side-xds" }, BalancerAttributes: {"<%!p(hierarchy.pathKeyType=grpc.internal.address.hierarchical_path)>": "<0x4000ac6c10>" , "<%!p(internal.localityKeyType=grpc.xds.internal.address.locality)>": "<%!p(internal.LocalityID={region-1 zone-1 subzone-1})>" , "<%!p(wrrlocality.attributeKey={})>": "Locality Weight: 1" , "<%!p(weightedroundrobin.attributeKey={})>": "Weight: 1" }}]]. Parameters: successRate=0.000000, mean=0.500000, stddev=0.500000, requiredSuccessRate=0.499500 (t=+89.231231ms)
tlogger.go:116: INFO balancer.go:885 [xds] [Channel #849] Subchannel ejected: [{Addr: "localhost:45485", ServerName: "", Attributes: {"<%!p(internal.handshakeClusterNameKey={})>": "cluster-my-service-client-side-xds" }, BalancerAttributes: {"<%!p(weightedroundrobin.attributeKey={})>": "Weight: 1" , "<%!p(hierarchy.pathKeyType=grpc.internal.address.hierarchical_path)>": "<0x4000ac6c10>" , "<%!p(internal.localityKeyType=grpc.xds.internal.address.locality)>": "<%!p(internal.LocalityID={region-1 zone-1 subzone-1})>" , "<%!p(wrrlocality.attributeKey={})>": "Locality Weight: 1" }}] (t=+89.491544ms)
tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0x40005d16e0:{{Addr: "localhost:39293", ServerName: "", BalancerAttributes: {"<%!p(wrrlocality.attributeKey={})>": "Locality Weight: 1" , "<%!p(weightedroundrobin.attributeKey={})>": "Weight: 1" , "<%!p(hierarchy.pathKeyType=grpc.internal.address.hierarchical_path)>": "<0x4000ac6bd0>" , "<%!p(internal.localityKeyType=grpc.xds.internal.address.locality)>": "<%!p(internal.LocalityID={region-1 zone-1 subzone-1})>" }}}]} (t=+89.79086ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [weighted-target-lb 0x40005d1200] Balancer state update from locality {"region":"region-1","zone":"zone-1","subZone":"subzone-1"}, new state: {ConnectivityState:READY Picker:0x4000ac69a0} (t=+89.919167ms)
tlogger.go:116: INFO aggregator.go:252 [xds] [weighted-target-lb 0x40005d1200] Child pickers with config: map[{"region":"region-1","zone":"zone-1","subZone":"subzone-1"}:weight:1,picker:0x4000ac69a0,state:READY,stateToAggregate:READY] (t=+90.032973ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [priority-lb 0x40003d35e0] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0x40004d1f80} (t=+90.421394ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [xds-cluster-manager-lb 0x40005d05c0] Balancer state update from locality cluster:cluster-my-service-client-side-xds, new state: {ConnectivityState:READY Picker:0x40004d1f80} (t=+90.550801ms)
tlogger.go:116: INFO balancerstateaggregator.go:255 [xds] [xds-cluster-manager-lb 0x40005d05c0] Child pickers: map[cluster:cluster-my-service-client-side-xds:picker:0x40004d1f80,state:READY,stateToAggregate:READY] (t=+90.653606ms)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #849 SubChannel #855] Subchannel Connectivity change to READY (t=+91.946775ms)
tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[0x40005d16e0:{{Addr: "localhost:39293", ServerName: "", BalancerAttributes: {"<%!p(hierarchy.pathKeyType=grpc.internal.address.hierarchical_path)>": "<0x4000ac6bd0>" , "<%!p(internal.localityKeyType=grpc.xds.internal.address.locality)>": "<%!p(internal.LocalityID={region-1 zone-1 subzone-1})>" , "<%!p(wrrlocality.attributeKey={})>": "Locality Weight: 1" , "<%!p(weightedroundrobin.attributeKey={})>": "Weight: 1" }}} 0x40005d1940:{{Addr: "localhost:46753", ServerName: "", BalancerAttributes: {"<%!p(hierarchy.pathKeyType=grpc.internal.address.hierarchical_path)>": "<0x4000ac6bf0>" , "<%!p(internal.localityKeyType=grpc.xds.internal.address.locality)>": "<%!p(internal.LocalityID={region-1 zone-1 subzone-1})>" , "<%!p(wrrlocality.attributeKey={})>": "Locality Weight: 1" , "<%!p(weightedroundrobin.attributeKey={})>": "Weight: 1" }}}]} (t=+92.405699ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [weighted-target-lb 0x40005d1200] Balancer state update from locality {"region":"region-1","zone":"zone-1","subZone":"subzone-1"}, new state: {ConnectivityState:READY Picker:0x400077e960} (t=+92.53[240](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:241)6ms)
tlogger.go:116: INFO aggregator.go:252 [xds] [weighted-target-lb 0x40005d1200] Child pickers with config: map[{"region":"region-1","zone":"zone-1","subZone":"subzone-1"}:weight:1,picker:0x400077e960,state:READY,stateToAggregate:READY] (t=+92.644111ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [priority-lb 0x40003d35e0] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0x40007b3a28} (t=+92.793419ms)
tlogger.go:116: INFO balancergroup.go:559 [xds] [xds-cluster-manager-lb 0x40005d05c0] Balancer state update from locality cluster:cluster-my-service-client-side-xds, new state: {ConnectivityState:READY Picker:0x40007b3a28} (t=+92.895625ms)
tlogger.go:116: INFO balancerstateaggregator.go:255 [xds] [xds-cluster-manager-lb 0x40005d05c0] Child pickers: map[cluster:cluster-my-service-client-side-xds:picker:0x40007b3a28,state:READY,stateToAggregate:READY] (t=+92.99183ms)
xds_client_outlier_detection_test.go:310: error in expected round robin: timeout when waiting for roundrobin distribution of RPCs across addresses: [{Addr: "127.0.0.1:39293", ServerName: "", } {Addr: "127.0.0.1:46753", ServerName: "", } {Addr: "127.0.0.1:45485", ServerName: "", }]
tlogger.go:116: INFO clientconn.go:592 [core] [Channel #849] Channel Connectivity change to SHUTDOWN (t=+10.010498222s)
tlogger.go:116: INFO balancer_conn_wrappers.go:191 [core] [Channel #849] ccBalancerWrapper: closing (t=+10.01066713s)
tlogger.go:116: INFO cluster_handler.go:193 [xds] [cds-lb 0x40008bac00] CDS watch canceled on cluster-my-service-client-side-xds (t=+10.010899142s)
tlogger.go:116: INFO clusterimpl.go:304 [xds] [xds-cluster-impl-lb 0x400067ea00] Shutdown (t=+10.011272761s)
tlogger.go:116: INFO balancergroup.go:400 [xds] [priority-lb 0x40003d35e0] Removing child policy for locality "priority-0-0" (t=+10.01145117s)
tlogger.go:116: INFO clusterresolver.go:337 [xds] [xds-cluster-resolver-lb 0x400045a4e0] Shutdown (t=+10.011530074s)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.cluster.v3.Cluster[] and known map[cluster-my-service-client-side-xds:{}]. Diff [] (t=+10.011634879s)
tlogger.go:116: INFO simple.go:380 [xds-e2e] open watch 5 for type.googleapis.com/envoy.config.cluster.v3.Cluster[] from nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14", version "1" (t=+10.011791687s)
tlogger.go:116: INFO cdsbalancer.go:439 [xds] [cds-lb 0x40008bac00] Shutdown (t=+10.011960596s)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment[] and known map[endpoints-my-service-client-side-xds:{}]. Diff [] (t=+10.012145305s)
tlogger.go:116: INFO simple.go:380 [xds-e2e] open watch 6 for type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment[] from nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14", version "1" (t=+10.012293112s)
tlogger.go:116: INFO clustermanager.go:150 [xds] [xds-cluster-manager-lb 0x40005d05c0] Shutdown (t=+10.01[242](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:243)5419s)
tlogger.go:116: INFO resolver_conn_wrapper.go:126 [core] [Channel #849] Closing the name resolver (t=+10.012543025s)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #849 SubChannel #855] Subchannel Connectivity change to SHUTDOWN (t=+10.012692232s)
tlogger.go:116: INFO clientconn.go:1693 [core] [Channel #849 SubChannel #855] Subchannel deleted (t=+10.012807638s)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #849 SubChannel #856] Subchannel Connectivity change to SHUTDOWN (t=+10.012897743s)
tlogger.go:116: INFO clientconn.go:1693 [core] [Channel #849 SubChannel #856] Subchannel deleted (t=+10.012996348s)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #849 SubChannel #854] Subchannel Connectivity change to SHUTDOWN (t=+10.013091953s)
tlogger.go:116: INFO xds_resolver.go:146 [xds] [xds-resolver 0x4000[244](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:245)620] Watch cancel on resource name my-service-client-side-xds with xds-client 0x40005f3a90 (t=+10.013188557s)
tlogger.go:116: INFO clientconn.go:1693 [core] [Channel #849 SubChannel #854] Subchannel deleted (t=+10.013382167s)
tlogger.go:116: WARNING authority.go:417 [xds] [xds-client 0x4000881950] [127.0.0.1:43269] Watchers not notified since ADS stream failed after having received at least one response: rpc error: code = Canceled desc = context canceled (t=+10.01363408s)
tlogger.go:116: WARNING transport.go:497 [xds] [xds-client 0x4000881950] [127.0.0.1:43269] ADS stream closed: rpc error: code = Canceled desc = context canceled (t=+10.013754786s)
tlogger.go:116: INFO simple.go:359 [xds-e2e] nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14" requested type.googleapis.com/envoy.config.listener.v3.Listener[] and known map[my-service-client-side-xds:{}]. Diff [] (t=+10.013848691s)
tlogger.go:116: INFO simple.go:380 [xds-e2e] open watch 7 for type.googleapis.com/envoy.config.listener.v3.Listener[] from nodeID "f9c0941c-5126-453b-af33-d5bdcc6e5b14", version "1" (t=+10.013993498s)
tlogger.go:116: INFO clientconn.go:592 [core] [Channel #850] Channel Connectivity change to SHUTDOWN (t=+10.014198808s)
tlogger.go:116: INFO balancer_conn_wrappers.go:191 [core] [Channel #850] ccBalancerWrapper: closing (t=+10.014307414s)
tlogger.go:116: INFO resolver_conn_wrapper.go:126 [core] [Channel #850] Closing the name resolver (t=+10.0144[252](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:253)2s)
tlogger.go:116: INFO clientconn.go:318 [core] [Channel #849] Channel deleted (t=+10.014550226s)
tlogger.go:116: INFO server.go:806 [core] [Server #847 ListenSocket #848] ListenSocket deleted (t=+10.015009649s)
tlogger.go:116: INFO server.go:806 [core] [Server #845 ListenSocket #846] ListenSocket deleted (t=+10.015[256](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:257)862s)
tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #850 SubChannel #851] Subchannel Connectivity change to SHUTDOWN (t=+10.015467172s)
tlogger.go:116: INFO clientconn.go:1693 [core] [Channel #850 SubChannel #851] Subchannel deleted (t=+10.015609079s)
tlogger.go:116: INFO server.go:806 [core] [Server #843 ListenSocket #844] ListenSocket deleted (t=+10.015701884s)
tlogger.go:116: INFO server.go:806 [core] [Server #841 ListenSocket #842] ListenSocket deleted (t=+10.015864592s)
tlogger.go:116: INFO clientconn.go:318 [core] [Channel #850] Channel deleted (t=+10.016177608s)
tlogger.go:116: INFO clientimpl.go:88 [xds] [xds-client 0x4000881950] Shutdown (t=+10.016[296](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:297)114s)
tlogger.go:116: INFO xds_resolver.go:[322](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:323) [xds] [xds-resolver 0x4000244620] Shutdown (t=+10.016[395](https://github.com/grpc/grpc-go/actions/runs/6017419635/job/16323557911?pr=6595#step:8:396)119s)
FAIL
FAIL google.golang.org/grpc/test/xds 42.104s
Removing the P2 label since this fails quite often in blaze: http://sponge2/9755b204-9e27-46f7-bd0c-d12e720dd86d
https://github.com/grpc/grpc-go/actions/runs/7733517345/job/21085764301?pr=6953
https://github.com/grpc/grpc-go/actions/runs/10063211882/job/27817491867?pr=7432
https://github.com/grpc/grpc-go/actions/runs/10308428524/job/28535815523?pr=7458