Skip to content

Commit 8af8f69

Browse files
Stop the VCP e2e test hanging when the certificate never appears
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 <richard.wall@cyberark.com>
1 parent 7e728f6 commit 8af8f69

2 files changed

Lines changed: 30 additions & 9 deletions

File tree

.github/workflows/tests.yaml

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -86,6 +86,7 @@ jobs:
8686
# other unrelated work.
8787
if: github.event_name == 'workflow_dispatch' || contains(github.event.pull_request.labels.*.name, 'test-ark')
8888
runs-on: ubuntu-latest
89+
timeout-minutes: 30
8990
steps:
9091
- uses: actions/checkout@8e8c483db84b4bee98b60c0593521ed34d9990e8 # v6.0.1
9192
# Adding `fetch-depth: 0` makes sure tags are also fetched. We need
@@ -123,6 +124,7 @@ jobs:
123124
# TEMPORARY: require an explicit label to test NGTS until we have a stable test environment
124125
if: github.event_name == 'workflow_dispatch' || contains(github.event.pull_request.labels.*.name, 'test-ngts')
125126
runs-on: ubuntu-latest
127+
timeout-minutes: 30
126128
steps:
127129
- uses: actions/checkout@8e8c483db84b4bee98b60c0593521ed34d9990e8 # v6.0.1
128130
# Adding `fetch-depth: 0` makes sure tags are also fetched. We need
@@ -157,6 +159,9 @@ jobs:
157159
test-e2e:
158160
if: github.event_name == 'workflow_dispatch' || contains(github.event.pull_request.labels.*.name, 'test-e2e')
159161
runs-on: ubuntu-latest
162+
# A healthy run takes about 15 minutes. The backstop matters because the job
163+
# holds a GKE cluster for as long as it runs, and the default is 6 hours.
164+
timeout-minutes: 30
160165
steps:
161166
- uses: actions/checkout@8e8c483db84b4bee98b60c0593521ed34d9990e8 # v6.0.1
162167
# Adding `fetch-depth: 0` makes sure tags are also fetched. We need

hack/e2e/test.sh

Lines changed: 25 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -194,14 +194,13 @@ kubectl -n team-1 wait certificate app-0 --for=condition=Ready
194194

195195
# Wait 60s for log message indicating success.
196196
# Parse logs as JSON using jq to ensure logs are all JSON formatted.
197-
# Disable pipefail to prevent SIGPIPE (141) errors from tee
198-
# See https://unix.stackexchange.com/questions/274120/pipe-fail-141-when-piping-output-into-tee-why
199-
set +o pipefail
200-
kubectl logs deployments/venafi-kubernetes-agent \
201-
--follow \
202-
--namespace venafi \
203-
| timeout 60 jq 'if .msg | test("Data sent successfully") then . | halt_error(0) end'
204-
set -o pipefail
197+
#
198+
# Supply the logs by process substitution rather than a pipe, so that `timeout`
199+
# bounds jq itself. The pipe form has to disable pipefail to survive the SIGPIPE
200+
# it provokes in kubectl. Matches hack/ark/test-e2e.sh and hack/ngts/test-e2e.sh.
201+
timeout 60 jq -n \
202+
'inputs | if .msg | test("Data sent successfully") then . | halt_error(0) else . end' \
203+
<(kubectl logs deployments/venafi-kubernetes-agent --follow --namespace venafi)
205204

206205
# Create a unique TLS Secret and wait for it to appear in the Venafi certificate
207206
# 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:]')"
210209
openssl req -x509 -nodes -days 365 -newkey rsa:2048 -keyout /tmp/tls.key -out /tmp/tls.crt -subj "/CN=$commonname"
211210
kubectl create secret tls "$commonname" --cert=/tmp/tls.crt --key=/tmp/tls.key -o yaml --dry-run=client | kubectl apply -f -
212211

212+
# --max-time bounds the poll itself. curl has no default overall limit, and the
213+
# deadline below is only checked between polls, so a connection that stalls
214+
# after being accepted would hang here and never reach it.
213215
getCertificate() {
214216
jq -n '{
215217
"expression": {
@@ -226,10 +228,24 @@ getCertificate() {
226228
}' --arg commonname "${commonname}" \
227229
| curl "https://${VEN_API_HOST}/outagedetection/v1/certificatesearch?excludeSupersededInstances=true&ownershipTree=true" \
228230
-fsSL \
231+
--max-time 30 \
229232
-H "tppl-api-key: $VEN_API_KEY" \
230233
--json @- \
231234
| jq 'if .count == 0 then . | halt_error(1) end'
232235
}
233236

234237
# Wait 5 minutes for the certificate to appear.
235-
for ((i=0;;i++)); do if getCertificate; then exit 0; fi; sleep 30; done | timeout -v -- 5m cat
238+
#
239+
# Do not put the retry loop on the left of a pipe into `timeout`. That only
240+
# bounds the reader: while getCertificate is failing the loop writes nothing, so
241+
# it never takes a SIGPIPE, and Bash blocks forever waiting for it after
242+
# `timeout` has killed `cat`.
243+
certificate_timeout_seconds=300
244+
deadline=$((SECONDS + certificate_timeout_seconds))
245+
until getCertificate; do
246+
if ((SECONDS >= deadline)); then
247+
echo "Timed out after ${certificate_timeout_seconds}s waiting for certificate ${commonname} to appear in the Venafi inventory" >&2
248+
exit 1
249+
fi
250+
sleep 30
251+
done

0 commit comments

Comments
 (0)