java.awt event processing performance degradation on JRE7 - linux

[Anthony Petrov]

Hi Nicolas,

Frederico's patch is needed - with that patch we avoid string 
concatenation operations in XAWT code if logging has been disabled. 
These operations caused heavy memory usage, and eliminating them 
resolved the issue reported by Frederico. We don't want to revert that 
patch. In fact, I think that analyzing AWT logging code on other 
platforms (Windows and Mac) and developing a similar fix for them makes 
very much sense as well.

However, your suggestion is also valid. This is because in cases when we 
don't build complex strings for logging in AWT code, we don't usually 
guard such logging statements with if (...loggable...) checks. Your 
suggested change will address these specific cases, too, by eliminating 
some internal string building operations in the logger code itself, thus 
boosting performance even further.

Could you prepare a patch please, test it, and send it out for a review?

--
best regards,
Anthony

On 4/18/2012 5:01 AM, Nicolas Carranza wrote:
> Federico's patch solves  the performance regression (see:
> http://mail.openjdk.java.net/pipermail/jdk7u-dev/2012-April/002694.html
> ). But instead of this patch I find better to change the PlatformLogger
> class: insert "if(!isLoggable(level)) return;" at the beginning of the
> method sun.util.logging.PlatformLogger.JavaLogger.doLog(int level,
> String msg, Object... params) . The string convertion affecting the
> performance is done on the PlatformLogger.JavaLogger.doLog (even when
> the message is not loggable) and it is there where the problem should be
> fixed (to be more clear and also cover more use cases). Fixing it there
> also clears why the performance regression does not happen when
> redirectPlatformLoggers has not been called (when logging is not used):
> PlatformLogger.LoggerProxy.doLog(int level, String msg, Object...
> params) does not do the string convertion  when the message is not
> loggable.
> 
> Federico's patch has already been pushed to the jdk8 repository, when
> will it be applied to jdk7 (or my propossed change if it is preferred)?
> 
> [ Here is a jvisualvm memory profiling snapshot of
> PerformanceRegresionTest3:
> http://www.java.net/forum/topic/performance/general-performance-discussion/jre7s-javaawt-performance-degradation-caused-javautillogging-linux#comment-823486
> . ]
> 
> Cheers,
> Nicolas
> 
> On 04/16/2012 09:40 PM, Mandy Chung wrote:
>> Nicolas,
>>
>> Thanks for reporting the problem.   I am curious if you have collected
>> any profiling data that shows
>> sun.util.logging.PlatformLogger.redirectPlatformLoggers() is the cause
>> of the performance degradation.  This redirection is done as part of
>> the logging initialization before JFrame is initialized.  Since the
>> performance degradation you observed is after the JFrame has been
>> instantiated, it could be something else.  If it's logging-related, it
>> would be sun.util.logging.PlatformLogger.
>>
>> Mandy
>>
>> On 4/16/2012 6:18 AM, Daniel D. Daugherty wrote:
>>> java.util.logging is currently handled by the Serviceability Team.
>>> Adding that alias to this e-mail thread...
>>>
>>> Dan
>>>
>>>
>>> On 4/16/12 12:17 AM, Nicolas Carranza wrote:
>>>> Moving the mouse pointer over a java.awt.Window using JRE7 consumes
>>>> aprox. twice the CPU time as with JRE6 when logging is used (when a
>>>> call
>>>> to java.util.logging.getLogger(String)---even without using the
>>>> returned
>>>> Logger--- has been done). Keyboard key event processing suffers the
>>>> same
>>>> performance penalty. For steps to reproduce this problem please look
>>>> at:
>>>> http://www.java.net/forum/topic/performance/general-performance-discussion/jre7s-javaawt-performance-degradation-caused-javautillogging-linux
>>>>
>>>> .
>>>>
>>>> The performance degradation seems to be "enabled" by the call of
>>>> sun.util.logging.PlatformLogger.redirectPlatformLoggers() done inside
>>>> java.util.LogManager.readPrimorialConfiguration() on JRE7. Call chain:
>>>> Logger.getLogger()->LogManager.getLogManager()->
>>>> LogManager.readPrimordialConfiguration()->sun.util.logging.PlatformLogger.redirectPlatformLoggers().
>>>>
>>>>
>>>> This call is not made on JRE6. If this problem is not easy to solve
>>>> then
>>>> I guess is better to remove this call from JRE7's
>>>> readPrimordialConfiguration as it does more harm than good.
>>>>
>>>> Please let me know if there is a better place to report this problem. A
>>>> couple of weeks ago I "opened" a bug report on bugs.sun.com but I
>>>> received no response at all.
>>>>
>>>> Cheers,
>>>> Nicolas
>