Skip to content

Commit e82689a

Browse files
authored
fix(ci): stop the detached telemetry flush too, re-signal stragglers on a monotonic clock, and report HTTP E2E failures by route (#8706)
* fix(e2e): re-signal session stragglers on a monotonic clock and report HTTP E2E failures once, by route - stop-session.sh times its grace period from /proc/uptime, which is monotonic and free of the locale's decimal separator, re-signals every 0.1s so a process that joins the session after the first signal is stopped too, and explains why zombies don't count - version compare: a request whose body times out names its route like a request that never answered - desktop inbox: callers that join an executor pull in flight share it, so a failed pull is logged once * fix(e2e): log a failed executor pull with its stack * fix(ci): also stop the detached telemetry flush an HTTP end-to-end app leaves behind `next dev` spawns its telemetry flush detached, in a session of its own, even with telemetry disabled. That process outlives the app's session and writes .next/dev/trace after stop-session.sh returned, so the next app's `rm -rf .next/dev` could fail with "Directory not empty". Each app now starts under an E2E_APP tag that every process it spawns inherits, and stop-session.sh stops and waits for tagged processes as well as the session's members.
1 parent 351b8b9 commit e82689a

4 files changed

Lines changed: 81 additions & 54 deletions

File tree

‎.github/scripts/stop-session.sh‎

Lines changed: 50 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -1,62 +1,84 @@
11
#!/usr/bin/env bash
2-
# Stops every process in a session started with `setsid`, and returns only once none is left.
2+
# Stops every process an app started, and returns only once none is left.
33
#
4-
# Usage: stop-session.sh <session-leader-pid>
4+
# Usage: stop-session.sh <session-leader-pid> <app-tag>
55
#
6-
# `next dev` runs its server and workers as child processes. Waiting on `next dev` alone returns
7-
# while those can still be running, and the next app in the job reuses the same .next directory.
8-
# Every member of the session is signalled, including one that moved to its own process group.
9-
# The leader stays a zombie until the shell that started it waits on it, so zombies don't count.
6+
# Start the app as `E2E_APP=<app-tag> setsid <command> &`. Its processes are the members of the
7+
# leader's session, plus any process that inherited `E2E_APP=<app-tag>` but left the session.
8+
# `next dev` needs both: its server and workers stay in the session, while its telemetry flush is
9+
# spawned detached, in a session of its own, and writes .next/dev/trace after `next dev` exits.
10+
# The next app in the job wipes that directory, so it must not start while any of them runs.
11+
#
12+
# Every member is signalled, including one that moved to its own process group, and one that
13+
# started after the first signal.
14+
#
15+
# Zombies don't count as running: they have exited and only await reaping. The leader is one
16+
# until the shell that started it waits on it, which that shell does after this returns.
1017
set -u
1118

1219
leader=$1
20+
tag=$2
1321
grace_seconds=10
1422

15-
session_pids() {
16-
ps -s "$leader" -o pid=,stat= 2>/dev/null | awk '$2 !~ /^Z/ { print $1 }'
23+
app_pids() {
24+
{
25+
ps -s "$leader" -o pid=,stat= 2>/dev/null | awk '$2 !~ /^Z/ { print $1 }'
26+
grep -lzx "E2E_APP=$tag" /proc/[0-9]*/environ 2>/dev/null | cut -d/ -f3
27+
} | sort -u
1728
}
1829

19-
signal_session() {
30+
signal_app() {
2031
local pids
21-
pids=$(session_pids)
32+
pids=$(app_pids)
2233
[ -z "$pids" ] || kill "-$1" $pids 2>/dev/null || true
2334
}
2435

2536
running() {
26-
[ -n "$(session_pids)" ]
37+
[ -n "$(app_pids)" ]
2738
}
2839

2940
leader_running() {
3041
ps -p "$leader" -o stat= 2>/dev/null | grep -qv '^Z'
3142
}
3243

33-
now_us() {
34-
echo "${EPOCHREALTIME/./}"
44+
list_app() {
45+
local pids
46+
pids=$(app_pids | paste -sd, -)
47+
[ -z "$pids" ] || ps -p "$pids" -o pid,sid,stat,etimes,args 2>/dev/null | cut -c1-200 || true
48+
}
49+
50+
# Centiseconds since boot: monotonic, and independent of the locale's decimal separator.
51+
now_cs() {
52+
local uptime
53+
read -r uptime _ < /proc/uptime
54+
echo "${uptime/./}"
3555
}
3656

37-
# Waits while the given check holds, until the shared deadline. Succeeds once it stops holding.
38-
wait_while() {
39-
while (($(now_us) < deadline)); do
57+
# Re-sends the signal every 0.1s while the check holds, until the shared deadline.
58+
# Succeeds once the check stops holding.
59+
signal_while() {
60+
local signal=$1
61+
shift
62+
while ((10#$(now_cs) < deadline)); do
4063
"$@" || return 0
64+
signal_app "$signal"
4165
sleep 0.1
4266
done
4367
! "$@"
4468
}
4569

46-
deadline=$(($(now_us) + grace_seconds * 1000000))
47-
signal_session TERM
48-
wait_while leader_running
70+
deadline=$((10#$(now_cs) + grace_seconds * 100))
71+
signal_while TERM leader_running
4972
if ! leader_running && running; then
50-
echo "Processes from session $leader outlived its leader:"
51-
ps -s "$leader" -o pid,stat,etimes,args 2>/dev/null | cut -c1-200 || true
73+
echo "Processes from app $tag outlived its leader:"
74+
list_app
5275
fi
53-
wait_while running && exit 0
76+
signal_while TERM running && exit 0
5477

55-
echo "::warning::Processes from session $leader were still running ${grace_seconds}s after SIGTERM:"
56-
ps -s "$leader" -o pid,stat,etimes,args 2>/dev/null | cut -c1-200 || true
57-
deadline=$(($(now_us) + grace_seconds * 1000000))
58-
signal_session KILL
59-
wait_while running && exit 0
78+
echo "::warning::Processes from app $tag were still running ${grace_seconds}s after SIGTERM:"
79+
list_app
80+
deadline=$((10#$(now_cs) + grace_seconds * 100))
81+
signal_while KILL running && exit 0
6082

61-
echo "::error::Processes from session $leader survived SIGKILL for ${grace_seconds}s."
83+
echo "::error::Processes from app $tag survived SIGKILL for ${grace_seconds}s."
6284
exit 1

‎.github/workflows/test-build.yml‎

Lines changed: 12 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -211,8 +211,10 @@ jobs:
211211
# same lifecycle. It starts from an empty Turbopack dev cache: a cache written under
212212
# other NEXT_PUBLIC_* values, by a server that `next dev` SIGKILLs 100ms after
213213
# SIGTERM, can panic Turbopack or wedge a route compile on restore. It runs in its
214-
# own session, and stop-session.sh returns only once all of it has exited, so no app
215-
# starts beside one still writing .next/dev.
214+
# own session under an E2E_APP tag, and stop-session.sh returns only once every
215+
# process in that session or carrying that tag has exited (Next's telemetry flush
216+
# runs detached and still writes .next/dev), so no app starts beside one still
217+
# writing .next/dev.
216218
- name: Verify SCIM, administration and workflow comparisons over real HTTP
217219
working-directory: apps/sim
218220
env:
@@ -240,11 +242,11 @@ jobs:
240242
server_log="$report_dir/scim-next.log"
241243
mkdir -p "$report_dir"
242244
rm -rf .next/dev
243-
setsid node ../../node_modules/next/dist/bin/next dev --hostname 127.0.0.1 --port 3017 > "$server_log" 2>&1 &
245+
E2E_APP=scim setsid node ../../node_modules/next/dist/bin/next dev --hostname 127.0.0.1 --port 3017 > "$server_log" 2>&1 &
244246
server_pid=$!
245247
finish() {
246248
status=$?
247-
bash ../../.github/scripts/stop-session.sh "$server_pid" || status=1
249+
bash ../../.github/scripts/stop-session.sh "$server_pid" scim || status=1
248250
wait "$server_pid" 2>/dev/null || true
249251
awk '/^ (GET|POST|PUT|PATCH|DELETE|HEAD) \/api\// { print }' "$server_log" > "$report_dir/scim-http-status.log"
250252
if [ "$status" -ne 0 ]; then
@@ -293,11 +295,11 @@ jobs:
293295
server_log="$report_dir/cli-next.log"
294296
mkdir -p "$report_dir"
295297
rm -rf .next/dev
296-
setsid node ../../node_modules/next/dist/bin/next dev --hostname 127.0.0.1 --port 3018 > "$server_log" 2>&1 &
298+
E2E_APP=cli setsid node ../../node_modules/next/dist/bin/next dev --hostname 127.0.0.1 --port 3018 > "$server_log" 2>&1 &
297299
server_pid=$!
298300
finish() {
299301
status=$?
300-
bash ../../.github/scripts/stop-session.sh "$server_pid" || status=1
302+
bash ../../.github/scripts/stop-session.sh "$server_pid" cli || status=1
301303
wait "$server_pid" 2>/dev/null || true
302304
if [ "$status" -ne 0 ]; then
303305
tail -n 200 "$server_log"
@@ -344,11 +346,11 @@ jobs:
344346
server_log="$report_dir/stop-after-next.log"
345347
mkdir -p "$report_dir"
346348
rm -rf .next/dev
347-
setsid node ../../node_modules/next/dist/bin/next dev --hostname 127.0.0.1 --port 3018 > "$server_log" 2>&1 &
349+
E2E_APP=stop-after setsid node ../../node_modules/next/dist/bin/next dev --hostname 127.0.0.1 --port 3018 > "$server_log" 2>&1 &
348350
server_pid=$!
349351
finish() {
350352
status=$?
351-
bash ../../.github/scripts/stop-session.sh "$server_pid" || status=1
353+
bash ../../.github/scripts/stop-session.sh "$server_pid" stop-after || status=1
352354
wait "$server_pid" 2>/dev/null || true
353355
awk '/^ (GET|POST|PUT|PATCH|DELETE|HEAD) \/api\// { print }' "$server_log" > "$report_dir/stop-after-http-status.log"
354356
if [ "$status" -ne 0 ]; then
@@ -395,11 +397,11 @@ jobs:
395397
server_log="$report_dir/desktop-inbox-next.log"
396398
mkdir -p "$report_dir"
397399
rm -rf .next/dev
398-
setsid node ../../node_modules/next/dist/bin/next dev --hostname 127.0.0.1 --port 3019 > "$server_log" 2>&1 &
400+
E2E_APP=desktop-inbox setsid node ../../node_modules/next/dist/bin/next dev --hostname 127.0.0.1 --port 3019 > "$server_log" 2>&1 &
399401
server_pid=$!
400402
finish() {
401403
status=$?
402-
bash ../../.github/scripts/stop-session.sh "$server_pid" || status=1
404+
bash ../../.github/scripts/stop-session.sh "$server_pid" desktop-inbox || status=1
403405
wait "$server_pid" 2>/dev/null || true
404406
awk '/^ (GET|POST|PUT|PATCH|DELETE|HEAD) \/api\// { print }' "$server_log" > "$report_dir/desktop-inbox-http-status.log"
405407
if [ "$status" -ne 0 ]; then

‎apps/sim/scripts/test-desktop-inbox-e2e.ts‎

Lines changed: 7 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -358,22 +358,17 @@ function startExecutor(desktop: Desktop, doorbell: ReturnType<typeof openDoorbel
358358
inFlight = null
359359
}
360360
}
361+
/** Callers that join a pull in flight share it, so its failure is logged once, here. */
361362
const pull = () => {
362363
if (inFlight) {
363364
rerun = true
364-
return inFlight
365+
return
365366
}
366-
inFlight = drain()
367-
return inFlight
367+
inFlight = drain().catch((error) => logger.error('executor pull failed', error))
368368
}
369-
const offDoorbell = doorbell.onEvent(
370-
() => void pull().catch((error) => logger.error('pull failed', error))
371-
)
372-
const timer = setInterval(
373-
() => void pull().catch((error) => logger.error('reconcile failed', error)),
374-
RECONCILE_MS
375-
)
376-
void pull().catch((error) => logger.error('pull failed', error))
369+
const offDoorbell = doorbell.onEvent(pull)
370+
const timer = setInterval(pull, RECONCILE_MS)
371+
pull()
377372
return {
378373
ran,
379374
completed,
@@ -385,7 +380,7 @@ function startExecutor(desktop: Desktop, doorbell: ReturnType<typeof openDoorbel
385380
stopped = true
386381
offDoorbell()
387382
clearInterval(timer)
388-
await inFlight?.catch(() => {})
383+
await inFlight
389384
},
390385
}
391386
}

‎apps/sim/scripts/test-workflow-version-compare-e2e.ts‎

Lines changed: 12 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -356,10 +356,18 @@ async function get(path: string, auth: { key?: string; session?: string } = {},
356356
assert.match(response.headers.get('content-type') ?? '', /application\/json/)
357357
if (path.startsWith('/api/v2/'))
358358
assert.equal(response.headers.get('cache-control'), 'private, no-store')
359-
const text = await readResponseTextWithLimit(response, {
360-
maxBytes: MAX_RESPONSE_BYTES,
361-
label: 'Version comparison E2E response',
362-
})
359+
let text: string
360+
try {
361+
text = await readResponseTextWithLimit(response, {
362+
maxBytes: MAX_RESPONSE_BYTES,
363+
label: 'Version comparison E2E response',
364+
})
365+
} catch (error) {
366+
/** `get` passes no signal of its own, so an abort here is the request timeout. */
367+
if (!(error instanceof DOMException && ['TimeoutError', 'AbortError'].includes(error.name)))
368+
throw error
369+
throw new Error(`GET ${path}: response body not complete within ${REQUEST_TIMEOUT_MS / 1000}s`)
370+
}
363371
return record(JSON.parse(text))
364372
}
365373

0 commit comments

Comments
 (0)