We continually send load that goes 1 -> 2 -> 3.
The pod is 25 hours old, however as you can see here something happened at 14:35 which broke istio-test-app-3 (1 and 2 remain fine).
{"level":"info","time":"2020-10-17T14:39:40.757245Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:39:40.757366Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:39:40.757625Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:39:40.757772Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T14:39:40.875744Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:39:40.875865Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:39:40.876142Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:39:40.876315Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T14:44:40.680854Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
{"level":"info","time":"2020-10-17T14:44:40.680939Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
2020-10-17T14:44:40.681104Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-44"
2020-10-17T14:44:40.681167Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-45"
{"level":"info","time":"2020-10-17T14:44:40.989664Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:44:40.989763Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:44:40.989996Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:44:40.990130Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T14:44:41.101797Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:44:41.101917Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:44:41.102142Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:44:41.102384Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T14:49:40.680826Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
{"level":"info","time":"2020-10-17T14:49:40.680922Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
2020-10-17T14:49:40.681068Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-46"
2020-10-17T14:49:40.681109Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-47"
{"level":"info","time":"2020-10-17T14:49:40.853145Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:49:40.853301Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:49:40.853587Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:49:40.853768Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T14:49:40.917526Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:49:40.917640Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:49:40.917876Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:49:40.918032Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T14:54:40.680797Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
{"level":"info","time":"2020-10-17T14:54:40.680866Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
2020-10-17T14:54:40.680941Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-48"
2020-10-17T14:54:40.681040Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-49"
{"level":"info","time":"2020-10-17T14:54:40.758052Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:54:40.758157Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:54:40.758426Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:54:40.758584Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T14:54:41.127609Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:54:41.127721Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:54:41.127964Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:54:41.128115Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T14:59:40.680900Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
{"level":"info","time":"2020-10-17T14:59:40.680941Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
2020-10-17T14:59:40.681091Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-50"
2020-10-17T14:59:40.681147Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-51"
{"level":"info","time":"2020-10-17T14:59:40.795179Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:59:40.795280Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:59:40.795539Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:59:40.795689Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T14:59:41.114830Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T14:59:41.114952Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T14:59:41.115164Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T14:59:41.115318Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T15:04:40.680881Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
{"level":"info","time":"2020-10-17T15:04:40.680970Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
2020-10-17T15:04:40.681071Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-52"
2020-10-17T15:04:40.681126Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-53"
{"level":"info","time":"2020-10-17T15:04:40.980455Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T15:04:40.980561Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T15:04:40.980783Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T15:04:40.980906Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T15:04:41.180954Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T15:04:41.181074Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T15:04:41.181312Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T15:04:41.181612Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T15:09:40.680961Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
2020-10-17T15:09:40.681152Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-54"
2020-10-17T15:09:40.681253Z warning envoy config [bazel-out/k8-opt/bin/external/envoy/source/common/config/_virtual_includes/grpc_stream_lib/common/config/grpc_stream.h:92] StreamSecrets gRPC config stream closed: 2, resource:default Close connection to proxy "sidecar~10.206.4.33~istio-test-app-3-69d695bf8b-b256m.istio-test-app-3~istio-test-app-3.svc.cluster.local-55"
{"level":"info","time":"2020-10-17T15:09:40.681058Z","scope":"sds","msg":"resource:default connection is terminated: rpc error: code = Canceled desc = context canceled"}
{"level":"info","time":"2020-10-17T15:09:40.842526Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T15:09:40.842666Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T15:09:40.842911Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T15:09:40.843082Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
{"level":"info","time":"2020-10-17T15:09:40.893759Z","scope":"sds","msg":"resource:default new connection"}
{"level":"info","time":"2020-10-17T15:09:40.893894Z","scope":"sds","msg":"Skipping waiting for ingress gateway secret"}
{"level":"info","time":"2020-10-17T15:09:40.894106Z","scope":"cache","msg":"GenerateSecret from file default"}
{"level":"info","time":"2020-10-17T15:09:40.894256Z","scope":"sds","msg":"resource:default pushed key/cert pair to proxy"}
Which shows the certificates are indeed out of date - and expired exactly when we started seeing issues.
This made me check another app where we mount certificates in this way (prometheus) and sure enough I see its certs are out of date too:
Bug description
In our
1.6qualifying environment we have an application that is rejecting requests withupstream connect error or disconnect/reset before headers. reset reason: connection failure.We have three (almost) identical test apps:
We continually send load that goes 1 -> 2 -> 3.
We rolling restart
istio-test-app-1every 10 minutes to create config churnThe pod is 25 hours old, however as you can see here something happened at 14:35 which broke
istio-test-app-3(1 and 2 remain fine).The istio proxy logs contain lots of sds noise:
The only difference that
istio-test-app-3has vs 1 and 2 is that it uses:As per this documentation.
To write certs to this
volumeMount:In order to write the certs to disk (as I was experimenting with for prometheus)
Looking at the logs I see:
Which makes me check:
Which shows the certificates are indeed out of date - and expired exactly when we started seeing issues.
This made me check another app where we mount certificates in this way (prometheus) and sure enough I see its certs are out of date too:
Restarting the pod renewed the certificates:
[ ] Docs
[ ] Installation
[ ] Networking
[ ] Performance and Scalability
[ ] Extensions and Telemetry
[x] Security
[ ] Test and Release
[x] User Experience
[ ] Developer Infrastructure
Expected behavior
SDS certs to be updated correctly when using
OUTPUT_CERTSSteps to reproduce the bug
No idea
Version (include the output of
istioctl version --remoteandkubectl version --shortandhelm versionif you used Helm)1.6.12
How was Istio installed?
Helm
Environment where bug was observed (cloud vendor, OS, etc)
GKE