Stop the VCP e2e test hanging when the certificate never appears

[wallrj-cyberark]

The VCP e2e test can hang forever. This makes it fail instead.

Why now?

Run 34356382122 sat on one step for 50 minutes and I cancelled it by hand. Left alone it would have held a GKE cluster until the default six hour job timeout. A healthy run takes about 14 minutes.

The final wait in hack/e2e/test.sh cannot time out:

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, which is still going. The exit 0 on success only leaves the subshell, so it cannot end the script either.

The cancelled run shows how bad this gets: the certificate did eventually arrive, and the test could no longer see it. Detail below.

What changes

• The certificate wait becomes a plain deadline loop. It now fails at five minutes with a message naming the certificate it gave up on.
• getCertificate's curl gets --max-time 30. curl sets no default overall limit and the deadline is only checked between polls, so a connection that stalls once accepted would hang inside the poll and never reach the check. Same class of hang, moved from the loop into the request. Raised by @FelixPhipps in review.
• The log wait above it moves to the process substitution form already used by hack/ark/test-e2e.sh and hack/ngts/test-e2e.sh, which lets timeout bound jq directly. That one was not broken, but it only worked because kubectl keeps writing and so does take a SIGPIPE, which is why it needed set +o pipefail wrapped around it. That dance goes away.
• The three e2e jobs get a timeout-minutes. They had none, so the default six hours applied. This is a backstop, not the fix.

What this does not fix

This run would still have failed, just promptly and with a clear message. Two separate problems, both worth their own change:

• The certificate took about 22 minutes to appear in the inventory. The five minute budget is unchanged here. If that latency is normal now rather than a blip, the budget needs revisiting on its own evidence.
• Every 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, and $RANDOM only spans 0–32767. That loop also has no sleep, so if it ever fails to converge it will hammer the API rather than stall. Its curls are unbounded too, as are the rest in the script; only getCertificate's is fixed here.

Timeline from the cancelled run, showing the certificate arriving after the reader was already dead

Time (UTC)	What the log shows
13:28:54	Polling begins
13:33:54	timeout: sending signal TERM to command 'cat' — five minute budget expires, reader dies, script does not exit
13:34–13:50	Loop keeps polling a dead pipe, logging {"count":0,"certificates":[]} to stderr
13:50:36	Output flips to jq: error: writing output failed: Broken pipe
14:13:54	Cancelled by hand

That last line is the important one. getCertificate ends in:

| jq 'if .count == 0 then . | halt_error(1) end'

halt_error writes to stderr, which is why the count":0 lines still reach the log after the pipe is gone. jq only attempts a stdout write when the condition is false, so a broken pipe error means count was non-zero. The certificate had landed at 13:50:36, roughly 22 minutes after polling began and 17 minutes after the reader was killed.

How this was tested, given the e2e itself needs a GKE cluster and a live tenant

I extracted both wait constructs into standalone harnesses and drove them with a stub that succeeds and one that never does.

Old certificate wait, stub that never succeeds, outer kill after 25s:

start 1788963103
timeout: sending signal TERM to command 'cat'
outer exit=124 (124 = the script never returned)

timeout fired at 5s and the script still had to be killed from outside.

Replacement, same stub:

Timed out after 5s waiting for certificate example.test to appear in the Venafi inventory
case1 (never appears) exit=1

Replacement, stub that succeeds at 4s:

{"count":1}
SUCCESS: fell through to end of script
case2 (appears at 4s) exit=0

New log wait, stream that emits the success line:

{"msg":"Data sent successfully"}
match: exit=0 (want 0, fast)

New log wait, stream that never emits it:

nomatch: exit=124 (want 124, no hang)

bash -n passes on the script and the workflow parses as valid YAML with the three new timeouts in place.

e2e result

Green: run 34373985024, 15m10s against the ~14 minute baseline, with the test-e2e label.

Both changed waits were exercised, so it is not a pass by luck. The log wait matched Data sent successfully and returned; the deadline loop polled four times at 30s intervals and hit on the fourth, about 90 seconds in. There is not one jq: error: writing output failed: Broken pipe in the log, which was the old bug's signature.

That also settles the latency question above: this morning's ~22 minutes was a blip, not the new normal, so the five minute budget stands.

Note for the label route: adding the label alone does not start a run. on: pull_request: {} uses the default activity types — opened, synchronize, reopened — and labeled is not among them. Label, then push.

[FelixPhipps]

Reviewed the diff and reproduced both wait constructs locally against a stub that succeeds and one that never does. The diagnosis and the fix hold up: the replacement deadline loop exits 1 at the deadline with the named certificate and 0 on success, and the process-substitution log wait exits 0 promptly on match and 124 on timeout, which errexit turns into a script failure. It matches the form already in hack/ark/test-e2e.sh and hack/ngts/test-e2e.sh, and dropping the set +o pipefail dance is correct — nothing else in the script depended on it.

