java.awt event processing performance degradation on JRE7 - linux

[Nicolas Carranza]

hi Anthony,

The little patch against the current
http://hg.openjdk.java.net/jdk8/jdk8/jdk repo is attached.
Running:
  time -f '%P' java PerformanceRegressionTest2 useLogging
3 times using the (JRE 1.7.0_03-b04 + escapeDoLog.patch) gives the
following CPU usages: 14%, 13%, 13%.
 
Please let me know if I can be of further help.

Cheers,
Nicolas

On 04/18/2012 05:08 AM, Anthony Petrov wrote:
> 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
>>
>

-------------- next part --------------
A non-text attachment was scrubbed...
Name: escapeDoLog.patch
Type: text/x-patch
Size: 877 bytes
Desc: not available
Url : http://mail.openjdk.java.net/pipermail/jdk7u-dev/attachments/20120423/665e6e2d/escapeDoLog.patch