echidna icon indicating copy to clipboard operation
echidna copied to clipboard

Profiling Request: Slow fuzzing setup with conversions

Open rappie opened this issue 2 years ago • 15 comments

I have created a fuzzing setup for a Code4rena competition that turned out to be very slow. Both compile time and fuzzing speed are slow.

The code contains a lot of conversion (bytes, int, unicode) so I thought someone at ToB might be interested in profiling this.

The code can be found here: https://github.com/code-423n4/2023-03-canto-identity/tree/main/canto-namespace-protocol

Interesting conversion code:

  • https://github.com/code-423n4/2023-03-canto-identity/blob/main/canto-namespace-protocol/src/Tray.sol#L245
  • https://github.com/code-423n4/2023-03-canto-identity/blob/main/canto-namespace-protocol/src/Utils.sol#L73

The fuzzing setup repo is private but I can provide invites if necessary.

Note: The contest is over so I don't need the setup anymore. Feel free to close the issue if it's not an interesting subject to profile :smile:

rappie avatar Mar 22 '23 11:03 rappie

@rappie can you re-test with the latest version of master ? It should show how much time echidna spent in the different parts of the startup process (compilation, slither, etc).

gustavo-grieco avatar Apr 03 '23 08:04 gustavo-grieco

[2023-04-03 15:44:53.97] Compiling .... Done! (67.398573363s)
Analyzing contract: .../echidna/Echidna.sol:Echidna
[2023-04-03 15:46:01.60] Running slither on .... Done! (3.263365893s)
Loaded total of 0 transactions from echidna-corpus/reproducers
Loaded total of 0 transactions from echidna-corpus/coverage
...
AssertionFailed(..):  fuzzing (1047/100000000000)
Unique instructions: 10418
Unique codehashes: 4
Corpus size: 4
Seed: 5538361848559717460
[2023-04-03 15:48:23.10] Saving test reproducers... Done! (0.000001412s)
[2023-04-03 15:48:23.10] Saving corpus... Done! (2.654064758s)

Compilation is slow and fuzzing is slow. As you can see it took more than 2 minutes to only do ~1000 tests.

rappie avatar Apr 03 '23 13:04 rappie

Can you check coverage report to see if there the code is running out of gas in some line? that could induce a very slow fuzzing.

gustavo-grieco avatar Apr 03 '23 14:04 gustavo-grieco

As requested, I tested this with medusa. It seems to be much faster:

fuzz: elapsed: 27s, call: 133944 (4465/sec), seq/s: 44, resets/s: 0, cov: 47

rappie avatar Apr 11 '23 14:04 rappie

was this tested with a single worker or with multiple ones?

gustavo-grieco avatar Apr 11 '23 20:04 gustavo-grieco

Multiple (the default settings)

rappie avatar Apr 12 '23 08:04 rappie

Can you re-run with a single worker? It will help to get numbers that we can more easily compare.

gustavo-grieco avatar Apr 12 '23 09:04 gustavo-grieco

Creating 1 workers ...
fuzz: elapsed: 0s, call: 0 (0/sec), seq/s: 0, resets/s: 0, cov: 48
fuzz: elapsed: 3s, call: 5199 (1732/sec), seq/s: 24, resets/s: 0, cov: 48
fuzz: elapsed: 6s, call: 11873 (2224/sec), seq/s: 21, resets/s: 0, cov: 48
fuzz: elapsed: 9s, call: 18338 (2154/sec), seq/s: 21, resets/s: 0, cov: 48
fuzz: elapsed: 12s, call: 24077 (1912/sec), seq/s: 19, resets/s: 0, cov: 49
fuzz: elapsed: 15s, call: 28524 (1482/sec), seq/s: 14, resets/s: 0, cov: 49
fuzz: elapsed: 18s, call: 33158 (1544/sec), seq/s: 15, resets/s: 0, cov: 49
fuzz: elapsed: 21s, call: 37738 (1526/sec), seq/s: 15, resets/s: 0, cov: 49
fuzz: elapsed: 24s, call: 43037 (1766/sec), seq/s: 17, resets/s: 0, cov: 49
fuzz: elapsed: 27s, call: 47466 (1476/sec), seq/s: 14, resets/s: 0, cov: 50
fuzz: elapsed: 30s, call: 52150 (1560/sec), seq/s: 15, resets/s: 0, cov: 50

rappie avatar Apr 12 '23 12:04 rappie

So echidna is doing 500 tx per minute and medusa is doing 1500 * 60 txs per minute?

gustavo-grieco avatar Apr 12 '23 12:04 gustavo-grieco

Correct

rappie avatar Apr 12 '23 12:04 rappie

@arcz can you take a look?

gustavo-grieco avatar Apr 12 '23 17:04 gustavo-grieco

@rappie do you still have the testing for this? it could be useful for benchmarking

gustavo-grieco avatar May 08 '24 17:05 gustavo-grieco

Yes. I've made the repo public: https://github.com/rappie/canto-c4-fuzzing

rappie avatar May 08 '24 19:05 rappie

It seems that some dependencies are missing?

crytic-compile  .
INFO:CryticCompile:'forge clean' running (wd: canto-c4-fuzzing)
INFO:CryticCompile:'forge build --build-info' running (wd: canto-c4-fuzzing)
ERROR:CryticCompile:'forge' returned non-zero exit code 1
ERROR:CryticCompile:2024-05-08T19:53:41.597230Z ERROR foundry_compilers::artifacts: error="canto-c4-fuzzing/lib/solmate/src/tokens/ERC721.sol": No such file or directory (os error 2)
ERROR:CryticCompile:Error: 
stderr: failed to resolve file: "canto-c4-fuzzing/lib/solmate/src/tokens/ERC721.sol": No such file or directory (os error 2); check configured remappings
stderr: 	--> canto-c4-fuzzing/src/Namespace.sol
stderr: 	solmate/tokens/ERC721.sol
ERROR:CryticCompile:Compilation failed. Can you run build command?
out/build-info is not a directory.

gustavo-grieco avatar May 08 '24 19:05 gustavo-grieco

Ah, you're right. Seems like I didn't know Foundry very well yet back then :sweat_smile:

I've added the libraries now (all files, no submodules). Should work now. I've tested it, and it is indeed still very slow.

rappie avatar May 08 '24 20:05 rappie