<AWT Dev> <Swing Dev> sun.awt.X11 logs still using String + (waste)

Anthony Petrov anthony.petrov at oracle.com
Tue Apr 2 02:16:03 PDT 2013


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
>>
>> Fix: http://cr.openjdk.java.net/~anthony/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
>>>> (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/
>>>>
>>>> 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>.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>(""); 
>>>>>
>>>>>
>>>>> 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>>
>>>>>
>>>>>     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>>
>>>>>
>>>>>         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 
>>>>>
>>>>>
>>>>>         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>>
>>>>>
>>>>>             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 awt-dev mailing list