From 8af8f69893c2f7bfe35ff757530143a6377a350d Mon Sep 17 00:00:00 2001 From: Richard Wall Date: Wed, 9 Sep 2026 14:21:39 +0000 Subject: [PATCH] Stop the VCP e2e test hanging when the certificate never appears MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Run 34356382122 sat on a single step for 50 minutes and had to be cancelled by hand. It would otherwise have held a GKE cluster until the default six hour job timeout. A healthy run takes about 14 minutes. The cause is the final wait in hack/e2e/test.sh: for ((i=0;;i++)); do if getCertificate; then exit 0; fi; sleep 30; done \ | timeout -v -- 5m cat `timeout` bounds `cat`, not the loop. While getCertificate is failing it writes nothing to the pipe, so it never takes a SIGPIPE. When `timeout` kills `cat` at five minutes, Bash blocks forever waiting for the loop subshell, which is still going. The `exit 0` on success only leaves that subshell, so it cannot end the script either. The logs of the cancelled run show how bad this gets. `cat` was killed at 13:33:54. The loop then polled a dead pipe for another seventeen minutes. At 13:50:36 the output changed to "jq: error: writing output failed: Broken pipe", which is the branch jq only reaches when count is non-zero. The certificate had arrived and the test could no longer observe it. Replace the pipeline with a plain deadline loop, so the wait fails at five minutes with a message naming the certificate it gave up on. Bound the poll itself as well. getCertificate's curl had no time limit, and the deadline is only checked after a poll returns, so a connection that stalls once accepted would hang inside the poll and never reach the check — the same class of hang, moved from the loop into the request. Confirmed against a server that accepts and then sends nothing: bare `curl -fsSL` had to be killed from outside after 45s, while `--max-time 10` returned on its own with exit 28. curl's 300s default connect timeout does not help, since it already exceeds the budget and does not apply once the connection is up. Also apply the same reasoning to the log wait above it. That one worked, but only because kubectl keeps writing and so does take a SIGPIPE, which is why it needed `set +o pipefail` around it. hack/ark/test-e2e.sh and hack/ngts/test-e2e.sh already solve this properly by passing the stream in by process substitution and letting `timeout` bound jq itself. Use that form here too and drop the pipefail dance. Finally, give the three e2e jobs a timeout-minutes. They had none, so the default six hours applied. This is a backstop, not a fix: the script should fail on its own, and a job that holds a GKE cluster should not be able to run for six hours if it does not. Two things this does not address, both worth their own change: - The certificate took about 22 minutes to appear in the inventory. The five minute budget is unchanged here, so this run would still have failed, just promptly and with a clear message. - Each run leaks two Venafi service accounts, the registry one created around line 90 and the agent one created in the unbounded `while true` loop around line 140. Nothing deletes them. That loop has no sleep, so if it ever fails to converge it will hammer the API. The other curls in the script are likewise unbounded. Tested by extracting both wait constructs into harnesses and running them against a stream that succeeds and one that never does. The old loop had to be killed from outside and exited 124; the replacement exits 1 at the deadline and still exits 0 on success. The new log wait exits 0 on match and 124 on timeout. Signed-off-by: Richard Wall --- .github/workflows/tests.yaml | 5 +++++ hack/e2e/test.sh | 34 +++++++++++++++++++++++++--------- 2 files changed, 30 insertions(+), 9 deletions(-) diff --git a/.github/workflows/tests.yaml b/.github/workflows/tests.yaml index 9881a6a0..0981d0cc 100644 --- a/.github/workflows/tests.yaml +++ b/.github/workflows/tests.yaml @@ -86,6 +86,7 @@ jobs: # other unrelated work. if: github.event_name == 'workflow_dispatch' || contains(github.event.pull_request.labels.*.name, 'test-ark') runs-on: ubuntu-latest + timeout-minutes: 30 steps: - uses: actions/checkout@8e8c483db84b4bee98b60c0593521ed34d9990e8 # v6.0.1 # Adding `fetch-depth: 0` makes sure tags are also fetched. We need @@ -123,6 +124,7 @@ jobs: # TEMPORARY: require an explicit label to test NGTS until we have a stable test environment if: github.event_name == 'workflow_dispatch' || contains(github.event.pull_request.labels.*.name, 'test-ngts') runs-on: ubuntu-latest + timeout-minutes: 30 steps: - uses: actions/checkout@8e8c483db84b4bee98b60c0593521ed34d9990e8 # v6.0.1 # Adding `fetch-depth: 0` makes sure tags are also fetched. We need @@ -157,6 +159,9 @@ jobs: test-e2e: if: github.event_name == 'workflow_dispatch' || contains(github.event.pull_request.labels.*.name, 'test-e2e') runs-on: ubuntu-latest + # A healthy run takes about 15 minutes. The backstop matters because the job + # holds a GKE cluster for as long as it runs, and the default is 6 hours. + timeout-minutes: 30 steps: - uses: actions/checkout@8e8c483db84b4bee98b60c0593521ed34d9990e8 # v6.0.1 # Adding `fetch-depth: 0` makes sure tags are also fetched. We need diff --git a/hack/e2e/test.sh b/hack/e2e/test.sh index c76a2bae..1d041e0c 100755 --- a/hack/e2e/test.sh +++ b/hack/e2e/test.sh @@ -194,14 +194,13 @@ kubectl -n team-1 wait certificate app-0 --for=condition=Ready # Wait 60s for log message indicating success. # Parse logs as JSON using jq to ensure logs are all JSON formatted. -# Disable pipefail to prevent SIGPIPE (141) errors from tee -# See https://unix.stackexchange.com/questions/274120/pipe-fail-141-when-piping-output-into-tee-why -set +o pipefail -kubectl logs deployments/venafi-kubernetes-agent \ - --follow \ - --namespace venafi \ - | timeout 60 jq 'if .msg | test("Data sent successfully") then . | halt_error(0) end' -set -o pipefail +# +# Supply the logs by process substitution rather than a pipe, so that `timeout` +# bounds jq itself. The pipe form has to disable pipefail to survive the SIGPIPE +# it provokes in kubectl. Matches hack/ark/test-e2e.sh and hack/ngts/test-e2e.sh. +timeout 60 jq -n \ + 'inputs | if .msg | test("Data sent successfully") then . | halt_error(0) else . end' \ + <(kubectl logs deployments/venafi-kubernetes-agent --follow --namespace venafi) # Create a unique TLS Secret and wait for it to appear in the Venafi certificate # inventory API. The case conversion is due to macOS' version of uuidgen which @@ -210,6 +209,9 @@ commonname="venafi-kubernetes-agent-e2e.$(uuidgen | tr '[:upper:]' '[:lower:]')" openssl req -x509 -nodes -days 365 -newkey rsa:2048 -keyout /tmp/tls.key -out /tmp/tls.crt -subj "/CN=$commonname" kubectl create secret tls "$commonname" --cert=/tmp/tls.crt --key=/tmp/tls.key -o yaml --dry-run=client | kubectl apply -f - +# --max-time bounds the poll itself. curl has no default overall limit, and the +# deadline below is only checked between polls, so a connection that stalls +# after being accepted would hang here and never reach it. getCertificate() { jq -n '{ "expression": { @@ -226,10 +228,24 @@ getCertificate() { }' --arg commonname "${commonname}" \ | curl "https://${VEN_API_HOST}/outagedetection/v1/certificatesearch?excludeSupersededInstances=true&ownershipTree=true" \ -fsSL \ + --max-time 30 \ -H "tppl-api-key: $VEN_API_KEY" \ --json @- \ | jq 'if .count == 0 then . | halt_error(1) end' } # Wait 5 minutes for the certificate to appear. -for ((i=0;;i++)); do if getCertificate; then exit 0; fi; sleep 30; done | timeout -v -- 5m cat +# +# Do not put the retry loop on the left of a pipe into `timeout`. That only +# bounds the reader: while getCertificate is failing the loop writes nothing, so +# it never takes a SIGPIPE, and Bash blocks forever waiting for it after +# `timeout` has killed `cat`. +certificate_timeout_seconds=300 +deadline=$((SECONDS + certificate_timeout_seconds)) +until getCertificate; do + if ((SECONDS >= deadline)); then + echo "Timed out after ${certificate_timeout_seconds}s waiting for certificate ${commonname} to appear in the Venafi inventory" >&2 + exit 1 + fi + sleep 30 +done