Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

bug: expectEmit and expectCall don't only check the next call #1745

Closed
2 tasks
mds1 opened this issue May 26, 2022 · 6 comments · Fixed by #4920
Closed
2 tasks

bug: expectEmit and expectCall don't only check the next call #1745

mds1 opened this issue May 26, 2022 · 6 comments · Fixed by #4920
Labels
A-cheatcodes Area: cheatcodes C-forge Command: forge Cmd-forge-test Command: forge test T-bug Type: bug
Milestone

Comments

@mds1
Copy link
Collaborator

mds1 commented May 26, 2022

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 (4fcd7e0 2022-05-26T00:08:37.693306Z)

What command(s) is the bug in?

forge test

Operating System

No response

Describe the bug

My understanding is that the expected behavior of expectEmit is "look for event in the next call" but it seems to actually be "look for expected event before the end of the test". And the docs are contradictory here—one part says it must be the "next event" (which seems to imply it needs to be the first event in the next call), another part says "before the end of the current function". Similarly issue for expectCall behavior.

To ensure tests are clear, I think expectEmit and expectCall should only look in the next call. Otherwise this can result in bugs where your event was emitted eventually in a later portion of your test, but not emitted at the time you expected it, and the test still passes.

Reproduce with this test:

// SPDX-License-Identifier: UNLICENSED
pragma solidity 0.8.13;

import "forge-std/Test.sol";

contract CallMe {
  function calling() public {}
}

contract MyContract {
  CallMe callMe;

  constructor(CallMe _callMe) {
    callMe = _callMe;
  }

  event MyEvent();
  event OtherEvent();

  function noEventOrCall() public {}

  function myEventAndCall() public {
    emit OtherEvent(); // Shows event order does not matter if only checking for MyEvent.
    emit MyEvent();
    callMe.calling();
  }
}

contract ExpectTest is Test {
  event MyEvent();
  CallMe callMe;
  MyContract myContract;

  function setUp() public {
    callMe = new CallMe();
    myContract = new MyContract(callMe);
  }

  // -------- expectEmit Tests --------

  function test_MyEvent() public {
    // Passes like expected.
    vm.expectEmit(true, true, true, true);
    emit MyEvent();
    myContract.myEventAndCall();
  }

  function test_NoEventOrCall() public {
    // Fails like expected.
    vm.expectEmit(true, true, true, true);
    emit MyEvent();
    myContract.noEventOrCall();
  }

  function test_EventuallyMyEvent() public {
    // Passes, but should fail, because expectEmit should only check the next call.
    vm.expectEmit(true, true, true, true);
    emit MyEvent();
    myContract.noEventOrCall();
    myContract.myEventAndCall();
  }

  // -------- expectCall Tests --------

  function test_Call() public {
    // Passes like expected.
    vm.expectCall(address(callMe), abi.encodeWithSelector(CallMe.calling.selector));
    myContract.myEventAndCall();
  }

  function test_NoCall() public {
    // Fails like expected.
    vm.expectCall(address(callMe), abi.encodeWithSelector(CallMe.calling.selector));
    myContract.noEventOrCall();
  }

  function test_EventuallyCall() public {
    // Passes, but should fail, because expectCall should only check the next call.
    vm.expectCall(address(callMe), abi.encodeWithSelector(CallMe.calling.selector));
    emit MyEvent();
    myContract.noEventOrCall();
    myContract.myEventAndCall();
  }
}
@mds1 mds1 added the T-bug Type: bug label May 26, 2022
@onbjerg onbjerg added this to Foundry May 26, 2022
@onbjerg onbjerg moved this to Todo in Foundry May 26, 2022
@onbjerg
Copy link
Collaborator

onbjerg commented May 27, 2022

This is documented in the book and has always been the behavior. I'm not entirely sure if we should change it, but if we should, then this is definitely a breaking change and we should try to bundle it up with other breaking changes.

image

@onbjerg onbjerg moved this from Todo to May be solved in Foundry May 27, 2022
@onbjerg onbjerg added Cmd-forge-test Command: forge test C-forge Command: forge A-cheatcodes Area: cheatcodes labels May 27, 2022
@onbjerg
Copy link
Collaborator

onbjerg commented May 27, 2022

one part says it must be the "next event" (which seems to imply it needs to be the first event in the next call), another part says "before the end of the current function".

