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

feat(cheatcodes): mark unmatched expectedEmits as unemitted #8686

Draft
wants to merge 2 commits into
base: master
Choose a base branch
from

Conversation

topocount
Copy link

Motivation

It can be very difficult to find a failing expectEmit when looking
as traces involving deep traces with a lot of events.

fixes #8506

Solution

If an emitted event is marked as unmatched, it can then be hilighted
as an error in red.

This is accomplished by passing the sequence index of the first event
that was expected but not emitted as a revert error, and then
finding that event during tracing and marking it as unmatched.

please see paradigmxyz/revm-inspectors#181 for
the dependent changes that allow for the actual highlighting

Copy link
Member

@klkvr klkvr left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Really like the idea! Wondering if we can also resolve #592 here by highlighting mismatched topics?

Left comments re errors enum, and I think we'd want to change event indexes tracking logic

@@ -11,6 +11,11 @@ use revm::interpreter::InstructionResult;
use rustc_hash::FxHashMap;
use std::sync::OnceLock;

pub enum VmErr {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There's no need in introducing this, sol! macro in vm.rs will produce errors enum with abi_decode methods

@@ -325,6 +325,13 @@ impl CallTraceDecoder {
pub async fn populate_traces(&self, traces: &mut Vec<CallTraceNode>) {
for node in traces {
node.trace.decoded = self.decode_function(&node.trace).await;

if let VmErr::UnemittedEventError(error_index) =
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This can be just VmErrors::abi_decode(&node.trace.output, false)

// Where the revert is set and where color mode might be
// indicated for a given event that wasn't matched
outcome.result.output = Vm::UnemittedEventError {
positionExpected: not_found.sequence + self.expected_emits_offset,
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this is incorrect as sequence only knows about events which came after expectEmit which might not always be the only events emitted during execution

I think we'd want to directly use tracing inspector indexes here, which should be possible after #8696

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

hey @topocount #8696 just got merged and CheatcodesExecutor was extended with tracing_inspector fn which provides a reference to a tracing inspector from which you can check the log indicies directly

that way sequence value can be just set to something like tracer.traces().nodes().last().expect("no trace nodes").logs.len()

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I should have time to work on this this week

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@klkvr I've added tracer.traces().nodes().last().expect("no trace nodes").logs.len() to expect_emit but still need the offset to cover an edge case where a prior call completes successfully, otherwise that prior call is erroneously highlighted red instead.

not_found.sequence holds the tracer length call from from when the expected emit payload is initially pushed onto the stack.

Copy link
Author

@topocount topocount Sep 17, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This comment is incorrect after my debugging outline below
hmm there are still edge cases that aren't satisfied by this, namely if multiple expectedEmits are added for a given call, the incorrect one (the one that is matched) is highlighted. I need to dig into this more.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

it doesn't look like this is incrementing. Is this array lazily constructed then?

that way sequence value can be just set to something like tracer.traces().nodes().last().expect("no trace nodes").logs.len()

Copy link
Author

@topocount topocount Sep 17, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Here's a debug trace where we're expecting the same event twice:

Click here
[crates/cheatcodes/src/inspector.rs:1366:17] &self.expected_emits = [
    ExpectedEmit {
        depth: 1,
        log: Some(
            LogData {
                topics: [
                    0xf6ef72180c46cadbda80997bfa03fc39b76911c9bc988da15e4a47d55d687a31,
                ],
                data: 0x00000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000005,
            },
        ),
        checks: [
            true,
            false,
            false,
            false,
            true,
        ],
        address: Some(
            0x5615deb798bb3e4dfa0139dfa1b3d433cc23b72f,
        ),
        anonymous: false,
        found: false,
        sequence: 0,
    },
    ExpectedEmit {
        depth: 1,
        log: Some(
            LogData {
                topics: [
                    0xf6ef72180c46cadbda80997bfa03fc39b76911c9bc988da15e4a47d55d687a31,
                ],
                data: 0x00000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000005,
            },
        ),
        checks: [
            true,
            false,
            false,
            false,
            true,
        ],
        address: Some(
            0x5615deb798bb3e4dfa0139dfa1b3d433cc23b72f,
        ),
        anonymous: false,
        found: true,
        sequence: 0,
    },
]

If an emitted event is marked as unmatched, it can then be hilighted
as an error in red.
@topocount topocount marked this pull request as ready for review September 17, 2024 04:27
for log in node.logs.iter_mut() {
log.decoded = self.decode_event(&log.raw_log).await;
}

if let Ok(e) = Vm::UnemittedEventError::abi_decode(&node.trace.output, false) {
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I could actually add the unmatched event name to the revert error here, if that's desirable.

@topocount topocount marked this pull request as draft September 17, 2024 05:12
@zerosnacks
Copy link
Member

Hi @topocount, would be great to get this in - let me know if you are running into any blockers / have any questions

@topocount
Copy link
Author

@zerosnacks I've been blocked here: #8686 (comment)

I could possibly sort this out by reading through the impl that isn't behaving as expected, I just haven't had time. Can probably look back into this next week

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

feat(tracing): log failed expectEmit events as error traces
3 participants