yonlu/yellowjacket
1
1
Fork 0
Code Issues 55 Pull Requests 6 Actions Packages Projects Releases 12 Wiki Activity

Flaky: TestYtDlpSearchSkipsUnparseableLines failed once in a full make test run #146

New Issue
Open
opened 2026-08-20 00:26:43 +00:00 by logan · 3 comments
logan commented 2026-08-20 00:26:43 +00:00
Collaborator
Copy Link
Copy Source

Report

TestYtDlpSearchSkipsUnparseableLines failed once inside a full
make test run on feat/27-jobs-into-settings, on a tree whose diff
touches only backend/config and the frontend:

--- FAIL: TestYtDlpSearchSkipsUnparseableLines (0.02s)
FAIL	yellowjacket/backend/download	3.801s

It has not reproduced since: 6 runs of -run TestYtDlp -race -count=1,
4 runs of the whole package with -race, and a second full make test
all pass. It also passes on a stashed (pristine) tree.

Findings

  • The test is t.Parallel() and drives newStubYtDlp, which writes a
    stub shell script and runs it as an external process — so it depends
    on a fork/exec and on the filesystem, which is the usual shape of a
    test that fails once under load. The machine was running the Vitest
    browser suite and a headless app at the time.
  • Search is called with context.Background(), so a timeout is not
    the mechanism; whatever failed, failed inside the stub or its exec.
  • The assertion that would have fired is one of two t.Fatalfs — a
    Search error, or a candidate count other than 2. The output was
    captured only as the summary line, so which one is not known.

Direction

Not worth chasing blind. What is worth doing is making the next
occurrence self-describing: the failure gave no message beyond the test
name, because the interesting values (err, len(got), the stub's
stderr) are not in the Fatalfs. Include the stub's combined output in
the error text, then leave it until it recurs.

Filed rather than mentioned in passing because a once-in-a-run failure
in a package nobody is touching is exactly what gets attributed to
whatever change happens to be in flight — this one was not it, and #140
and #138 are already two of those.

**Report** `TestYtDlpSearchSkipsUnparseableLines` failed once inside a full `make test` run on `feat/27-jobs-into-settings`, on a tree whose diff touches only `backend/config` and the frontend: ``` --- FAIL: TestYtDlpSearchSkipsUnparseableLines (0.02s) FAIL yellowjacket/backend/download 3.801s ``` It has not reproduced since: 6 runs of `-run TestYtDlp -race -count=1`, 4 runs of the whole package with `-race`, and a second full `make test` all pass. It also passes on a stashed (pristine) tree. **Findings** - The test is `t.Parallel()` and drives `newStubYtDlp`, which writes a stub shell script and runs it as an external process — so it depends on a fork/exec and on the filesystem, which is the usual shape of a test that fails once under load. The machine was running the Vitest browser suite and a headless app at the time. - `Search` is called with `context.Background()`, so a timeout is not the mechanism; whatever failed, failed inside the stub or its exec. - The assertion that would have fired is one of two `t.Fatalf`s — a `Search` error, or a candidate count other than 2. The output was captured only as the summary line, so which one is not known. **Direction** Not worth chasing blind. What is worth doing is making the next occurrence self-describing: the failure gave no message beyond the test name, because the interesting values (`err`, `len(got)`, the stub's stderr) are not in the `Fatalf`s. Include the stub's combined output in the error text, then leave it until it recurs. Filed rather than mentioned in passing because a once-in-a-run failure in a package nobody is touching is exactly what gets attributed to whatever change happens to be in flight — this one was not it, and #140 and #138 are already two of those.
logan added the Platform/Desktop
Priority
Low
4
Area/DownloadsKind/Bug labels 2026-08-20 00:26:43 +00:00
logan commented 2026-08-28 07:56:03 +00:00
Author
Collaborator
Copy Link
Copy Source

Reproduced in CI, with the message this issue asked for.

Run 18244's first attempt (job check, commit 26251ba on
docs/220-skill-check-scope, a diff containing no Go at all):

--- FAIL: TestYtDlpSearchSkipsUnparseableLines (0.00s)
    provider_ytdlp_test.go:178: Search: yt-dlp failed: search:
        fork/exec /tmp/TestYtDlpSearchSkipsUnparseableLines745121200/001/yt-dlp:
        text file busy
FAIL	yellowjacket/backend/download	6.823s

A re-run of the same commit passed, so it is the flake this issue
describes and not a regression.

