goevmlab icon indicating copy to clipboard operation
goevmlab copied to clipboard
verified publisher icon holiman

`revme` performance regression

Open holiman opened this issue 1 year ago • 4 comments

For some reason, revm is super slow now, 10x slower than it used to be.

INFO [06-05|11:19:12.946] Stats gethbatch-0                        execSpeed=32.7ms  longest=440.665257ms count=935
INFO [06-05|11:19:12.946] Stats eelsbatch-0                        execSpeed=950.5ms longest=6.400992834s count=35
INFO [06-05|11:19:12.946] Stats nethbatch-0                        execSpeed=36.8ms  longest=2.215896613s count=815
INFO [06-05|11:19:12.946] Stats besubatch-0                        execSpeed=26.8ms  longest=2.438839096s count=909
INFO [06-05|11:19:12.946] Stats erigonbatch-0                      execSpeed=64.8ms  longest=3.793626718s count=402
INFO [06-05|11:19:12.946] Stats nimbus-0                           execSpeed=336.4ms longest=2.510137747s count=108
INFO [06-05|11:19:12.946] Stats evmone-0                           execSpeed=48.6ms  longest=1.495841309s count=872
INFO [06-05|11:19:12.946] Stats revm-0                             execSpeed=587.7ms longest=3.731686224s count=67

cc @rakita

holiman avatar Jun 05 '24 11:06 holiman

Did you build it in release? We are checking with valgrind for perf degredations: https://github.com/bluealloy/revm/pull/1467#issuecomment-2140860061

rakita avatar Jun 05 '24 11:06 rakita

@holiman did you have time to test this?

rakita avatar Jun 11 '24 15:06 rakita

This is how I build it: https://github.com/holiman/goevmlab/blob/master/docker/Dockerfile#L96

The regression might not be "evm gas per second", might just be an added few milliseconds during startup

namiloh avatar Jun 11 '24 16:06 namiloh

This is still happening, even after #164. Case in point, during 20hours of fuzzing revme executed 150K tests, neth, geth and besu did 1.5M each.

INFO [07-10|08:18:23.774] Executing                                tests=3,037,180 time=20h0m40.006s    test/s=42.2 "avg steps"=2362.3  globa
l=3,037,180
INFO [07-10|08:18:23.774] Stats gethbatch-0                        execSpeed=27.4ms  longest=13.62003604s    count=1,512,544
INFO [07-10|08:18:23.774] Stats nethbatch-0                        execSpeed=42.4ms  longest=15.049601233s   count=1,501,076
INFO [07-10|08:18:23.774] Stats besubatch-0                        execSpeed=36.3ms  longest=14.283025827s   count=1,580,720
INFO [07-10|08:18:23.774] Stats erigonbatch-0                      execSpeed=92.4ms  longest=16.435428931s   count=874,354                   
INFO [07-10|08:18:23.774] Stats nimbus-0                           execSpeed=144.2ms longest=1m40.614011541s count=454,912
INFO [07-10|08:18:23.774] Stats revm-0                             execSpeed=266.5ms longest=1m29.401637475s count=150,756

holiman avatar Jul 10 '24 09:07 holiman

@holiman is this still the case?

I think it was a problem with bytecode analysis that was not cached

rakita avatar Jan 14 '25 12:01 rakita

Afaik this is fixed, yes. I'll reopen if that's not the case

holiman avatar Jan 14 '25 13:01 holiman

Well, seems to be pretty slow still. 965 versus nearly 5K for besu (though to be fair: besu in batch-mode, so not starting/stopping the jvm) and evmone. But it's not as bad as nimbus.

INFO [01-14|16:50:09.986] Stats gethbatch-0                        execSpeed=47.5ms  longest=748.232624ms count=3599
INFO [01-14|16:50:09.986] Stats eelsbatch-0                        execSpeed=287.2ms longest=2.851300387s count=758
INFO [01-14|16:50:09.986] Stats nethbatch-0                        execSpeed=33ms    longest=612.234769ms count=3935
INFO [01-14|16:50:09.986] Stats besubatch-0                        execSpeed=20.2ms  longest=1.25910473s  count=4673
INFO [01-14|16:50:09.986] Stats erigonbatch-0                      execSpeed=32.4ms  longest=1.631289184s count=4096
INFO [01-14|16:50:09.986] Stats nimbus-0                           execSpeed=1.9586s longest=2.485122237s count=81
INFO [01-14|16:50:09.986] Stats evmone-0                           execSpeed=23.8ms  longest=347.386774ms count=4706
INFO [01-14|16:50:09.986] Stats revm-0                             execSpeed=104.1ms longest=2.241833214s count=965

holiman avatar Jan 14 '25 16:01 holiman

hm, would you happen to have a statetest json that I can use to bench?

rakita avatar Jan 14 '25 18:01 rakita

Rebuilt today

INFO [01-31|15:20:18.867] Stats gethbatch-0                        execSpeed=24.7ms  longest=269.163453ms count=1420
INFO [01-31|15:20:18.867] Stats eelsbatch-0                        execSpeed=286.9ms longest=2.736520433s count=118
INFO [01-31|15:20:18.867] Stats nethbatch-0                        execSpeed=69.2ms  longest=895.171084ms count=461
INFO [01-31|15:20:18.867] Stats besubatch-0                        execSpeed=15.7ms  longest=1.249022644s count=1495
INFO [01-31|15:20:18.867] Stats erigonbatch-0                      execSpeed=63.7ms  longest=1.731526966s count=746
INFO [01-31|15:20:18.867] Stats nimbus-0                           execSpeed=1.8717s longest=2.71826434s  count=19
INFO [01-31|15:20:18.867] Stats evmone-0                           execSpeed=17.2ms  longest=230.537372ms count=1500
INFO [01-31|15:20:18.867] Stats revm-0                             execSpeed=20.5ms  longest=419.680005ms count=1455

Now it seems to be fast again 🤷 Well done, I guess!

holiman avatar Jan 31 '25 15:01 holiman

This PR fixed the writing: https://github.com/bluealloy/revm/pull/2033

rakita avatar Feb 06 '25 21:02 rakita