Community
Participate
Working Groups
Hi, Currently, the org.eclipse.draw2d.geometry.Rectangle class is widely used among projects, notably GMF. It does what it is meant to well, yet the "getCopy" method puzzles me : public Rectangle getCopy() { try { return (Rectangle)clone(); } catch (CloneNotSupportedException exc) { return new Rectangle(this); } } We built an application against GMF which in turn makes great use of GEF and draw2d. In our diagrams, an impressive amount of time is lost in this "getCopy" method : I've never thought "clone()" to be fast, but that one is ridiculous : replacing all "*.getCopy()" calls by "new Rectangle(*)" proved to provide roughly 15% time enhancement in diagrams opening (from 44 seconds to 36 seconds). I believe this has been done to allow subclasses of rectangle to get copied properly. Why then not overriding "Rectangle.clone()" to use the copy constructor and having subclasses do the same? PrecisionRectangle overrides getCopy() to properly create a new PrecisionRectangle, that leaves "org.eclipse.draw2d.graph.Obstacle" in the way. I'm willing to provide a patch for either approach (overriding clone()) or "getCopy()" in both Rectangle and Obstacle). Awaiting your input though as to why this has been handled that way.
That's very interesting. Can you shed some light on how many calls were being made to getCopy() which led to that performance yield? Is your editor doing something that led to more than the usual number of invocations of that method? Does this change realize a similar performance improvement in the logic example editor? I am not sure why we're using clone for Rectangle, but not Point. Unfortunately, your suggested fix would break clients who're depending on the clone() functionality for any of their subclasses. We could, however, optimize it by checking to see if the class of the object is the same as draw2d.geometry.Rectangle and, if so, then using the copy constructor instead of clone.
Hi Patrik, I was using Yourkit Java profiler in order to detect hot spots in our application, unfortunately I didn't use it in tracing mode and have no hint as to how many calls to getCopy() (hence clone()) were made. As for the suggested fix, I aggree that removing the clone() call from Rectangle.getCopy() would break the API for most clients, yet overriding Rectangle.clone() (currently delegating to the native Object.clone()) to use the copy constructor or simply create a new Rectangle and set its values manually would not IIUC. Optimizing getCopy() to check the actual class against draw2d.geometry.Rectangle would also do the trick in our (and GMF's) case. I just tried the logic example in order to have a comparison standpoint. Without any modification to draw2d, opening a diagram took 18 seconds. Then I overrode Rectangle.clone() as such : protected Object clone() throws CloneNotSupportedException { return new Rectangle(this); } and opened the same diagram in the same conditions (opening it a first time, then measuring time on the second opening to avoid measuring plugin initialization time). It lasted 14 seconds for a rough gain of 4 seconds, 23% of the original time (take not that these are wall times). The logic diagram I tested on contained a lot of leds, circuits and other Rectangles as this is also how my GMF diagrams looked like.
Are the statistics you're providing while running in normal mode? i.e., not running in debug mode or with yourkit tracing or sampling active?
Randy, All of these times are wall time, retrieved under linux (debian) using sun's Java 1.5. They were measured with Eclipse 3.3 (a similar gain can be observed with 3.4 though I have no figures on this). GEF version is 3.3.2 (we use GMF 2.0.1 as a side note). All tests were made in a normal mode without any profiling on. They were all made in the same conditions : - launch my runtime workbench - open a random diagram without measuring the time (did this step with another diagram to try and avoid any caches. its only purpose is to clear plugin initialization times out of the way) - close the diagram - open the diagram to measure times on - close the runtime workbench
Based on the existence of subclasses, I don't think this could be changed safely. Perhaps there are places where unnecessary copies are being made? 4 seconds is a lot of cloning! Do you know which methods are calling getCopy() the most?
Randy, I fail to see how overriding clone() would break the API : the current implementation delegates to the native Object.clone() which, AFAIK, does the same as the Rectangle copy constructor since all fields are primitive : instantiate a new Rectangle and set all field values. Subclasses overriding clone() will still have their own clone() implementation called, and the other will simply have this new Rectangle.clone() be called instead of the lengthy Object.clone(). As for who calls getCopy() the most, I'm afraid calls are too scattered thoughout both GMF and GEF to actually find a culprit. I'll try and have a look but do not have high hopes there. you can still have a look at all of GMF figures though (org.eclipse.gmf.runtime.diagram.ui.figures.*) most if not all of the "getExtendedBounds" methods call getCopy() (and hence clone()) on the Figure, then if there are border nodes they call their own "getExtendedBounds" which in turn ... and then on those extended bounds they once again call getCopy() ... this leads to intense cloning and is quite representative of what I could see scattered almost everywhere in the code. Granted, the culprit in this case is GMF. Granted, the clone() calls wouldn't be an issue if getCopy() wasn't used so wildly... And yet I still think this should be handled there as it represents the true bottleneck.
Laurent, the problem would be for subclasses which do not override getCopy(). For example, PrecisionRectangle didn't need to override getCopy() (yet it does, for some reason). By default, cloning would have resulted in another PrescisionRectangle. So, in theory, existing client subclasses *could* be relying on the current cloning implementation.
Yes, didn't see that one :(. Only remains the instanceof check as Pratik mentionned to avoid the unnecessary cloning I guess.
Snippet showing the problem: int iterations = 10000000; Rectangle original = new Rectangle(10, 20, 30, 40); Rectangle clone = null; long begin = System.currentTimeMillis(); for (int i = 0; i < iterations; i++) clone = original.getCopy(); long time = System.currentTimeMillis() - begin; System.out.println("Cloning time: " + time); begin = System.currentTimeMillis(); for (int i = 0; i < iterations; i++) clone = new Rectangle(original); time = System.currentTimeMillis() - begin; System.out.println("Copying time: " + time); Sample output: Cloning time: 3062 Copying time: 219 On my laptop, I am seeing that the copy constructor is about 14 times faster than the clone() method. For cloning to be taking several seconds, though, must mean that opening Laurent's editor results in that method being invoked tens of millions of times.
Pratik, Such a high invocation count doesn't really seem possible ... guess I'll have to get the actual count hoping that Yourkit can record it accurately :). the actual seconds gain was roughly 8 seconds on my GMF-based editor, 4 on the logic GEF example ... that would mean quite a number of cloning (given that your snippet doesn't get optimized by the vm and you tested this on linux that is).
Created attachment 121599 [details] patch for the 3.4 branch
ok, took a little time today to record the actual invocation counts of both "Rectangle.getCopy()" and "Rectangle.clone()". I did this with static integers I reseted before each diagram opening. Anyway, here's how the figures go : - opening a GEF logic diagram with two leds - copy count (== clone count) : 27 - opening large GEF logic diagram (2742 leds) - copy count (== clone count) : 7756 - opening a GMF logic diagram with two leds - copy count (== clone count) : 421 - opening large GEF logic diagram (410 nodes) - copy count (== clone count) : 395 559 For the record, here are the counts for our GMF-based diagrams : - opening small diagram (55 nodes) : - copy count (== clone count) : 230 581 - opening large diagram (1228 nodes) : - copy count (== clone count) : 172 773 930 So even if the cloning isn't really an issue in GEF, it really is in GMF because of the number of calls to getCopy. And that is further emphasized in our own diagrams. I should also mention than each refresh (and in fact most actions) of a diagram (either GEF or GMF) calls for even more clones. Nevertheless and regardless of invocation counts, Pratik's snippet highlighted that using the copy constructor is 14x faster than cloning. I think this in itself calls for an optimization.
Created attachment 121610 [details] patch for the 3.3 branch
172 million invocations!? The ratio of cloning invocation count to node count seems alarmingly high in GMF. That should be looked into on the GMF side as well. > - opening large GEF logic diagram (410 nodes) > - copy count (== clone count) : 395 559 Laurent, did you mean GMF logic diagram for the above case?
whoops, yup that was the GMF logic diagram for that one ... copy/paste power :). And yes, the ratio is indeed anormally high. don't know who I could cc to this bug in order to have them take a look (then again I could make another bug, but I am not so keen as to answer as many questions from them since all information is already here :d)
I CCed an additional GMF committer (Linda) who spent a significant amount of time in Galileo on performance. I do not recall this API being flagged as an issue in GMF.
I don't recall having this issue brought to my attention before, either, but our investigations in Galilao were focussed on reducing memory use and on performance regressions from previous releases. This is likely a long-standing issue that was already part of our baseline performance numbers. I'll investigate what's going on in GMF to cause the high clone():node ratio.
Linda, I should probably mention that most of our own diagrams' elements are either BorderedNodeFigure or BorderedItemContainerFigure. That could explain a higher number of calls to Rectangle.getCopy() for our diagrams than there are for GMF (through these classes "getExtendedBounds" method). Still remains that GMF yields significantly more calls to that particular method than GEF does.
Laurent, the number of wires is probably more of a factor here. Can you provide more consistent measurements using content with a known number of wires, such as a bunch of full-adders? You should try to find out if the number of calls is linear or polynomial with respect to the number of wires+nodes. I suspect that the cloning is occurring in the connection locators and/or routers. It sounds like there also might be an issue with multiple layouts occurring on open.
Randy, There was _no_ edges whatsoever on the GEF and GMF logic diagrams I measured these on. I merely opened the diagrammes and created LED components as I could (copy pasted on GEF diagrams, manually clicking on GMF diagrams ... that's why there are way less nodes on these ^^). I wrote "xx LEDs" and well, I truly meant it. The only diagram were there actually were some edges are the two very last ones (our custom GMF based diagrams) I provided for the record since they are the ones a client of ours created and on which we try and improve performances.
(In reply to comment #12 and comment #20) TEST #1 > - opening a GEF logic diagram with two leds > - copy count (== clone count) : 27 So, at worst 13:1 ratio (clone-to-LED) TEST #2 > - opening large GEF logic diagram (2742 leds) > - copy count (== clone count) : 7756 So, the ratio in GEF is probably more like 3:1 or 2:1. It probably depends on whether or not the LED is visible and paints. TEST #3 > - opening a GMF logic diagram with two leds > - copy count (== clone count) : 421 At most 200:1 ratio, which is a bit concerning. TEST #4 > - opening large GEF logic diagram (410 nodes) > - copy count (== clone count) : 395 559 964:1!? I hope there is more than just LED's involved in this test case. Was this a pure GEF or pure GMF test? Could you provide the file? TEST #5 > For the record, here are the counts for our GMF-based diagrams : > - opening small diagram (55 nodes) : > - copy count (== clone count) : 230 581 4,000 : 1!!?? More details about diagram contents might help here, although the previous "pure GEF/GMF" examples are already somewhat beyond expectation. TEST #6 > - opening large diagram (1228 nodes) : > - copy count (== clone count) : 172 773 930 140,000 : 1 !!!!!!!!!!!!!!!!! Ok, there are some serious problems here. Even if we switched to calling the constructor, creating 172 million temporary objects just to open (and paint?) your editor should feel wrong. More details or a reproducible example would help a *lot* here! LED-only scalability in the GEF example appeared linearly. If you use more complex content in the GEF example, does it scale linearly too? Perhaps TEST #4 compared to that same context copied and pasted once? Thanks for all the useful info thus far!
As(In reply to comment #21) > (In reply to comment #12 and comment #20) > TEST #1 > > - opening a GEF logic diagram with two leds > > - copy count (== clone count) : 27 > > So, at worst 13:1 ratio (clone-to-LED) After some more investigation, seems that 16 calls are made when opening an _empty_ diagram so the ratio is more like 5:1 here. > > TEST #2 > > - opening large GEF logic diagram (2742 leds) > > - copy count (== clone count) : 7756 > > So, the ratio in GEF is probably more like 3:1 or 2:1. It probably depends on > whether or not the LED is visible and paints. Ha ... that I didn't pay enough attention to and indeed, there were "invisible" nodes since I copy pasted like crazy. > > TEST #4 > > - opening large GEF logic diagram (410 nodes) > > - copy count (== clone count) : 395 559 > > 964:1!? I hope there is more than just LED's involved in this test case. Was > this a pure GEF or pure GMF test? Could you provide the file? As mentionned in comment #15 I missed a copy/paste here. This is "opening a large *GMF* logic diagram. I simply used the GMF logic example ... and sure I have the file around ... but as mentionned above, I simply created as many LEDs as I could before being bored of left-clicking. > > TEST #5 > > For the record, here are the counts for our GMF-based diagrams : > > - opening small diagram (55 nodes) : > > - copy count (== clone count) : 230 581 > > 4,000 : 1!!?? More details about diagram contents might help here, although the > previous "pure GEF/GMF" examples are already somewhat beyond expectation. Agreed, but as I told in comment #20 those are diagrams custom made by a client and I'm afraid I have no right to deliver these. What I can say about the content is mostly in comment #18 : that one contains 55 BorderedNodeFigures (think that's the one that can hold bordered nodes) and 54 Edges. > > TEST #6 > > - opening large diagram (1228 nodes) : > > - copy count (== clone count) : 172 773 930 > > 140,000 : 1 !!!!!!!!!!!!!!!!! > Ok, there are some serious problems here. Even if we switched to calling the > constructor, creating 172 million temporary objects just to open (and paint?) > your editor should feel wrong. More details or a reproducible example would > help a *lot* here! Unfortunately, same as above :(. Though I did take the courage to make a GMF logic example going up in the thousand elements too : TEST #7 - opening GMF logic diagram with 1117 LEDs - copy count : 2 748 041 indeed, the problem is even more emphasized in our diagrams than it is in GMF... we'll try and investigate to see if we can reduce this but I fear it is due to our client needs being a little more than what the GMF example does :). > > LED-only scalability in the GEF example appeared linearly. If you use more > complex content in the GEF example, does it scale linearly too? Perhaps TEST #4 > compared to that same context copied and pasted once? calls to getCopy for the GEF logic example : - diagram opening - empty : 16 - 2 of each LED, Full-adder, Half-adder, circuit : 188 - 10 of each of the above : 625 - 60 of each : 3962 So yes, seems linear for GEF. Creating GMF diagrams is way too expensive though and I clearly cannot take enough time to make such tests. > > Thanks for all the useful info thus far! >
Created attachment 121709 [details] diagrams used for all described tests
Created attachment 121799 [details] GMF calls to Rectangle.clone() Linda, Anthony, Thought you might find this useful. I used a profiler (yourkit) to see who was calling Rectangle.getCopy the most (used the diagram of TEST #7 for this, GMF logic example with 1117 LEDs and nothing else). First of all, yourkit sees less invocations that I did at first (2 583 840). As I thought, Most of them (2 506 548, 97%) came from BorderedNodeFigure.getExtendedBounds(). In turn, 97% of the calls to BorderedNodeFigure.getExtendedBounds() came from BorderItemsAwareFreeFormLayer.getBounds(). I believe something can be done in one of thos two to reduce the calls since I saw at least one useless call to getCopy (see attached image for Yourkit's results).
Created attachment 121800 [details] patch for GMF Runtime head Hi, Please find attached a patch for GMF BorderedNodeFigure#getExtendedBounds() method. I think this the getCopy() is not useful, as Rectangle#union(Rectangle rect) do not reference the rectangle instance given as parameter, but only uses its attributes. Regards, Mariot
Created attachment 121801 [details] patch for GMF Runtime Revision 2.1 branch
Created attachment 121802 [details] GMF calls to Rectangle.clone() once patched As I still had Yourkit launched, I'm attaching here its results using the GMF patch Mariot just provided. I took the snapshot a little late (my comp was on screensaver mode when I came back and I think the diagram got one refresh more than previously because of this), yet the invocation count still got effectively halved. I still wonder why 10 000 calls to BorderItemsAwareFreeFormLayer.getBounds() result in 1 000 000 calls to BorderNodeFigure.getExtendedBounds() for a mere thousand LEDs in the diagram, yet since the actual cost of those invocations is the Rectangle.getCopy, it still is nice reduce it.
Created attachment 121803 [details] GMF calls to Rectangle.clone() once patched whoops ignore the above attached image :)
Regarding comment #24 with respect to reducing the number of calls to BorderedNodeFigure#getExtendedBounds(), is there a reason why we don't cache the extended bounds once they've been calculated, clearing the cached value when the figure is invalidated (like we do in BorderedItemContainerFigure)? My tests on a GMF logic example diagram with different numbers of LEDs showed a constant 9:1 ratio of calls to BorderedNodeFigure#getExtendedBounds() to the number of LEDs on the diagram. When I tried caching the BorderedNodeFigure#getExtendedBounds() value, the ratio of was 1:1 of BorderedNodeFigure extended bounds re-computation to the number of LEDs on the diagram.
Adding Alex Boyko to comment as well. Moving the Bugzilla to GMF.
Looking back on it, it would seem I should have duplicated this bug to have another one against GMF since the actual bug has shifted from "performance issue in Rectangle class" GEF to "performance issue with BorderedNodeFigure" GMF ... and I still think both should be handled (and Mariot provided patch for both though Linda's solution for the second seems more appropriate).
> Looking back on it, it would seem I should have duplicated this bug to have > another one against GMF since the actual bug has shifted from "performance > issue in Rectangle class" GEF to "performance issue with BorderedNodeFigure" > GMF ... and I still think both should be handled (and Mariot provided patch for > both though Linda's solution for the second seems more appropriate). Yes, this could potentially be split into 2 bugs. If we were paranoid about maintaining compatibility, then the proper GEF fix would have to be: public Rectangle getCopy() { if (getClass() != Rectangle.class) try { return (Rectangle)clone(); } catch (CloneNotSupportedException exc) { } return new Rectangle(x,y,width,height); } Would this implementation still show the performance improvements as the one in comment 9?
Randy, yes, it would since your code is exactly what the copy constructor does. public Rectangle(Rectangle rect) { this(rect.x, rect.y, rect.width, rect.height); } Of course if we were truly looking at the nanosec, your code would probably be better as it makes one less method call. I'd rather see the copy constructor used as far as readability is concerned though.
(In reply to comment #27) > I still wonder why 10 000 calls to BorderItemsAwareFreeFormLayer.getBounds() > result in 1 000 000 calls to BorderNodeFigure.getExtendedBounds() for a mere > thousand LEDs in the diagram, yet since the actual cost of those invocations > is the Rectangle.getCopy, it still is nice reduce it. I'm a bit puzzled by these numbers. Using GMF 2.2 I only measured 8,936 calls to BorderNodeFigure#getExtendedBounds() when I opened the attached test7_gmf_logic.logic2 diagram that has 1,117 LEDs (zoomed to fit, so that they're all visible). That's an 8:1 ratio. Then I realized that I didn't have the outline view open. I opened the outline view and re-opened the diagram, and got 32,393 calls to BorderNodeFigure#getExtendedBounds(). That's a 29:1 ratio, which is pretty bad, but it's still a long way from the 1,000,000 calls that you measured. Using GMF 2.1.2 I got 25,691 calls to BorderNodeFigure#getExtendedBounds() for this same scenario (23:1), so it looks like we've actually regressed a bit in 2.2. I'm counting the number of calls just by printing out a counter value from BorderNodeFigure#getExtendedBounds(). How did you count yours? Do you have other views open that might affect the count? I also checked that caching the extended bounds in BorderedNodeFigure still reduces the ratio to 1:1 even when the outline view is open. However, I don't know if this is a viable solution -- is it safe to cache this value?
(In reply to comment #34) > I'm counting the number of calls just by printing out a counter value from > BorderNodeFigure#getExtendedBounds(). How did you count yours? Do you have > other views open that might affect the count? At first, I used the same approach wtih a counter value I printed out. Then I used yourkit java profiler and observed the same results. I then abandonned my counters and relied on Yourkit for all instruction counts. The two images I've attached to this bug show my results. I'm on the Java perspective with only Package Explorer, Outline and Problems views opened and showing. My diagram was _not_ zoomed to fit so all nodes weren't showing. Then again, the version of GMF I'm using for these tests is the same as what we use for our clients : 2.0.1. My configuration is on comment #4 . With the numbers you get, I understand why this issue has never been found out though ... Makes me fear that this is yet another linux-specific problem :/. I'll try out this very same test case under ganymede / GMF 2.2 > > I also checked that caching the extended bounds in BorderedNodeFigure still > reduces the ratio to 1:1 even when the outline view is open. However, I don't > know if this is a viable solution -- is it safe to cache this value? > I really cannot answer this question. Guess this is directed at Anthony or Alex.
Linda, the same test case (TEST #7) with eclipse 3.4 / GMF 2.2 gives me results approximately equal to yours with ~30 000 calls to BorderedNodeFigure.getExtendedBounds() when opening a diagram with the outline opened. The 7 digits figures I was observing were due to an issue in GMF 2.0.1. If you do manage to take down those calls to a 1:1 ratio, would it be possible for the fix to be backported to 2.0 maintenance?
The number of calls to BorderedNodeFigure#invalidate() can be very large in 2.1.2 due the bug I've introduced in 2.1.2. This has been fixed in 2.1.3 and 2.2 with bug 250018. Now, we don't cache extended bounds on the bordered node figure, because the extended bounds of a bordered node figure are determined by border item container figure (a child), where extended bounds are cached. So, by chaching extended bounds on the bordered node figure will save only on calculating the union of two rectangles.
(In reply to comment #36) Laurent, if the solution turns out to be suitable for the 2.0 maintenance branch we could deliver it to CVS. However, it is my understanding that we aren't doing 2.0 maintenance builds anymore, so you would have to do the build yourselves (maybe you'd only need to build the one plug-in jar that contains the fix...). (In reply to comment #37) Alex, even though caching the extended bounds on the BorderedNodeFigure will only save on calculating the union of two rectangles, it is this calculation that is expensive because it makes those two calls to Rectangle#getCopy(). When a diagram is opened (with outline view) this calculation is done 29 times for each visible node on the diagram (in GMF 2.2). Mariot has proposed a patch that cuts the number of calls to Rectangle#getCopy() in half, which is great. I thought that maybe we could also improve things by caching the extended bounds so that the calculation is only done 1 time for each visible node on the diagram when the diagram opens. Do you think it will be safe to cache the extended bounds for the BorderedNodeFigure?
Yes, I think it'll be safe. We could just make caching for BorderedNodeFigure the same as it is on BorderItemContainerFigure, since it directly depends on the latter.
Created attachment 122267 [details] Merged Mariot's patch with the fix to cache the extended bounds in BorderedNodeFigure. As per Alex's suggestion, I implemented the cached extended bounds just like it's implemented in BorderItemContainerFigure, which clears the cached value on #invalidate(), #validate() and #fireFigureModed(). With this implementation, the ratio of #getExtendedBounds calculation to nodes is 3:1 when I open the attached test_7_gmf_logic.logic2.
Nice :). We'll have to build manually with this last patch as this yields even better results with GMF 2.0... shame we cannot simply have our clients switch to 2.2 :(. While I'm at it, Randy : if you do patch GEF to avoid the call to clone() when the Rectangle is not a subclass, will this be backported to the GEF 3.3.2 maintenance or will we need to have our own build? Thanks for your time!
(In reply to comment #41) > While I'm at it, Randy : if you do patch GEF to avoid the call to clone() when > the Rectangle is not a subclass, will this be backported to the GEF 3.3.2 > maintenance or will we need to have our own build? > Since we now have two fixes we need a new GEF bugzilla for the GEF patch. I can commit to the GEF 3.3.2 stream in CVS but there will be no further GEF 3.3.2 builds.
(In reply to comment #42) > (In reply to comment #41) > > While I'm at it, Randy : if you do patch GEF to avoid the call to clone() when > > the Rectangle is not a subclass, will this be backported to the GEF 3.3.2 > > maintenance or will we need to have our own build? > > > > Since we now have two fixes we need a new GEF bugzilla for the GEF patch. > > I can commit to the GEF 3.3.2 stream in CVS but there will be no further GEF > 3.3.2 builds. > I created bug #260740
Committed Mariot's patch and the additional change to cache the extended bounds in BorderedNodeFigure to: R2_0_maintenance (no builds) R2_1_maintenance (2.1.3, Ganymede SR2) HEAD (2.2 M5, Galileo)
[target cleanup] 2.2 M5 was the original target milestone for this bug
[GMF Restructure] Bug 319140 : product GMF and component Runtime was the original product and component for this bug
