<AWT Dev> <Swing Dev> sun.awt.X11 logs still using String + (waste)
Laurent Bourgès
bourges.laurent at gmail.com
Mon Apr 8 10:06:53 UTC 2013
Peter, Mandy,
I think it would be great to make PlatformLogger very similar to Logger
API:
I mean JUL Logger already has only 1 convenient method with 1 param so it
may be great to have the same API in PlatformLogger too: maybe extend it to
2 or 3 params ...
Peter, could you look at the API differences between Logger /
PlatformLogger to make PlatformLogger API more similar to JUL Logger ?
Laurent
2013/4/8 Peter Levart <peter.levart at gmail.com>
> On 04/07/2013 07:11 PM, Laurent Bourgès wrote:
>
> Hi
>
> I started fixing All PlatformlLogger "bad" usages and I am fixing also
> many jul Logger usages without isLoggable ...
> That represents a lot of changes and a very boring job.
>
> I think sending a webrew tomorrow.
>
>
> Hi Laurent,
>
> Since you're already deep in the task, you might have a rough feeling what
> part of such unguarded log statements are of the following type:
>
> logger.[fine,info,...]("a message with {0} and {1} placeholders",
> someArg1, someArg2);
>
> where someArg1, ... are some values that are already present in the
> context of the logging statement and don't have to be computed just for
> satisfying the logging (not even boxing). Such usages could be effectively
> optimized by adding some overloaded methods to PlatformLogger that take 1,
> 2, 3, ... arguments:
>
> class PlatformLogger {
>
> ...
>
> public void finest(String msg, Object param1) {
> if (isLoggable(Level.FINEST)) {
> loggerProxy.doLog(Level.FINEST, msg, param1);
> }
> }
>
> public void finest(String msg, Object param1, Object param2) {
> if (isLoggable(Level.FINEST)) {
> loggerProxy.doLog(Level.FINEST, msg, param1, param2);
> }
> }
>
> public void finest(String msg, Object param1, Object param2, Object
> param3) {
> if (isLoggable(Level.FINEST)) {
> loggerProxy.doLog(Level.FINEST, msg, param1, param2, param3);
> }
> }
>
> ...
>
> This would effectively guard creation of the arguments array with an
> isLoggable check for some common usages, eliminating the need to explicitly
> guard such statements. Of course, the user would have to be aware of when
> such unguarded logging statement is without overhead and when not...
>
> How do you feel about such API extension?
>
>
> Regards, Peter
>
>
>
> Laurent
> Le 4 avr. 2013 14:08, "Laurent Bourgès" <bourges.laurent at gmail.com> a
> écrit :
>
>> Ok, I can provide an updated patch after finding / fixing all usages.
>>
>> Probably in 1 or 2 days,
>>
>> Laurent
>>
>> 2013/4/4 Anthony Petrov <anthony.petrov at oracle.com>
>>
>>> Yes, this makes sense. Do you want to update your fix for 8010297 to
>>> include these changes as well?
>>>
>>> --
>>> best regards,
>>> Anthony
>>>
>>>
>>> On 04/04/13 15:47, Laurent Bourgès wrote:
>>>
>>>> Dear all,
>>>>
>>>> I just realized there is another problem with PlatformLogger log
>>>> statements:
>>>> XBaseWindow:
>>>> public boolean grabInput() {
>>>> grabLog.fine("Grab input on {0}", this);
>>>> ...
>>>> }
>>>>
>>>> This calls the PlatformLogger.fine( varargs):
>>>> public void fine(String msg, Object... params) {
>>>> logger.doLog(FINE, msg, params);
>>>> }
>>>>
>>>> Doing so, the JVM creates a new Object[] instance to provide params as
>>>> varargs.
>>>>
>>>> I would recommend using isLoggable() test to avoid such waste if the log
>>>> is disabled (fine, finer, finest ...).
>>>>
>>>> Do you want me to provide a new patch related to this problem ?
>>>>
>>>> Does somebody have an idea to automatically analyze the JDK code and
>>>> detect missing isLoggable statements ...
>>>>
>>>> Regards,
>>>> Laurent
>>>>
>>>> 2013/4/3 Laurent Bourgès <bourges.laurent at gmail.com
>>>> <mailto:bourges.laurent at gmail.com>>
>>>>
>>>>
>>>> Anthony,
>>>>
>>>> could you tell me once it is in the OpenJDK8 repository ?
>>>> I would then perform again profiling tests to check if there is no
>>>> more missing isLoggable() statements.
>>>>
>>>> Once JMX and other projects switch to PlatformLogger, I could check
>>>> again.
>>>>
>>>> Maybe I could write a small java code checker (pmd rule) to test if
>>>> there is missing isLoggable() statements wrapping PlatformLogger log
>>>> statements. Any idea about how to reuse java parser to do so ?
>>>>
>>>> Regards,
>>>>
>>>> Laurent
>>>>
>>>> 2013/4/2 Anthony Petrov <anthony.petrov at oracle.com
>>>> <mailto:anthony.petrov at oracle.com>>
>>>>
>>>>
>>>> Looks fine to me as well. Thanks for fixing this, Laurent.
>>>>
>>>> Let's wait a couple more days in case Net or Swing folks want to
>>>> review the fix. After that I'll push it to the repository.
>>>>
>>>> --
>>>> best regards,
>>>> Anthony
>>>>
>>>>
>>>> On 4/2/2013 15:35, Laurent Bourgès wrote:
>>>>
>>>> Here is the updated patch:
>>>> http://jmmc.fr/~bourgesl/__share/webrev-8010297.2/
>>>> <http://jmmc.fr/%7Ebourgesl/share/webrev-8010297.2/>
>>>>
>>>>
>>>> Fixed inconsistencies between FINE / FINER log statements:
>>>> - XScrollbarPeer
>>>> - XWindowPeer
>>>>
>>>> Laurent
>>>>
>>>> 2013/4/2 Anthony Petrov <anthony.petrov at oracle.com
>>>> <mailto:anthony.petrov at oracle.com>
>>>> <mailto:anthony.petrov at oracle.__com
>>>>
>>>> <mailto:anthony.petrov at oracle.com>>>
>>>>
>>>>
>>>> 1. Sergey: I believe this is for purposes of better
>>>> formating the
>>>> log output and making it more readable by separating or
>>>> highlighting
>>>> some sections. I don't think this should be changed.
>>>>
>>>> 2. Laurent: can you please address this issue and send
>>>> us a new patch?
>>>>
>>>> --
>>>> best regards,
>>>> Anthony
>>>>
>>>>
>>>> On 4/1/2013 16:08, Sergey Bylokhov wrote:
>>>>
>>>>
>>>> Hi, Anthony
>>>> Only two comments:
>>>> 1 Why we need some special text in the log output
>>>> like "***" and
>>>> "###"
>>>> 2 XScrollbarPeer.java:
>>>>
>>>> + if
>>>> (log.isLoggable(____PlatformLogger.FINEST)) {
>>>>
>>>>
>>>> + log.finer("KeyEvent on scrollbar: " +
>>>> event);
>>>> + }
>>>>
>>>>
>>>>
>>>> On 4/1/13 12:20 PM, Anthony Petrov wrote:
>>>>
>>>> Awt, Swing, Net engineers,
>>>>
>>>> Could anyone review the fix please? For your
>>>> convenience:
>>>>
>>>> Bug:
>>>> http://bugs.sun.com/view_bug.____do?bug_id=8010297
>>>> <http://bugs.sun.com/view_bug.__do?bug_id=8010297>
>>>>
>>>> <http://bugs.sun.com/view_bug.__do?bug_id=8010297
>>>> <http://bugs.sun.com/view_bug.do?bug_id=8010297>>
>>>>
>>>> Fix:
>>>>
>>>> http://cr.openjdk.java.net/~____anthony/8-55-isLoggable-____8010297.0/
>>>> <
>>>> http://cr.openjdk.java.net/%7E__anthony/8-55-isLoggable-__8010297.0/>
>>>> <
>>>> http://cr.openjdk.java.net/%__7Eanthony/8-55-isLoggable-__8010297.0/
>>>> <
>>>> http://cr.openjdk.java.net/%7Eanthony/8-55-isLoggable-8010297.0/>>
>>>>
>>>> -- best regards,
>>>> Anthony
>>>>
>>>> On 3/22/2013 2:26, Anthony Petrov wrote:
>>>>
>>>> Hi Laurent,
>>>>
>>>> The fix looks great to me. Thank you very
>>>> much.
>>>>
>>>> We still need at least one review, though.
>>>> Hopefully
>>>> net-dev@ and/or swing-dev@ folks might
>>>> help
>>>> us out a bit.
>>>>
>>>> -- best regards,
>>>> Anthony
>>>>
>>>> On 3/20/2013 15:10, Anthony Petrov wrote:
>>>>
>>>> Hi Laurent,
>>>>
>>>> Thanks for the patch. I've filed a bug
>>>> at:
>>>> http://bugs.sun.com/view_bug.____do?bug_id=8010297
>>>> <http://bugs.sun.com/view_bug.__do?bug_id=8010297>
>>>>
>>>>
>>>> <http://bugs.sun.com/view_bug.__do?bug_id=8010297
>>>> <http://bugs.sun.com/view_bug.do?bug_id=8010297>>
>>>> (should be available in a day or two)
>>>>
>>>> and published a webrev generated from
>>>> your patch at:
>>>>
>>>> http://cr.openjdk.java.net/~____anthony/8-55-isLoggable-____8010297.0/
>>>> <
>>>> http://cr.openjdk.java.net/%7E__anthony/8-55-isLoggable-__8010297.0/>
>>>> <
>>>> http://cr.openjdk.java.net/%__7Eanthony/8-55-isLoggable-__8010297.0/
>>>> <
>>>> http://cr.openjdk.java.net/%7Eanthony/8-55-isLoggable-8010297.0/>>
>>>>
>>>>
>>>> I'm also copying swing-dev@ and
>>>> net-dev@ because the
>>>> fix affects those areas too. I myself
>>>> will review
>>>> the fix a bit later but am sending it
>>>> now for other
>>>> folks to take a look at it.
>>>>
>>>> On 3/19/2013 15:29, Laurent Bourgès
>>>> wrote:
>>>>
>>>> I am sorry I started modifying
>>>> PlatformLogger
>>>> and reverted changes to this class
>>>> as it is
>>>> another topic to be discussed
>>>> later: isLoggable
>>>> performance and waste due to
>>>> HashMap<Integer,
>>>> Level> leads to Integer allocations
>>>> (boxing).
>>>>
>>>>
>>>> I saw your message to core-libs-dev@,
>>>> so I just
>>>> dropped all changes to the
>>>> PlatformLogger from this
>>>> patch.
>>>>
>>>> Finally, I have another question
>>>> related to the
>>>> WrapperGenerator class: it
>>>> generates a lot of
>>>> empty log statements (XEvent):
>>>>
>>>> log
>>>> <
>>>> http://grepcode.com/file/____repository.grepcode.com/java/____root/jdk/openjdk/6-b14/sun/____awt/X11/XWrapperBase.java#____XWrapperBase.0log
>>>> <
>>>> http://grepcode.com/file/__repository.grepcode.com/java/__root/jdk/openjdk/6-b14/sun/__awt/X11/XWrapperBase.java#__XWrapperBase.0log>
>>>>
>>>>
>>>> <
>>>> http://grepcode.com/file/__repository.grepcode.com/java/__root/jdk/openjdk/6-b14/sun/__awt/X11/XWrapperBase.java#__XWrapperBase.0log
>>>> <
>>>> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/sun/awt/X11/XWrapperBase.java#XWrapperBase.0log
>>>> >>>.finest
>>>> <
>>>> http://grepcode.com/file/____repository.grepcode.com/java/____root/jdk/openjdk/6-b14/java/____util/logging/Logger.java#____Logger.finest%28java.lang.____String%29
>>>> <
>>>> http://grepcode.com/file/__repository.grepcode.com/java/__root/jdk/openjdk/6-b14/java/__util/logging/Logger.java#__Logger.finest%28java.lang.__String%29>
>>>>
>>>>
>>>> <
>>>> http://grepcode.com/file/__repository.grepcode.com/java/__root/jdk/openjdk/6-b14/java/__util/logging/Logger.java#__Logger.finest%28java.lang.__String%29
>>>> <
>>>> http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/6-b14/java/util/logging/Logger.java#Logger.finest%28java.lang.String%29
>>>> >>>("");
>>>>
>>>>
>>>> Is it really useful to have such
>>>> statements ? I
>>>> would keep logs with non empty
>>>> messages only.
>>>>
>>>> See WrapperGenerator:753:
>>>> String s_log =
>>>>
>>>> (generateLog?"log.finest(\"\")____;":"");
>>>>
>>>>
>>>>
>>>>
>>>> I believe they're used for log
>>>> formatting purposes
>>>> to separate numerous events in a log
>>>> (e.g. think of
>>>> mouse-move events - there can be
>>>> hundreds of them in
>>>> a raw).
>>>>
>>>>
>>>> Please note that the hg export format
>>>> is not that
>>>> useful unless you're assigned an
>>>> OpenJDK id already
>>>> (please see Dalibor's message for
>>>> details) because I
>>>> can't import it directly. So for the
>>>> time being you
>>>> could send just raw patches (i.e. the
>>>> output of hg
>>>> diff only - and there's no need to
>>>> commit your
>>>> changes in this case). Also, please
>>>> note that the
>>>> mailing lists strip attachments. The
>>>> reason I got it
>>>> is because I was listed in To: of your
>>>> message. So
>>>> when sending patches you can:
>>>> 1) post them inline, or
>>>> 2) attach them and add a person to To:
>>>> of your
>>>> message, or
>>>> 3) upload them somewhere on the web.
>>>> However, it would be best if you could
>>>> generate a
>>>> webrev for your changes and upload it
>>>> somewhere.
>>>> Currently this is the standard format
>>>> for reviewing
>>>> fixes in OpenJDK.
>>>>
>>>> -- best regards,
>>>> Anthony
>>>>
>>>>
>>>> Regards,
>>>> Laurent
>>>>
>>>>
>>>>
>>>> 2013/3/19 Laurent Bourgès
>>>> <bourges.laurent at gmail.com <mailto:
>>>> bourges.laurent at gmail.com>
>>>> <mailto:bourges.laurent at gmail.__com
>>>> <mailto:bourges.laurent at gmail.com>>
>>>> <mailto:bourges.laurent at gmail.
>>>> <mailto:bourges.laurent at gmail.>____com
>>>>
>>>> <mailto:bourges.laurent at gmail.__com
>>>> <mailto:bourges.laurent at gmail.com>>>>
>>>>
>>>> Hi antony,
>>>>
>>>> FYI I started reviewing and
>>>> fixing all
>>>> PlatformLogger use cases (not
>>>> too many as I thought first)
>>>> mainly used by
>>>> awt / swing projects to
>>>> provide you a patch on latest
>>>> JDK8 source code:
>>>>
>>>> I am adding the log level check
>>>> when it is
>>>> missing:
>>>> if
>>>> (...log.isLoggable(____PlatformLogger.xxx)) {
>>>>
>>>>
>>>> log...
>>>> }
>>>>
>>>> I will not change the String +
>>>> operations to
>>>> use the message format
>>>> syntax in this patch.
>>>>
>>>> Do you accept such patch /
>>>> proposed
>>>> contribution ?
>>>>
>>>> Regards,
>>>> Laurent
>>>>
>>>>
>>>> 2013/3/18 Laurent Bourgès
>>>> <bourges.laurent at gmail.com <mailto:
>>>> bourges.laurent at gmail.com>
>>>> <mailto:bourges.laurent at gmail.__com
>>>> <mailto:bourges.laurent at gmail.com>>
>>>> <mailto:bourges.laurent at gmail.
>>>> <mailto:bourges.laurent at gmail.>____com
>>>>
>>>> <mailto:bourges.laurent at gmail.__com
>>>> <mailto:bourges.laurent at gmail.com>>>>
>>>>
>>>> Hi antony,
>>>>
>>>> 2 different things:
>>>> 1/ PlatformLogger was
>>>> patched (doLog
>>>> method) to avoid string
>>>> operations (message
>>>> formatting) for
>>>> disabled logs (patch
>>>> submiited on JDK8 and
>>>> JDK7u):
>>>>
>>>> http://mail.openjdk.java.net/____pipermail/jdk7u-dev/2012-____April/002751.html
>>>> <
>>>> http://mail.openjdk.java.net/__pipermail/jdk7u-dev/2012-__April/002751.html>
>>>>
>>>>
>>>>
>>>> <
>>>> http://mail.openjdk.java.net/__pipermail/jdk7u-dev/2012-__April/002751.html
>>>> <
>>>> http://mail.openjdk.java.net/pipermail/jdk7u-dev/2012-April/002751.html
>>>> >>
>>>>
>>>>
>>>> 2/ I looked 2 hours ago on
>>>> JDK7u AND
>>>> JDK8 source codes and both
>>>> still have:
>>>> - log statements WITHOUT
>>>> log level check
>>>> : if
>>>>
>>>> (log.isLoggable(____PlatformLogger.FINE))
>>>>
>>>>
>>>> log.fine(...);
>>>> - string operations (+) in
>>>> log calls
>>>> that could be improved
>>>> using the message format
>>>> syntax (String
>>>> + args): for example,
>>>> avoid using
>>>> PlatformLogger.fine(String +
>>>> ...) in favor of using
>>>> PlatformLogger.fine(String
>>>> msg,
>>>> Object... params)
>>>>
>>>> I reported in my previous
>>>> mail several
>>>> cases where the
>>>> isLoggable() call is
>>>> missing and leads
>>>> to useless String
>>>> operations but also method
>>>> calls
>>>> (Component.paramString() for
>>>> example).
>>>>
>>>> Finally, I also provided
>>>> other possible
>>>> cases (using grep);
>>>> maybe there is a better
>>>> alternative to
>>>> find all occurences of
>>>> String operations in log
>>>> calls.
>>>>
>>>> Regards,
>>>> Laurent
>>>>
>>>> 2013/3/18 Anthony Petrov
>>>> <anthony.petrov at oracle.com <mailto:
>>>> anthony.petrov at oracle.com>
>>>> <mailto:anthony.petrov at oracle.__com
>>>> <mailto:anthony.petrov at oracle.com>>
>>>> <mailto:anthony.petrov at oracle.
>>>> <mailto:anthony.petrov at oracle.>____com
>>>>
>>>> <mailto:anthony.petrov at oracle.__com
>>>> <mailto:anthony.petrov at oracle.com>>>>
>>>>
>>>> Hi Laurent,
>>>>
>>>> Normally we fix an
>>>> issue in JDK 8
>>>> first, and then back-port
>>>> the fix to a 7u
>>>> release. You're
>>>> saying that in JDK 8 the
>>>> problem isn't
>>>> reproducible anymore.
>>>> Can you please
>>>> investigate (using the
>>>> Mercurial
>>>> history log) what exact fix
>>>> resolved it in JDK 8?
>>>>
>>>> --
>>>> best regards,
>>>> Anthony
>>>>
>>>> On 03/18/13 15:09,
>>>> Laurent Bourgès
>>>> wrote:
>>>>
>>>> Dear all,
>>>>
>>>> I run recently
>>>> netbeans profiler
>>>> on my swing application
>>>> (Aspro2:
>>>> http://www.jmmc.fr/aspro) under
>>>> linux x64 platform and I
>>>> figured out
>>>> that a lot of
>>>> char[] instances
>>>> are coming from String +
>>>> operator called
>>>> by sun.awt.X11
>>>> code.
>>>>
>>>> I looked at
>>>> PlatformLogger
>>>> source code but found not way
>>>> to disable it
>>>> completely: maybe
>>>> an empty
>>>> logger implementation could
>>>> be interesting to
>>>> be used during
>>>> profiling or
>>>> normal use (not debugging).
>>>> Apparently JDK8
>>>> provides some
>>>> patchs to avoid String
>>>> creation when the
>>>> logger is disabled
>>>> (level).
>>>>
>>>> However, I looked
>>>> also to the
>>>> sun.awt code (jdk7u
>>>> repository) to see
>>>> the
>>>> origin of the
>>>> string allocations:
>>>> XDecoratedPeer:
>>>> public void
>>>> handleFocusEvent(XEvent xev) {
>>>> ...
>>>> *
>>>> focusLog.finer("Received focus event on shell:
>>>> " + xfe);
>>>> * }
>>>>
>>>> public boolean
>>>> requestWindowFocus(long time,
>>>> boolean
>>>> timeProvided) {
>>>> ...
>>>> *
>>>> focusLog.finest("Real native focused
>>>> window: " +
>>>>
>>>> realNativeFocusedWindow +
>>>> "\nKFM's focused window: " +
>>>> focusedWindow);
>>>> *...
>>>> *
>>>> focusLog.fine("Requesting focus to " + (this ==
>>>> toFocus ? "this
>>>> window" :
>>>> toFocus));
>>>> *...
>>>> }
>>>>
>>>> XBaseWindow:
>>>> public void
>>>> xSetBounds(int
>>>> x, int y, int width, int
>>>> height) {
>>>> ...
>>>> *
>>>> insLog.fine("Setting
>>>> bounds on " + this + " to
>>>> (" + x + ", " +
>>>> y + "), " + width +
>>>> "x" + height);
>>>> *}
>>>>
>>>> XNetProtocol:
>>>> boolean
>>>> doStateProtocol() {
>>>> ...
>>>> *
>>>> stateLog.finer("______doStateProtocol()
>>>> returns " +
>>>>
>>>>
>>>> res);
>>>> *}
>>>>
>>>> XSystemTrayPeer:
>>>>
>>>> XSystemTrayPeer(SystemTray
>>>> target) {
>>>> ...
>>>> * log.fine("
>>>> check if
>>>> system tray is available.
>>>> selection owner:
>>>> " + selection_owner);
>>>> *}
>>>> void
>>>> addTrayIcon(XTrayIconPeer tiPeer)
>>>> throws
>>>> AWTException {
>>>> ...
>>>> * log.fine("
>>>> send
>>>> SYSTEM_TRAY_REQUEST_DOCK
>>>> message to owner:
>>>> " +
>>>> selection_owner);
>>>> *}
>>>>
>>>> XFramePeer:
>>>> public void
>>>> handlePropertyNotify(XEvent xev) {
>>>> ...
>>>>
>>>> stateLog.finer("State is the same: " +
>>>> state);
>>>> }
>>>>
>>>> However I only give
>>>> here few
>>>> cases but certainly others
>>>> are still
>>>> present in the
>>>> source code;
>>>> maybe findbugs or netbeans
>>>> warnings could
>>>> help you finding
>>>> all of them.
>>>>
>>>> I advocate the
>>>> amount of waste
>>>> (GC) is not very
>>>> important but
>>>> String
>>>> conversion are also
>>>> calling
>>>> several toString() methods
>>>> that can be
>>>> costly (event,
>>>> Frame, window ...)
>>>>
>>>> Finally, I ran few
>>>> grep commands
>>>> on the sun.awt.X11 code
>>>> (jdk7u) and you
>>>> can look at them to
>>>> see all
>>>> string + operations related
>>>> to log statements.
>>>>
>>>> PS: I may help
>>>> fixing the source
>>>> code but I have no idea
>>>> how to
>>>> collaborate
>>>> (provide a patch ?)
>>>>
>>>> Regards,
>>>> Laurent Bourgès
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> -- Best regards, Sergey.
>>>>
>>>>
>>>>
>>>>
>>>>
>>
>
More information about the core-libs-dev
mailing list