istio: istio-proxy extremely slow start time (consistently 60s+)
Describe the bug I am seeing applications have extremely slow startup times due to istio-proxy taking absolutely ages to come online. This is extremely troublesome, as it:
- Causes issues for applications trying to talk outbound after booting
- Significantly slows down deployments
- Significantly impacts scaling up, especially via HPA
For example, this applications failed to connect to redis for around 90 seconds:
❯ kn logs oauth2-proxy-768b67f6f4-2tjjt master
2018-08-10T19:45:41.298Z at:oauth2-proxy:server:web starting server on port 4180
2018-08-10T19:45:41.390Z at:oauth2-proxy:server:metrics starting metrics server on port 9090
2018-08-10T19:45:41.395Z at:oauth2-proxy:server:metrics metrics server started
1 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
2 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
3 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
4 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
5 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
6 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
7 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
8 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
9 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
10 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
11 'Redis connection to oauth-redis:6379 failed - connect ECONNREFUSED 10.192.8.230:6379'
2018-08-10T19:47:19.350Z at:oauth2-proxy:clients:azure Discovered issuer, generating oauth client
Looking at the istio-pilot logs, you can see how long it took to start up, around 70 seconds to get to all dependencies initialized. starting workers
.
2018-08-10T19:45:38.539521Z info Monitored certs: []envoy.CertSource{envoy.CertSource{Directory:"/etc/certs/", Files:[]string{"cert-chain.pem", "key.pem", "root-cert.pem"}}}
2018-08-10T19:45:38.539934Z info Starting proxy agent
2018-08-10T19:45:38.540004Z info Received new config, resetting budget
2018-08-10T19:45:38.540022Z info Reconciling configuration (budget 10)
2018-08-10T19:45:38.540040Z info Epoch 0 starting
2018-08-10T19:45:38.540676Z info Envoy command: [-c /etc/istio/proxy/envoy-rev0.json --restart-epoch 0 --drain-time-s 45 --parent-shutdown-time-s 60 --service-cluster oauth2-proxy --service-node sidecar~10.194.2.82~oauth2-proxy-768b67f6f4-2tjjt.ingress-nginx~ingress-nginx.svc.cluster.local --max-obj-name-len 189 -l warn --v2-config-only]
[2018-08-10 19:45:38.557][23][info][main] external/envoy/source/server/server.cc:183] initializing epoch 0 (hot restart version=10.200.16384.256.options=capacity=16384, num_slots=8209 hash=228984379728933363 size=4882536)
[2018-08-10 19:45:38.557][23][info][main] external/envoy/source/server/server.cc:185] statically linked extensions:
[2018-08-10 19:45:38.557][23][info][main] external/envoy/source/server/server.cc:187] access_loggers: envoy.file_access_log,envoy.http_grpc_access_log
[2018-08-10 19:45:38.557][23][info][main] external/envoy/source/server/server.cc:190] filters.http: envoy.buffer,envoy.cors,envoy.ext_authz,envoy.fault,envoy.filters.http.header_to_metadata,envoy.filters.http.jwt_authn,envoy.filters.http.rbac,envoy.grpc_http1_bridge,envoy.grpc_json_transcoder,envoy.grpc_web,envoy.gzip,envoy.health_check,envoy.http_dynamo_filter,envoy.ip_tagging,envoy.lua,envoy.rate_limit,envoy.router,envoy.squash,istio_authn,jwt-auth,mixer
[2018-08-10 19:45:38.557][23][info][main] external/envoy/source/server/server.cc:193] filters.listener: envoy.listener.original_dst,envoy.listener.proxy_protocol,envoy.listener.tls_inspector
[2018-08-10 19:45:38.558][23][info][main] external/envoy/source/server/server.cc:196] filters.network: envoy.client_ssl_auth,envoy.echo,envoy.ext_authz,envoy.filters.network.thrift_proxy,envoy.http_connection_manager,envoy.mongo_proxy,envoy.ratelimit,envoy.redis_proxy,envoy.tcp_proxy,mixer
[2018-08-10 19:45:38.558][23][info][main] external/envoy/source/server/server.cc:198] stat_sinks: envoy.dog_statsd,envoy.metrics_service,envoy.stat_sinks.hystrix,envoy.statsd
[2018-08-10 19:45:38.558][23][info][main] external/envoy/source/server/server.cc:200] tracers: envoy.dynamic.ot,envoy.lightstep,envoy.zipkin
[2018-08-10 19:45:38.558][23][info][main] external/envoy/source/server/server.cc:203] transport_sockets.downstream: alts,envoy.transport_sockets.capture,raw_buffer,tls
[2018-08-10 19:45:38.558][23][info][main] external/envoy/source/server/server.cc:206] transport_sockets.upstream: alts,envoy.transport_sockets.capture,raw_buffer,tls
[2018-08-10 19:45:38.560][23][info][config] external/envoy/source/server/configuration_impl.cc:50] loading 0 static secret(s)
[2018-08-10 19:45:38.565][23][warning][upstream] external/envoy/source/common/config/grpc_mux_impl.cc:240] gRPC config stream closed: 14, no healthy upstream
[2018-08-10 19:45:38.565][23][warning][upstream] external/envoy/source/common/config/grpc_mux_impl.cc:41] Unable to establish new stream
[2018-08-10 19:45:38.565][23][info][config] external/envoy/source/server/configuration_impl.cc:60] loading 0 listener(s)
[2018-08-10 19:45:38.565][23][info][config] external/envoy/source/server/configuration_impl.cc:94] loading tracing configuration
[2018-08-10 19:45:38.565][23][info][config] external/envoy/source/server/configuration_impl.cc:103] loading tracing driver: envoy.zipkin
[2018-08-10 19:45:38.565][23][info][config] external/envoy/source/server/configuration_impl.cc:116] loading stats sink configuration
[2018-08-10 19:45:38.565][23][info][main] external/envoy/source/server/server.cc:410] starting main dispatch loop
[2018-08-10 19:45:38.599][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:129] cm init: initializing cds
[2018-08-10 19:45:50.218][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|53||kube-dns.kube-system.svc.cluster.local during init
[2018-08-10 19:45:50.219][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9094||alertmanager.data-platform.svc.cluster.local during init
[2018-08-10 19:45:50.219][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|6379||oauth-redis.ingress-nginx.svc.cluster.local during init
[2018-08-10 19:45:50.221][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|2181||zookeeper-headless.search-solr.svc.cluster.local during init
[2018-08-10 19:45:50.222][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|2888||zookeeper-headless.search-solr.svc.cluster.local during init
[2018-08-10 19:45:50.223][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|3888||zookeeper-headless.search-solr.svc.cluster.local during init
[2018-08-10 19:45:50.224][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.conference-application.svc.cluster.local during init
[2018-08-10 19:45:50.226][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9080||app.conference-application.svc.cluster.local during init
[2018-08-10 19:45:50.227][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||ingress-nginx-internal.ingress-nginx.svc.cluster.local during init
[2018-08-10 19:45:50.228][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||ingress-nginx-internal.ingress-nginx.svc.cluster.local during init
[2018-08-10 19:45:50.229][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||cloudwatch-exporter.data-platform.svc.cluster.local during init
[2018-08-10 19:45:50.230][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||kubeops.core-system.svc.cluster.local during init
[2018-08-10 19:45:50.231][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|44134||tiller-deploy.kube-system.svc.cluster.local during init
[2018-08-10 19:45:50.231][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|3000||grafana.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.232][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||default-http-backend.ingress-nginx.svc.cluster.local during init
[2018-08-10 19:45:50.232][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|5775||jaeger-agent.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.233][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|6831||jaeger-agent.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.233][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|6832||jaeger-agent.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.234][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.mercury-admin-tool.svc.cluster.local during init
[2018-08-10 19:45:50.235][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||oauth2-proxy.ingress-nginx.svc.cluster.local during init
[2018-08-10 19:45:50.236][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.supply-and-demand-service.svc.cluster.local during init
[2018-08-10 19:45:50.238][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9080||app.supply-and-demand-service.svc.cluster.local during init
[2018-08-10 19:45:50.238][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9093||prometheus-alertmanager-frontend.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.238][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9090||prometheus.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.239][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|8080||solr-headless.search-solr.svc.cluster.local during init
[2018-08-10 19:45:50.240][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.vehicle-metric-service.svc.cluster.local during init
[2018-08-10 19:45:50.242][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|8060||istio-citadel.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.243][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9093||istio-citadel.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.244][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9102||istio-statsd-prom-bridge.istio-system.svc.cluster.local during
[2018-08-10 19:45:50.245][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9125||istio-statsd-prom-bridge.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.247][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||metrics-server.kube-system.svc.cluster.local during init
[2018-08-10 19:45:50.248][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||cloudwatch-billing-exporter.data-platform.svc.cluster.local during init
[2018-08-10 19:45:50.249][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||istio-sidecar-injector.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.249][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||prometheus-pushgateway.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.249][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||weave-scope.core-system.svc.cluster.local during init
[2018-08-10 19:45:50.251][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.stock-roi-tool.svc.cluster.local during init
[2018-08-10 19:45:50.251][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||solr.search-solr.svc.cluster.local during init
[2018-08-10 19:45:50.252][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||ingress-nginx-external.ingress-nginx.svc.cluster.local during init
[2018-08-10 19:45:50.253][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||ingress-nginx-external.ingress-nginx.svc.cluster.local during init
[2018-08-10 19:45:50.254][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||heapster.kube-system.svc.cluster.local during init
[2018-08-10 19:45:50.256][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.platform-dashboard.svc.cluster.local during init
[2018-08-10 19:45:50.258][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.recruitment-website.svc.cluster.local during init
[2018-08-10 19:45:50.259][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9080||app.recruitment-website.svc.cluster.local during init
[2018-08-10 19:45:50.259][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||zookeeper.search-solr.svc.cluster.local during init
[2018-08-10 19:45:50.259][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|3000||grafana.data-platform.svc.cluster.local during init
[2018-08-10 19:45:50.260][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9091||istio-policy.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.261][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|15004||istio-policy.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.262][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9093||istio-policy.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.263][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.rate-of-sale-model-service.svc.cluster.local during init
[2018-08-10 19:45:50.264][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9080||app.rate-of-sale-model-service.svc.cluster.local during init
[2018-08-10 19:45:50.264][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9090||prometheus.data-platform.svc.cluster.local during init
[2018-08-10 19:45:50.265][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.build-status.svc.cluster.local during init
[2018-08-10 19:45:50.267][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9080||app.build-status.svc.cluster.local during init
[2018-08-10 19:45:50.267][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9093||alertmanager-frontend.data-platform.svc.cluster.local during init
[2018-08-10 19:45:50.268][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|15010||istio-pilot.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.269][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|15011||istio-pilot.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.270][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|8080||istio-pilot.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.272][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9093||istio-pilot.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.273][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.consumer-platform.svc.cluster.local during init
[2018-08-10 19:45:50.273][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|8000||zoonavigator.search-solr.svc.cluster.local during init
[2018-08-10 19:45:50.274][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.carzone-network-report.svc.cluster.local during init
[2018-08-10 19:45:50.274][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||tracing.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.275][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9411||zipkin.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.290][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.gradle-cache.svc.cluster.local during init
[2018-08-10 19:45:50.291][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9091||istio-telemetry.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.292][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|15004||istio-telemetry.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.292][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9093||istio-telemetry.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.292][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|42422||istio-telemetry.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.293][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9600||logstash.core-system.svc.cluster.local during init
[2018-08-10 19:45:50.295][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|4206||logstash.core-system.svc.cluster.local during init
[2018-08-10 19:45:50.296][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|4207||logstash.core-system.svc.cluster.local during init
[2018-08-10 19:45:50.298][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|4210||logstash.core-system.svc.cluster.local during init
[2018-08-10 19:45:50.301][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.metrics-triage.svc.cluster.local during init
[2018-08-10 19:45:50.302][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9080||app.metrics-triage.svc.cluster.local during init
[2018-08-10 19:45:50.303][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.platform-redirector.svc.cluster.local during init
[2018-08-10 19:45:50.305][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9000||zoonavigator-api.search-solr.svc.cluster.local during init
[2018-08-10 19:45:50.306][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.brand-performance.svc.cluster.local during init
[2018-08-10 19:45:50.307][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|5473||calico-typha.kube-system.svc.cluster.local during init
[2018-08-10 19:45:50.309][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.vehicle-valuations-service.svc.cluster.local during init
[2018-08-10 19:45:50.310][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.goal-collector-tool.svc.cluster.local during init
[2018-08-10 19:45:50.310][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||kubernetes.default.svc.cluster.local during init
[2018-08-10 19:45:50.311][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.vds-dvla-importer.svc.cluster.local during init
[2018-08-10 19:45:50.313][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|8080||kube-state-metrics.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.314][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|9094||prometheus-alertmanager.istio-system.svc.cluster.local during init
[2018-08-10 19:45:50.314][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||www.google-analytics.com during init
[2018-08-10 19:45:50.314][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||www.google-analytics.com during init
[2018-08-10 19:45:50.315][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||www.google.com during init
[2018-08-10 19:45:50.315][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||www.google.com during init
[2018-08-10 19:45:50.315][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||marketingplatform.google.com during init
[2018-08-10 19:45:50.315][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||marketingplatform.google.com during init
[2018-08-10 19:45:50.316][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||www.facebook.com during init
[2018-08-10 19:45:50.316][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||www.facebook.com during init
[2018-08-10 19:45:50.316][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||graph.facebook.com during init
[2018-08-10 19:45:50.316][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||graph.facebook.com during init
[2018-08-10 19:45:50.316][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||api-read.facebook.com during init
[2018-08-10 19:45:50.317][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||api-read.facebook.com during init
[2018-08-10 19:45:50.317][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||graph-video.facebook.com during init
[2018-08-10 19:45:50.317][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||graph-video.facebook.com during init
[2018-08-10 19:45:50.317][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||autotrader.avature.net during init
[2018-08-10 19:45:50.317][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||autotrader.avature.net during init
[2018-08-10 19:45:50.318][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||automotivemxin.com during init
[2018-08-10 19:45:50.318][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||automotivemxin.com during init
[2018-08-10 19:45:50.318][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||app.joindrover.com during init
[2018-08-10 19:45:50.318][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||app.joindrover.com during init
[2018-08-10 19:45:50.319][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||www.joindrover.com during init
[2018-08-10 19:45:50.319][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||www.joindrover.com during init
[2018-08-10 19:45:50.319][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||graph.microsoft.com during init
[2018-08-10 19:45:50.320][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||graph.microsoft.com during init
[2018-08-10 19:45:50.320][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||login.microsoftonline.com during init
[2018-08-10 19:45:50.320][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||login.microsoftonline.com during init
[2018-08-10 19:45:50.320][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|25||smtp.dummy.hosts during init
[2018-08-10 19:45:50.320][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|465||smtp.dummy.hosts during init
[2018-08-10 19:45:50.320][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|587||smtp.dummy.hosts during init
[2018-08-10 19:45:50.320][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||api.twitter.com during init
[2018-08-10 19:45:50.321][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||api.twitter.com during init
[2018-08-10 19:45:50.321][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||stream.twitter.com during init
[2018-08-10 19:45:50.321][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||stream.twitter.com during init
[2018-08-10 19:45:50.321][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||userstream.twitter.com during init
[2018-08-10 19:45:50.321][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||userstream.twitter.com during init
[2018-08-10 19:45:50.322][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||sitestream.twitter.com during init
[2018-08-10 19:45:50.322][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||sitestream.twitter.com during init
[2018-08-10 19:45:50.322][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|80||upload.twitter.com during init
[2018-08-10 19:45:50.322][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster outbound|443||upload.twitter.com during init
[2018-08-10 19:45:50.322][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster inbound|80||oauth2-proxy.ingress-nginx.svc.cluster.local during init
[2018-08-10 19:45:50.322][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:388] add/update cluster BlackHoleCluster during init
[2018-08-10 19:45:50.330][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:110] cm init: initializing secondary clusters
[2018-08-10 19:45:50.609][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:133] cm init: all clusters initialized
[2018-08-10 19:45:50.609][23][info][main] external/envoy/source/server/server.cc:390] all clusters initialized. initializing init manager
[2018-08-10 19:45:50.710][23][warning][upstream] external/envoy/source/common/config/grpc_mux_impl.cc:65] Too many sendDiscoveryRequest calls for type.googleapis.com/envoy.api.v2.ClusterLoadAssignment
[2018-08-10 19:45:58.176][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.194.2.82_4180'
[2018-08-10 19:45:58.230][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.11.73_443'
[2018-08-10 19:45:58.284][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.7.6_80'
[2018-08-10 19:45:58.337][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.5.191_443'
[2018-08-10 19:45:58.390][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.12.64_9102'
[2018-08-10 19:45:58.443][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.11.245_80'
[2018-08-10 19:45:58.499][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_587'
[2018-08-10 19:45:58.552][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_3888'
[2018-08-10 19:45:58.606][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_25'
[2018-08-10 19:45:58.663][23][warning][config] external/envoy/source/server/listener_manager_impl.cc:257] adding listener '0.0.0.0:443': filter chain match rules require TLS Inspector listener filter, but it isn't configured, trying to inject it (this might fail if Envoy is compiled without it)
[2018-08-10 19:45:58.663][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_443'
[2018-08-10 19:45:58.718][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.0.26_80'
[2018-08-10 19:45:58.771][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.5.111_80'
[2018-08-10 19:45:58.827][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.6.10_8080'
[2018-08-10 19:45:58.880][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.8.232_443'
[2018-08-10 19:45:58.935][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.10.21_15011'
[2018-08-10 19:45:58.988][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.3.11_9600'
[2018-08-10 19:45:59.039][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.9.73_44134'
[2018-08-10 19:45:59.092][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.3.11_4210'
[2018-08-10 19:45:59.144][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_2888'
[2018-08-10 19:45:59.196][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.0.1_443'
[2018-08-10 19:45:59.249][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.8.41_5473'
[2018-08-10 19:45:59.304][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.3.129_443'
[2018-08-10 19:45:59.356][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_465'
[2018-08-10 19:45:59.411][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.0.10_53'
[2018-08-10 19:45:59.463][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.8.89_42422'
[2018-08-10 19:45:59.517][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '10.192.8.230_6379'
[2018-08-10 19:45:59.571][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_8060'
[2018-08-10 19:45:59.627][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_2181'
[2018-08-10 19:45:59.681][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_9093'
[2018-08-10 19:45:59.737][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_9091'
[2018-08-10 19:45:59.790][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_15004'
[2018-08-10 19:45:59.844][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_8000'
[2018-08-10 19:45:59.897][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_9411'
[2018-08-10 19:45:59.950][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_9094'
[2018-08-10 19:46:00.003][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_8080'
[2018-08-10 19:46:00.058][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_3000'
[2018-08-10 19:46:00.110][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_9090'
[2018-08-10 19:46:00.163][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_15010'
[2018-08-10 19:46:00.216][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_9000'
[2018-08-10 19:46:00.269][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_80'
[2018-08-10 19:46:00.324][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_9080'
[2018-08-10 19:46:00.376][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener 'virtual'
[2018-08-10 19:46:46.822][23][info][config] external/envoy/source/server/listener_manager_impl.cc:903] all dependencies initialized. starting workers
[2018-08-10 19:47:33.014][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:394] add/update cluster outbound|80||echo-server-service.core-system.svc.cluster.local starting warming
[2018-08-10 19:47:33.016][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:394] add/update cluster outbound|80||rspec-cert-testing.default.svc.cluster.local starting warming
[2018-08-10 19:47:46.810][23][info][main] external/envoy/source/server/drain_manager_impl.cc:63] shutting down parent after drain
[2018-08-10 19:48:15.611][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:401] warming cluster outbound|80||rspec-cert-testing.default.svc.cluster.local complete
[2018-08-10 19:48:15.612][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:401] warming cluster outbound|80||echo-server-service.core-system.svc.cluster.local complete
[2018-08-10 19:48:21.716][23][warning][config] external/envoy/source/server/listener_manager_impl.cc:257] adding listener '0.0.0.0:443': filter chain match rules require TLS Inspector listener filter, but it isn't configured, trying to inject it (this might fail if Envoy is compiled without it)
[2018-08-10 19:48:21.717][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_443'
[2018-08-10 19:48:45.718][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:394] add/update cluster outbound|80||mtls-1.default.svc.cluster.local starting warming
[2018-08-10 19:49:31.101][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:401] warming cluster outbound|80||mtls-1.default.svc.cluster.local complete
[2018-08-10 19:49:39.288][23][warning][config] external/envoy/source/server/listener_manager_impl.cc:257] adding listener '0.0.0.0:443': filter chain match rules require TLS Inspector listener filter, but it isn't configured, trying to inject it (this might fail if Envoy is compiled without it)
[2018-08-10 19:49:39.289][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_443'
[2018-08-10 19:52:19.005][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:446] removing cluster outbound|80||mtls-1.default.svc.cluster.local
[2018-08-10 19:52:19.006][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:446] removing cluster outbound|80||rspec-cert-testing.default.svc.cluster.local
[2018-08-10 19:52:19.006][23][info][upstream] external/envoy/source/common/upstream/cluster_manager_impl.cc:446] removing cluster outbound|80||echo-server-service.core-system.svc.cluster.local
[2018-08-10 19:53:18.487][23][warning][config] external/envoy/source/server/listener_manager_impl.cc:257] adding listener '0.0.0.0:443': filter chain match rules require TLS Inspector listener filter, but it isn't configured, trying to inject it (this might fail if Envoy is compiled without it)
[2018-08-10 19:53:18.489][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_443'
[libprotobuf INFO src/istio/mixerclient/check_cache.cc:160] Add a new Referenced for check cache: Absence-keys: source.ip, Exact-keys: context.protocol, context.reporter.kind, destination.namespace, destination.port, destination.service, destination.uid, source.uid,
[2018-08-10 19:58:33.600][23][warning][config] external/envoy/source/server/listener_manager_impl.cc:257] adding listener '0.0.0.0:443': filter chain match rules require TLS Inspector listener filter, but it isn't configured, trying to inject it (this might fail if Envoy is compiled without it)
[2018-08-10 19:58:33.601][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_443'
[2018-08-10 19:59:36.980][23][warning][config] external/envoy/source/server/listener_manager_impl.cc:257] adding listener '0.0.0.0:443': filter chain match rules require TLS Inspector listener filter, but it isn't configured, trying to inject it (this might fail if Envoy is compiled without it)
[2018-08-10 19:59:36.980][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_443'
[libprotobuf INFO src/istio/mixerclient/check_cache.cc:160] Add a new Referenced for check cache: Absence-keys: source.ip, Exact-keys: context.protocol, context.reporter.kind, destination.namespace, destination.port, destination.service, destination.uid, source.uid,
[2018-08-10 20:01:08.598][23][warning][config] external/envoy/source/server/listener_manager_impl.cc:257] adding listener '0.0.0.0:443': filter chain match rules require TLS Inspector listener filter, but it isn't configured, trying to inject it (this might fail if Envoy is compiled without it)
[2018-08-10 20:01:08.598][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_443'
[2018-08-10 20:02:28.878][23][warning][config] external/envoy/source/server/listener_manager_impl.cc:257] adding listener '0.0.0.0:443': filter chain match rules require TLS Inspector listener filter, but it isn't configured, trying to inject it (this might fail if Envoy is compiled without it)
[2018-08-10 20:02:28.878][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_443'
[2018-08-10 20:03:41.899][23][warning][config] external/envoy/source/server/listener_manager_impl.cc:257] adding listener '0.0.0.0:443': filter chain match rules require TLS Inspector listener filter, but it isn't configured, trying to inject it (this might fail if Envoy is compiled without it)
[2018-08-10 20:03:41.900][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener '0.0.0.0_443'
[2018-08-10 19:45:50.710][23][warning][upstream] external/envoy/source/common/config/grpc_mux_impl.cc:65] Too many sendDiscoveryRequest calls for type.googleapis.com/envoy.api.v2.ClusterLoadAssignment
- sticks out to me?
Here are the cpu and RAM graphs for this pod + proxy:
Here is a cpu and RAM graph from one of the pilot instances:
This happens consistently across the cluster. I’ve noticed pretty consistently around 45 seconds between these lines:
[2018-08-10 19:46:00.376][23][info][upstream] external/envoy/source/server/lds_api.cc:73] lds: add/update listener 'virtual'
[2018-08-10 19:46:46.822][23][info][config] external/envoy/source/server/listener_manager_impl.cc:903] all dependencies initialized. starting workers
Cluster Info istio 1.0 on gke 1.10.5
- Services: 60
- VirtualServices: 30
- DestinationRules: 38
- Pods: 204
We have 4x pilots running 2500m cores, 1 gig ram
About this issue
- Original URL
- State: closed
- Created 6 years ago
- Reactions: 3
- Comments: 58 (44 by maintainers)
Commits related to this issue
- Update Envoy SHA to latest (release-1.0). Pulling the following changes from github.com/istio/proxy: 7a0fca9 Update Envoy SHA to latest with LcTrie optimizations (release-1.0). (#1919) d93f0fe Fix m... — committed to PiotrSikora/istio by PiotrSikora 6 years ago
- Update Envoy SHA to latest (release-1.0). (#7954) * Update Envoy SHA to latest (release-1.0). Pulling the following changes from github.com/istio/proxy: 7a0fca9 Update Envoy SHA to latest with ... — committed to istio/istio by PiotrSikora 6 years ago
- Update Envoy SHA to latest. Pulling the following changes from github.com/istio/proxy: 1fc6253 add debug logs for collecting rbac attributes (#1922) c5282b6 Update Envoy SHA to latest with LcTrie op... — committed to PiotrSikora/istio by PiotrSikora 6 years ago
- Update Envoy SHA to latest. (#7922) Pulling the following changes from github.com/istio/proxy: 1fc6253 add debug logs for collecting rbac attributes (#1922) c5282b6 Update Envoy SHA to latest with L... — committed to istio/istio by PiotrSikora 6 years ago
@mandarjog @rshriram Happy to report that a build from the latest commit to release-1.0 seems to have resolved the 503 issues. Looking forward to the 1.0.1 release - is there an ETA by any chance? Thanks
We are targeting a release end-of-week.
Piotr found the cause, fix should be ready in 1.0.1 ( hopefully this Fri )
FYI we saw these 503’s too and istio-policy on our cluster has more than the default allocation of 10m, and we run two of them.
Here are the CPU and RAM stats for one instance:
Regardless, 10m was the
request
, not thelimit
, so wouldn’t be cpu throttled anyway - feels like a bit of a red herring to me.Probably linked to https://github.com/istio/istio/issues/7759