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

Tue Mar 19 04:29:18 PDT 2013

Here is the patch in mercurial export format.

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).

Is the export in the expected format (text format) ?

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(\"\");":"");

Regards,
Laurent

2013/3/19 Laurent Bourgès <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>
>
>> 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>
>>
>>> 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
>>>>
>>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/awt-dev/attachments/20130319/77aabcbc/attachment.html 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: jdk8_fixed_logs.patch
Type: text/x-patch
Size: 136235 bytes
Desc: not available
Url : http://mail.openjdk.java.net/pipermail/awt-dev/attachments/20130319/77aabcbc/jdk8_fixed_logs.patch 