Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Flaky test: 145/10k: OutlierDetectionXDSDefaultOn #6599

Open
easwars opened this issue Aug 29, 2023 · 3 comments
Open

Flaky test: 145/10k: OutlierDetectionXDSDefaultOn #6599

easwars opened this issue Aug 29, 2023 · 3 comments
Assignees
@zasweq
Labels
P2 Type: Bug

Comments

@easwars
Copy link
Contributor

easwars commented Aug 29, 2023

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
@zasweq zasweq added the P2 label Sep 5, 2023
@easwars easwars changed the title Flaky test: OutlierDetectionXDSDefaultOn Flaky test: 145/10k: OutlierDetectionXDSDefaultOn Sep 19, 2023
@easwars
Copy link
Contributor Author

easwars commented Sep 19, 2023

Removing the P2 label since this fails quite often in blaze: http://sponge2/9755b204-9e27-46f7-bd0c-d12e720dd86d

@easwars easwars removed the P2 label Sep 19, 2023
@zasweq
Copy link
Contributor

zasweq commented Sep 19, 2023

Yikes. Will try and get to this this week then.

@dfawley dfawley added the P1 label Sep 26, 2023
@zasweq zasweq added P2 and removed P1 labels Nov 15, 2023
@arvindbr8
Copy link
Member

https://github.com/grpc/grpc-go/actions/runs/7733517345/job/21085764301?pr=6953

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@zasweq zasweq

Labels
P2 Type: Bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@easwars @arvindbr8 @dfawley @zasweq