=== T16 Test Execution Log === Namespace: istio-vt-t16 Manifest: manifest.yaml (client pod, echo deploy+svc, ServiceEntry+DestinationRule for mock.istio-verify-ext external target, idleTimeout=20s + tcpKeepalive time=3s/interval=2s/probes=10) DEVIATION NOTE: Istio 1.30 default proxyStatsMatcher (mesh-wide, no custom Telemetry/ProxyConfig found) only allows inclusion_list prefixes [reporter=, cluster_manager, listener_manager, server, cluster.xds-grpc, wasm, component, istio, + rbac/shadow suffixes, vhost route regex] through the /stats admin endpoint. Per-cluster outbound stats (upstream_cx_idle_timeout etc.) for "outbound|80||mock.istio-verify-ext..." were NOT exposed by default -- confirmed empty grep both before ANY traffic and after a real successful curl to the service. This is standard Istio stats-scope reduction, not specific to this test. To make the spec's exact grep-based observation possible, the client pod was recreated with annotation: sidecar.istio.io/statsInclusionPrefixes: "cluster.outbound|80||mock.istio-verify-ext.svc.homelab.local" This only affects admin-endpoint stat VISIBILITY, not proxy behavior (idleTimeout/tcpKeepalive enforcement itself is unaffected by stats inclusion config). After recreation, cluster.outbound|80||mock... upstream_cx_idle_timeout: 0 appeared and pod client was re-waited to Ready (2/2) before proceeding. === Pre-check: cluster/pod state === NAME READY STATUS RESTARTS AGE IP NODE NOMINATED NODE READINESS GATES client 2/2 Running 0 36s 10.255.159.163 k8s-master1 echo-5767bbcc56-ptgfp 2/2 Running 0 3m40s 10.255.194.121 k8s-worker1 cluster.outbound|80||mock.istio-verify-ext.svc.homelab.local === CMD1: before_idle stats === $ kubectl -n istio-vt-t16 exec client -c istio-proxy -- curl -s localhost:15000/stats | grep 'outbound|80||mock.istio-verify-ext.svc.homelab.local.*upstream_cx_idle_timeout' > /tmp/before_idle.txt; cat /tmp/before_idle.txt cluster.outbound|80||mock.istio-verify-ext.svc.homelab.local;.upstream_cx_idle_timeout: 0 === CMD2: open idle TCP connection with keep-alive header, hold 30s (background) === $ kubectl -n istio-vt-t16 exec client -c curl -- sh -c 'exec 3<>/dev/tcp/mock.istio-verify-ext.svc.homelab.local/80; printf ...; head -c 200 <&3; sleep 30; exec 3<&-' & background PID: 1181495 === CMD3: sleep 35 (waiting for idle timeout window to pass) === 2026-07-04T22:50:31Z start sleep35 2026-07-04T22:51:06Z end sleep35 bg exit code: 127 --- background curl/tcp output --- sh: can't create /dev/tcp/mock.istio-verify-ext.svc.homelab.local/80: nonexistent directory command terminated with exit code 1 === CMD2 (ADAPTED): curlimages/curl uses busybox ash which lacks /dev/tcp support (confirmed: 'sh: can't create /dev/tcp/.../80: nonexistent directory'). === Substituted with functionally-equivalent busybox nc: send one keep-alive HTTP request, read response, then hold the TCP socket open idle for ~30s via a trailing 'sleep 30' before stdin/connection closes, in background. $ kubectl -n istio-vt-t16 exec client -c curl -- sh -c '(printf "GET / HTTP/1.1 Host: mock.istio-verify-ext.svc.homelab.local Connection: keep-alive "; sleep 30) | nc mock.istio-verify-ext.svc.homelab.local 80 > /tmp_nc_out' & 2026-07-04T22:52:15Z launched background idle-hold connection (bgpid=1183719) === CMD3: sleep 35 (waiting for idle timeout window ~20s + margin to elapse) === 2026-07-04T22:52:21Z start sleep35 2026-07-04T22:52:56Z end sleep35 bg wait exit code: 127 --- background nc output (client pod, local capture at /tmp/t16_nc_out.txt on this host, redirected inside kubectl exec stdout) --- cat: /tmp/t16_nc_out.txt: No such file or directory --- CORRECTED: background nc output fetched from inside container /tmp/t16_nc_out.txt --- HTTP/1.1 200 OK x-powered-by: Express content-type: application/json; charset=utf-8 content-length: 1198 etag: W/"4ae-6DFC1MKyZM99BRiMdnh7OzUSrtE" date: Sat, 04 Jul 2026 22:52:15 GMT x-envoy-upstream-service-time: 2 server: envoy { "path": "/", "headers": { "host": "mock.istio-verify-ext.svc.homelab.local", "x-forwarded-proto": "http", "x-request-id": "c0394dec-d75f-4ae3-940e-0922b53fc679", "x-envoy-decorator-operation": "mock.istio-verify-ext.svc.homelab.local:80/*", "x-envoy-peer-metadata-id": "sidecar~10.255.159.163~client.istio-vt-t16~istio-vt-t16.svc.cluster.local", "x-envoy-peer-metadata": "ChoKCkNMVVNURVJfSUQSDBoKS3ViZXJuZXRlcwp7CgZMQUJFTFMScSpvCg8KA2FwcBIIGgZjbGllbnQKKwofc2VydmljZS5pc3Rpby5pby9jYW5vbmljYWwtbmFtZRIIGgZjbGllbnQKLwojc2VydmljZS5pc3Rpby5pby9jYW5vbmljYWwtcmV2aXNpb24SCBoGbGF0ZXN0ChAKBE5BTUUSCBoGY2xpZW50ChsKCU5BTUVTUEFDRRIOGgxpc3Rpby12dC10MTYKSAoFT1dORVISPxo9a3ViZXJuZXRlczovL2FwaXMvYXBwcy92MS9uYW1lc3BhY2VzL2lzdGlvLXZ0LXQxNi9wb2RzL2NsaWVudAoZCg1XT1JLTE9BRF9OQU1FEggaBmNsaWVudA==", "x-envoy-attempt-count": "1" }, "method": "GET", "body": "", "fresh": false, "hostname": "mock.istio-verify-ext.svc.homelab.local", "ip": "::ffff:10.255.159.163", "ips": [], "protocol": "http", "query": {}, "subdomains": [ "svc", "istio-verify-ext", "mock" ], "xhr": false, "os": { "hostname": "mock-597cccffdf-bwsnt" }, "connection": {} } === CMD5: after_idle stats === $ kubectl -n istio-vt-t16 exec client -c istio-proxy -- curl -s localhost:15000/stats | grep 'outbound|80||mock.istio-verify-ext.svc.homelab.local.*upstream_cx_idle_timeout' > /tmp/after_idle.txt; cat /tmp/after_idle.txt cluster.outbound|80||mock.istio-verify-ext.svc.homelab.local;.upstream_cx_idle_timeout: 0 === SECOND DEVIATION NOTE === First attempt used the spec's literal idleTimeout=20s / tcpKeepalive(time=3s,interval=2s,probes=10) / hold=30s. Result: upstream_cx_idle_timeout stayed 0 in both before/after, BUT upstream_cx_destroy_remote incremented to 3 and upstream_cx_length_ms histogram showed connection lifetime ~6025-6075ms (P50=6050ms) across all 3 connections made so far -- i.e. every upstream connection was closed by the REMOTE peer (the shared mock.istio-verify-ext backend, mendhak/http-https-echo / Node.js Express) at ~6s, which matches Node.js's default http.Server keepAliveTimeout=5000ms (+ ~1s headers grace). This means the backend's OWN idle-connection-close fires long before Envoy's 20s idleTimeout ever gets a chance to -- the spec's 20s value can never be observed against this particular shared backend. CORRECTION APPLIED (still scoped only to our own namespace's DestinationRule/ServiceEntry, does not touch istio-verify-ext ns): lowered idleTimeout to 4s (comfortably below the ~6s backend ceiling) and tcpKeepalive to time=1s/interval=1s/probes=10 (so multiple keepalive rounds -- ~1s,2s,3s -- complete successfully before the 4s cutoff). Re-ran the manifest apply + full before/hold/sleep/after/logs sequence with these corrected parameters. This preserves the exact mechanism under test (idleTimeout vs tcpKeepalive) while working around the confound. pod/client configured deployment.apps/echo unchanged service/echo unchanged serviceentry.networking.istio.io/idletimeout-mock-se unchanged destinationrule.networking.istio.io/idletimeout-mock-dr configured {"idleTimeout":"4s","tcpKeepalive":{"interval":"1s","probes":10,"time":"1s"}} === Confirmed via /config_dump: cluster outbound|80||mock...homelab.local has === common_http_protocol_options.idle_timeout = 4s upstream_connection_options.tcp_keepalive = {time:1, interval:1, probes:10} (confirms idleTimeout and tcpKeepalive are two separate config paths: L7 idle timer vs L4 SO_KEEPALIVE) === CMD1 (re-run, corrected params): before_idle stats === cluster.outbound|80||mock.istio-verify-ext.svc.homelab.local;.upstream_cx_idle_timeout: 0 === CMD2 (re-run, corrected): open idle TCP conn via nc, hold 10s idle (background) === $ kubectl -n istio-vt-t16 exec client -c curl -- sh -c '(printf "GET ... Connection: keep-alive "; sleep 10) | nc mock.istio-verify-ext.svc.homelab.local 80 > /tmp/t16_nc_out2.txt' & 2026-07-04T22:56:46Z launched background idle-hold connection (idleTimeout=4s, hold=10s) === CMD3 (re-run, corrected): sleep 15 (idleTimeout=4s window + margin) === 2026-07-04T22:56:51Z start sleep15 2026-07-04T22:57:06Z end sleep15 --- background nc output (fetched from inside client container) --- HTTP/1.1 200 OK x-powered-by: Express content-type: application/json; charset=utf-8 content-length: 1198 etag: W/"4ae-RaS8EjNCe1yO2dBps/9lzi4cbPk" date: Sat, 04 Jul 2026 22:56:46 GMT x-envoy-upstream-service-time: 2 server: envoy { "path": "/", "headers": { "host": "mock.istio-verify-ext.svc.homelab.local", "x-forwarded-proto": "http", "x-request-id": "e6e8a6e6-8201-4df3-8bfb-e76ddfed7602", "x-envoy-decorator-operation": "mock.istio-verify-ext.svc.homelab.local:80/*", "x-envoy-peer-metadata-id": "sidecar~10.255.159.163~client.istio-vt-t16~istio-vt-t16.svc.cluster.local", "x-envoy-peer-metadata": "ChoKCkNMVVNURVJfSUQSDBoKS3ViZXJuZXRlcwp7CgZMQUJFTFMScSpvCg8KA2FwcBIIGgZjbGllbnQKKwofc2VydmljZS5pc3Rpby5pby9jYW5vbmljYWwtbmFtZRIIGgZjbGllbnQKLwojc2VydmljZS5pc3Rpby5pby9jYW5vbmljYWwtcmV2aXNpb24SCBoGbGF0ZXN0ChAKBE5BTUUSCBoGY2xpZW50ChsKCU5BTUVTUEFDRRIOGgxpc3Rpby12dC10MTYKSAoFT1dORVISPxo9a3ViZXJuZXRlczovL2FwaXMvYXBwcy92MS9uYW1lc3BhY2VzL2lzdGlvLXZ0LXQxNi9wb2RzL2NsaWVudAoZCg1XT1JLTE9BRF9OQU1FEggaBmNsaWVudA==", "x-envoy-attempt-count": "1" }, "method": "GET", "body": "", "fresh": false, "hostname": "mock.istio-verify-ext.svc.homelab.local", "ip": "::ffff:10.255.159.163", "ips": [], "protocol": "http", "query": {}, "subdomains": [ "svc", "istio-verify-ext", "mock" ], "xhr": false, "os": { "hostname": "mock-597cccffdf-bwsnt" }, "connection": {} } === CMD5 (re-run, corrected): after_idle stats === cluster.outbound|80||mock.istio-verify-ext.svc.homelab.local;.upstream_cx_idle_timeout: 1 === CMD6: istio-proxy logs, last 1m, tail -20 === [2026-07-04T22:56:46.286Z] "GET / HTTP/1.1" 200 - via_upstream - "-" 0 1198 4 2 "-" "-" "e6e8a6e6-8201-4df3-8bfb-e76ddfed7602" "mock.istio-verify-ext.svc.homelab.local" "10.250.183.220:80" outbound|80||mock.istio-verify-ext.svc.homelab.local 10.255.159.163:46856 10.250.183.220:80 10.255.159.163:33419 - default === FINAL SUMMARY === before_idle.txt: upstream_cx_idle_timeout: 0 after_idle.txt: upstream_cx_idle_timeout: 1 (>= 1, matches pass_criteria) Supporting evidence: - upstream_cx_destroy_local: 0 -> 1 (this specific connection was destroyed LOCALLY by Envoy's own idle timer, unlike the 3 earlier connections which were all upstream_cx_destroy_remote, i.e. closed by the backend's own ~5-6s Node.js keepAliveTimeout) - upstream_cx_length_ms histogram gained a new data point at ~4050ms, matching the configured idleTimeout=4s almost exactly - The initial HTTP request/response over the held connection succeeded (200 OK, full body, envoy access log shows normal 200 completion) -- confirming the connection was healthy/functional, not already broken, right up to the moment Envoy's idle timer cut it - /config_dump confirmed idleTimeout maps to common_http_protocol_options.idle_timeout (L7 HTTP idle timer) while tcpKeepalive maps to upstream_connection_options.tcp_keepalive (L4 SO_KEEPALIVE socket options) -- two independent mechanisms, exactly as the claims under test assert Conclusion: tcpKeepalive (time=1s/interval=1s/probes=10) being configured and operating normally did NOT prevent/reset idleTimeout's disconnect; the connection was cut at ~idleTimeout regardless. PASS.