Our Istio proxy sidecar take more than 5 mins to get ready. This happened to all three of our cluster. Wonder what might cause this delay?
Istio version: 1.7.8
client version: 1.7.8
control plane version: 1.7.8
data plane version: 1.7.8 (307 proxies)
istio-proxy log
2022-03-21T02:31:33.322779Z info FLAG: --concurrency="2"
2022-03-21T02:31:33.322824Z info FLAG: --disableInternalTelemetry="false"
2022-03-21T02:31:33.322831Z info FLAG: --domain="XXX-sit-staging.svc.cluster.local"
2022-03-21T02:31:33.322835Z info FLAG: --help="false"
2022-03-21T02:31:33.322838Z info FLAG: --id=""
2022-03-21T02:31:33.322841Z info FLAG: --ip=""
2022-03-21T02:31:33.322844Z info FLAG: --log_as_json="false"
2022-03-21T02:31:33.322847Z info FLAG: --log_caller=""
2022-03-21T02:31:33.322850Z info FLAG: --log_output_level="default:info"
2022-03-21T02:31:33.322854Z info FLAG: --log_rotate=""
2022-03-21T02:31:33.322857Z info FLAG: --log_rotate_max_age="30"
2022-03-21T02:31:33.322861Z info FLAG: --log_rotate_max_backups="1000"
2022-03-21T02:31:33.322864Z info FLAG: --log_rotate_max_size="104857600"
2022-03-21T02:31:33.322867Z info FLAG: --log_stacktrace_level="default:none"
2022-03-21T02:31:33.322879Z info FLAG: --log_target="[stdout]"
2022-03-21T02:31:33.322883Z info FLAG: --meshConfig="./etc/istio/config/mesh"
2022-03-21T02:31:33.322886Z info FLAG: --mixerIdentity=""
2022-03-21T02:31:33.322889Z info FLAG: --outlierLogPath=""
2022-03-21T02:31:33.322893Z info FLAG: --proxyComponentLogLevel="misc:error"
2022-03-21T02:31:33.322896Z info FLAG: --proxyLogLevel="warning"
2022-03-21T02:31:33.322900Z info FLAG: --serviceCluster="ops-box.XXX-sit-staging"
2022-03-21T02:31:33.322903Z info FLAG: --serviceregistry="Kubernetes"
2022-03-21T02:31:33.322906Z info FLAG: --stsPort="0"
2022-03-21T02:31:33.322910Z info FLAG: --templateFile=""
2022-03-21T02:31:33.322914Z info FLAG: --tokenManagerPlugin="GoogleTokenExchange"
2022-03-21T02:31:33.322917Z info FLAG: --trust-domain="cluster.local"
2022-03-21T02:31:33.322944Z info Version 1.7.8-30e54dcb8a1c6196e48394f79fed1399e2562ed3-Clean
2022-03-21T02:31:33.323093Z info Obtained private IP [10.149.4.231]
2022-03-21T02:31:33.323179Z info Apply proxy config from env {"discoveryAddress":"istiod-1-7-8.istio-system.svc:15012","tracing":{"zipkin":{"address":"zipkin.observability-de:9411"}},"proxyMetadata":{"DNS_AGENT":""}}
2022-03-21T02:31:33.324117Z info Effective config: binaryPath: /usr/local/bin/envoy
concurrency: 2
configPath: ./etc/istio/proxy
controlPlaneAuthPolicy: MUTUAL_TLS
discoveryAddress: istiod-1-7-8.istio-system.svc:15012
drainDuration: 45s
envoyAccessLogService: {}
envoyMetricsService: {}
parentShutdownDuration: 60s
proxyAdminPort: 15000
proxyMetadata:
DNS_AGENT: ""
serviceCluster: ops-box.XXX-sit-staging
statNameLength: 189
statusPort: 15020
terminationDrainDuration: 5s
tracing:
zipkin:
address: zipkin.observability-de:9411
2022-03-21T02:31:33.324164Z info Proxy role: &model.Proxy{Type:"sidecar", IPAddresses:[]string{"10.149.4.231"}, ID:"ops-box-fdf7ff8d7-l4cbn.XXX-sit-staging", Locality:(*envoy_config_core_v3.Locality)(nil), DNSDomain:"XXX-sit-staging.svc.cluster.local", ConfigNamespace:"", Metadata:(*model.NodeMetadata)(nil), SidecarScope:(*model.SidecarScope)(nil), PrevSidecarScope:(*model.SidecarScope)(nil), MergedGateway:(*model.MergedGateway)(nil), ServiceInstances:[]*model.ServiceInstance(nil), IstioVersion:(*model.IstioVersion)(nil), ipv6Support:false, ipv4Support:false, GlobalUnicastIP:"", XdsResourceGenerator:model.XdsResourceGenerator(nil), Active:map[string]*model.WatchedResource(nil), ActiveExperimental:map[string]*model.WatchedResource(nil), RequestedTypes:struct { CDS string; EDS string; RDS string; LDS string }{CDS:"", EDS:"", RDS:"", LDS:""}}
2022-03-21T02:31:33.324169Z info JWT policy is third-party-jwt
2022-03-21T02:31:33.324191Z warn Using existing certificate ./etc/certs
2022-03-21T02:31:33.324206Z info PilotSAN []string{"istiod-1-7-8.istio-system.svc"}
2022-03-21T02:31:33.324213Z info MixerSAN []string{"spiffe://cluster.local/ns/istio-system/sa/istio-mixer-service-account"}
2022-03-21T02:31:33.324249Z info sa.serverOptions.CAEndpoint == istiod-1-7-8.istio-system.svc:15012
2022-03-21T02:31:33.324254Z info Using user-configured CA istiod-1-7-8.istio-system.svc:15012
2022-03-21T02:31:33.324258Z info istiod uses self-issued certificate
2022-03-21T02:31:33.324298Z info the CA cert of istiod is: -----BEGIN CERTIFICATE-----
MIIC3jCCAcagAwIBAgIRAJl3sq2dJAYuX+MI++bPm1cwDQYJKoZIhvcNAQELBQAw
XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
HzyvurlwgM8zS29LDD3Z2ea5UDq6v9O8PurUDt3isA0oyVqt97bczaHAvka8kYkz
dlJtm1t/sjFzY5SlefAPmcJP
-----END CERTIFICATE-----
2022-03-21T02:31:33.365666Z info sds SDS gRPC server for workload UDS starts, listening on "./etc/istio/proxy/SDS"
2022-03-21T02:31:33.365735Z info Starting proxy agent
2022-03-21T02:31:33.365803Z info Opening status port 15020
2022-03-21T02:31:33.365891Z info Received new config, creating new Envoy epoch 0
2022-03-21T02:31:33.365925Z info Epoch 0 starting
2022-03-21T02:31:33.366011Z info sds Start SDS grpc server
2022-03-21T02:31:33.566294Z info Envoy command: [-c etc/istio/proxy/envoy-rev0.json --restart-epoch 0 --drain-time-s 45 --parent-shutdown-time-s 60 --service-cluster ops-box.XXX-sit-staging --service-node sidecar~10.149.4.231~ops-box-fdf7ff8d7-l4cbn.XXX-sit-staging~XXX-sit-staging.svc.cluster.local --local-address-ip-version v4 --log-format-prefix-with-location 0 --log-format %Y-%m-%dT%T.%fZ %l envoy %n %v -l warning --component-log-level misc:error --concurrency 2]
2022-03-21T02:31:33.604130Z warning envoy runtime Unable to use runtime singleton for feature envoy.reloadable_features.activate_fds_next_event_loop
2022-03-21T02:31:33.639945Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, no healthy upstream
2022-03-21T02:31:33.639977Z warning envoy config Unable to establish new stream
2022-03-21T02:31:33.650450Z info sds resource:default new connection
2022-03-21T02:31:33.650556Z info sds Skipping waiting for gateway secret
2022-03-21T02:31:33.650764Z info cache adding watcher for file ./etc/certs/cert-chain.pem
2022-03-21T02:31:33.650926Z info cache GenerateSecret from file default
2022-03-21T02:31:33.651287Z info sds resource:default pushed key/cert pair to proxy
2022-03-21T02:31:33.653500Z warning envoy main there is no configured limit to the number of allowed active connections. Set a limit via the runtime key overload.global_downstream_max_connections
2022-03-21T02:31:33.868374Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
...
2022-03-21T02:31:49.230398Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:32:05.295221Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:32:07.294529Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:32:08.179729Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:32:09.294659Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:32:17.294532Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:32:18.351395Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:32:19.294691Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:32:25.294549Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:32:26.368087Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:32:27.294501Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:32:33.294571Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:32:35.132355Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:32:35.294710Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:32:53.294537Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:32:53.745724Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:32:55.294652Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:33:07.294660Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:33:08.605655Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:33:09.294469Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:33:33.294503Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:33:34.445614Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:33:35.142225Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:33:35.294739Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:34:01.294751Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:34:03.070839Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:34:03.294405Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:34:23.294518Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:34:23.886704Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:34:25.294520Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:34:45.294498Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:34:46.643190Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:34:47.294509Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:34:51.294401Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:34:51.940264Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:34:53.294601Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:35:15.294530Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:35:15.807198Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:35:17.294691Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:35:18.259253Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:35:19.294519Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:35:33.294598Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:35:33.809956Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:35:35.295326Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:35:51.294512Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:35:52.946812Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:35:53.294575Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:36:09.294557Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:36:11.006171Z warning envoy config StreamAggregatedResources gRPC config stream closed: 14, upstream connect error or disconnect/reset before headers. reset reason: connection failure
2022-03-21T02:36:11.294724Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:36:33.294613Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:36:33.659384Z info cache Root cert has changed, start rotating root cert for SDS clients
2022-03-21T02:36:33.659560Z info sds resource:default pushed key/cert pair to proxy
2022-03-21T02:36:33.659592Z info sds Dynamic push for secret default
2022-03-21T02:36:35.294661Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
...
2022-03-21T02:36:55.294692Z warn Envoy proxy is NOT ready: config not received from Pilot (is Pilot running?): cds updates: 0 successful, 0 rejected; lds updates: 0 successful, 0 rejected
2022-03-21T02:36:55.989780Z info sds resource:ROOTCA new connection
2022-03-21T02:36:55.989896Z info sds Skipping waiting for gateway secret
2022-03-21T02:36:55.990084Z info cache adding watcher for file ./etc/certs/root-cert.pem
2022-03-21T02:36:55.990147Z info cache GenerateSecret from file ROOTCA
2022-03-21T02:36:55.990367Z info sds resource:ROOTCA pushed root cert to proxy
2022-03-21T02:36:57.295644Z info Envoy proxy is ready
istio pilot log
2022-03-21 13:31:25.848 AEDT2022-03-21T02:31:25.847973Z info AdmissionReview for Kind=/v1, Kind=Pod Namespace=XXX-sit-staging Name= (ops-box-fdf7ff8d7-***** (actual name not yet known)) UID=cc596a64-dec7-4a2a-8030-583922c8f57e Rfc6902PatchOperation=CREATE UserInfo={system:serviceaccount:kube-system:replicaset-controller adae6497-094b-4ad0-bf12-adeb0ed50734 [system:serviceaccounts system:serviceaccounts:kube-system system:authenticated] map[]}
2022-03-21 13:31:30.858 AEDT2022-03-21T02:31:30.858477Z info ads ADS: "10.149.5.72:58856" sidecar~10.149.5.72~ops-box-fdf7ff8d7-kpnn6.XXX-sit-staging~XXX-sit-staging.svc.cluster.local-436 terminated rpc error: code = Canceled desc = context canceled
2022-03-21 13:36:55.782 AEDT2022-03-21T02:36:55.782101Z info ads ADS:CDS: REQ sidecar~10.149.4.231~ops-box-fdf7ff8d7-l4cbn.XXX-sit-staging~XXX-sit-staging.svc.cluster.local-450 version:
2022-03-21 13:36:55.784 AEDT2022-03-21T02:36:55.784505Z info ads CDS: PUSH for node:ops-box-fdf7ff8d7-l4cbn.XXX-sit-staging clusters:84 services:49 version:2022-03-19T17:39:01Z/8
2022-03-21 13:36:55.787 AEDT2022-03-21T02:36:55.787614Z info ads LDS: PUSH for node:ops-box-fdf7ff8d7-l4cbn.XXX-sit-staging listeners:49
2022-03-21 13:36:55.826 AEDT2022-03-21T02:36:55.825836Z info ads EDS: PUSH for node:ops-box-fdf7ff8d7-l4cbn.XXX-sit-staging clusters:71 endpoints:137 empty:5
2022-03-21 13:36:55.977 AEDT2022-03-21T02:36:55.977647Z info ads RDS: PUSH for node:ops-box-fdf7ff8d7-l4cbn.XXX-sit-staging routes:33
K8s Version
Client Version: version.Info{Major:"1", Minor:"20", GitVersion:"v1.20.7", GitCommit:"132a687512d7fb058d0f5890f07d4121b3f0a2e2", GitTreeState:"clean", BuildDate:"2021-05-12T12:40:09Z", GoVersion:"go1.15.12", Compiler:"gc", Platform:"darwin/amd64"}
Server Version: version.Info{Major:"1", Minor:"20+", GitVersion:"v1.20.15-gke.300", GitCommit:"d71f5620130949cf5f74de04e6ae8f3a96e4b718", GitTreeState:"clean", BuildDate:"2022-01-24T09:27:41Z", GoVersion:"go1.15.15b5", Compiler:"gc", Platform:"linux/amd64"}
Proxy sidecar resource
cpu requested 100m limit: 2
memory requested 128Mi limit: 1Gi