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

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

                        <mailto:bourges.laurent@gmail.
            <mailto:bourges.laurent@gmail.>__com
                        <mailto:bourges.laur...@gmail.com
            <mailto: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.laur...@gmail.com>
            <mailto:bourges.laur...@gmail.com
            <mailto:bourges.laur...@gmail.com>>
                        <mailto:bourges.laurent@gmail.
            <mailto:bourges.laurent@gmail.>__com
                        <mailto:bourges.laur...@gmail.com
            <mailto:bourges.laur...@gmail.com>>>
                        <mailto:bourges.laurent@gmail
            <mailto:bourges.laurent@gmail>.
                        <mailto:bourges.laurent@gmail
            <mailto:bourges.laurent@gmail>.>____com

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

                        <mailto:anthony.petrov@oracle.
            <mailto:anthony.petrov@oracle.>__com
                        <mailto:anthony.pet...@oracle.com
            <mailto: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.






Reply via email to