Verbose output not showing

[officialemeka]

Hi fellow researchers,

While going through the security course specifically at Debugging Fuzz sequences lesson. After writing the Handler proxy and setting up the Invariant test, I attempted to run my statefulFuzz_testInvariantBreaksHander test to show some verbose logging

forge test --mt statefulFuzz_testInvariantBreaksHandler -vvvv

This test failed, as expected, but I was looking forward to seeing some verbose outputs hinting at the reason the test failed but it did not show a trace of the output. Rather, it showed only this

Ran 1 test for test/invariant-break/handler/Invariant.t.sol:InvariantBreak
[FAIL: EvmError: Revert] constructor() (gas: 0)
Suite result: FAILED. 0 passed; 1 failed; 0 skipped; finished in 1.39ms (0.00ns CPU time)

Ran 1 test suite in 13.70ms (1.39ms CPU time): 0 tests passed, 1 failed, 0 skipped (1 total tests)

Failing tests:
Encountered 1 failing test in test/invariant-break/handler/Invariant.t.sol:InvariantBreak
[FAIL: EvmError: Revert] constructor() (gas: 0)

Encountered a total of 1 failing tests, 0 tests succeeded

After doing some self-triage as well as running foundryup several times, I couldn't seem to find a solution or cause for this. I was directed by @PatrickAlphaC to put it up here in discussion.

I look forward to the community assistance.

[EngrPips]

That is weird, as the -vvvvv verbosity command still works correctly for me.

forge test --mt testRedeemStraightAway -vvvv
[⠊] Compiling...
[⠑] Compiling 47 files with Solc 0.8.24
[⠃] Solc 0.8.24 finished in 1.70s
Compiler run successful!

Ran 1 test for test/RebaseToken.t.sol:RebaseTokenTest
[PASS] testRedeemStraightAway(uint256) (runs: 256, μ: 163231, ~: 163457)
Logs:
  false

Traces:
  [201786] RebaseTokenTest::testRedeemStraightAway(34049624636384 [3.404e13])
    ├─ [0] console::log("Bound result", 34049624636384 [3.404e13]) [staticcall]
    │   └─ ← [Stop]
    ├─ [0] VM::startPrank(user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D])
    │   └─ ← [Return]
    ├─ [0] VM::deal(user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D], 34049624636384 [3.404e13])
    │   └─ ← [Return]
    ├─ [109621] Vault::deposit{value: 34049624636384}()
    │   ├─ [2566] RebaseToken::getGlobalInterestRate() [staticcall]
    │   │   └─ ← [Return] 50000000000 [5e10]
    │   ├─ [101658] RebaseToken::mint(user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D], 34049624636384 [3.404e13], 50000000000 [5e10])
    │   │   ├─ [0] console::log("The current timestamp is: ", 1) [staticcall]
    │   │   │   └─ ← [Stop]
    │   │   ├─ [0] console::log("The last time the user claimed is: ", 0) [staticcall]
    │   │   │   └─ ← [Stop]
    │   │   ├─ emit Transfer(from: 0x0000000000000000000000000000000000000000, to: user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D], value: 0)
    │   │   ├─ emit Transfer(from: 0x0000000000000000000000000000000000000000, to: user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D], value: 34049624636384 [3.404e13])
    │   │   └─ ← [Stop]
    │   ├─ emit Vault__Deposit(_recipient: user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D], _amount: 34049624636384 [3.404e13])
    │   └─ ← [Stop]
    ├─ [4711] RebaseToken::balanceOf(user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D]) [staticcall]
    │   ├─ [0] console::log("The current timestamp is: ", 1) [staticcall]
    │   │   └─ ← [Stop]
    │   ├─ [0] console::log("The last time the user claimed is: ", 1) [staticcall]
    │   │   └─ ← [Stop]
    │   └─ ← [Return] 34049624636384 [3.404e13]
    ├─ [0] console::log("start balance is: ", 34049624636384 [3.404e13]) [staticcall]
    │   └─ ← [Stop]
    ├─ [0] VM::assertEq(34049624636384 [3.404e13], 34049624636384 [3.404e13]) [staticcall]
    │   └─ ← [Return]
    ├─ [52838] Vault::redeem(115792089237316195423570985008687907853269984665640564039457584007913129639935 [1.157e77])
    │   ├─ [4711] RebaseToken::balanceOf(user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D]) [staticcall]
    │   │   ├─ [0] console::log("The current timestamp is: ", 1) [staticcall]
    │   │   │   └─ ← [Stop]
    │   │   ├─ [0] console::log("The last time the user claimed is: ", 1) [staticcall]
    │   │   │   └─ ← [Stop]
    │   │   └─ ← [Return] 34049624636384 [3.404e13]
    │   ├─ [11579] RebaseToken::burn(user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D], 34049624636384 [3.404e13])
    │   │   ├─ [0] console::log("The current timestamp is: ", 1) [staticcall]
    │   │   │   └─ ← [Stop]
    │   │   ├─ [0] console::log("The last time the user claimed is: ", 1) [staticcall]
    │   │   │   └─ ← [Stop]
    │   │   ├─ emit Transfer(from: 0x0000000000000000000000000000000000000000, to: user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D], value: 0)
    │   │   ├─ emit Transfer(from: user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D], to: 0x0000000000000000000000000000000000000000, value: 34049624636384 [3.404e13])
    │   │   └─ ← [Stop]
    │   ├─ [0] console::log("The eth balance of this pool at this point is: ", 34049624636384 [3.404e13]) [staticcall]
    │   │   └─ ← [Stop]
    │   ├─ [0] user::fallback{value: 34049624636384}()
    │   │   └─ ← [Stop]
    │   ├─ emit Vault_Redeem(_recipient: user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D], _amount: 34049624636384 [3.404e13])
    │   └─ ← [Stop]
    ├─ [4711] RebaseToken::balanceOf(user: [0x6CA6d1e2D5347Bfab1d91e883F1915560e09129D]) [staticcall]
    │   ├─ [0] console::log("The current timestamp is: ", 1) [staticcall]
    │   │   └─ ← [Stop]
    │   ├─ [0] console::log("The last time the user claimed is: ", 1) [staticcall]
    │   │   └─ ← [Stop]
    │   └─ ← [Return] 0
    ├─ [0] VM::assertEq(0, 0) [staticcall]
    │   └─ ← [Return]
    ├─ [0] VM::assertEq(34049624636384 [3.404e13], 34049624636384 [3.404e13]) [staticcall]
    │   └─ ← [Return]
    ├─ [0] VM::stopPrank()
    │   └─ ← [Return]
    └─ ← [Stop]

Suite result: ok. 1 passed; 0 failed; 0 skipped; finished in 226.99ms (215.87ms CPU time)

Ran 1 test suite in 566.02ms (226.99ms CPU time): 1 tests passed, 0 failed, 0 skipped (1 total tests)

@PatrickAlphaC, we will appreciate your insight here, sir.