2024/03/15 12:58:17 Creating Client App ... 2024/03/15 12:58:17 Pod - chatclient-5c9b9bc87-k4mh7 starting as client 2024/03/15 12:58:17 Creating GRPC Connection to: xds:///chatservice:16000 2024/03/15 12:58:17 INFO: [core] [Channel #1] Channel created 2024/03/15 12:58:17 INFO: [core] [Channel #1] original dial target is: "xds:///chatservice:16000" 2024/03/15 12:58:17 INFO: [core] [Channel #1] parsed dial target is: resolver.Target{URL:url.URL{Scheme:"xds", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/chatservice:16000", RawPath:"", OmitHost:false, ForceQuery:false, RawQuery:"", Fragment:"", RawFragment:""}} 2024/03/15 12:58:17 INFO: [core] [Channel #1] Channel authority set to "chatservice:16000" 2024/03/15 12:58:17 INFO: [xds] [xds-resolver 0xc000303b90] Creating resolver for target: xds:///chatservice:16000 2024/03/15 12:58:17 INFO: [xds] [xds-bootstrap] Using bootstrap file with name "/etc/istio/proxy/grpc-bootstrap.json" 2024/03/15 12:58:17 INFO: [xds] [xds-bootstrap] Bootstrap config for creating xds-client: { "XDSServer": { "server_uri": "unix:///etc/istio/proxy/XDS", "channel_creds": [ { "type": "insecure" } ], "server_features": [ "xds_v3" ] }, "CertProviderConfigs": { "default": {} }, "ServerListenerResourceNameTemplate": "xds.istio.io/grpc/lds/inbound/%s", "ClientDefaultListenerResourceNameTemplate": "%s", "Authorities": null, "NodeProto": { "id": "sidecar~10.196.109.181~chatclient-5c9b9bc87-k4mh7.default~default.svc.cluster.local", "metadata": { "ANNOTATIONS": { "inject.istio.io/templates": "grpc-agent", "kubectl.kubernetes.io/default-container": "chatclient", "kubectl.kubernetes.io/default-logs-container": "chatclient", "kubernetes.io/config.seen": "2024-03-15T12:24:48.561320298Z", "kubernetes.io/config.source": "api", "prometheus.io/path": "/stats/prometheus", "prometheus.io/port": "15020", "prometheus.io/scrape": "true", "proxy.istio.io/config": "{\"holdApplicationUntilProxyStarts\": true}", "proxy.istio.io/overrides": "{\"containers\":[{\"name\":\"chatclient\",\"image\":\"nicolaka/netshoot:latest\",\"command\":[\"/go/src/app/client\",\"-addr\",\"chatservice:16000\",\"-xds\",\"true\"],\"env\":[{\"name\":\"GRPC_GO_LOG_SEVERITY_LEVEL\",\"value\":\"info\"},{\"name\":\"GRPC_GO_LOG_VERBOSITY_LEVEL\",\"value\":\"99\"}],\"resources\":{},\"volumeMounts\":[{\"name\":\"grpcmount\",\"mountPath\":\"/go/src/app\"},{\"name\":\"kube-api-access-7bnsf\",\"readOnly\":true,\"mountPath\":\"/var/run/secrets/kubernetes.io/serviceaccount\"}],\"terminationMessagePath\":\"/dev/termination-log\",\"terminationMessagePolicy\":\"File\",\"imagePullPolicy\":\"IfNotPresent\"}]}", "sidecar.istio.io/rewriteAppHTTPProbers": "false", "sidecar.istio.io/status": "{\"initContainers\":null,\"containers\":[\"istio-proxy\",\"chatclient\"],\"volumes\":[\"workload-socket\",\"workload-certs\",\"istio-xds\",\"istio-data\",\"istio-podinfo\",\"istio-token\",\"istiod-ca-cert\"],\"imagePullSecrets\":null,\"revision\":\"default\"}" }, "APP_CONTAINERS": "chatclient", "CLUSTER_ID": "Kubernetes", "ENVOY_PROMETHEUS_PORT": 15090, "ENVOY_STATUS_PORT": 15021, "GENERATOR": "grpc", "INSTANCE_IPS": "10.196.109.181", "ISTIO_PROXY_SHA": "c5837eae93559dfa0279db04b3d565b9ec01c833", "ISTIO_VERSION": "1.15.0", "LABELS": { "app": "chatclient", "pod-template-hash": "5c9b9bc87", "service.istio.io/canonical-name": "chatclient", "service.istio.io/canonical-revision": "latest", "sidecar.istio.io/inject": "true" }, "MESH_ID": "cluster.local", "NAME": "chatclient-5c9b9bc87-k4mh7", "NAMESPACE": "default", "OWNER": "kubernetes://apis/apps/v1/namespaces/default/deployments/chatclient", "PILOT_SAN": [ "istiod.istio-system.svc" ], "PLATFORM_METADATA": { "azure_CreatedAt": "1710498077", "azure_CreatedFor": "kraval", "azure_CreatorEmail": "kraval@a5gnet.com", "azure_Environment": "Functional Testing", "azure_Role": "worker0", "azure_StayForHours": "\"10\"", "azure_location": "CentralIndia", "azure_name": "kravalworker0", "azure_vmId": "4bc54273-43a8-4fd1-9943-bd7d37ae75bc" }, "PROV_CERT": "var/run/secrets/istio/root-cert.pem", "PROXY_CONFIG": { "binaryPath": "/usr/local/bin/envoy", "concurrency": 2, "configPath": "./etc/istio/proxy", "controlPlaneAuthPolicy": "MUTUAL_TLS", "discoveryAddress": "istiod.istio-system.svc:15012", "drainDuration": "45s", "holdApplicationUntilProxyStarts": true, "parentShutdownDuration": "60s", "proxyAdminPort": 15000, "serviceCluster": "istio-proxy", "statNameLength": 189, "statusPort": 15020, "terminationDrainDuration": "5s", "tracing": { "zipkin": { "address": "zipkin.istio-system:9411" } } }, "SERVICE_ACCOUNT": "default", "WORKLOAD_NAME": "chatclient" }, "locality": { "region": "CentralIndia" }, "user_agent_name": "gRPC Go", "UserAgentVersionType": { "UserAgentVersion": "1.60.1" }, "client_features": [ "envoy.lb.does_not_support_overprovisioning", "xds.config.resource-in-sotw" ] } } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] Created client to xDS management server: unix:///etc/istio/proxy/XDS-insecure-xds_v3 2024/03/15 12:58:17 INFO: [xds] xDS node ID: sidecar~10.196.109.181~chatclient-5c9b9bc87-k4mh7.default~default.svc.cluster.local 2024/03/15 12:58:17 INFO: [core] [Channel #2] Channel created 2024/03/15 12:58:17 INFO: [core] [Channel #2] original dial target is: "unix:///etc/istio/proxy/XDS" 2024/03/15 12:58:17 INFO: [core] [Channel #2] parsed dial target is: resolver.Target{URL:url.URL{Scheme:"unix", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/etc/istio/proxy/XDS", RawPath:"", OmitHost:false, ForceQuery:false, RawQuery:"", Fragment:"", RawFragment:""}} 2024/03/15 12:58:17 INFO: [core] [Channel #2] Channel authority set to "localhost" 2024/03/15 12:58:17 INFO: [core] [Channel #2] Resolver state updated: { "Addresses": [ { "Addr": "/etc/istio/proxy/XDS", "ServerName": "", "Attributes": { "\u003c%!p(networktype.keyType=grpc.internal.transport.networktype)\u003e": "unix" }, "BalancerAttributes": null, "Metadata": null } ], "Endpoints": [ { "Addresses": [ { "Addr": "/etc/istio/proxy/XDS", "ServerName": "", "Attributes": { "\u003c%!p(networktype.keyType=grpc.internal.transport.networktype)\u003e": "unix" }, "BalancerAttributes": null, "Metadata": null } ], "Attributes": null } ], "ServiceConfig": null, "Attributes": null } (resolver returned new addresses) 2024/03/15 12:58:17 INFO: [core] [Channel #2] Channel switches to new LB policy "pick_first" 2024/03/15 12:58:17 INFO: [core] [pick-first-lb 0xc0003c4420] Received new config { "shuffleAddressList": false }, resolver state { "Addresses": [ { "Addr": "/etc/istio/proxy/XDS", "ServerName": "", "Attributes": { "\u003c%!p(networktype.keyType=grpc.internal.transport.networktype)\u003e": "unix" }, "BalancerAttributes": null, "Metadata": null } ], "Endpoints": [ { "Addresses": [ { "Addr": "/etc/istio/proxy/XDS", "ServerName": "", "Attributes": { "\u003c%!p(networktype.keyType=grpc.internal.transport.networktype)\u003e": "unix" }, "BalancerAttributes": null, "Metadata": null } ], "Attributes": null } ], "ServiceConfig": null, "Attributes": null } 2024/03/15 12:58:17 INFO: [core] [Channel #2 SubChannel #3] Subchannel created 2024/03/15 12:58:17 INFO: [core] [Channel #2] Channel Connectivity change to CONNECTING 2024/03/15 12:58:17 INFO: [core] [Channel #2] Channel exiting idle mode 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Created transport to server "unix:///etc/istio/proxy/XDS" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] New watch for type "ListenerResource", resource name "chatservice:16000" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] First watch for type "ListenerResource", resource name "chatservice:16000" 2024/03/15 12:58:17 INFO: [xds] [xds-resolver 0xc000303b90] Watch started on resource name chatservice:16000 with xds-client 0xc0003c2090 2024/03/15 12:58:17 INFO: [core] [Channel #1] Channel exiting idle mode 2024/03/15 12:58:17 INFO: [core] [Channel #2 SubChannel #3] Subchannel Connectivity change to CONNECTING 2024/03/15 12:58:17 Sending - Sender-chatclient-5c9b9bc87-k4mh7, ULID-4-DDDD-AAAA-BBBB-CCCC, Msg-0 2024/03/15 12:58:17 INFO: [core] [Channel #2 SubChannel #3] Subchannel picks a new address "/etc/istio/proxy/XDS" to connect 2024/03/15 12:58:17 Sending - Sender-chatclient-5c9b9bc87-k4mh7, ULID-3-CCCC-DDDD-AAAA-BBBB, Msg-0 2024/03/15 12:58:17 INFO: [core] [pick-first-lb 0xc0003c4420] Received SubConn state update: 0xc0003c45a0, {ConnectivityState:CONNECTING ConnectionError:} 2024/03/15 12:58:17 INFO: [core] [Channel #2 SubChannel #3] Subchannel Connectivity change to READY 2024/03/15 12:58:17 INFO: [core] [pick-first-lb 0xc0003c4420] Received SubConn state update: 0xc0003c45a0, {ConnectivityState:READY ConnectionError:} 2024/03/15 12:58:17 Sending - Sender-chatclient-5c9b9bc87-k4mh7, ULID-2-BBBB-CCCC-DDDD-AAAA, Msg-0 2024/03/15 12:58:17 Sending - Sender-chatclient-5c9b9bc87-k4mh7, ULID-1-AAAA-BBBB-CCCC-DDDD, Msg-0 2024/03/15 12:58:17 INFO: [core] [Channel #2] Channel Connectivity change to READY 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS stream created 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "node": { "id": "sidecar~10.196.109.181~chatclient-5c9b9bc87-k4mh7.default~default.svc.cluster.local", "metadata": { "ANNOTATIONS": { "inject.istio.io/templates": "grpc-agent", "kubectl.kubernetes.io/default-container": "chatclient", "kubectl.kubernetes.io/default-logs-container": "chatclient", "kubernetes.io/config.seen": "2024-03-15T12:24:48.561320298Z", "kubernetes.io/config.source": "api", "prometheus.io/path": "/stats/prometheus", "prometheus.io/port": "15020", "prometheus.io/scrape": "true", "proxy.istio.io/config": "{\"holdApplicationUntilProxyStarts\": true}", "proxy.istio.io/overrides": "{\"containers\":[{\"name\":\"chatclient\",\"image\":\"nicolaka/netshoot:latest\",\"command\":[\"/go/src/app/client\",\"-addr\",\"chatservice:16000\",\"-xds\",\"true\"],\"env\":[{\"name\":\"GRPC_GO_LOG_SEVERITY_LEVEL\",\"value\":\"info\"},{\"name\":\"GRPC_GO_LOG_VERBOSITY_LEVEL\",\"value\":\"99\"}],\"resources\":{},\"volumeMounts\":[{\"name\":\"grpcmount\",\"mountPath\":\"/go/src/app\"},{\"name\":\"kube-api-access-7bnsf\",\"readOnly\":true,\"mountPath\":\"/var/run/secrets/kubernetes.io/serviceaccount\"}],\"terminationMessagePath\":\"/dev/termination-log\",\"terminationMessagePolicy\":\"File\",\"imagePullPolicy\":\"IfNotPresent\"}]}", "sidecar.istio.io/rewriteAppHTTPProbers": "false", "sidecar.istio.io/status": "{\"initContainers\":null,\"containers\":[\"istio-proxy\",\"chatclient\"],\"volumes\":[\"workload-socket\",\"workload-certs\",\"istio-xds\",\"istio-data\",\"istio-podinfo\",\"istio-token\",\"istiod-ca-cert\"],\"imagePullSecrets\":null,\"revision\":\"default\"}" }, "APP_CONTAINERS": "chatclient", "CLUSTER_ID": "Kubernetes", "ENVOY_PROMETHEUS_PORT": 15090, "ENVOY_STATUS_PORT": 15021, "GENERATOR": "grpc", "INSTANCE_IPS": "10.196.109.181", "ISTIO_PROXY_SHA": "c5837eae93559dfa0279db04b3d565b9ec01c833", "ISTIO_VERSION": "1.15.0", "LABELS": { "app": "chatclient", "pod-template-hash": "5c9b9bc87", "service.istio.io/canonical-name": "chatclient", "service.istio.io/canonical-revision": "latest", "sidecar.istio.io/inject": "true" }, "MESH_ID": "cluster.local", "NAME": "chatclient-5c9b9bc87-k4mh7", "NAMESPACE": "default", "OWNER": "kubernetes://apis/apps/v1/namespaces/default/deployments/chatclient", "PILOT_SAN": [ "istiod.istio-system.svc" ], "PLATFORM_METADATA": { "azure_CreatedAt": "1710498077", "azure_CreatedFor": "kraval", "azure_CreatorEmail": "kraval@a5gnet.com", "azure_Environment": "Functional Testing", "azure_Role": "worker0", "azure_StayForHours": "\"10\"", "azure_location": "CentralIndia", "azure_name": "kravalworker0", "azure_vmId": "4bc54273-43a8-4fd1-9943-bd7d37ae75bc" }, "PROV_CERT": "var/run/secrets/istio/root-cert.pem", "PROXY_CONFIG": { "binaryPath": "/usr/local/bin/envoy", "concurrency": 2, "configPath": "./etc/istio/proxy", "controlPlaneAuthPolicy": "MUTUAL_TLS", "discoveryAddress": "istiod.istio-system.svc:15012", "drainDuration": "45s", "holdApplicationUntilProxyStarts": true, "parentShutdownDuration": "60s", "proxyAdminPort": 15000, "serviceCluster": "istio-proxy", "statNameLength": 189, "statusPort": 15020, "terminationDrainDuration": "5s", "tracing": { "zipkin": { "address": "zipkin.istio-system:9411" } } }, "SERVICE_ACCOUNT": "default", "WORKLOAD_NAME": "chatclient" }, "locality": { "region": "CentralIndia" }, "userAgentName": "gRPC Go", "userAgentVersion": "1.60.1", "clientFeatures": [ "envoy.lb.does_not_support_overprovisioning", "xds.config.resource-in-sotw" ] }, "resourceNames": [ "chatservice:16000" ], "typeUrl": "type.googleapis.com/envoy.config.listener.v3.Listener" } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS response received: { "versionInfo": "2024-03-15T12:37:57Z/103", "resources": [ { "@type": "type.googleapis.com/envoy.config.listener.v3.Listener", "name": "chatservice:16000", "address": { "socketAddress": { "address": "0.0.0.0", "portValue": 16000 } }, "apiListener": { "apiListener": { "@type": "type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager", "rds": { "configSource": { "ads": { } }, "routeConfigName": "outbound|16000||chatservice.default.svc.cluster.local" }, "httpFilters": [ { "name": "envoy.filters.http.fault", "typedConfig": { "@type": "type.googleapis.com/envoy.extensions.filters.http.fault.v3.HTTPFault" } }, { "name": "envoy.filters.http.router", "typedConfig": { "@type": "type.googleapis.com/envoy.extensions.filters.http.router.v3.Router" } } ] } } } ], "typeUrl": "type.googleapis.com/envoy.config.listener.v3.Listener", "nonce": "5tlvTWkSfuQ=e8c3d81c-55c5-48fb-8aaf-291c48682d81", "controlPlane": { "identifier": "{\"Component\":\"istiod\",\"ID\":\"istiod-86cd5997bb-sq788\",\"Info\":{\"version\":\"1.15.0\",\"revision\":\"e3364ab424b70ca8ee1ca76cb0b3afb73476aaac\",\"golang_version\":\"go1.19\",\"status\":\"Clean\",\"tag\":\"1.15.0\"}}" } } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Resource type "ListenerResource" with name "chatservice:16000" added to cache 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Sending ACK for resource type: "type.googleapis.com/envoy.config.listener.v3.Listener", version: "2024-03-15T12:37:57Z/103", nonce: "5tlvTWkSfuQ=e8c3d81c-55c5-48fb-8aaf-291c48682d81" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "versionInfo": "2024-03-15T12:37:57Z/103", "resourceNames": [ "chatservice:16000" ], "typeUrl": "type.googleapis.com/envoy.config.listener.v3.Listener", "responseNonce": "5tlvTWkSfuQ=e8c3d81c-55c5-48fb-8aaf-291c48682d81" } 2024/03/15 12:58:17 INFO: [xds] [xds-resolver 0xc000303b90] received LDS update: { "RouteConfigName": "outbound|16000||chatservice.default.svc.cluster.local", "InlineRouteConfig": null, "MaxStreamDuration": 0, "HTTPFilters": [ { "Name": "envoy.filters.http.fault", "Filter": {}, "Config": { "FilterConfig": null } }, { "Name": "envoy.filters.http.router", "Filter": {}, "Config": { "FilterConfig": null } } ], "InboundListenerCfg": null, "Raw": { "type_url": "type.googleapis.com/envoy.config.listener.v3.Listener", "value": "ChFjaGF0c2VydmljZToxNjAwMBIOCgwSBzAuMC4wLjAYgH2aAfECCu4CCmV0eXBlLmdvb2dsZWFwaXMuY29tL2Vudm95LmV4dGVuc2lvbnMuZmlsdGVycy5uZXR3b3JrLmh0dHBfY29ubmVjdGlvbl9tYW5hZ2VyLnYzLkh0dHBDb25uZWN0aW9uTWFuYWdlchKEAipiChhlbnZveS5maWx0ZXJzLmh0dHAuZmF1bHQiRgpEdHlwZS5nb29nbGVhcGlzLmNvbS9lbnZveS5leHRlbnNpb25zLmZpbHRlcnMuaHR0cC5mYXVsdC52My5IVFRQRmF1bHQqYQoZZW52b3kuZmlsdGVycy5odHRwLnJvdXRlciJECkJ0eXBlLmdvb2dsZWFwaXMuY29tL2Vudm95LmV4dGVuc2lvbnMuZmlsdGVycy5odHRwLnJvdXRlci52My5Sb3V0ZXIaOwoCGgASNW91dGJvdW5kfDE2MDAwfHxjaGF0c2VydmljZS5kZWZhdWx0LnN2Yy5jbHVzdGVyLmxvY2Fs" } }, err: 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] New watch for type "RouteConfigResource", resource name "outbound|16000||chatservice.default.svc.cluster.local" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] First watch for type "RouteConfigResource", resource name "outbound|16000||chatservice.default.svc.cluster.local" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "resourceNames": [ "outbound|16000||chatservice.default.svc.cluster.local" ], "typeUrl": "type.googleapis.com/envoy.config.route.v3.RouteConfiguration" } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS response received: version_info:"2024-03-15T12:37:57Z/103" resources:{[type.googleapis.com/envoy.config.route.v3.RouteConfiguration]:{name:"outbound|16000||chatservice.default.svc.cluster.local" virtual_hosts:{name:"chatservice.default.svc.cluster.local:16000" domains:"chatservice.default.svc.cluster.local" domains:"chatservice.default.svc.cluster.local:16000" domains:"chatservice" domains:"chatservice:16000" domains:"chatservice.default.svc" domains:"chatservice.default.svc:16000" domains:"chatservice.default" domains:"chatservice.default:16000" domains:"*.chatservice.default.svc.cluster.local" domains:"*.chatservice.default.svc.cluster.local:16000" domains:"*.chatservice" domains:"*.chatservice:16000" domains:"*.chatservice.default.svc" domains:"*.chatservice.default.svc:16000" domains:"*.chatservice.default" domains:"*.chatservice.default:16000" routes:{match:{prefix:"/" case_sensitive:{value:true}} route:{cluster:"outbound|16000||chatservice.default.svc.cluster.local" timeout:{} retry_policy:{retry_on:"connect-failure,refused-stream,unavailable,cancelled,retriable-status-codes" num_retries:{value:2} retry_host_predicate:{name:"envoy.retry_host_predicates.previous_hosts" typed_config:{type_url:"type.googleapis.com/envoy.extensions.retry.host.previous_hosts.v3.PreviousHostsPredicate"}} host_selection_retry_max_attempts:5 retriable_status_codes:503} hash_policy:{header:{header_name:"ULID"}} max_stream_duration:{max_stream_duration:{}}} metadata:{filter_metadata:{key:"istio" value:{fields:{key:"config" value:{string_value:"/apis/networking.istio.io/v1alpha3/namespaces/default/virtual-service/chatvirtualservice"}}}}} decorator:{operation:"chatservice.default.svc.cluster.local:16000/*"}} include_request_attempt_count:true}}} type_url:"type.googleapis.com/envoy.config.route.v3.RouteConfiguration" nonce:"5tlvTWkSfuQ=7e8d6514-9f70-4d81-988f-85504781ea42" control_plane:{identifier:"{\"Component\":\"istiod\",\"ID\":\"istiod-86cd5997bb-sq788\",\"Info\":{\"version\":\"1.15.0\",\"revision\":\"e3364ab424b70ca8ee1ca76cb0b3afb73476aaac\",\"golang_version\":\"go1.19\",\"status\":\"Clean\",\"tag\":\"1.15.0\"}}"} 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Resource type "RouteConfigResource" with name "outbound|16000||chatservice.default.svc.cluster.local" added to cache 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Sending ACK for resource type: "type.googleapis.com/envoy.config.route.v3.RouteConfiguration", version: "2024-03-15T12:37:57Z/103", nonce: "5tlvTWkSfuQ=7e8d6514-9f70-4d81-988f-85504781ea42" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "versionInfo": "2024-03-15T12:37:57Z/103", "resourceNames": [ "outbound|16000||chatservice.default.svc.cluster.local" ], "typeUrl": "type.googleapis.com/envoy.config.route.v3.RouteConfiguration", "responseNonce": "5tlvTWkSfuQ=7e8d6514-9f70-4d81-988f-85504781ea42" } 2024/03/15 12:58:17 INFO: [xds] [xds-resolver 0xc000303b90] received RDS update: { "VirtualHosts": [ { "Domains": [ "chatservice.default.svc.cluster.local", "chatservice.default.svc.cluster.local:16000", "chatservice", "chatservice:16000", "chatservice.default.svc", "chatservice.default.svc:16000", "chatservice.default", "chatservice.default:16000", "*.chatservice.default.svc.cluster.local", "*.chatservice.default.svc.cluster.local:16000", "*.chatservice", "*.chatservice:16000", "*.chatservice.default.svc", "*.chatservice.default.svc:16000", "*.chatservice.default", "*.chatservice.default:16000" ], "Routes": [ { "Path": null, "Prefix": "/", "Regex": null, "CaseInsensitive": false, "Headers": null, "Fraction": null, "HashPolicies": [ { "HashPolicyType": 0, "Terminal": false, "HeaderName": "ULID", "Regex": null, "RegexSubstitution": "" } ], "MaxStreamDuration": 0, "HTTPFilterConfigOverride": null, "RetryConfig": { "RetryOn": { "1": true, "14": true }, "NumRetries": 2, "RetryBackoff": { "BaseInterval": 25000000, "MaxInterval": 250000000 } }, "ActionType": 1, "WeightedClusters": { "outbound|16000||chatservice.default.svc.cluster.local": { "Weight": 1, "HTTPFilterConfigOverride": null } }, "ClusterSpecifierPlugin": "" } ], "HTTPFilterConfigOverride": null, "RetryConfig": null } ], "ClusterSpecifierPlugins": {}, "Raw": { "type_url": "type.googleapis.com/envoy.config.route.v3.RouteConfiguration", "value": "CjVvdXRib3VuZHwxNjAwMHx8Y2hhdHNlcnZpY2UuZGVmYXVsdC5zdmMuY2x1c3Rlci5sb2NhbBLXBworY2hhdHNlcnZpY2UuZGVmYXVsdC5zdmMuY2x1c3Rlci5sb2NhbDoxNjAwMBIlY2hhdHNlcnZpY2UuZGVmYXVsdC5zdmMuY2x1c3Rlci5sb2NhbBIrY2hhdHNlcnZpY2UuZGVmYXVsdC5zdmMuY2x1c3Rlci5sb2NhbDoxNjAwMBILY2hhdHNlcnZpY2USEWNoYXRzZXJ2aWNlOjE2MDAwEhdjaGF0c2VydmljZS5kZWZhdWx0LnN2YxIdY2hhdHNlcnZpY2UuZGVmYXVsdC5zdmM6MTYwMDASE2NoYXRzZXJ2aWNlLmRlZmF1bHQSGWNoYXRzZXJ2aWNlLmRlZmF1bHQ6MTYwMDASJyouY2hhdHNlcnZpY2UuZGVmYXVsdC5zdmMuY2x1c3Rlci5sb2NhbBItKi5jaGF0c2VydmljZS5kZWZhdWx0LnN2Yy5jbHVzdGVyLmxvY2FsOjE2MDAwEg0qLmNoYXRzZXJ2aWNlEhMqLmNoYXRzZXJ2aWNlOjE2MDAwEhkqLmNoYXRzZXJ2aWNlLmRlZmF1bHQuc3ZjEh8qLmNoYXRzZXJ2aWNlLmRlZmF1bHQuc3ZjOjE2MDAwEhUqLmNoYXRzZXJ2aWNlLmRlZmF1bHQSGyouY2hhdHNlcnZpY2UuZGVmYXVsdDoxNjAwMBrdAwoHIgIIAQoBLyJxCm8KBWlzdGlvEmYKZAoGY29uZmlnEloaWC9hcGlzL25ldHdvcmtpbmcuaXN0aW8uaW8vdjFhbHBoYTMvbmFtZXNwYWNlcy9kZWZhdWx0L3ZpcnR1YWwtc2VydmljZS9jaGF0dmlydHVhbHNlcnZpY2UqLwotY2hhdHNlcnZpY2UuZGVmYXVsdC5zdmMuY2x1c3Rlci5sb2NhbDoxNjAwMC8qEq0CQgBK4gEKS2Nvbm5lY3QtZmFpbHVyZSxyZWZ1c2VkLXN0cmVhbSx1bmF2YWlsYWJsZSxjYW5jZWxsZWQscmV0cmlhYmxlLXN0YXR1cy1jb2RlcxICCAIqiAEKKmVudm95LnJldHJ5X2hvc3RfcHJlZGljYXRlcy5wcmV2aW91c19ob3N0cxpaClh0eXBlLmdvb2dsZWFwaXMuY29tL2Vudm95LmV4dGVuc2lvbnMucmV0cnkuaG9zdC5wcmV2aW91c19ob3N0cy52My5QcmV2aW91c0hvc3RzUHJlZGljYXRlMAU6AvcDeggKBgoEVUxJRKICAgoACjVvdXRib3VuZHwxNjAwMHx8Y2hhdHNlcnZpY2UuZGVmYXVsdC5zdmMuY2x1c3Rlci5sb2NhbHAB" } }, err: 2024/03/15 12:58:17 INFO: [xds] [xds-resolver 0xc000303b90] Received update on resource chatservice:16000 from xds-client 0xc0003c2090, generated service config: { "loadBalancingConfig": [ { "xds_cluster_manager_experimental": { "children": { "cluster:outbound|16000||chatservice.default.svc.cluster.local": { "childPolicy": [ { "cds_experimental": { "cluster": "outbound|16000||chatservice.default.svc.cluster.local" } } ] } } } } ] } 2024/03/15 12:58:17 INFO: [core] [Channel #1] 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": "\u003c0xc00060a230\u003e", "\u003c%!p(xdsclient.clientKeyType=grpc.xds.internal.client.Client)\u003e": "\u003c0xc0003c2090\u003e" } } (service config updated) 2024/03/15 12:58:17 INFO: [core] [Channel #1] Channel switches to new LB policy "xds_cluster_manager_experimental" 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Created 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] update with config { "LoadBalancingConfig": null, "Children": { "cluster:outbound|16000||chatservice.default.svc.cluster.local": { "ChildPolicy": [ { "cds_experimental": { "LoadBalancingConfig": null, "Cluster": "outbound|16000||chatservice.default.svc.cluster.local" } } ] } } }, resolver state {Addresses:[] Endpoints:[] ServiceConfig:0xc000488180 Attributes:{"<%!p(xdsclient.clientKeyType=grpc.xds.internal.client.Client)>": "<0xc0003c2090>" , "<%!p(resolver.csKeyType=grpc.internal.resolver.configSelector)>": "<0xc00060a230>" }} 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Adding child policy of type "cds_experimental" for locality "cluster:outbound|16000||chatservice.default.svc.cluster.local" 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Creating child policy of type "cds_experimental" for locality "cluster:outbound|16000||chatservice.default.svc.cluster.local" 2024/03/15 12:58:17 INFO: [xds] [cds-lb 0xc000268780] Created 2024/03/15 12:58:17 INFO: [xds] [cds-lb 0xc000268780] xDS credentials in use: false 2024/03/15 12:58:17 INFO: [xds] [cds-lb 0xc000268780] Received balancer config update: { "LoadBalancingConfig": null, "Cluster": "outbound|16000||chatservice.default.svc.cluster.local" } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] New watch for type "ClusterResource", resource name "outbound|16000||chatservice.default.svc.cluster.local" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] First watch for type "ClusterResource", resource name "outbound|16000||chatservice.default.svc.cluster.local" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "resourceNames": [ "outbound|16000||chatservice.default.svc.cluster.local" ], "typeUrl": "type.googleapis.com/envoy.config.cluster.v3.Cluster" } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS response received: { "versionInfo": "2024-03-15T12:37:57Z/103", "resources": [ { "@type": "type.googleapis.com/envoy.config.cluster.v3.Cluster", "name": "outbound|16000||chatservice.default.svc.cluster.local", "type": "EDS", "edsClusterConfig": { "edsConfig": { "ads": { } }, "serviceName": "outbound|16000||chatservice.default.svc.cluster.local" }, "lbPolicy": "RING_HASH", "ringHashLbConfig": { "minimumRingSize": "1024" } } ], "typeUrl": "type.googleapis.com/envoy.config.cluster.v3.Cluster", "nonce": "5tlvTWkSfuQ=db224fdf-8210-45eb-8bfd-70d968ba020c", "controlPlane": { "identifier": "{\"Component\":\"istiod\",\"ID\":\"istiod-86cd5997bb-sq788\",\"Info\":{\"version\":\"1.15.0\",\"revision\":\"e3364ab424b70ca8ee1ca76cb0b3afb73476aaac\",\"golang_version\":\"go1.19\",\"status\":\"Clean\",\"tag\":\"1.15.0\"}}" } } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Resource type "ClusterResource" with name "outbound|16000||chatservice.default.svc.cluster.local" added to cache 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Sending ACK for resource type: "type.googleapis.com/envoy.config.cluster.v3.Cluster", version: "2024-03-15T12:37:57Z/103", nonce: "5tlvTWkSfuQ=db224fdf-8210-45eb-8bfd-70d968ba020c" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "versionInfo": "2024-03-15T12:37:57Z/103", "resourceNames": [ "outbound|16000||chatservice.default.svc.cluster.local" ], "typeUrl": "type.googleapis.com/envoy.config.cluster.v3.Cluster", "responseNonce": "5tlvTWkSfuQ=db224fdf-8210-45eb-8bfd-70d968ba020c" } 2024/03/15 12:58:17 INFO: [xds] [cds-lb 0xc000268780] Received Cluster resource: { "ClusterType": 0, "ClusterName": "outbound|16000||chatservice.default.svc.cluster.local", "EDSServiceName": "outbound|16000||chatservice.default.svc.cluster.local", "LRSServerConfig": 0, "SecurityCfg": null, "MaxRequests": null, "DNSHostName": "", "PrioritizedClusterNames": null, "LBPolicy": [ { "ring_hash_experimental": { "minRingSize": 1024, "maxRingSize": 8388608 } } ], "OutlierDetection": null, "Raw": { "type_url": "type.googleapis.com/envoy.config.cluster.v3.Cluster", "value": "CjVvdXRib3VuZHwxNjAwMHx8Y2hhdHNlcnZpY2UuZGVmYXVsdC5zdmMuY2x1c3Rlci5sb2NhbBo7CgIaABI1b3V0Ym91bmR8MTYwMDB8fGNoYXRzZXJ2aWNlLmRlZmF1bHQuc3ZjLmNsdXN0ZXIubG9jYWwwAhADugEFCgMIgAg=" } } 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-resolver-lb 0xc000103040] Created 2024/03/15 12:58:17 INFO: [xds] [cds-lb 0xc000268780] Created child policy 0xc000103040 of type cluster_resolver_experimental 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-resolver-lb 0xc000103040] Received new balancer config: { "discoveryMechanisms": [ { "cluster": "outbound|16000||chatservice.default.svc.cluster.local", "edsServiceName": "outbound|16000||chatservice.default.svc.cluster.local", "outlierDetection": {} } ], "xdsLbPolicy": [ { "ring_hash_experimental": { "minRingSize": 1024, "maxRingSize": 8388608 } } ] } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] New watch for type "EndpointsResource", resource name "outbound|16000||chatservice.default.svc.cluster.local" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] First watch for type "EndpointsResource", resource name "outbound|16000||chatservice.default.svc.cluster.local" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "resourceNames": [ "outbound|16000||chatservice.default.svc.cluster.local" ], "typeUrl": "type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment" } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS response received: { "versionInfo": "2024-03-15T12:37:57Z/103", "resources": [ { "@type": "type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment", "clusterName": "outbound|16000||chatservice.default.svc.cluster.local", "endpoints": [ { "locality": { }, "lbEndpoints": [ { "endpoint": { "address": { "socketAddress": { "address": "10.196.109.179", "portValue": 16000 } } }, "healthStatus": "HEALTHY", "metadata": { "filterMetadata": { "istio": { "workload": "chatserver;default;chatserver;latest;Kubernetes" } } }, "loadBalancingWeight": 1 }, { "endpoint": { "address": { "socketAddress": { "address": "10.196.109.183", "portValue": 16000 } } }, "healthStatus": "HEALTHY", "metadata": { "filterMetadata": { "istio": { "workload": "chatserver;default;chatserver;latest;Kubernetes" } } }, "loadBalancingWeight": 1 }, { "endpoint": { "address": { "socketAddress": { "address": "10.196.109.188", "portValue": 16000 } } }, "healthStatus": "HEALTHY", "metadata": { "filterMetadata": { "istio": { "workload": "chatserver;default;chatserver;latest;Kubernetes" } } }, "loadBalancingWeight": 1 } ], "loadBalancingWeight": 3 } ] } ], "typeUrl": "type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment", "nonce": "5tlvTWkSfuQ=931cd515-dd5d-4149-87ec-857278f55642", "controlPlane": { "identifier": "{\"Component\":\"istiod\",\"ID\":\"istiod-86cd5997bb-sq788\",\"Info\":{\"version\":\"1.15.0\",\"revision\":\"e3364ab424b70ca8ee1ca76cb0b3afb73476aaac\",\"golang_version\":\"go1.19\",\"status\":\"Clean\",\"tag\":\"1.15.0\"}}" } } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Resource type "EndpointsResource" with name "outbound|16000||chatservice.default.svc.cluster.local" added to cache 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Sending ACK for resource type: "type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment", version: "2024-03-15T12:37:57Z/103", nonce: "5tlvTWkSfuQ=931cd515-dd5d-4149-87ec-857278f55642" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "versionInfo": "2024-03-15T12:37:57Z/103", "resourceNames": [ "outbound|16000||chatservice.default.svc.cluster.local" ], "typeUrl": "type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment", "responseNonce": "5tlvTWkSfuQ=931cd515-dd5d-4149-87ec-857278f55642" } 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Created 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-resolver-lb 0xc000103040] Built child policy config: { "children": { "priority-0-0": { "config": [ { "outlier_detection_experimental": { "interval": "10s", "baseEjectionTime": "30s", "maxEjectionTime": "300s", "maxEjectionPercent": 10, "childPolicy": [ { "xds_cluster_impl_experimental": { "cluster": "outbound|16000||chatservice.default.svc.cluster.local", "edsServiceName": "outbound|16000||chatservice.default.svc.cluster.local", "childPolicy": [ { "ring_hash_experimental": { "minRingSize": 1024, "maxRingSize": 4096 } } ] } } ] } } ], "ignoreReresolutionRequests": true } }, "priorities": [ "priority-0-0" ] } 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Received an update with balancer config: { "children": { "priority-0-0": { "config": [ { "outlier_detection_experimental": { "interval": "10s", "baseEjectionTime": "30s", "maxEjectionTime": "300s", "maxEjectionPercent": 10, "childPolicy": [ { "xds_cluster_impl_experimental": { "cluster": "outbound|16000||chatservice.default.svc.cluster.local", "edsServiceName": "outbound|16000||chatservice.default.svc.cluster.local", "childPolicy": [ { "ring_hash_experimental": { "minRingSize": 1024, "maxRingSize": 4096 } } ] } } ] } } ], "ignoreReresolutionRequests": true } }, "priorities": [ "priority-0-0" ] } 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] childInUse, childUpdating: "", "priority-0-0" 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Balancer state update from locality cluster:outbound|16000||chatservice.default.svc.cluster.local, new state: {ConnectivityState:CONNECTING Picker:0xc0003c2cc0} 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Child pickers: map[cluster:outbound|16000||chatservice.default.svc.cluster.local:picker:0xc0003c2cc0,state:CONNECTING,stateToAggregate:CONNECTING] 2024/03/15 12:58:17 INFO: [core] [Channel #1] Channel Connectivity change to CONNECTING 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Switching to ("priority-0-0", 0) in syncPriority 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Adding child policy of type "outlier_detection_experimental" for locality "priority-0-0" 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Creating child policy of type "outlier_detection_experimental" for locality "priority-0-0" 2024/03/15 12:58:17 INFO: [xds] [outlier-detection-lb 0xc00064a240] Created 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-impl-lb 0xc0005aa600] Created 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-impl-lb 0xc0005aa600] Received update from resolver, balancer config: { "cluster": "outbound|16000||chatservice.default.svc.cluster.local", "edsServiceName": "outbound|16000||chatservice.default.svc.cluster.local", "childPolicy": [ { "ring_hash_experimental": { "minRingSize": 1024, "maxRingSize": 4096 } } ] } 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Created 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Received update from resolver, balancer config: { "minRingSize": 1024, "maxRingSize": 4096 } 2024/03/15 12:58:17 INFO: [core] [Channel #1 SubChannel #5] Subchannel created 2024/03/15 12:58:17 INFO: [core] [Channel #1 SubChannel #6] Subchannel created 2024/03/15 12:58:17 INFO: [core] [Channel #1 SubChannel #7] Subchannel created 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] newRing: number of subConns is 3, minRingSize is 1024, maxRingSize is 4096 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] newRing: normalized subConn weights is [{0xc0004981e0 0.3333333333333333} {0xc0004983c0 0.3333333333333333} {0xc0004984e0 0.3333333333333333}] 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] newRing: creating new ring of size 1026 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Balancer state update from locality priority-0-0, new state: {ConnectivityState:IDLE Picker:0xc0006601c8} 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] childInUse, childUpdating: "priority-0-0", "priority-0-0" 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Balancer state update from locality cluster:outbound|16000||chatservice.default.svc.cluster.local, new state: {ConnectivityState:IDLE Picker:0xc0006601c8} 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Child pickers: map[cluster:outbound|16000||chatservice.default.svc.cluster.local:picker:0xc0006601c8,state:IDLE,stateToAggregate:IDLE] 2024/03/15 12:58:17 INFO: [core] [Channel #1] Channel Connectivity change to IDLE 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Switching to ("priority-0-0", 0) in syncPriority 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] [subConn 0xc0004983c0] Executing a queued connect for subConn in state: IDLE 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] [subConn 0xc0004983c0] Executing a queued connect for subConn in state: IDLE 2024/03/15 12:58:17 INFO: [core] [Channel #1 SubChannel #6] Subchannel Connectivity change to CONNECTING 2024/03/15 12:58:17 INFO: [core] [Channel #1 SubChannel #6] Subchannel picks a new address "10.196.109.183:16000" to connect 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Handle SubConn state change: 0xc000619640, CONNECTING 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] [subConn 0xc0004983c0] Executing a queued connect for subConn in state: IDLE 2024/03/15 12:58:17 INFO: [core] connect called on addrConn in non-idle state (CONNECTING); ignoring. 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] SubConn's effective old state was: IDLE, new state is CONNECTING 2024/03/15 12:58:17 INFO: [core] connect called on addrConn in non-idle state (CONNECTING); ignoring. 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] [subConn 0xc0004981e0] Executing a queued connect for subConn in state: IDLE 2024/03/15 12:58:17 INFO: [core] [Channel #1 SubChannel #5] Subchannel Connectivity change to CONNECTING 2024/03/15 12:58:17 INFO: [core] [Channel #1 SubChannel #5] Subchannel picks a new address "10.196.109.179:16000" to connect 2024/03/15 12:58:17 INFO: [core] [Channel #1 SubChannel #6] Subchannel Connectivity change to READY 2024/03/15 12:58:17 INFO: [core] [Channel #1 SubChannel #5] Subchannel Connectivity change to READY 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Pushing new state CONNECTING and picker 0xc000702000 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Handle SubConn state change: 0xc0006194c0, CONNECTING 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] SubConn's effective old state was: IDLE, new state is CONNECTING 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Pushing new state CONNECTING and picker 0xc0007aa048 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Handle SubConn state change: 0xc000619640, READY 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] SubConn's effective old state was: CONNECTING, new state is READY 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Pushing new state READY and picker 0xc000702048 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Handle SubConn state change: 0xc0006194c0, READY 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] SubConn's effective old state was: CONNECTING, new state is READY 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] Pushing new state READY and picker 0xc0007020a8 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0xc0007020d8} 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Balancer state update from locality priority-0-0, new state: {ConnectivityState:CONNECTING Picker:0xc000702108} 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc000702138} 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Balancer state update from locality priority-0-0, new state: {ConnectivityState:READY Picker:0xc0007aa090} 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] childInUse, childUpdating: "priority-0-0", "priority-0-0" 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Balancer state update from locality cluster:outbound|16000||chatservice.default.svc.cluster.local, new state: {ConnectivityState:CONNECTING Picker:0xc0007020d8} 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Child pickers: map[cluster:outbound|16000||chatservice.default.svc.cluster.local:picker:0xc0007020d8,state:CONNECTING,stateToAggregate:CONNECTING] 2024/03/15 12:58:17 INFO: [core] [Channel #1] Channel Connectivity change to CONNECTING 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Switching to ("priority-0-0", 0) in syncPriority 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] childInUse, childUpdating: "priority-0-0", "priority-0-0" 2024/03/15 12:58:17 INFO: [xds] [ring-hash-lb 0xc0004a1a00] [subConn 0xc0004981e0] Queueing a connect for subConn in state: READY 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Balancer state update from locality cluster:outbound|16000||chatservice.default.svc.cluster.local, new state: {ConnectivityState:CONNECTING Picker:0xc000702108} 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Child pickers: map[cluster:outbound|16000||chatservice.default.svc.cluster.local:picker:0xc000702108,state:CONNECTING,stateToAggregate:CONNECTING] 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Switching to ("priority-0-0", 0) in syncPriority 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] childInUse, childUpdating: "priority-0-0", "priority-0-0" 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Balancer state update from locality cluster:outbound|16000||chatservice.default.svc.cluster.local, new state: {ConnectivityState:READY Picker:0xc000702138} 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Child pickers: map[cluster:outbound|16000||chatservice.default.svc.cluster.local:picker:0xc000702138,state:READY,stateToAggregate:READY] 2024/03/15 12:58:17 INFO: [core] [Channel #1] Channel Connectivity change to READY 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Switching to ("priority-0-0", 0) in syncPriority 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] childInUse, childUpdating: "priority-0-0", "priority-0-0" 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Balancer state update from locality cluster:outbound|16000||chatservice.default.svc.cluster.local, new state: {ConnectivityState:READY Picker:0xc0007aa090} 2024/03/15 12:58:17 INFO: [xds] [xds-cluster-manager-lb 0xc000488220] Child pickers: map[cluster:outbound|16000||chatservice.default.svc.cluster.local:picker:0xc0007aa090,state:READY,stateToAggregate:READY] 2024/03/15 12:58:17 INFO: [xds] [priority-lb 0xc000620a10] Switching to ("priority-0-0", 0) in syncPriority 2024/03/15 12:58:17 Recv - Rsp-chatserver-7f969bc4d9-z5vdt-3668 2024/03/15 12:58:17 Recv - Rsp-chatserver-7f969bc4d9-pglb2-10262 2024/03/15 12:58:17 Recv - Rsp-chatserver-7f969bc4d9-pglb2-10262 2024/03/15 12:58:17 Recv - Rsp-chatserver-7f969bc4d9-pglb2-10263 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS response received: { "versionInfo": "2024-03-15T12:37:57Z/103", "resources": [ { "@type": "type.googleapis.com/envoy.config.cluster.v3.Cluster", "name": "outbound|16000||chatservice.default.svc.cluster.local", "type": "EDS", "edsClusterConfig": { "edsConfig": { "ads": { } }, "serviceName": "outbound|16000||chatservice.default.svc.cluster.local" }, "lbPolicy": "RING_HASH", "ringHashLbConfig": { "minimumRingSize": "1024" } } ], "typeUrl": "type.googleapis.com/envoy.config.cluster.v3.Cluster", "nonce": "5tlvTWkSfuQ=bc541913-fd6d-452e-b37a-70e920122145", "controlPlane": { "identifier": "{\"Component\":\"istiod\",\"ID\":\"istiod-86cd5997bb-sq788\",\"Info\":{\"version\":\"1.15.0\",\"revision\":\"e3364ab424b70ca8ee1ca76cb0b3afb73476aaac\",\"golang_version\":\"go1.19\",\"status\":\"Clean\",\"tag\":\"1.15.0\"}}" } } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Resource type "ClusterResource" with name "outbound|16000||chatservice.default.svc.cluster.local" added to cache 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Sending ACK for resource type: "type.googleapis.com/envoy.config.cluster.v3.Cluster", version: "2024-03-15T12:37:57Z/103", nonce: "5tlvTWkSfuQ=bc541913-fd6d-452e-b37a-70e920122145" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "versionInfo": "2024-03-15T12:37:57Z/103", "resourceNames": [ "outbound|16000||chatservice.default.svc.cluster.local" ], "typeUrl": "type.googleapis.com/envoy.config.cluster.v3.Cluster", "responseNonce": "5tlvTWkSfuQ=bc541913-fd6d-452e-b37a-70e920122145" } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS response received: { "versionInfo": "2024-03-15T12:37:57Z/103", "resources": [ { "@type": "type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment", "clusterName": "outbound|16000||chatservice.default.svc.cluster.local", "endpoints": [ { "locality": { }, "lbEndpoints": [ { "endpoint": { "address": { "socketAddress": { "address": "10.196.109.179", "portValue": 16000 } } }, "healthStatus": "HEALTHY", "metadata": { "filterMetadata": { "istio": { "workload": "chatserver;default;chatserver;latest;Kubernetes" } } }, "loadBalancingWeight": 1 }, { "endpoint": { "address": { "socketAddress": { "address": "10.196.109.183", "portValue": 16000 } } }, "healthStatus": "HEALTHY", "metadata": { "filterMetadata": { "istio": { "workload": "chatserver;default;chatserver;latest;Kubernetes" } } }, "loadBalancingWeight": 1 }, { "endpoint": { "address": { "socketAddress": { "address": "10.196.109.188", "portValue": 16000 } } }, "healthStatus": "HEALTHY", "metadata": { "filterMetadata": { "istio": { "workload": "chatserver;default;chatserver;latest;Kubernetes" } } }, "loadBalancingWeight": 1 } ], "loadBalancingWeight": 3 } ] } ], "typeUrl": "type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment", "nonce": "5tlvTWkSfuQ=1932c04b-f153-40b0-aadf-092a913a541b", "controlPlane": { "identifier": "{\"Component\":\"istiod\",\"ID\":\"istiod-86cd5997bb-sq788\",\"Info\":{\"version\":\"1.15.0\",\"revision\":\"e3364ab424b70ca8ee1ca76cb0b3afb73476aaac\",\"golang_version\":\"go1.19\",\"status\":\"Clean\",\"tag\":\"1.15.0\"}}" } } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Resource type "EndpointsResource" with name "outbound|16000||chatservice.default.svc.cluster.local" added to cache 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Sending ACK for resource type: "type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment", version: "2024-03-15T12:37:57Z/103", nonce: "5tlvTWkSfuQ=1932c04b-f153-40b0-aadf-092a913a541b" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS response received: { "versionInfo": "2024-03-15T12:37:57Z/103", "resources": [ { "@type": "type.googleapis.com/envoy.config.listener.v3.Listener", "name": "chatservice:16000", "address": { "socketAddress": { "address": "0.0.0.0", "portValue": 16000 } }, "apiListener": { "apiListener": { "@type": "type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager", "rds": { "configSource": { "ads": { } }, "routeConfigName": "outbound|16000||chatservice.default.svc.cluster.local" }, "httpFilters": [ { "name": "envoy.filters.http.fault", "typedConfig": { "@type": "type.googleapis.com/envoy.extensions.filters.http.fault.v3.HTTPFault" } }, { "name": "envoy.filters.http.router", "typedConfig": { "@type": "type.googleapis.com/envoy.extensions.filters.http.router.v3.Router" } } ] } } } ], "typeUrl": "type.googleapis.com/envoy.config.listener.v3.Listener", "nonce": "5tlvTWkSfuQ=44680cb1-3f17-4df8-a845-f57b59f42244", "controlPlane": { "identifier": "{\"Component\":\"istiod\",\"ID\":\"istiod-86cd5997bb-sq788\",\"Info\":{\"version\":\"1.15.0\",\"revision\":\"e3364ab424b70ca8ee1ca76cb0b3afb73476aaac\",\"golang_version\":\"go1.19\",\"status\":\"Clean\",\"tag\":\"1.15.0\"}}" } } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "versionInfo": "2024-03-15T12:37:57Z/103", "resourceNames": [ "outbound|16000||chatservice.default.svc.cluster.local" ], "typeUrl": "type.googleapis.com/envoy.config.endpoint.v3.ClusterLoadAssignment", "responseNonce": "5tlvTWkSfuQ=1932c04b-f153-40b0-aadf-092a913a541b" } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Resource type "ListenerResource" with name "chatservice:16000" added to cache 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Sending ACK for resource type: "type.googleapis.com/envoy.config.listener.v3.Listener", version: "2024-03-15T12:37:57Z/103", nonce: "5tlvTWkSfuQ=44680cb1-3f17-4df8-a845-f57b59f42244" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "versionInfo": "2024-03-15T12:37:57Z/103", "resourceNames": [ "chatservice:16000" ], "typeUrl": "type.googleapis.com/envoy.config.listener.v3.Listener", "responseNonce": "5tlvTWkSfuQ=44680cb1-3f17-4df8-a845-f57b59f42244" } 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS response received: version_info:"2024-03-15T12:37:57Z/103" resources:{[type.googleapis.com/envoy.config.route.v3.RouteConfiguration]:{name:"outbound|16000||chatservice.default.svc.cluster.local" virtual_hosts:{name:"chatservice.default.svc.cluster.local:16000" domains:"chatservice.default.svc.cluster.local" domains:"chatservice.default.svc.cluster.local:16000" domains:"chatservice" domains:"chatservice:16000" domains:"chatservice.default.svc" domains:"chatservice.default.svc:16000" domains:"chatservice.default" domains:"chatservice.default:16000" domains:"*.chatservice.default.svc.cluster.local" domains:"*.chatservice.default.svc.cluster.local:16000" domains:"*.chatservice" domains:"*.chatservice:16000" domains:"*.chatservice.default.svc" domains:"*.chatservice.default.svc:16000" domains:"*.chatservice.default" domains:"*.chatservice.default:16000" routes:{match:{prefix:"/" case_sensitive:{value:true}} route:{cluster:"outbound|16000||chatservice.default.svc.cluster.local" timeout:{} retry_policy:{retry_on:"connect-failure,refused-stream,unavailable,cancelled,retriable-status-codes" num_retries:{value:2} retry_host_predicate:{name:"envoy.retry_host_predicates.previous_hosts" typed_config:{type_url:"type.googleapis.com/envoy.extensions.retry.host.previous_hosts.v3.PreviousHostsPredicate"}} host_selection_retry_max_attempts:5 retriable_status_codes:503} hash_policy:{header:{header_name:"ULID"}} max_stream_duration:{max_stream_duration:{}}} metadata:{filter_metadata:{key:"istio" value:{fields:{key:"config" value:{string_value:"/apis/networking.istio.io/v1alpha3/namespaces/default/virtual-service/chatvirtualservice"}}}}} decorator:{operation:"chatservice.default.svc.cluster.local:16000/*"}} include_request_attempt_count:true}}} type_url:"type.googleapis.com/envoy.config.route.v3.RouteConfiguration" nonce:"5tlvTWkSfuQ=c54bdf94-c2b8-4936-b507-c94a0de1927f" control_plane:{identifier:"{\"Component\":\"istiod\",\"ID\":\"istiod-86cd5997bb-sq788\",\"Info\":{\"version\":\"1.15.0\",\"revision\":\"e3364ab424b70ca8ee1ca76cb0b3afb73476aaac\",\"golang_version\":\"go1.19\",\"status\":\"Clean\",\"tag\":\"1.15.0\"}}"} 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Resource type "RouteConfigResource" with name "outbound|16000||chatservice.default.svc.cluster.local" added to cache 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] Sending ACK for resource type: "type.googleapis.com/envoy.config.route.v3.RouteConfiguration", version: "2024-03-15T12:37:57Z/103", nonce: "5tlvTWkSfuQ=c54bdf94-c2b8-4936-b507-c94a0de1927f" 2024/03/15 12:58:17 INFO: [xds] [xds-client 0xc00034c780] [unix:///etc/istio/proxy/XDS] ADS request sent: { "versionInfo": "2024-03-15T12:37:57Z/103", "resourceNames": [ "outbound|16000||chatservice.default.svc.cluster.local" ], "typeUrl": "type.googleapis.com/envoy.config.route.v3.RouteConfiguration", "responseNonce": "5tlvTWkSfuQ=c54bdf94-c2b8-4936-b507-c94a0de1927f" } 2024/03/15 12:58:18 Sending - Sender-chatclient-5c9b9bc87-k4mh7, ULID-2-BBBB-CCCC-DDDD-AAAA, Msg-1 2024/03/15 12:58:18 Sending - Sender-chatclient-5c9b9bc87-k4mh7, ULID-1-AAAA-BBBB-CCCC-DDDD, Msg-1 2024/03/15 12:58:18 Sending - Sender-chatclient-5c9b9bc87-k4mh7, ULID-3-CCCC-DDDD-AAAA-BBBB, Msg-1 2024/03/15 12:58:18 Sending - Sender-chatclient-5c9b9bc87-k4mh7, ULID-4-DDDD-AAAA-BBBB-CCCC, Msg-1 2024/03/15 12:58:18 Recv - Rsp-chatserver-7f969bc4d9-z5vdt-3671 2024/03/15 12:58:18 Recv - Rsp-chatserver-7f969bc4d9-pglb2-10270 2024/03/15 12:58:18 Recv - Rsp-chatserver-7f969bc4d9-pglb2-10272 2024/03/15 12:58:18 Recv - Rsp-chatserver-7f969bc4d9-pglb2-10272 ....