Invariant test called twice

[0xTimepunk]

Component

Forge

Have you ensured that all of these are up to date?

• Foundry
• Foundryup

What version of Foundry are you on?

forge 0.2.0 (e0722a1 2023-10-10T00:28:23.851012000Z)

What command(s) is the bug in?

forge test

Operating System

macOS (Apple Silicon)

Describe the bug

A foundry invariant test assertion reverts and is called twice in a row in a setup with multiple runs and multiple depth. From the sequence printed its not useful to decipher what's going on

foundry.toml looks like this:

[invariant]
runs = 20
depth = 5 # “Calls” refer to the number of times functions in the smart contract are called during a single test run. “Reverts” refers to the number of times a call to any function within the smart contract resulted in a transaction being reverted due to an error or exception.
fail_on_revert = true
call_override = false

The test looks like this:

    function invariant_vaultShares() public useCurrentTimestamp {
        assertEq(vaultSharesStore.superPositionsSum(), vaultSharesStore.vaultShares());
    }

SuperPositionsSum and VaultShares are set at the end of each function call in our handler in a specific store (vaultSharesStore).

  [24210] VaultSharesInvariantTest::invariant_vaultShares()
    ├─ [0] VM::selectFork(0)
    │   └─ ← ()
    ├─ [2407] TimestampStore::currentTimestamp() [staticcall]
    │   └─ ← 1694186515 [1.694e9]
    ├─ [0] VM::warp(1694186515 [1.694e9])
    │   └─ ← ()
    ├─ [2429] VaultSharesStore::superPositionsSum() [staticcall]
    │   └─ ← 2149673676847473860205 [2.149e21]
    ├─ [2495] VaultSharesStore::vaultShares() [staticcall]
    │   └─ ← 2149673676847473860205 [2.149e21]
    └─ ← ()

  [37972] VaultSharesInvariantTest::invariant_vaultShares()
    ├─ [0] VM::selectFork(0)
    │   └─ ← ()
    ├─ [2407] TimestampStore::currentTimestamp() [staticcall]
    │   └─ ← 1694186515 [1.694e9]
    ├─ [0] VM::warp(1694186515 [1.694e9])
    │   └─ ← ()
    ├─ [2429] VaultSharesStore::superPositionsSum() [staticcall]
    │   └─ ← 1103485652139861249137 [1.103e21]
    ├─ [2495] VaultSharesStore::vaultShares() [staticcall]
    │   └─ ← 2149673676847473860205 [2.149e21]
    ├─ emit log(: Error: a == b not satisfied [uint])
    ├─ emit log_named_uint(key:       Left, val: 1103485652139861249137 [1.103e21])
    ├─ emit log_named_uint(key:      Right, val: 2149673676847473860205 [2.149e21])
    ├─ [0] VM::store(VM: [0x7109709ECfa91a80626fF3989D68f67F5b1DD12D], 0x6661696c65640000000000000000000000000000000000000000000000000000, 0x0000000000000000000000000000000000000000000000000000000000000001)
    │   └─ ← ()
    └─ ← ()

I can't seem to understand this behaviour, but I noticed that instruction [24210] appears multiple times in the different calls that are successful, but only in the last one (where the call sequence reverts) there is a 2nd instruction [37972] (repeated??)

I noticed as well that the values I am asserting change between these two calls even though nothing happens between them. Is foundry doing something under the hood on these values that is not being logged?

Why are two invariant tests called like that in a row?

[0xTimepunk]

@Evalir @gakonst @mattsse any chance or thoughts?

[77abe77]

Im seeing this exact issue for a project Ive been working on as well. I basically inspect the state consecutively where there should be no change and for some reason the state gets corrupted similar to what your logs show.

[0xTimepunk]

Im seeing this exact issue for a project Ive been working on as well. I basically inspect the state consecutively where there should be no change and for some reason the state gets corrupted similar to what your logs show.

@Evalir I'm sorry to tag you again, but it's been a week and this impacts our invariant testing severely (cannot proceed).

It's great to see other people are experiencing the same thing, although it's hard to reproduce.

For this reason, and because we are advancing in our development cycle, we will soon open source our repo so this issue will be made public and it will be easier for you guys to verify what's going on.

It's a cross-chain protocol, so there's a lot of fork switching going on