revme performance regression

[holiman]

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

[rakita]

Did you build it in release? We are checking with valgrind for perf degredations: bluealloy/revm#1467 (comment)

[rakita]

@holiman did you have time to test this?

[namiloh]

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

[holiman]

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

[rakita]

@holiman is this still the case?

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

[holiman]

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

[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

[rakita]

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

[holiman]

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!

[rakita]

This PR fixed the writing: bluealloy/revm#2033