So it is the Search error branch, and the mechanism is ETXTBSY on
the exec, not anything inside the stub. "text file busy" is the
kernel refusing to exec a file that is open for writing anywhere in the
process — the classic shape is that newStubYtDlp writes and closes
the script, and a concurrent fork in another goroutine duplicates
that still-open write descriptor into a child that outlives the close,
so the exec a moment later sees a writer. t.Parallel() plus a package
whose tests each write and exec their own stub is exactly the
population needed, which is also why it only appears under a loaded full
run and never under -run TestYtDlp.

Two consequences for the Direction already on this issue:

  • The suggestion to include the stub's combined output in the Fatalf
    would not have helped here — the stub never ran. What identified it
    was the wrapped err, which provider_ytdlp_test.go:178 already
    prints; the original report simply captured only the summary line.
  • The fix is likely on the writing side rather than the asserting
    side: close the file before any sibling can fork (or write the stub
    once per package into a shared dir, rather than once per test), which
    is a change to newStubYtDlp and not to the test that happens to
    lose the race. O_CLOEXEC alone does not close it, since the window
    is between another goroutine's fork and its exec.

Still Priority/Low from here: it costs a re-run, not a wrong answer.

**Reproduced in CI, with the message this issue asked for.** Run 18244's first attempt (job `check`, commit `26251ba` on `docs/220-skill-check-scope`, a diff containing no Go at all): ``` --- FAIL: TestYtDlpSearchSkipsUnparseableLines (0.00s) provider_ytdlp_test.go:178: Search: yt-dlp failed: search: fork/exec /tmp/TestYtDlpSearchSkipsUnparseableLines745121200/001/yt-dlp: text file busy FAIL yellowjacket/backend/download 6.823s ``` A re-run of the same commit passed, so it is the flake this issue describes and not a regression. **So it is the `Search` error branch, and the mechanism is ETXTBSY on the exec, not anything inside the stub.** "text file busy" is the kernel refusing to exec a file that is open for writing *anywhere in the process* — the classic shape is that `newStubYtDlp` writes and closes the script, and a **concurrent** `fork` in another goroutine duplicates that still-open write descriptor into a child that outlives the close, so the exec a moment later sees a writer. `t.Parallel()` plus a package whose tests each write and exec their own stub is exactly the population needed, which is also why it only appears under a loaded full run and never under `-run TestYtDlp`. Two consequences for the Direction already on this issue: - The suggestion to include the stub's combined output in the `Fatalf` would not have helped here — the stub never ran. What identified it was the wrapped `err`, which `provider_ytdlp_test.go:178` already prints; the original report simply captured only the summary line. - The fix is likely on the *writing* side rather than the asserting side: close the file before any sibling can fork (or write the stub once per package into a shared dir, rather than once per test), which is a change to `newStubYtDlp` and not to the test that happens to lose the race. `O_CLOEXEC` alone does not close it, since the window is between another goroutine's fork and its exec. Still `Priority/Low` from here: it costs a re-run, not a wrong answer.
logan self-assigned this 2026-08-30 11:36:52 +00:00
logan added the
Status
In Progress
 label 2026-08-30 11:36:53 +00:00
logan commented 2026-08-30 11:36:53 +00:00
Author
Collaborator
Copy Link
Copy Source

Picking this up on fix/146-stub-etxtbsy.

The mechanism reproduces on demand, which is what makes it takeable
rather than a blind chase. A standalone harness — 12 goroutines, each
writing an executable script into its own temp dir and exec'ing it,
which is stubYtDlp's exact shape — produces 271–302 ETXTBSY failures
in 4800 execs, in under a second, on this machine.

And the fix is on the writing side, as the comment above predicted,
though neither of the two options named there is the one that works.
Closing sooner is not available: os.WriteFile has already closed the
file before the exec, and the descriptor that makes the kernel refuse is
a copy taken by a sibling's fork while it was briefly open. Writing
the stub once per package into a shared dir narrows the window but does
not remove it — the first write of each script still races.

What removes it is holding syscall.ForkLock across the write. That is
the lock syscall.forkExec takes exclusively around the fork, so no
child can be created while our write descriptor exists, and a child
forked before the write cannot hold a descriptor for a file that did not
yet exist. Measured on the same harness: 0 of 4800, three runs.

Change is confined to stubYtDlp in backend/download/provider_ytdlp_test.go
— it is the only test helper in the repo that writes an executable and
then execs it (cmd/indexbuild/deps_test.go execs go list).