The job durations back the new caps. Recent successful test-e2e runs are 14m16s and 14m19s; ark-test-e2e and ngts-test-e2e are 3–4 minutes. 30 minutes is a comfortable backstop for all three.

Two things worth a look.

1. The timeout-minutes backstop leans on a cleanup step that has been observed getting cut short.

timeout-minutes cancels the job, and GitHub bounds how long the if: always() steps get after a cancellation. Run 34356382122 shows this happening: Delete GKE Cluster started at 14:13:55, printed Deleting cluster test-secretless-260909-132042..., and was terminated at 14:18:08 with exit code 143 about 4m13s in, before gcloud returned.

gcloud container clusters delete issues the delete and then polls, so the cluster was most likely still removed server-side — but that is worth confirming for that specific cluster, because the reason given for adding timeout-minutes is not holding a GKE cluster, and the cancellation path is now the routine way this job will end when something goes wrong rather than a manual rarity.

2. getCertificate's curl has no timeout, so the five minute deadline is only enforced between polls.

curl "https://${VEN_API_HOST}/..." -fsSL -H "tppl-api-key: $VEN_API_KEY" --json @-

No --connect-timeout or --max-time, and curl has no default overall limit. The ((SECONDS >= deadline)) check only runs after a poll returns, so a curl that blocks — a blackholed connection rather than a refusal — hangs indefinitely and never reaches it. That is the same class of hang this PR is closing, just moved from the loop into the poll, and it is now bounded by the 30 minute job timeout rather than by the script. A --max-time on that curl would make the five minute budget actually hold.

Neither blocks this as a clear improvement on what is there today.

[Generated with claude code]

[wallrj-cyberark]

Thanks Felix. Point 2 is a real bug and I have fixed it. Point 1 I had already verified — the cluster is gone.

The curl timeout. You are right, and it is the same hang in a different place. I reproduced it against a server that accepts the connection 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 rescue it either — that already exceeds the five minute budget, and it does not apply once the connection is up. Added --max-time 30 to that curl, which is generous given polls are 30s apart and the request normally returns in well under a second. Amended onto the branch.

The other curls in the script are unbounded too, including the ones in the while true service account loop. I have left those alone here and noted them with the other follow-ups, since that loop needs its own fix.

The cluster from run 34356382122 was deleted. I checked before opening this. No human account can see machineidentitysecurity-jsci-e — neither of mine can even projects describe it — so I ran a throwaway push-triggered branch that reused the repo's existing GCP auth to list clusters from CI, which does have the credential. It reported ABSENT, and the project holds zero clusters, so nothing has leaked from earlier runs either. That branch is deleted. Worth knowing that GKE returns an identical 403 whether a cluster exists or not, so a 403 tells you nothing about existence.

On the wider concern: I think the framing is the wrong way round. Cancellation is the current failure mode — before this change a stuck script ran to the six hour default or waited for someone to notice. After it the script fails on its own at five minutes, and with the curl fix that deadline is now actually enforced, so the job ends through ordinary step failure and the always() step gets its full time. timeout-minutes only bites if something hangs in a way neither bound catches.

I also considered --async on the delete so gcloud returns as soon as the request is accepted rather than polling. I decided against it: the delete is already asynchronous server-side, which is why being killed mid-poll did no harm here, and --async would hide a server-side deletion failure that the polling form surfaces. Happy to add it if you would rather have the belt and braces.

[FelixPhipps]

Thanks for the fix! belt and braces will not be necessary.

Approved!

[wallrj-cyberark]

e2e is green with the test-e2e label: run 34373985024, 15m10s, against the ~14 minute baseline. Nothing broken.

Both changed waits were genuinely exercised, so this is not a pass by luck:

• The process-substitution log wait matched Data sent successfully at 16:09:21 and returned.
• The deadline loop polled four times at 30s intervals — {"count":0,"certificates":[]} at 16:09:23, 16:09:53 and 16:10:23, then a hit on the fourth. About 90 seconds, well inside the five minute budget.
• Zero jq: error: writing output failed: Broken pipe in the whole log. That was the signature of the old bug, so its absence is the positive result.

One useful data point for your first question, @FelixPhipps. On this run Delete GKE Cluster ran to completion and took 4m52s — Deleting cluster test-secretless-260909-160127... at 16:10:55, Deleted [...] at 16:15:47. When the job was cancelled yesterday the same step was killed at 4m13s, so it genuinely would not have finished polling. The cluster was still removed, because the delete is server-side asynchronous. That is the mechanism, measured on both paths.

It also settles the latency question: this morning's ~22 minutes was a blip, not the new normal. Ninety seconds today. So the five minute budget stands and does not need raising.

Worth noting for anyone using the label route in future: adding the label on its own does not start a run. on: pull_request: {} uses the default activity types, opened, synchronize and reopened, and labeled is not one of them. You have to label and then push. I re-triggered this with a force-push.