Worker call and gas counters reset to zero when a fuzz worker hits --timeout
- Dominant language
- Haskell
- Stars
- 3.2k
- Forks
- 432
- Avg merge
- 1d 20h
- Merged PRs (30d)
- 5
Description
### Describe the issue:
When a fuzz worker stops because the campaign time limit was reached, and at least one test still needs shrinking, the final report claims `Total calls: 0` no matter how many calls the campaign actually made. The status line drops to `fuzzing: 0/` and the gas rate goes negative.
Only the reporting is wrong — findings, corpus and coverage are all correct.
**Root cause**
`spawnWorker` gives each worker a single `stateRef` (`lib/Echidna/UI.hs:249`), and that ref is the only channel through which a worker's `WorkerState` reaches the reporting layer — `workerStates` just reads it back (`lib/Echidna/UI.hs:287-288`). The worker publishes into it through the callback `get >>= writeIORef stateRef` (`lib/Echidna/UI.hs:259`).
When a fuzz worker stops on `TimeLimitReached` with tests still needing shrinking, a second, shrink-only worker run is started outside the timeout (`lib/Echidna/UI.hs:276-278`, added for #839) — and it is handed **the same `stateRef`**:
```haskell
when (any needsShrinking tests) $ void $
runReaderT (runWorker FuzzWorker (get >>= writeIORef stateRef)
vm dict workerId [] 0 cliSelectedContract) env
```
`runFuzzWorker` unconditionally builds a fresh `initialState` (`lib/Echidna/Campaign.hs:339-347`) with `ncalls = 0`, `ncallseqs = 0`, `totalGas = 0`, `newCoverage = False` and the pristine `dict`. The first thing that run does inside `runStateT` is `lift callback` (`lib/Echidna/Campaign.hs:351`), *before* any shrinking happens — so the zeroed state is written straight over the accumulated one, and every later reader sees zeros:
- `ppTotalCalls` (`lib/Echidna/UI/Report.hs:52-55`) → `Total calls: 0`
- `statusLine` (`lib/Echidna/UI.hs:431-438`) → `fuzzing: 0/N`; and since `deltaGas = totalGas - gasTracker.totalGasConsumed`, the reset makes the delta negative, hence the negative `gas/s`
- the TUI's `Total calls` and gas rate (`lib/Echidna/UI/Widgets.hs:199`, `:273-276`)
**Scope**
Triggers when both hold, so it is easy to hit with any `--timeout`/`timeout:` run that finds something:
1. a fuzz worker stops with `TimeLimitReached`, and
2. at least one test still needs shrinking at that moment.
Confirmed **not** affected:
- Findings and exit code — tests live in `env.testRefs`, not `WorkerState`.
- Corpus and coverage — also `Env` refs.
- `Seed:` — `ppSeed` reads `genDict.defSeed`, which the second run recomputes identically.
- Shrinking quality, despite the `genDict` reset: `shrinkTest` is `(MonadIO, MonadThrow, MonadRandom, MonadReader Env)` with no `MonadState` constraint, and `updateTests` never touches the state, so the worker's dictionary never reaches the shrinker.
**Expected behaviour**
`Total calls:` should report the calls the campaign made, the status line should keep its count, and the gas rate should never be negative.
**Suggested fix**
Stop the shrink-only pass from publishing into the ref the campaign reports from — e.g. hand it a throwaway `IORef`, since nothing needs its live state once the campaign is over. Alternatively, seed the second run with the state the first one finished with so the counters keep accumulating across both.
### Code example to reproduce the issue:
Any contract with a falsifiable property works. Using `tests/solidity/basic/flags.sol` from this repo:
```solidity
contract Test {
event Flag(bool);
bool private flag0 = true;
bool private flag1 = true;
function set0(int val) public returns (bool){
if (val % 100 == 0)
flag0 = false;
}
function set1(int val) public returns (bool){
if (val % 10 == 0 && !flag0)
flag1 = false;
}
function echidna_alwaystrue() public returns (bool){
return(true);
}
function echidna_revert_always() public returns (bool){
revert();
}
function echidna_sometimesfalse() public returns (bool){
emit Flag(flag0);
emit Flag(flag1);
return(flag1);
}
}
```
Run it with a time limit short enough that shrinking is still outstanding when it fires:
```
echidna basic/flags.sol --format text --test-limit 100000000 --timeout 5 --workers 2
```
### Version:
```
Echidna 2.3.3 (built from master at 2bfa64ef)
slither 0.11.3
```
macOS (aarch64), GHC 9.8.4. Reproduces with both `--format text` and the interactive TUI.
### Relevant log output:
```shell
[19:07:29.90] [status] tests: 1/3, fuzzing: 67593/100000000, values: [], cov: 404, corpus: 3, gas/s: 500363892
[19:07:31.90] [Worker 0] Time limit reached. Stopping.
[19:07:31.90] [Worker 1] Time limit reached. Stopping.
[19:07:31.90] [status] tests: 1/3, fuzzing: 0/100000000, values: [], cov: 404, corpus: 3, gas/s: -750545838
echidna_sometimesfalse: failed!💥
Reason: ReturnFalse
Call sequence:
Test.set0(0)
Test.set1(0)
echidna_alwaystrue: passing
echidna_revert_always: passing
Unique instructions: 404
Unique codehashes: 1
Corpus size: 3
Seed: 8331856644448189321
Total calls: 0
```
Note the last status line before the summary: the call count drops from 67593 to 0, and `gas/s` is negative.
Contributor guide
Research direction
Start in lib/Echidna/UI.hs at spawnWorker, workerStates, and the shrink-only run around lines 276-278, then inspect runFuzzWorker and initialState in lib/Echidna/Campaign.hs. Check how the callback updates WorkerState and how lib/Echidna/UI/Report.hs and lib/Echidna/UI/Widgets.hs read counters. Reproduce with tests/solidity/basic/flags.sol and the provided timeout command; done means calls remain nonzero and gas/s is not negative after shrinking.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- haskell, solidity
- Domain
- security, testing
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Quiet
- Clarity
- Clearly specified
- Newbie friendliness
- 76/100