Skip to content

fix(datadir): wait out schelk state-lock contention instead of failing the job - #290

Merged
qu0b merged 2 commits into
masterfrom
qu0b/schelk-mount-lock-retry
Aug 3, 2026
Merged

fix(datadir): wait out schelk state-lock contention instead of failing the job#290
qu0b merged 2 commits into
masterfrom
qu0b/schelk-mount-lock-retry

Conversation

@qu0b

@qu0b qu0b commented Aug 3, 2026

Copy link
Copy Markdown
Member

What happened

benchmark-ci-6 destroyed five consecutive Besu jobs today, each in ~12 seconds, all in the Build state-actor data directory step:

Build failed error=ensuring schelk mount: `schelk mount` failed: exit status 1
  0: Another schelk process is already running (flock on /var/lib/schelk/schelk.lock): EAGAIN: Try again

Every Besu job that landed on a different runner succeeded. ci-6 has no successful job at all in its history today.

Root cause

Runners serialise schelk work through a single flock at /var/lib/schelk/schelk.lock. While another schelk process holds it, schelk mount exits non-zero with EAGAIN — and EnsureSchelkMounted returned that straight to the caller:

output, runErr := RunSchelk(ctx, log, "mount", "-y")
if runErr != nil {
    return fmt.Errorf("`%s mount` failed: %w (output: %s)", bin, runErr, ...)
}

So a transient, self-clearing condition discarded a multi-hour benchmark job before it ran a single block.

It also compounds: the job fails in ~12s, the runner is immediately free, so it wins the next queued job of that client and burns that one too. One host with a held lock acts as a black hole, and the failure rate scales with how much work is queued.

Note the lock holder is necessarily a live process — flock is released on process death, so this is never a stale lock file. Waiting is the correct response.

Change

Retry schelk mount while the failure is lock contention, up to SchelkLockWait (10m), polling every 15s. Any other failure still returns on the first attempt, so genuine mount problems — including the is_mounted inconsistency that needs full-recover — stay fail-fast.

This covers both call sites, since state_actor.go and eest_payloads.go both go through EnsureSchelkMounted.

Tests

  • TestSchelkLockHeld — classification, including that "Volume is already mounted" is not treated as lock contention
  • TestMountWaitingForLock_RetriesUntilLockClears — fake schelk fails with the flock error twice then succeeds; asserts exactly 3 attempts
  • TestMountWaitingForLock_NonLockErrorFailsImmediately — asserts exactly 1 attempt, no retry

go test ./pkg/datadir/ and go vet pass.

Not a substitute for unblocking ci-6

This stops one stuck host from shredding the queue, but something is still holding that lock on benchmark-ci-6. That needs lsof /var/lib/schelk/schelk.lock on the host to identify the holder, and the runner pulled from the pool until it is cleared.

qu0b added 2 commits August 3, 2026 16:12
Runners serialise all schelk work through a single flock. When another
schelk process holds it, `schelk mount` exits non-zero with EAGAIN, and
EnsureSchelkMounted surfaced that as a fatal error — so a benchmark job died
in its build step over a condition that clears on its own.

Seen on benchmark-ci-6, where a held lock destroyed five consecutive besu
jobs in ~12s each. Because the host frees up immediately on failure, it kept
winning the next queued besu job and burning it too.

Retry mount while the lock is held, up to SchelkLockWait (10m). Every other
failure still returns on the first attempt, so genuine mount problems stay
fail-fast.
Addresses review on #290.

The retry warn dereferenced the logger unconditionally, but
config.go:3153 calls EnsureSchelkMounted with a nil logger and RunSchelk
documents that log may be nil. The panic would have fired on exactly the
lock-contention path this change exists to survive. Guarded, matching the
existing style at schelk.go:92 and :108.

schelkLockHeld also matched a bare "schelk.lock" substring, which would
classify an unwritable or missing lock path as contention and retry it for
the full 10 minutes rather than surfacing it. Narrowed to the explicit
contention wording and the EAGAIN marker.

Tests: nil-logger regression (verified it panics without the guard) and a
permission-denied-on-lock-path case asserting it is not treated as
contention.
@qu0b

qu0b commented Aug 3, 2026

Copy link
Copy Markdown
Member Author

Both points were valid — fixed in 8d22bbe.

🟡 nil-logger panic — confirmed and fixed. Verified the call chain rather than taking it on trust: pkg/config/config.go:3153 does pass nil, RunSchelk documents "log may be nil" (schelk.go:57), and the file already guards at :92 and :108. My warn dereferenced it unconditionally, so it would have panicked on precisely the contention path this PR exists to survive — the original code never logged there, which is why nil was safe before. Guarded in the existing if log != nil style.

Added TestMountWaitingForLock_NilLoggerDoesNotPanic, and checked it actually catches the bug by removing the guard:

--- FAIL: TestMountWaitingForLock_NilLoggerDoesNotPanic
    Error: func (assert.PanicTestFunc) should not panic
    Panic value: runtime error: invalid memory address or nil pointer dereference

Suggestion on schelk.lock matching — agreed, narrowed. You're right that it inverts the intent: I added it as a hedge against wording changes, but the failure it creates is worse than the one it prevents. A missing or unwritable lock path names the file too, and would then be retried for the full 10 minutes and hang the host instead of surfacing. If the wording ever changes, the narrow match just falls back to today's fail-fast behaviour — strictly better than masking a real error.

