Analyze speed deterioration of v4

[holgerd77]

On v4 speed of commit() has substantially deteriorated, @s1na suspects this commit c315566 as the cause.

This need some investigation and fix.

A release on this would be a prerequisite for the VM v5 release ethereumjs/ethereumjs-monorepo#681

[holgerd77]

Ok, did some first further analysis here with the MPT benchmarks and couldn't find any signification deterioration on first run.

First run on current master with npm run build && ts-node benchmarks/index.ts, results on my local PC:

1. Run
benchmarks/random.ts | rounds: 1000, ERA_SIZE: 1000, sys: 799.467ms
benchmarks/checkpointing.ts | average execution time: 0s 206.067ms

2. Run
benchmarks/random.ts | rounds: 1000, ERA_SIZE: 1000, sys: 835.272ms
benchmarks/checkpointing.ts | average execution time: 0s 199.895ms

3. Run
benchmarks/random.ts | rounds: 1000, ERA_SIZE: 1000, sys: 849.828ms
benchmarks/checkpointing.ts | average execution time: 0s 204.285ms

I then checkout the commit mentioned above with git checkout c3155665c19b5106991cd708137d7d8272e5d13f, reinstalled dependencies with npm i, had to manually install a missing dependency npm i semaphore-async-await.

I then copied over the benchmarks folder from master to benchmarks-new (did the older-version runs in a copy of the repo) to have some unified benchmark code basis for comparison and then ran npm run build && ts-node benchmarks-new/index.ts, following results:

1. Run
benchmarks/random.ts | rounds: 1000, ERA_SIZE: 1000, sys: 1094.841ms
benchmarks/checkpointing.ts | average execution time: 0.05s 197.308ms

2. Run
benchmarks/random.ts | rounds: 1000, ERA_SIZE: 1000, sys: 871.622ms
benchmarks/checkpointing.ts | average execution time: 0s 219.057ms

3. Run
benchmarks/random.ts | rounds: 1000, ERA_SIZE: 1000, sys: 958.409ms
benchmarks/checkpointing.ts | average execution time: 0s 251.631ms

On a third round I checked out the commit mentioned as parent commit of c315566 by GitHub with git checkout git checkout 029b5fe`, results:

1. Run
benchmarks/random.ts | rounds: 1000, ERA_SIZE: 1000, sys: 955.015ms
benchmarks/checkpointing.ts | average execution time: 0s 227.782ms

2. Run
benchmarks/random.ts | rounds: 1000, ERA_SIZE: 1000, sys: 853.373ms
benchmarks/checkpointing.ts | average execution time: 0s 255.643ms

3. Run
benchmarks/random.ts | rounds: 1000, ERA_SIZE: 1000, sys: 860.376ms
benchmarks/checkpointing.ts | average execution time: 0s 209.612ms

So everything is pretty comparable here, no great deterioration or deviation recognizable.

//cc @s1na

[holgerd77]

I now added a trie.commit() (since this was not executed and at the same time commit() is suspected to do the speed deterioration) to benchmarks/checkpointing.ts:

for (let i = 0; i < numOfIter; i++) {
      await trie.put(vals[i], keys[i])
      trie.checkpoint()
      await trie.get(Buffer.from('test'))
      trie.commit()
      numOfOps++
      if (numOfOps === numOfIter) {
        const hrend = process.hrtime(hrstart)
        resolve(hrend)
      }
    }

also adopted to 50 iterations and 10 samples, since runs were so slow, results:

c315566 :

1. Run
benchmarks/checkpointing.ts | average execution time: 0s 203.428ms

2. Run
benchmarks/checkpointing.ts | average execution time: 0s 211.407ms

3. Run
benchmarks/checkpointing.ts | average execution time: 0s 211.639ms

On c315566 :

1. Run
benchmarks/checkpointing.ts | average execution time: 0s 208.688ms

2. Run
benchmarks/checkpointing.ts | average execution time: 0s 216.011ms

3. Run
benchmarks/checkpointing.ts | average execution time: 0s 210.697ms

@s1na Where/how did you actually detect this speed deterioration? Is this reproduceable? 🤔

[s1na]

@holgerd77 My set-up was a bit twisted.

I had 2 clones of the VM:

1. VM's master branch which included the most recent MPT release to run the benchmarks
2. Compared that to the VM at commit ethereumjs/ethereumjs-monorepo@b6beae4 which is right before this PR Update merkle-patricia-tree to v4, move account trie-related methods to StateManager ethereumjs-monorepo#787 was merged.

Then I had a clone of MPT and was checking previous commits to see which one caused the slowdown. So what I did was revert to those commits and then publish that commit (with a new version number) to verdaccio and then used that version in the VM.

Looking now I had a second script for only testing insertions and checkpoint/commit flow. Posting it as a gist here.

[ryanio]

@holgerd77 I noticed in #124 (comment) you would have to await the commit. I am wondering though, is there a reason to do the checkpoint after the put? I would think one would want to do checkpoint -> put -> commit

[holgerd77]

@ryanio ah no, sorry for the confusion, the put -> checkpoint order was just there and I didn't have a close-enough look and just added the commit afterwards. You are right, checkpoint -> put -> commit makes more sense.

[holgerd77]

Nothing found on further investigation, will close. Work on MPT performance will continue and new dedicated issues can be opened along this work.