Short jBPM Performance Showdown

I got quite some reactions on the performance numbers in my last post about jBPM. Since I couldn’t provide source code at that moment, I understand the disbelief of some people (I would react the same). So, it’s time now to show some code and prove the numbers I stated in my previous post.

To test the performance of jBPM, I’ve create a “jBPM performance test”. You can download the executable jar here. The source code is contained in the jar, for those that are interested.

When executing the jar, the main method of the JbpmPerformanceShowndown class is executed. In this method, the jBPM processes are deployed. These processes are loaded and configured using a simple Spring configuration (and, off course with some more XML ;-). Two command line arguments need to be suplied when running the jar: a number of iterations and a configuration number (see later):

“java -jar JbpmPerformanceShowdown.jar 2500 1”

Every iteration, a random process is chosen, started and signalled. When all the iterations are finished, the total time, average time/process and the number of processes/hour are calculated and shown.

The following processes are used in the performance test:

Process 1:

After the start of the process, seven custom actions are executed using the custom node construct. This process doesn’t halt in any node. Every action is a different ActionHandler class, whose only logic is a signal() call to continue the process (so no custom overhead is introduced).

Process 2:

This process tests a basic fork/join

Process 3:

This process tests a complex fork/join construction (large fork, containing a smaller fork/join) with a lot of actions

Process 4:

This process tests the use of a process variable (set in the action after the start node), and a decision based on that variable. The decision is implemented by evaluating an expression on the transitions (using the condition construct, so no DecisionHandler is used)

Process 5:

This process uses a wait state. When arriving in the waitstate, the process will wait until a trigger from an external entity is received. Before continuing, a process variable must be set by this entity, so that the decision can be done using this variable. This time, a custom DecisionHandler is used instead of expressions on the transitions.

Process 6:

This process acts as a trigger for the waitstate of process 5. After the trigger action, a task is created for the actor “Joe”. In this test, “Joe” is implemented as a simple java thread which periodically checks if there are tasks open and completes them (and thus ending the process). So, when interpreting the results, be sure to take in account that another thread is taking some CPU time at the same time.

Environment

The tests were run on my development machine: an Intel Core 2 T5600, 2 GB of ram and a 5400 rpm HD (so not the fastest machine, or not even a server machine).

For persistence, a MySQL 5 database was used, conigured using the my-large.ini configuration file. If you want to run the jar, you will have change the Hibernate configurations in the main/main.jar file.

Every configuration was tested with a clean database.

Performance results: Test 1 (Configuration 1)

