Implement JMH benchmark for support process instance creation on larger state

[Zelldon]

related to #12033

Description

In the POC for determining whether the found issues can help us to resolve the issue, I created a simple unit test which also showed us the performance regression on a unit test level.

The test is on a branch, you had to run it in a loop to see the performance differences, to allow jit kick in, etc.

Ideally, we have a JMH benchmark which allows verifying the performance of new process instance creations when we have a larger state or have a similar setup (maybe with decreasing the size of RocksDB which mimics the large state scenarios).

Later, we should think about how we can automate such JMH benchmarks, to avoid regressions. For the first iteration, it should be enough to build such a JMH setup and use it to validate certain changes we plan with #12033

Resources:

• integrate JMH with unit tests
• all POC changes in order to resolve the large state issue
• running jmh from eclipse
• idea jmh plugin pretty cool to easily run the jmh benchmark

[Zelldon]

🧪 Small breakthrough on the performance test site. I was able to write a JMH benchmark, which I want to use to test the improvements. I have run with the base (no state) and one with a big state to see the differences.

We can see that base (as expected) is ~3-4 times faster than with bigger state. I will try to play around with the rocksdb config to easier reproduce the big state test, without having the big state in the repo (as resources).

  // BASE
  //  Result "io.camunda.zeebe.engine.perf.EnginePerformanceTest.measureProcessExecutionTime":
  //      0.370 ±(99.9%) 0.029 ops/ms [Average]
  //      (min, avg, max) = (0.088, 0.370, 0.670), stdev = 0.125
  //  CI (99.9%): [0.340, 0.399] (assumes normal distribution)
  //
  //  # Run complete. Total time: 00:00:04
  //
  //  Benchmark                                           Mode  Cnt  Score   Error   Units
  //  EnginePerformanceTest.measureProcessExecutionTime  thrpt  200  0.370 ± 0.029  ops/ms
  //
  //  Process finished with exit code 0

  //  BIG STATE
  //  Result "io.camunda.zeebe.engine.perf.EnginePerformanceTest.measureProcessExecutionTime":
  //      0.093 ±(99.9%) 0.003 ops/ms [Average]
  //      (min, avg, max) = (0.051, 0.093, 0.117), stdev = 0.014
  //  CI (99.9%): [0.090, 0.097] (assumes normal distribution)
  //  # Run complete. Total time: 00:00:05
  //  Benchmark                                           Mode  Cnt  Score   Error   Units
  //  EnginePerformanceTest.measureProcessExecutionTime  thrpt  200  0.093 ± 0.003  ops/ms

Related branch https://github.com/camunda/zeebe/tree/zell-performance-test-engine

[Zelldon]

I merged fixes branch into the branch with the JMH benchmark to see what difference it makes with the large state snapshot.

// fixes
//  Result "io.camunda.zeebe.engine.perf.EnginePerformanceTest.measureProcessExecutionTime":
//      0.417 ±(99.9%) 0.035 ops/ms [Average]
//      (min, avg, max) = (0.081, 0.417, 0.768), stdev = 0.146
//  CI (99.9%): [0.383, 0.452] (assumes normal distribution)
//
//
//      # Run complete. Total time: 00:00:04
//
//  Benchmark                                           Mode  Cnt  Score   Error   Units
//  EnginePerformanceTest.measureProcessExecutionTime  thrpt  200  0.417 ± 0.035  ops/ms
//

Looks pretty good, as we also have seen in our performance hack day 🙂 👍

I will try now whether I can reproduce the slow performance with a smaller RocksDB config, instead of having a large state in the repo. 😅

[Zelldon]

🔧 Benchmark Improvements

I have changed the output time unit to seconds to make the results more representative. Also, the timeUnit for the test runs has been changed to seconds, which means it tries to run as many operations as possible in one second. Furthermore, I increased the iterations for warmup and benchmark measurement (100 & 200). This means we will already build up a lot of states in the warm-up phase, which shows based on our results of base already that the throughput drastically decreases.

The Base result now looks like this (with default configs):

INFO  io.camunda.zeebe.engine.perf - Started 10720 process instances

Result "io.camunda.zeebe.engine.perf.EnginePerformanceTest.measureProcessExecutionTime":
  20.182 ±(99.9%) 0.868 ops/s [Average]
  (min, avg, max) = (12.536, 20.182, 29.170), stdev = 3.674
  CI (99.9%): [19.314, 21.050] (assumes normal distribution)


# Run complete. Total time: 00:05:15

Benchmark                                           Mode  Cnt   Score   Error  Units
EnginePerformanceTest.measureProcessExecutionTime  thrpt  200  20.182 ± 0.868  ops/s

This means we can on average start ~20 PI per second, in the benchmark output we can see that it actually starts strong with ~370 PI/s but it drops quite fast.

