cardano-testnet: fail fast with a diagnosis when the chain stalls irrecoverably#6616
cardano-testnet: fail fast with a diagnosis when the chain stalls irrecoverably#6616palas wants to merge 2 commits into
Conversation
…ecoverably A `cardano-testnet` network permanently stops producing blocks whenever no block is forged for longer than the ledger view forecast horizon of `3 * securityParam / activeSlotsCoeff` slots - `300 slots = 30s` of wall clock with the default genesis options (`securityParam=5`, `activeSlotsCoeff=0.05`, `slotLength=0.1s`). Past that point every node fails its leadership check with `Forge.Loop.NoLedgerView` and the chain can never extend again. This happens when node startup exceeds the start-time offset (`startTimeOffsetSeconds`, `15s`) plus the horizon, or when an overloaded machine starves the nodes of CPU for longer than the horizon mid-run, and it made tests hang forever in chain-progress waits (`waitForEpochs`/`waitForBlocks`/`waitUntilEpoch`) whose deadlines are measured in epochs/blocks/slots that never arrive. Detect the situation instead, as early as it is provable, and explain it: * `chainForecastHorizon` computes the horizon from the `ShelleyGenesis` backing the testnet (read via the node configuration); the stall threshold is `max 60s (2 * horizon)` - `60s` with the default genesis - falling back to a conservative `300s` when the genesis cannot be read. * `retryUntilRightM`: when no chain-state update arrives for the whole stall threshold (previously a silently swallowed `300s` fallback), fail with a message explaining the mechanism, the actual horizon, and pointing at the node logs. * `waitUntilEpoch`: `race` `foldEpochState` against a stall watchdog with the same semantics and diagnostic. * `waitForBlockThrow`: the startup deadline is now derived from the genesis (`startTimeOffsetSeconds + horizon + 15s` margin instead of a flat `45s`) and the error explains the likely cause and remedy. Attempts to fix #5762 (the hangs)
33b397e to
933264a
Compare
… teardown Two teardown hardenings for overloaded machines, where a test suite run can wedge with no output at all - not even the per-test 600s watchdogs fire visibly - until the CI-level timeout kills it. * `initiateProcess` now releases processes with `cleanupProcessBounded` instead of `cleanupProcess`. The bounded variant waits a `15s` grace period and escalates to `SIGKILL`, which cannot be ignored or blocked, so node termination is guaranteed; if the process still survives (uninterruptible kernel sleep) it is leaked rather than waited on. * `asyncRegister_` no longer waits unboundedly for the cancelled thread: `H.cancel` blocks until the thread finishes, and resource release actions run with asynchronous exceptions masked, so a thread stuck in a foreign call would wedge the teardown forever with nothing able to interrupt it. Cap the wait at `15s` and leak the thread instead.
| @@ -1,5 +1,11 @@ | |||
| {-# LANGUAGE CPP #-} | |||
There was a problem hiding this comment.
Could we not add more places with CPP?
I propose the following refactor: move any OS-specific signaling logic to Testnet.Handlers. Rename Testnet.Handlers to Testnet.Signal or Testnet.OS.Signal (singular noun preferred).
| -- @ShelleyGenesisFile@ key in the (JSON) node configuration, resolves it relative to the | ||
| -- configuration file's directory, and decodes the genesis. Returns 'Nothing' whenever | ||
| -- anything cannot be read, so callers can fall back to conservative defaults. | ||
| readShelleyGenesis :: MonadIO m => NodeConfigFile In -> m (Maybe ShelleyGenesis) |
There was a problem hiding this comment.
- that function does not belong to this module
- Why is this redefined instead of using
readGenesis?
carbolymer
left a comment
There was a problem hiding this comment.
This is a wrong place to fix this. This change will only affect tests using EpochStateView. Tests like LeadershipSchedule or KesPeriodInfo are still waiting using other means.
I think this should be implemented as an optional (on by default) network watchdog running in the background instead.
| result <- H.evalIO . runExceptT $ | ||
| foldEpochState | ||
| nodeConfigFile socketPath QuickValidation desiredEpoch () (\_ _ _ -> pure ConditionNotMet) | ||
| mHorizon <- fmap chainForecastHorizon <$> readShelleyGenesis nodeConfigFile |
There was a problem hiding this comment.
Genesis is read and decoded on every waitUntilEpoch call. This is wasteful.
| -- resources, starving the machine further. See the CI-timeout flavour of | ||
| -- https://github.com/IntersectMBO/cardano-node/issues/5762 | ||
| cleanupProcessBounded :: (Maybe Handle, Maybe Handle, Maybe Handle, ProcessHandle) -> IO () | ||
| cleanupProcessBounded (mStdin, mStdout, mStderr, hProcess) = do |
There was a problem hiding this comment.
This could be useful I think. 👍🏻
| -- appear within the forecast horizon after it (see 'chainForecastHorizon'), plus margin. | ||
| let startupHorizon = chainForecastHorizon shelleyGenesis | ||
| startupBlockTimeout = startTimeOffsetSeconds + ceiling startupHorizon + 15 | ||
| mapConcurrently_ (waitForBlockThrow startupHorizon startupBlockTimeout (File nodeConfigFile)) testnetNodes' |
There was a problem hiding this comment.
This is a change in a good direction. False negatives could've come up here on a slow machines, although I haven't seen it yet. I think the margin value needs more explanation.
But on the other side, the goal of this check is to fail early, rather than wait for the latest possible moment for the chain expansions. The tests need a network producing blocks fast, so if the network is not advancing fast enough, TestWatchdog will start killing test cases.
For our test configuration the wait here will be 60s (unix) and 135s (windows). So I guess your change should not degrade our early detection of slow networks.
| , case lastPoint of | ||
| Just (SlotNo slotNo, BlockNo blockNo) -> | ||
| "Last observed chain state: slot " <> show slotNo <> ", block " <> show blockNo <> "." | ||
| Nothing -> "No chain state update was observed at all." |
There was a problem hiding this comment.
"No chain state update was observed at all."
Does this mean no blocks were produced at all? I.e nothing from genesis?
| throwString $ "foldBlocks on " <> nodeName <> " encountered an error while waiting for new blocks: " <> show (prettyError err) | ||
| _ -> | ||
| throwString $ nodeName <> " was unable to produce any blocks for " <> show timeoutSeconds <> "s" | ||
| throwString $ nodeName <> " was unable to produce any blocks for " <> show timeoutSeconds <> "s. " |
Good idea, that way we don't have to worry about all the possible ways one can watch the network |
Another attempt at reducing/avoiding the flakiness of tests by stopping the waits when the chain is dead.
Description
A
cardano-testnetnetwork permanently stops producing blocks whenever no block is forged for longer than the ledger view forecast horizon of3 * securityParam / activeSlotsCoeffslots -300 slots = 30sof wall clock with the default genesis options (securityParam=5,activeSlotsCoeff=0.05,slotLength=0.1s). Past that point every node fails its leadership check withForge.Loop.NoLedgerViewand the chain can never extend again. This happens when node startup exceeds the start-time offset (startTimeOffsetSeconds,15s) plus the horizon, or when an overloaded machine starves the nodes of CPU for longer than the horizon mid-run, and it made tests hang forever in chain-progress waits (waitForEpochs/waitForBlocks/waitUntilEpoch) whose deadlines are measured in epochs/blocks/slots that never arrive.Detect the situation instead, as early as it is provable, and explain it:
chainForecastHorizoncomputes the horizon from theShelleyGenesisbacking the testnet (read via the node configuration); the stall threshold ismax 60s (2 * horizon)-60swith the default genesis - falling back to a conservative300swhen the genesis cannot be read.retryUntilRightM: when no chain-state update arrives for the whole stall threshold (previously a silently swallowed300sfallback), fail with a message explaining the mechanism, the actual horizon, and pointing at the node logs.waitUntilEpoch:racefoldEpochStateagainst a stall watchdog with the same semantics and diagnostic.waitForBlockThrow: the startup deadline is now derived from the genesis (startTimeOffsetSeconds + horizon + 15smargin instead of a flat45s) and the error explains the likely cause and remedy.In addition to that:
Two teardown hardenings for overloaded machines, where a test suite run can wedge with no output at all - not even the per-test 600s watchdogs fire visibly - until the CI-level timeout kills it.
initiateProcessnow releases processes withcleanupProcessBoundedinstead ofcleanupProcess. The bounded variant waits a15sgrace period and escalates toSIGKILL, which cannot be ignored or blocked, so node termination is guaranteed; if the process still survives (uninterruptible kernel sleep) it is leaked rather than waited on.asyncRegister_no longer waits unboundedly for the cancelled thread:H.cancelblocks until the thread finishes, and resource release actions run with synchronous exceptions masked, so a thread stuck in a foreign call would wedge the teardown forever with nothing able to interrupt it. Cap the wait at15sand leak the thread instead.Attempts to fix #5762 (the hangs)
Checklist
See Running tests for more details
CHANGELOG.mdfor affected package.cabalfiles are updatedhlint. See.github/workflows/check-hlint.ymlto get thehlintversionstylish-haskell. See.github/workflows/stylish-haskell.ymlto get thestylish-haskellversionghc-9.6andghc-9.12