<AWT Dev> <Swing Dev> sun.awt.X11 logs still using String + (waste)
Laurent Bourgès
bourges.laurent at gmail.com
Sun Apr 7 17:11:23 UTC 2013
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.
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 <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 <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/>
>>> <http://jmmc.fr/%7Ebourgesl/**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<anthony.petrov at oracle.com>
>>> >
>>> <mailto:anthony.petrov at oracle.**__com
>>>
>>> <mailto:anthony.petrov at oracle.**com<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>
>>> >
>>>
>>> <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/%**
>>> 7E__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/<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>
>>> >
>>>
>>>
>>> <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/%**
>>> 7E__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/<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>
>>> >
>>>
>>> <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>
>>> >
>>>
>>> <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 <bourges.laurent at gmail.com>>
>>> <mailto:bourges.laurent at gmail.**__com
>>> <mailto:bourges.laurent at gmail.**com<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<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 <bourges.laurent at gmail.com>>
>>> <mailto:bourges.laurent at gmail.**__com
>>> <mailto:bourges.laurent at gmail.**com<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<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>
>>> >
>>>
>>>
>>> <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 <anthony.petrov at oracle.com>>
>>> <mailto:anthony.petrov at oracle.**__com
>>> <mailto:anthony.petrov at oracle.**com<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<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