java.awt event processing performance degradation on JRE7 - linux

[Nicolas Carranza]

java.util.logging.LogManager isn't loaded when running the
PerformanceRegressionTest2 without using logging
(http://www.java.net/forum/topic/performance/general-performance-discussion/jre7s-javaawt-performance-degradation-caused-javautillogging-linux):
> java -verbose:class PerformanceRegressionTest2  | grep LogManager
-- nothing on stdout.

But when using logging:
> java -verbose:class PerformanceRegressionTest2 useLogging | grep
LogManager
-- I get on stdout:
[Loaded java.util.logging.LogManager from
/opt/oracle-jdk-bin-1.7.0.3/jre/lib/rt.jar] ...
And the performance degradation is enabled.

When I started searching for the cause this problem I tryed comparing
the scenarios by profiling using jvisualvm but I couldn't find any
difference. I later discovered that jvisualvm seems to cause to always
load the LogManager class on the jvm it is connecting to. jvisualvm was
profiling always the scenario of performance degradation:
> java -verbose:class PerformanceRegressionTest2  | grep LogManager
-- then connecting jvisualvm always causes:
[Loaded java.util.logging.LogManager from
/opt/oracle-jdk-bin-1.7.0.3/jre/lib/rt.jar] ...

I haven't done any more profiling so far.

By comparing the java.util.logging sources of the JRE6 and JRE7 I
noticed the new
sun.util.logging.PlatformLogger.redirectPlatformLoggers() call done in
LogManager and changed the line 'Logger.getLogger("")' on
PerformanceRegressionTest2 to
'sun.util.logging.PlatformLogger.redirectPlatformLoggers()' (as
Logger.getLogger calls indirectly redirectPlatformLoggers) and found
that it  caused the same performance degradation.

Thank you!
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
>