The first thing I tried was a standard jBPM and Hibernate configuration. jBPM logging was on, show_sql was true and no caching was used. (the command to execute with this configuration is “java -jar JbpmPerformanceShowdown 2500 1“.

After 2500 runs, these are the numbers:

134,63 ms/process

26 740 processes/hour

Owtch. This is not so good… and far from the numbers I stated in my previous post (I admint, at this point I began to believe I made a mistake the last time).

The first thing that is clear when executing with this configuration, is the enormous amount of console output. So, the first thing to try out is disabling the console output.

Performance results: Test 2 (Configuration 1)

This configuration is exact the same as the previous configuration, but now the console output is thrown into a file instead of the console screen (“java -jar JbpmPerformanceShowndown.jar 1 > someFile.txt)

After 2500 iterations, these are the results:

29.78 ms/process

120 892 processes/hour

Wow… that’s about 4,5 times faster compared to the previous configuration. Off course, this test doesn’t teach us anything about jBPM. This test simply shows that console output *is* slow (at least on my WinXP machine).

The generated file is a staggering 142 MB large, containing 249237 queries. That is *a lot*. All this output is generated by Hibernate, so disabling the output is the next thing we’ll try.

Performance results: Test 3 (Configuration 2)

As stated in the previous paragraph, this test doesn’t generated any Hibernate output. This is done by setting the show_sql property to false in the Hibernate configuration.

After 2500 iterations, these are the results:

27,59 ms/process

130 495 processes/hour

Hmmm. this configuration is only 8% faster than the previous configuration. I expected some better numbers for this configuration, but is seems that the Hibernate output system is quite fast. Off course, 8% means that the “BPM platform” can now do 10 000 processes more in the same hour.

Performance results: Test 4 (Configuration 3)

When looking though the tables of jBPM after the exeution of the test, something is very clear. jBPM generates a lot of log records (table JBPM_LOG). For my previous test run, more than 60 000 log records are generated. We’ll see if the jBPM logging has an influence on the jBPM performance. This can easily be done by removing the logging service from the jBPM configuration file (remove the line <service name=”logging” factory=”org.jbpm.logging.db.DbLoggingServiceFactory” />).

After 2500 iterations, these are the results:

9,38 ms/process

383 746 processes/hour

Damn!! Simply disabling the jBPM logging service allows us to do 250 000 processes more in the same hour (that’s about 3 times faster compared to the previous result, btw). I shouldn’t tell you this is a HUGE difference.

When inspecting the source code of the DBLoggingService (the default jBPM logging service), it is clear that the logging is done too simple: all the unpersisted LoggingInstances are simply persisted by passing them to a Hibernate Session object. This is a very basic approach and, as the numbers prove, there is definitely some work to do in this area.

Performance results: Test 5 (Configuration 4)

Up to this point, we haven’t fiddled with Hibernate caching yet. This will certainly have an influence, since jBPM is in fact nothing more then a “Hibernate-based” process engine. Since I’m no expert in this area, I used the standard HashTableCacheProvider, and set the properties hibernate.cache.use_query_cache and hibernate.cache.use_second_level_cache to true.

After 2500 iterations, these are the results:

8,97 ms/process

401 393 processes/hour

It is clear that extra Hibernate caching options (besides the standard caching system) do have some influence (about 5% faster).

This is the last configuration I tested. I’m sure some (minor) tweaks still can be done. I’ve tried changing the connection pool, or using C3PO for Hibernate, but the results varied (sometimes a larger connection pool led to better results, but sometimes not). So I stayed with my default of a connection pool of 5 connections.

Configuration comparison

When we compare the results of the tests, we can can clearly see that tweaking jBPM does have a purpose. The x-axis shows the different tests (1 to 5) and the y-axis shows the number of processes/hour.

Conclusion

The main goal of this post, was to prove the correctness of my measurements (and to show how I was able to get them so low).

Altough no “real” business processes are used in the tests, the numbers give a good indication about the jBPM performance overhead.

As stated in my previous post (and now proven): the performance of jBPM is good. Doing 400 000 processes in one hour is incredible, taking in account my non-server/laptop machine. Of course, some sacrifces were made (the Hibernate output and more important, the jBPM logging).

In my point of view, the jBPM logging needs a revision. I’m sure a better implementation can be found (using a logging service whose logging level can be configured or simply a more performant way of doing logging). If I find some spare time in the next weeks, I’ll try to work something out.

The best conclusion can be found in the blog post of Tom Baeyens:

All of this shows that the overhead created by jBPM runtime process management is really small. Doing the statemanagement of such processes yourself will lead to a lot more development time, and in many cases, the performance will not be as optimized as just using jBPM.

Thanx for reading!

Remarks/questions are appreciated!

Joram

3 Comments

  1. Andries Inzé April 15, 2008

    Impressive results, excellent post.

    Although I do disagree with your point, that you don’t need the jBPM logging. Bugs in process definitions are hard to spot as it is. You need all the logging you can get.

    btw: Process 3 is pasted twice.

  2. Joram Barrez April 16, 2008

    Andries,

    You are correct, the jBPM logging is really valuable and necesary. I was wrong in formulating my opinion about it: I merely wanted to state that the jBPM logging certainly needs some kind of revision, given the bad performance.

    (btw: Process 3 was indeed pasted twice, thanks for noticing! I can’t believe I didn’t see that when i reviewed the post)

  3. pou April 22, 2008

    Great!!!
    Now that you have a testsuite, why don’t you try to do a multithreading tests. What application is going to execute processes one after the other. Probably your app will execute lot`s of process instances at the same time.
    Try this, and please, post your results.
    Also, if you want, read:
    http://www.jboss.com/index.html?module=bb&op=viewtopic&t=133647

Comments are Disabled