I don't think this is contradictory, but it might lead to some confusion that could be cleared up.

Assert a specific log is emitted before the end of the current function.

This is the overall usage for expectEmit - we use it to expect that a certain log is emitted anywhere in the current test function.

It then follows up:

  1. Call the cheat code, specifying whether we should check the first, second or third topic, and the log data. Topic 0 is always checked.
  2. Emit the event we are supposed to see before the end of the current function.
  3. Perform the call.

This explains the call order: we call the cheatcode, we emit the event we expect, and then we perform a call that emits the event.

It then also goes on in an info box:

ℹ️ Ordering matters

If we call expectEmit and emit an event, then the next event emitted must match the one we expect.

This is essentially saying that if we call expectEmit, emit the event we expect and then some other part of our code emits a second event, then the second event must match the first.

@mds1
Copy link
Collaborator Author

mds1 commented May 27, 2022

I'm not entirely sure if we should change it, but if we should, then this is definitely a breaking change and we should try to bundle it up with other breaking changes.

If this is not a bug, do you know what the rationale was for this behavior originally? It feels like this provides minimal UX benefits, makes tests harder to read, and introduces greater risk of testing bugs, especially for e.g. long integration tests where the event might be emitted many txs after you declared to expect it. It also deviates from other frameworks where you specify the exact call/receipt emitting the event (see waffle (used in hardhat) and brownie).

It then also goes on in an info box:

ℹ️ Ordering matters
If we call expectEmit and emit an event, then the next event emitted must match the one we expect.

This is essentially saying that if we call expectEmit, emit the event we expect and then some other part of our code emits a second event, then the second event must match the first.

This is exactly the part of the docs that seem contradictory! 😅 Both "the next event emitted must match the one we expect" and "the second event must match the first" are not true. Ordering only matters in the sense that you must have vm.expectEmit(...); emit MyEvent(); first, and the event emission you're looking for can come any time after until the test ends. This test below passes, but I really think it should fail for the reasons above.

contract MyContract {
  event MyEvent();
  event OtherEvent();

  function noEvent() public {}

  function otherEvent() public {
    emit OtherEvent();
  }

  function myEvent() public {
    emit OtherEvent();
    emit MyEvent();
  }
}

contract ExpectTest is Test {
  event MyEvent();
  MyContract myContract;

  function setUp() public {
    myContract = new MyContract();
  }

  function test_EventuallyMyEvent() public {
    vm.expectEmit(true, true, true, true);
    emit MyEvent();
    myContract.otherEvent();
    myContract.noEvent();
    myContract.otherEvent();
    myContract.myEvent();
  }
}

@onbjerg
Copy link
Collaborator

onbjerg commented May 27, 2022

Perhaps the confusion is that it's the event data (topics + data) and not topic0 that needs to match? I.e. if I emit a MyEvent(123) and then a MyEvent(456) then it would fail since the data + topics do not match.

If this is not a bug, do you know what the rationale was for this behavior originally?

It's not a bug but I do not know the rationale, I believe expectEmit was originally added by @brockelmore so maybe he can add some insight. For expectCall I believe I was mirroring how it works in Hardhat?

@mds1
Copy link
Collaborator Author

mds1 commented May 27, 2022

From the description in the original PR (#329) it does sound like it was supposed to only work for the next call:

After the call, if the expected events are found, it continues execution. Otherwise, if the expected logs aren't found, it reverts.

It's also possible it used to fail if not found in the next call, and a subsequent PR changed that. But yea we'll see what @brockelmore says 👍

@brockelmore
Copy link
Member

Ye I believe things got switched around. I believe the reason it got changed was people seemed to like to just define a bunch of logs they expect at the beginning of the test then write the test like normal to improve readability. I.e.:

function logs() internal {
    vm.expectEmit(..);
    emit event(..);
    vm.expectEmit(..);
    emit event(..);
}

function testA() public {
    logs();
    // do normal test stuff that likely includes multiple calls & static calls
}

It may have also been because we were considering static calls in that group which was an even bigger footgun? I dont have strong preferences here, but we should filter out static calls if we change expectEmit

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-cheatcodes Area: cheatcodes C-forge Command: forge Cmd-forge-test Command: forge test T-bug Type: bug
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

3 participants