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

fix: fuzz console log #7781

Merged
merged 4 commits into from
May 15, 2024
Merged

fix: fuzz console log #7781

merged 4 commits into from
May 15, 2024

Conversation

Azleal
Copy link
Contributor

@Azleal Azleal commented Apr 25, 2024

Motivation

**Closes #7928 #3843 **
when using fuzz test, console.log doesn't work as expected(display console log info). this PR is to fix console.log in fuzz test

Solution

current version of foundry only keep the logs for failed fuzz test case. so in this PR, added logs to keep logs in every CaseOutcome and display logs for every run case in a fuzz test.

@Azleal
Copy link
Contributor Author

Azleal commented Apr 25, 2024

I tried to figure out how to add a test as instructed here, but I didn't figure it out. appreciate if anyone could kindly point out how to add one, i'll recommit this PR. thanks

Copy link
Member

@mattsse mattsse left a comment

Choose a reason for hiding this comment

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

wdyt @grandizzy ?

@grandizzy
Copy link
Collaborator

grandizzy commented Apr 25, 2024

I tried to figure out how to add a test as instructed here, but I didn't figure it out. appreciate if anyone could kindly point out how to add one, i'll recommit this PR. thanks

I think a test for this could be done similar to https://github.com/foundry-rs/foundry/pull/7544/files#diff-815e5f4f8a07901e1a8da4960e8334a0ba54a5bbd94ce5c620a7bd24ec1f36e9R530-R578 where it basically runs forge test -vv

/// forge-config: default.fuzz.runs = 1
function testConsoleLogFromFunction(uint256 x) public {
    console.log("logging from function");
}

and then make sure it prints logs properly by checking output for

Logs:
  logging from function

sequence

@Azleal
Copy link
Contributor Author

Azleal commented Apr 26, 2024

I tried to figure out how to add a test as instructed here, but I didn't figure it out. appreciate if anyone could kindly point out how to add one, i'll recommit this PR. thanks

I think a test for this could be done similar to https://github.com/foundry-rs/foundry/pull/7544/files#diff-815e5f4f8a07901e1a8da4960e8334a0ba54a5bbd94ce5c620a7bd24ec1f36e9R530-R578 where it basically runs forge test -vv

/// forge-config: default.fuzz.runs = 1
function testConsoleLogFromFunction(uint256 x) public {
    console.log("logging from function");
}

and then make sure it prints logs properly by checking output for

Logs:
  logging from function

sequence

@grandizzy Thank you for your reference. I added a test for fuzz test console log.

@Azleal
Copy link
Contributor Author

Azleal commented Apr 29, 2024

Hi @mattsse @grandizzy , I'm wondering if my updated PR meets the requirements for testing. If not, I'd like to discuss further and make improvements. hope to see this feature included in the next release soon.

@@ -127,7 +131,9 @@ impl FuzzedExecutor {
// to run at least one more case to find a minimal failure
// case.
let call_res = _counterexample.1.result.clone();
let _logs = _counterexample.1.logs.clone();
Copy link
Collaborator

Choose a reason for hiding this comment

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

I think this can be one liner as logs.borrow_mut().extend(_counterexample.1.logs.clone());

Copy link
Contributor Author

Choose a reason for hiding this comment

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

@grandizzy thank you for pointing it out, one liner is much cleaner.

@grandizzy
Copy link
Collaborator

Hi @mattsse @grandizzy , I'm wondering if my updated PR meets the requirements for testing. If not, I'd like to discuss further and make improvements. hope to see this feature included in the next release soon.

I think that's a really cool addition, would be nice to have such for invariant tests as well, but out of the scope of this PR. @mattsse @DaniPopes pls have a look 🙏

@Azleal
Copy link
Contributor Author

Azleal commented Apr 30, 2024

Hi @mattsse @grandizzy , I'm wondering if my updated PR meets the requirements for testing. If not, I'd like to discuss further and make improvements. hope to see this feature included in the next release soon.

I think that's a really cool addition, would be nice to have such for invariant tests as well, but out of the scope of this PR. @mattsse @DaniPopes pls have a look 🙏

I'll dig into invariant tests console logging after this PR closed

@Azleal
Copy link
Contributor Author

Azleal commented May 11, 2024

Hi @mattsse @grandizzy , I'm wondering if my updated PR meets the requirements for testing. If not, I'd like to discuss further and make improvements. hope to see this feature included in the next release soon.

I think that's a really cool addition, would be nice to have such for invariant tests as well, but out of the scope of this PR. @mattsse @DaniPopes pls have a look 🙏

hi @grandizzy @mattsse @DaniPopes , it's been a while since this PR was committed. i'm using this feature by building foundry locally. and i noticed many others need this feature too. so i wonder if there's anything that i can do to push this forward? please don't hesitate to comment if anything that i can do. thanks for your time.

Copy link
Member

@mattsse mattsse left a comment

Choose a reason for hiding this comment

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

sgtm,

only have one smol nit, ptal @grandizzy

Comment on lines 154 to 155
decoded_logs: decode_console_logs(&logs.clone().into_inner()),
logs: logs.into_inner(),
Copy link
Member

Choose a reason for hiding this comment

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

this clone can be avoided by tmp converting into_inner and borrow from there.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

this clone can be avoided by tmp converting into_inner and borrow from there.

how about this? @mattsse

@grandizzy
Copy link
Collaborator

lgtm, pls address the nit above

@grandizzy grandizzy merged commit a470d63 into foundry-rs:master May 15, 2024
19 checks passed
@Azleal Azleal deleted the fix-fuzz-console branch May 15, 2024 15:04
@j-vp
Copy link

j-vp commented May 16, 2024

I believe this commit causes the more verbose test runs to have extremely large outputs, especially on high-fuzz github actions (ie: 2000 runs, 500 tests, 2-3 bounds/test = a lot of logging).

Even on local tests, using -vvv to get failing test traces, this now becomes unworkable. Example: https://github.com/arcadia-finance/accounts-v2/actions/runs/9116420829/job/25065457315?pr=209

@grandizzy
Copy link
Collaborator

that's correct, it is because bounds are logged in forge std
https://github.com/foundry-rs/forge-std/blob/d44c4fbbb9ff054fb334babbdd34f9b6e899b3d6/src/StdUtils.sol#L62
https://github.com/foundry-rs/forge-std/blob/d44c4fbbb9ff054fb334babbdd34f9b6e899b3d6/src/StdUtils.sol#L87

@mattsse I am going to revert this commit for now as it looks it needs some more work
@mds1 do you know any reason for Result bound to be logged in forge-std while others are not?

grandizzy added a commit to grandizzy/foundry that referenced this pull request May 16, 2024
mattsse pushed a commit that referenced this pull request May 16, 2024
@mds1
Copy link
Collaborator

mds1 commented May 16, 2024

So this PR now print console logs for every iteration of a fuzz set? I think previously we only printed them for the last successful run? Printing for every run feels extremely noisy

But the reason we log the bound result is to make debugging failed fuzz tests easier to reason about, and to simplify creating test cases to reproduce the failure with

@grandizzy
Copy link
Collaborator

So this PR now print console logs for every iteration of a fuzz set? I think previously we only printed them for the last successful run? Printing for every run feels extremely noisy

But the reason we log the bound result is to make debugging failed fuzz tests easier to reason about, and to simplify creating test cases to reproduce the failure with

gotcha, we have to re evaluate the proper way to implement such to avoid all the noise

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.

Logs are not displayed when for functions that take fuzzing varilables
5 participants