<AWT Dev> <Swing Dev> sun.awt.X11 logs still using String + (waste)
Anthony Petrov
anthony.petrov at oracle.com
Thu Apr 4 12:05:03 UTC 2013
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>>
>
> 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>>
>
> 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.petrov at oracle.com
> <mailto:anthony.petrov at oracle.com>
> <mailto:anthony.petrov at oracle.__com
> <mailto: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>>
>
> 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.laurent at gmail.com <mailto:bourges.laurent at gmail.com>
> <mailto:bourges.laurent at gmail.__com
> <mailto: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>>>>
>
> 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>
> <mailto:bourges.laurent at gmail.__com
> <mailto: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>>>>
>
> 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.petrov at oracle.com <mailto:anthony.petrov at oracle.com>
> <mailto:anthony.petrov at oracle.__com
> <mailto: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>>>>
>
> 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