The idea and goal are, even if we have a longer warm-up phase or big state to start with the operations count per second (throughput shouldn't decrease), which is right now the case.

🕵️ Changing config

After reducing the RocksDB memory size:

    // enable consistency checks for tests - this is enabled in our benchmarks as well
    final var consistencyChecks = new ConsistencyChecksSettings(true, true);
    final var zbFactory =
        new ZeebeRocksDbFactory<ZbColumnFamilies>(
            new RocksDbConfiguration().setMemoryLimit(5 * 1024), consistencyChecks);
    streamProcessingComposite =
        new StreamProcessingComposite(testStreams, 1, zbFactory, actorScheduler);

We can see as a result the performance dropped in the same way as it did before with more iterations (in the benchmark we had also high iteration count). BTW I have played before just with the configuration, without changing the iteration and got an similar effect.

Result "io.camunda.zeebe.engine.perf.EnginePerformanceTest.measureProcessExecutionTime":
  20.099 ±(99.9%) 0.784 ops/s [Average]
  (min, avg, max) = (13.999, 20.099, 28.292), stdev = 3.319
  CI (99.9%): [19.315, 20.883] (assumes normal distribution)


# Run complete. Total time: 00:05:15

Benchmark                                           Mode  Cnt   Score   Error  Units
EnginePerformanceTest.measureProcessExecutionTime  thrpt  200  20.099 ± 0.784  ops/s

I think the base benchmark is enough for now since we already have seen with many iterations that the throughput goes down. We can start with the first increment of changes and improvements and validate this with the JMH benchmarks, but of course also with our normal Zeebe benchmarks.

Later if we a confident we found several solutions which make the base look good/well, we can play around again with starting direct with bigger state and/or different configs, which should have a negligible effect.

[Zelldon]

Since I have changed the configs of the JMH recently I have rerun the previous benchmark with the state fixes. Furthermore, I pushed the JMH with the fixes to a separate branch here, to rerun it later.

What is interesting is that we would expect much better performance with our POC, we can see that it improved by ~1.5 but still the drop of performance over time is still significant. Either we need to adjust/reevaluate our benchmark or also check again the POC changes again with our other zeebe cluster benchmark were we started endless instances.

I looked into this and found out that the RecordingExporter was an issue, I reset it now after every run, and this no longer slows the benchmark down. This also shows again that the POC changes perform pretty good.

---

I will update this comment continuously in order to reflect our progress and how the changes affect performance.

Test	Mode	Count	Score	Error rate	Units
Base	thrpt	200	230.023	± 26.432	ops/s
POC	thrpt	200	540.681	± 103.742	ops/s
Blacklist fix	thrpt	200	227.188	± 19.717	ops/s
Disable consistency check (base)	thrpt	200	442.961	± 27.054	ops/s
Cache static process version	thrpt	200	249.552	± 45.303	ops/s
POC: Cache key generator values	thrpt	200	251.027	± 55.103	ops/s
Increase fixed prefix extractor	thrpt	200	552.536	± 89.015	ops/s
Introduce SST partitioning	thrpt	200	656.639	± 91.394	ops/s
POC: Enhance CF prefix check	thrpt	200	223.584	± 2.052	ops/s
POC: Introduce Key Formats	thrpt	200	227.234	± 15.272	ops/s
POC: Zeebe db cache	thrpt	200	225.579	± 2.684	ops/s
POC: Zeebe db cache + disable consistency checks	thrpt	200	442.611	± 15.342	ops/s
POC: Create additional CF	thrpt	200	681.872	± 77.924	ops/s

[Zelldon]

With the JMH tests running in Intellij, I'm also able to run the async profiler inside the IDE.

This allowed me to give some more insights into what might be pressing and potential issues to fix.

For example, we can see that seek is a big part of the equation and that we check for existence where it might be not necessary yet.

This brings again up the topic of rearranging data for better operability. Like if we would prefix most keys, for example of variables with the scope key, we could do a range delete instead of iterating over the column family.

---

Update: Without consistency check it becomes even more obvious.

To note in the benchmarks we don't use any variables.

[Zelldon]

Just to document what I have discussed with @oleschoenburg

Notes:

• it is important that the test all run with the same set up (same large state)
• We lean to recreate the state in the JMH setup code, because:
  • makes it less complex, if we have a pre-built state we need to resolve where to store, how to receive etc.
  • state creation allows to always have a compatible state
  • makes variation simpler
  • We will create state in setup code, not via warm-up to guarantee to always have the same setting and same large state e.g. same amount of instances
• JUNIT
  • test should stay in Engine module, but extra naming (like randomise tests), this way performance test run only once via ci
  • Integrate in CI but extra job, to give own resources etc
  • If possible verify whether junit test can be excluded from intellij, so it just run via maven profile, so it is not executed by accident when run all tests in intellij
  • Setup the unit test similar to
    https://www.retit.de/continuous-benchmarking-with-jmh-and-junit-2/
    Last run
    Iteration 200: 11:17:20.385 [] INFO io.camunda.zeebe.engine.perf - Started 227176 process instances
    Result "io.camunda.zeebe.engine.perf.EnginePerformanceTest.measureProcessExecutionTime":
    615.279 ±(99.9%) 28.398 ops/s [Average]
    (min, avg, max) = (322.794, 615.279, 945.527), stdev = 120.239
    CI (99.9%): [586.881, 643.677] (assumes normal distribution)
    Current:
    https://camunda.slack.com/archives/D02MKQEC30D/p1686662505116359

Next steps

• Move creating state in setup code
• Clean up code
• Create junit test which executed benchmark
• Ignore for intellij, exclude for junit, define new pattern to run as separate ci job
• Create ci job
• Run as separate ci job

[Zelldon]

With #13135 we added a unit test which allows us to integrate the JMH benchmark in our CI and run it everytime when our CI runs.

I would mark this issue as resolved then.