Almost all sun.awt.X11.XWrapperBase subclasses have similarly horrible getFieldsAsString() implementations, but they are all automatically generated (which is a relief as there was no human being actually writing such code).
They all say at the beginning: // This file is an automatically generated file, please do not edit this file, modify the WrapperGenerator.java file instead ! My guess is in file /openjdk/jdk/src/solaris/classes/sun/awt/X11/generator/WrapperGenerator.java in line 678 public void writeToString(StructType stp, PrintWriter pw) { starts the code generating bit. 2011/10/26 Oleg Sukhodolsky <son....@gmail.com>: > +1 to Artem. > > It is better to fix this too. > > Oleg. > > On Wed, Oct 26, 2011 at 7:34 PM, Artem Ananiev <artem.anan...@oracle.com> > wrote: >> >> On 10/26/2011 7:26 PM, Anthony Petrov wrote: >>> >>> On 10/26/2011 7:12 PM, Artem Ananiev wrote: >>>> >>>> On 10/21/2011 4:00 PM, Anthony Petrov wrote: >>>>> >>>>> Indeed, this is a nasty issue. Thanks for spotting it. You may notice >>>>> that in most other places where something is logged, the code usually >>>>> checks whether logging is enabled for a certain level of logging, e.g.: >>>>> >>>>>> if (shapeLog.isLoggable(PlatformLogger.FINER)) { >>>>>> shapeLog.finer( >>>>>> "*** INFO: Setting shape: PEER: " + this >>>>>> + "; WINDOW: " + getWindow() >>>>>> + "; TARGET: " + target >>>>>> + "; SHAPE: " + shape); >>>>>> } >>>>> >>>>> So basically, we could simply wrap the line in question into a similar >>>>> if(){} statement to make sure it gets executed only when the FINEST >>>>> level of logging is enabled. A similar solution may also apply to >>>>> another call to enableLog.finer() in the same method just a few lines >>>>> below. >>>> >>>> Although the fix has been already pushed to the workspace, let me >>>> wonder if, in addition to wrapping the logging calls with the "if ()" >>>> checks, we should have also rewritten isEventDisabled() to use >>>> StringBuilder? >>> >>> I guess you really mean the XEvent.getFieldsAsString() here [1], right? >> >> Yes, exactly. Thanks for this correction. >> >>> Possibly. But with Federico's fix this method now only gets called when >>> logging is enabled, and as such the impact of the issue is limited. >> >> I realize that. My point is that we just hide the problem, or make it less >> visible, or make it appear less frequently - whatever you prefer. However, >> the problematic code that contains char[] allocation is still in the >> workspace, and we know how often people use the current code as a pattern >> for future changes... >> >> Thanks, >> >> Artem >> >>> [1] >>> http://mail.openjdk.java.net/pipermail/awt-dev/2011-October/001952.html >>> >>> -- >>> best regards, >>> Anthony >>> >>> >>>> >>>> Thanks, >>>> >>>> Artem >>>> >>>>> Could you make a patch, test it, and post it to this mailing list for >>>>> review please? >>>>> >>>>> -- >>>>> best regards, >>>>> Anthony >>>>> >>>>> On 10/21/2011 7:10 AM, Federico Tello Gentile wrote: >>>>>> >>>>>> Hi. >>>>>> I'm running >>>>>> >>>>>> java -version >>>>>> java version "1.7.0_147-icedtea" >>>>>> OpenJDK Runtime Environment (IcedTea7 2.0pre) >>>>>> (7~b147-2.0~pre6-1ubuntu1) >>>>>> OpenJDK 64-Bit Server VM (build 21.0-b17, mixed mode) >>>>>> >>>>>> and profiling a simple Swing application. >>>>>> >>>>>> Just by opening a JFrame and moving the mouse over it for 10 secods I >>>>>> see 600 MB of char[] being created. I can easily create several >>>>>> terabytes or those if I move the mouse a little longer. Thanks to the >>>>>> incredibly efficient garbage collector the application performance is >>>>>> not visibly affected on my 4GB quad core machine. >>>>>> >>>>>> The problem is an incredibly inefficient method >>>>>> sun.awt.X11.XEvent.getFieldsAsString() which I pasted at the end of >>>>>> this >>>>>> message. >>>>>> >>>>>> The way it it handling string concatenation forces StringBuilder to >>>>>> grow >>>>>> many times and ends up calling Arrays.copyOf a lot of times. >>>>>> It is being called by the sun.awt.X11.XWrapperBase.toString() just for >>>>>> the sake of logging here: >>>>>> >>>>>> sun.awt.X11.XComponentPeer >>>>>> >>>>>> protected boolean isEventDisabled(XEvent e) >>>>>> >>>>>> enableLog.finest("Component is {1}, checking for disabled event >>>>>> {0}", e, >>>>>> (isEnabled()?"enabled":"disable")); >>>>>> >>>>>> The worse part is that even if logging is disabled and nothing at >>>>>> all is >>>>>> ever logged, the toString is called anyway and all those char[] are >>>>>> created anyway. >>>>>> >>>>>> Here's a NetBeans profiler memory snapshot. >>>>>> >>>>>> http://ubuntuone.com/4xkprEzadUM4sUSdAnWlN5 >>>>>> >>>>>> >>>>>> This does not happen *at all* if I run the same profiling with this >>>>>> openjdk version >>>>>> >>>>>> java -version >>>>>> java version "1.6.0_23" >>>>>> OpenJDK Runtime Environment (IcedTea6 1.11pre) (6b23~pre10-0ubuntu5) >>>>>> OpenJDK 64-Bit Server VM (build 20.0-b11, mixed mode) >>>>>> >>>>>> I hope we can do something to improve this situation. I guess all Swing >>>>>> applications are affected. >>>>>> >>>>>> I look forward for any comments. >>>>>> >>>>>> Here's the "thing"... >>>>>> >>>>>> --------------------------------------------------- >>>>>> >>>>>> String getFieldsAsString() { >>>>>> String ret=""; >>>>>> >>>>>> ret += ""+"type = " + XlibWrapper.eventToString[get_type()] +", "; >>>>>> ret += ""+"xany = " + get_xany() +", "; >>>>>> ret += ""+"xkey = " + get_xkey() +", "; >>>>>> ret += ""+"xbutton = " + get_xbutton() +", "; >>>>>> ret += ""+"xmotion = " + get_xmotion() +", "; >>>>>> ret += ""+"xcrossing = " + get_xcrossing() +", "; >>>>>> ret += ""+"xfocus = " + get_xfocus() +", "; >>>>>> ret += ""+"xexpose = " + get_xexpose() +", "; >>>>>> ret += ""+"xgraphicsexpose = " + get_xgraphicsexpose() +", "; >>>>>> ret += ""+"xnoexpose = " + get_xnoexpose() +", "; >>>>>> ret += ""+"xvisibility = " + get_xvisibility() +", "; >>>>>> ret += ""+"xcreatewindow = " + get_xcreatewindow() +", "; >>>>>> ret += ""+"xdestroywindow = " + get_xdestroywindow() +", "; >>>>>> ret += ""+"xunmap = " + get_xunmap() +", "; >>>>>> ret += ""+"xmap = " + get_xmap() +", "; >>>>>> ret += ""+"xmaprequest = " + get_xmaprequest() +", "; >>>>>> ret += ""+"xreparent = " + get_xreparent() +", "; >>>>>> ret += ""+"xconfigure = " + get_xconfigure() +", "; >>>>>> ret += ""+"xgravity = " + get_xgravity() +", "; >>>>>> ret += ""+"xresizerequest = " + get_xresizerequest() +", "; >>>>>> ret += ""+"xconfigurerequest = " + get_xconfigurerequest() +", "; >>>>>> ret += ""+"xcirculate = " + get_xcirculate() +", "; >>>>>> ret += ""+"xcirculaterequest = " + get_xcirculaterequest() +", "; >>>>>> ret += ""+"xproperty = " + get_xproperty() +", "; >>>>>> ret += ""+"xselectionclear = " + get_xselectionclear() +", "; >>>>>> ret += ""+"xselectionrequest = " + get_xselectionrequest() +", "; >>>>>> ret += ""+"xselection = " + get_xselection() +", "; >>>>>> ret += ""+"xcolormap = " + get_xcolormap() +", "; >>>>>> ret += ""+"xclient = " + get_xclient() +", "; >>>>>> ret += ""+"xmapping = " + get_xmapping() +", "; >>>>>> ret += ""+"xerror = " + get_xerror() +", "; >>>>>> ret += ""+"xkeymap = " + get_xkeymap() +", "; >>>>>> ret += "{" + get_pad(0) + " " + get_pad(1) + " " + get_pad(2) + " " + >>>>>> get_pad(3) + " " + get_pad(4) + " " + get_pad(5) + " " + get_pad(6) + " >>>>>> " + get_pad(7) + " " + get_pad(8) + " " + get_pad(9) + " " + >>>>>> get_pad(10) >>>>>> + " " + get_pad(11) + " " + get_pad(12) + " " + get_pad(13) + " " + >>>>>> get_pad(14) + " " + get_pad(15) + " " + get_pad(16) + " " + get_pad(17) >>>>>> + " " + get_pad(18) + " " + get_pad(19) + " " + get_pad(20) + " " + >>>>>> get_pad(21) + " " + get_pad(22) + " " + get_pad(23) + " " + "}"; >>>>>> return ret; >>>>>> } >>>>>> >>>>>> >> >