Skip to content

e2e: skrog reset --to <snapshot> — restored engine does not come back within 2m #468

Description

@zcsizmadia

TestAcceptance/EngineSnapshotSaveAndList fails on skrog reset --to:

e2e_test.go:814: skrog reset --to e2e: exit status 1
    skrog: restored engine did not come back within 2m0s

The stage took 153.8 s before giving up.

This is newly reachable, not a regression

The suite stops at the first failing stage. Until #429 was fixed it died at SupervisorRestartReplacesTheProcess, which runs before this one, so EngineSnapshotSaveAndList had never executed in CI at all:

run 35515835217 (before the fix):  grep -c EngineSnapshotSaveAndList  ->  0
                                   stage SupervisorRestartReplacesTheProcess failed; skipping the rest

run 35662530599 (after the fix):   --- PASS: TestAcceptance/SupervisorRestartReplacesTheProcess (8.33s)
                                   --- FAIL: TestAcceptance/EngineSnapshotSaveAndList (153.83s)

So this is the second bug in the queue becoming visible, which is the suite working. It says nothing about whether reset --to ever worked — only that CI has never checked.

What the stage does

Everything before the failure passed: snapshot save, snapshot list, and both artifacts on disk (snapshots/e2e.tar, snapshots/e2e.json). The failure is the restore:

run(t, 5*time.Minute, s.skrog, "reset", "--state-dir", s.stateDir, "--json", "--to", "e2e")

reset --to verifies the archive, unregisters the distro, re-imports it and waits for the engine. The wait is what expired — the suite's own 5-minute budget was not reached, so skrog's internal 2-minute engine-start timeout fired first.

Worth checking, roughly in order

  1. Is 2m simply too short on a hosted runner after a fresh wsl --import? The first engine start after an import is the slowest one there is — cold VM, cold page cache, first dockerd launch. skrog stop then start takes 6.6-9.4 s to a running container #398 already measured a plain stop/start at 6.6–9.4 s, but that is a warm distro. If this is just slow, the fix is the timeout and a log line saying what it is waiting for.
  2. Does the supervisor interfere? It is running throughout, serving skrog-e2e-suite, and it has its own reconcile loop that starts the engine. A reset that unregisters the distro underneath a supervisor mid-tick is a plausible way to get two things racing to import or start.
  3. Does the engine actually come up late, or never? The stage gives no evidence either way. skrog status and the supervisor log immediately after the failure would separate "slow" from "stuck", and the suite should capture them on this failure rather than leaving the next person to guess.

Note on the timeout

skrog: restored engine did not come back within 2m0s does not say what it was waiting for or what it last saw. For a two-minute wait that ends in a failed restore, that is not enough to act on — whatever the cause turns out to be, that message should name the distro, the engine state it observed, and where the log is.

Related: #429 (which was masking this), #448 (the nightly stays off until the suite can be green), #398 (engine start latency), #142 (reset --to).

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions