summary

In the Session.flush method has a lost of perfomance about 50% when flush a large amout of data

Description

When the flush method is called this method call the onFlush method of class DefaultFlushEventListener and then the method flushEverythingToExecutions(event).

This method (flushEverythingToExecutions) call many times (loop) the method log.isDebugEnabled().

This cause a big overhead in this method.

I suggest you to put an attribute in the method flushEverythingToExecutions(flushEverythingToExecutions(FlushEvent event, Boolean isDebugEnable) and verify this attribute before the loop for.

Attached the print screen of profiling that help me to detect this issue.

Tks.

Environment

Linux / DB2 / version 3.2.6 and above

Activity

Show:

Juraci Paixão Kröhling

June 11, 2010, 10:28 AM

Fabiano,

Would you please provide more details and/or a code that depicts this? I wasn't able to find this bottleneck in any of my tests, so, maybe I don't have the same environment as you. I have Fedora 13, Sun HotSpot Server JVM 1.6.22 32-bit, Log4J, local mysql database, Hibernate 3.3.2.GA. You seem to have Linux, DB2 and Hibernate 3.2 (tested in higher versions too). Which VM are you using (IBM? Sun? 32 x 64 bit?) and with which parameters? It seems you are using logback logging facility. Do you see the same result with Log4J?

Also, it's very strange that isDebugEnabled would cause such a performance hit, as it's supposed to be a very inexpensive operation. I didn't checked that, but I think that the HotSpot VM would also take care of optimizing this call.

Juraci Paixão Kröhling

April 2, 2010, 10:52 AM

Sure thing. I'll add this to my list.

Strong Liu

April 2, 2010, 7:42 AM

Juca,

would you like do some pref test on this case to see if this change is worth　to　apply?

Fabiano Cury

April 1, 2010, 9:14 PM

In a nutshell: notice that over 3% of the TOTAL EXECUTION TIME of this application is wasted by Hibernate calling method isDebugEnabled (although debug is disabled) inside a loop over 2 million times. This overhead could be easily avoided simply calling this method just once, outside the loop, and then assigning it to a local variable defined as "final boolean isDebugEnabled".