Now matches the explicit contention wording or the EAGAIN marker, with a test asserting "failed to open /var/lib/schelk/schelk.lock: permission denied" is not classified as contention.

go vet and the full pkg/datadir suite pass (11 tests).

@qu0b qu0b changed the title datadir: wait out schelk state-lock contention instead of failing the job fix(datadir): wait out schelk state-lock contention instead of failing the job Aug 3, 2026
@qu0b
qu0b merged commit fcfa4b8 into master Aug 3, 2026
7 of 8 checks passed
@qu0b
qu0b deleted the qu0b/schelk-mount-lock-retry branch August 3, 2026 14:25
qu0b added a commit that referenced this pull request Aug 3, 2026
A single `503` from `raw.githubusercontent.com` kills the job before
benchmarkoor starts. It just destroyed a stateful Besu run
([30826993105](https://github.com/ethpandaops/benchmarkoor-tests/actions/runs/30826993105))
that had *already completed* its state-actor build:

```
Downloading config from https://raw.githubusercontent.com/ethpandaops/benchmarkoor-tests/b711e361/configs/global.yaml
curl: (22) The requested URL returned error: 503
##[error]Process completed with exit code 22.
```

Both config downloads used bare `curl -fsSL` with no retry, so any blip
on GitHub's raw CDN throws away the job — and for a stateful run that is
a multi-hour slot on a scarce client-pinned runner.

## Change

```
curl -fsSL --retry 5 --retry-delay 2 --retry-max-time 120
```

on both the build-config and run-config downloads.

`--retry` covers exactly the transient class — 5xx, 429, 408, connection
timeouts — and leaves a genuine 404 failing on the **first** attempt, so
a config typo still surfaces immediately instead of hiding behind two
minutes of pointless retries. I deliberately did not use
`--retry-all-errors`, which would blur that line.

`--retry-max-time 120` bounds the worst case.

## Why it matters beyond this one job

This is the same shape as #290: a transient, self-clearing condition
treated as fatal, discarding hours of work. Worth a sweep for other
unguarded network calls in the action — this one only surfaced because
it happened to fire during an incident I was already watching.

action.yaml parses cleanly.
skylenet pushed a commit that referenced this pull request Aug 5, 2026
Hardens the dependencies action against the transient failures that have
now killed **four** benchmark jobs in two days. Every one died before
benchmarkoor started, discarding a slot on a scarce client-pinned
runner.

## Failures this addresses

**dpkg lock** —
[30904315843](https://github.com/ethpandaops/benchmarkoor-tests/actions/runs/30904315843),
nethermind, dead in 8s:

```
E: Could not get lock /var/lib/dpkg/lock-frontend. It is held by process 3758271 (apt-get)
##[error]Process completed with exit code 100.
```

**crun download** —
[30947072151](https://github.com/ethpandaops/benchmarkoor-tests/actions/runs/30947072151),
nethermind, dead in 10s:

```
Installing crun 1.26 with CRIU support...
curl: (22) The requested URL returned error: 502
```

## Changes

| what | fix |
|---|---|
| all **10** `apt`/`apt-get` calls | `-o DPkg::Lock::Timeout=300` —
block for the lock instead of exiting 100 |
| gh archive keyring (`wget`) | `--tries=5 --waitretry=2
--retry-connrefused` |
| crun (`curl`) | `--retry 5 --retry-delay 2 --retry-max-time 120` |
| yq (`wget`) | `--tries=5 --waitretry=2 --retry-connrefused` |

Genuine failures still surface unchanged: a missing package, a bad repo,
or a 404 on a release asset fails on the first attempt. Only "someone
else holds the lock" and the transient HTTP class are retried.

#291 fixed the config downloads in `action.yaml`; these three fetches
live in the dependencies action and were missed. After this change **no
`curl` or `wget` under `.github/actions/` or in `action.yaml` is left
without a retry** — verified by grep, not by eye.

## The pattern

Fourth instance in two days of one bug: a transient, self-clearing
condition treated as fatal.

| | condition | was |
|---|---|---|
| #290 | schelk state flock held | dies in 12s |
| #291 | `raw.githubusercontent.com` 503 | dies at exit 22 |
| this | dpkg lock held | dies in 8s |
| this | crun asset 502 | dies in 10s |

Each fails *fast*, so the freed runner immediately claims the next
queued job and burns it too — damage scales with queue depth rather than
being contained.

## Verification

- action.yaml parses
- no `apt`/`apt-get` without a lock timeout remains
- no `curl`/`wget` without retry remains anywhere in the repo's actions
skylenet added a commit that referenced this pull request Aug 5, 2026
Conflict in pkg/datadir/schelk.go: both sides appended a new block directly
after EnsureSchelkMounted, so git overlapped two independent additions.

Kept both, ordered master's first since EnsureSchelkMounted calls into it:
- master (#290): SchelkLockWait/schelkLockPollWait, schelkLockHeld,
  mountWaitingForLock — retry `schelk mount` through flock contention.
- this branch: RestoreSchelk — `schelk restore` (recover + mount) so pre_runs
  advances from a clean baseline.

No semantic overlap: master's helpers serve the mount path, RestoreSchelk is a
separate entry point called from pkg/builder/pre_runs.go. schelk_test.go
auto-merged and carries both sides' tests.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant