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.laur...@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.pet...@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.pet...@oracle.com <mailto:
>>> anthony.petrov@oracle.**com <anthony.pet...@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.laur...@gmail.com
>>>
>>> <mailto:bourges.laurent@gmail.**com<bourges.laur...@gmail.com>
>>> >
>>> <mailto:bourges.laurent@gmail.**__com
>>>
>>>
>>> <mailto:bourges.laurent@gmail.**com<bourges.laur...@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.laur...@gmail.com
>>>
>>> <mailto:bourges.laurent@gmail.**com<bourges.laur...@gmail.com>
>>> >
>>> <mailto:bourges.laurent@gmail.**__com
>>>
>>>
>>> <mailto:bourges.laurent@gmail.**com<bourges.laur...@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.pet...@oracle.com
>>>
>>> <mailto:anthony.petrov@oracle.**com<anthony.pet...@oracle.com>
>>> >
>>> <mailto:anthony.petrov@oracle.**__com
>>>
>>>
>>> <mailto:anthony.petrov@oracle.**com<anthony.pet...@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.
>>>
>>>
>>>
>