Picking this up on `fix/146-stub-etxtbsy`. **The mechanism reproduces on demand**, which is what makes it takeable rather than a blind chase. A standalone harness — 12 goroutines, each writing an executable script into its own temp dir and exec'ing it, which is `stubYtDlp`'s exact shape — produces **271–302 ETXTBSY failures in 4800 execs**, in under a second, on this machine. **And the fix is on the writing side, as the comment above predicted, though neither of the two options named there is the one that works.** Closing sooner is not available: `os.WriteFile` has already closed the file before the exec, and the descriptor that makes the kernel refuse is a *copy* taken by a sibling's `fork` while it was briefly open. Writing the stub once per package into a shared dir narrows the window but does not remove it — the first write of each script still races. What removes it is holding `syscall.ForkLock` across the write. That is the lock `syscall.forkExec` takes exclusively around the fork, so no child can be created while our write descriptor exists, and a child forked before the write cannot hold a descriptor for a file that did not yet exist. Measured on the same harness: **0 of 4800, three runs.** Change is confined to `stubYtDlp` in `backend/download/provider_ytdlp_test.go` — it is the only test helper in the repo that writes an executable and then execs it (`cmd/indexbuild/deps_test.go` execs `go list`).
logan commented 2026-08-30 11:55:19 +00:00
Author
Collaborator
Copy Link
Copy Source

PR: #235 — CI green
(run 18482, check and e2e both success).

The fix is syscall.ForkLock held across the write in stubYtDlp,
which is on the writing side as this issue's comment directed, though it
is neither of the two options named there: closing sooner is not
available (os.WriteFile has already closed the file before anything
execs it — the offending descriptor is a copy taken by a fork already
in flight), and a shared per-package dir narrows the window rather than
removing it, since the first write of each script still races.

Measured on the helper itself, 12 concurrent writers, 2400 execs:
189 / 176 / 178 ETXTBSY before, 0 / 0 / 0 after. The probe that
produced those numbers is deliberately not committed — a stress test
that only sometimes fails is the class of thing this issue is about.

The original failure is still not reproducible as a failure; what is
now impossible is the mechanism, so a recurrence would mean a different
cause and would deserve its own issue.

PR: https://git.ljones.me/yonlu/yellowjacket/pulls/235 — CI green (run 18482, `check` and `e2e` both success). The fix is `syscall.ForkLock` held across the write in `stubYtDlp`, which is on the writing side as this issue's comment directed, though it is neither of the two options named there: closing sooner is not available (`os.WriteFile` has already closed the file before anything execs it — the offending descriptor is a *copy* taken by a fork already in flight), and a shared per-package dir narrows the window rather than removing it, since the first write of each script still races. Measured on the helper itself, 12 concurrent writers, 2400 execs: **189 / 176 / 178** ETXTBSY before, **0 / 0 / 0** after. The probe that produced those numbers is deliberately not committed — a stress test that only sometimes fails is the class of thing this issue is about. The original failure is still not reproducible *as a failure*; what is now impossible is the mechanism, so a recurrence would mean a different cause and would deserve its own issue.
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
Area/Design
Area/Downloads
Area/Explore
Area/Library-UI
Area/Metadata
Area/Packaging
Area/Player
Area/Queue
Area/Settings
Area/Shell-Nav
Compat/Breaking
Breaking change that won't be backward compatible
 Kind/Bug
Something is not working
 Kind/Documentation
Documentation changes
 Kind/Enhancement
Improve existing functionality
 Kind/Feature
New functionality
 Kind/Security
This is security issue
 Kind/Testing
Issue or pull request related to testing
 Platform/Android
Platform/Desktop
Priority
Critical
1
The priority is critical
Priority
High
2
The priority is high
Priority
Medium
3
The priority is medium
Priority
Low
4
The priority is low
Reviewed
Confirmed
1
Issue has been confirmed
Reviewed
Duplicate
2
This issue or pull request already exists
Reviewed
Invalid
3
Invalid issue
Reviewed
Won't Fix
3
This issue won't be fixed
Status
Blocked
1
Something is blocking this issue or pull request
Status
Need More Info
2
Feedback is required to reproduce issue or to continue work
Status
Abandoned
3
Somebody has started to work on this but abandoned work
Status
In Progress
Somebody is actively working on this right now
No labels Area/Downloads Kind/Bug Platform/Desktop
Priority
Low
4
Status
In Progress
Milestone
No items
No Milestone
Projects
Clear projects
No projects
Assignees
Clear assignees
logan yonlu
No Assignees logan
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: yonlu/yellowjacket#146