Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.
Bug 297053 - Performance significantly decreased in 0.8.0 stream
Summary: Performance significantly decreased in 0.8.0 stream
Status: CLOSED FIXED
Alias: None
Product: M2T
Classification: Modeling
Component: Xpand (show other bugs)
Version: 0.8.0   Edit
Hardware: PC Mac OS X - Carbon (unsup.)
: P3 normal (vote)
Target Milestone: M4   Edit
Assignee: Darius Jockel CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2009-12-07 05:02 EST by Sven Efftinge CLA
Modified: 2013-02-21 08:11 EST (History)
4 users (show)

See Also:
sven.efftinge: helios+


Attachments
Patch for bug 297053 and testcase (4.76 KB, patch)
2009-12-09 04:53 EST, Darius Jockel CLA
sven.efftinge: iplog+
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Sven Efftinge CLA 2009-12-07 05:02:55 EST
Hi folks,

I'm just experimenting with moving to 0.8.0 from 0.7.2 and I've noticed an, um.. significant change in performance characteristics. By significant, I mean that a model that was taking 1 second to generate is now taking 45 seconds . In general I'm seeing a 25-40x slow-down. This is with 0.8.0 v 2009092913 of Xpand, MWE, etc.. I've upgraded xtext as well but this happens on purely EMF based projects as well. Nothing else has changed (except for some API fixes for xtext in unrelated plugins) -- I've verified by reverting to each configuration.

Any guesses about what might be causing this? Areas where performance has been optimized for different cases? My templates are quite complex and use aspects and a lot of xtend calls.

I don't this this the class loader issues as the whole process seems to be much slower and again I haven't changed anything else.

cheers,
Miles

see: http://www.eclipse.org/forums/index.php?t=msg&th=157284&start=0&S=4d190433f14336676a612f80b6330c4e
Comment 1 Sven Efftinge CLA 2009-12-07 05:05:59 EST
Hi all,

> [...]
> significant, I mean that a model that was taking 1 second to generate is now taking 45 seconds . In general I'm seeing a 25-40x slow-down. This [...]

just tried to reproduce this using a workflow from the emfmodelvisualizer project [1]. On my machine, this workflow takes about 1.5 seconds with 0.7.2 and ~3 seconds using a 0.8 version. I was able to track it down to the following change in the EmfRegistryMetaModel:

@@ -262,20 +263,33 @@ public class EmfRegistryMetaModel implements MetaModel {
                return getTypeForEClassifier(el.getEEnum());
            }
            final EClass clazz = ((EObject) obj).eClass();
            return getTypeForEClassifier(clazz);
        }
+       
+        final Set<Type> types = getKnownTypes();
        if (obj instanceof Enumerator) {
-            final Set<Type> types = getKnownTypes();
            for (Type t : types) {
+                // check for EEnumType because the EDataTypeType for
+                // ecore::EEnumerator matches all enumerator instances
                if (t instanceof EEnumType) {
                    if (t.isInstance(obj)) {
                        return t;
                    }
                }
            }
+        } else {
+            // some other non-enumerated EDataType
+            for (Type t : types) {
+                if (t instanceof EDataTypeType) {
+                    if (t.isInstance(obj)) {
+                        return t;
+                    }
+                }
+            }
        }
+       
        return null;
    }

    public Set<Type> getKnownTypes() {
        final Set<Type> result = new HashSet<Type>();


without the else branch (which is executed for tons of objects, e.g. all Strings, Integers,...), it only took 1.5 seconds again. But simply removing it won't be a solution, as it has been added to fix a bug [2].
Although this is "only" factor 2 (in contrast to 25-40x) for this workflow, it probably is at least one of the causes of what you observed.

> --- [ekke wrote] ---
> after discussion with Karsten Thoms: there's some work-in-progress and no bugzilla needed at the moment

Is this still true? Or should I put this information into a new bug report?

Regards,
Daniel

[1] http://code.google.com/p/emfmodelvisualizer/source/browse/galileo/trunk/org.openarchitectureware.vis.graphviz.demo/src/visualizeEcore.mwe
[2] https://bugs.eclipse.org/bugs/show_bug.cgi?id=281269
Comment 2 Sven Efftinge CLA 2009-12-07 05:22:29 EST
Darius is working on it
Comment 3 ekkehard gentz CLA 2009-12-07 09:40:09 EST
(In reply to comment #2)
> Darius is working on it

great to hear this, because this blocks my move from 0.7.2 to 0.8.0

ekke
Comment 4 Karsten Thoms CLA 2009-12-07 10:12:55 EST
It should be examined whether EmfRegistryMetaModel#getKnownTypes() is valid to be cached. This solves the performance bottleneck.
Comment 5 Sven Efftinge CLA 2009-12-07 10:22:57 EST
(In reply to comment #4)
> It should be examined whether EmfRegistryMetaModel#getKnownTypes() is valid to
> be cached. This solves the performance bottleneck.

No it doesn't, as it is already cached.
The problem is the iteration over all known types. See the comment of Daniel Weber.
Comment 6 Daniel Weber CLA 2009-12-07 10:44:41 EST
(In reply to comment #5)
> (In reply to comment #4)
> > It should be examined whether EmfRegistryMetaModel#getKnownTypes() is valid to
> > be cached. This solves the performance bottleneck.
> 
> No it doesn't, as it is already cached.
> The problem is the iteration over all known types. See the comment of Daniel
> Weber.

I'm sorry, my original description was a little misleading. What brought me back to the original performance was

 1. removal of the else branch 
*and*
 2. Moving the call of getKnownTypes() back into the if branch.

==>

       if (obj instanceof Enumerator) {
                 final Set<Type> types = getKnownTypes();
			for (Type t : types) {
				// check for EEnumType because the EDataTypeType for
				// ecore::EEnumerator matches all enumerator instances
				if (t instanceof EEnumType) {
					if (t.isInstance(obj)) {
						return t;
					}
				}
			}
		}
		return null;
	}

The most expensive part really seems to be getKnownTypes(). The EmfRegistryMetaModel only caches the mappings from EClassifier to Type, but getKnownTypes() iterates over all available packages and all of the packages' classifiers every single time. 

Question is: Does the list of available packages change during the MetaModel's lifetime? As is uses EMF's registry, packages may be added at any time. So yes, the list can and most probably will change. But will the contents of the packages change as well? In theory one could register a dynamic package and add more classifiers at runtime... But does this really have to be supported? If not we could at least cache a list of classifiers per package.
Comment 7 Sven Efftinge CLA 2009-12-07 11:16:00 EST
(In reply to comment #6)
> The most expensive part really seems to be getKnownTypes(). The
> EmfRegistryMetaModel only caches the mappings from EClassifier to Type, but
> getKnownTypes() iterates over all available packages and all of the packages'
> classifiers every single time. 

Looking into the code it tells me that the set in geKnownTypes() is only computed once:

private Set<Type> knownTypes = null;
public Set<Type> getKnownTypes() {
  if (knownTypes == null) {
    final Set<Type> result = new HashSet<Type>();
    //....
    knownTypes = result;
  }
  return knownTypes;
}


> 
> Question is: Does the list of available packages change during the MetaModel's
> lifetime? As is uses EMF's registry, packages may be added at any time. So yes,
> the list can and most probably will change. But will the contents of the
> packages change as well? In theory one could register a dynamic package and add
> more classifiers at runtime... But does this really have to be supported? If
> not we could at least cache a list of classifiers per package.

No, we don't support changes in the EPackageRegistry.
Comment 8 Daniel Weber CLA 2009-12-07 11:43:31 EST
(In reply to comment #7)
> [...]
> Looking into the code it tells me that the set in geKnownTypes() is only
> computed once:
> 
> private Set<Type> knownTypes = null;
> public Set<Type> getKnownTypes() {
>   if (knownTypes == null) {
>     final Set<Type> result = new HashSet<Type>();
>     //....
>     knownTypes = result;
>   }
>   return knownTypes;
> }
>[...]

OK, it has been changed to work that way just yesterday, disguised as "resolved compiler warnings". I didn't have that change yet (git mirrors are currently out of date: #297060). So this seems to have been solved already. Sorry.
Comment 9 Darius Jockel CLA 2009-12-09 04:53:19 EST
Created attachment 154100 [details]
Patch for bug 297053 and testcase
Comment 10 Darius Jockel CLA 2009-12-09 04:57:19 EST
Please check the attached patch to improve the performance of the 0.8.0 stream again. 

The changes are done in respect to the bug 281269.
If you want to use self defined datatypes, you have to add the javabeans metamodel now.

Regards
Darius
Comment 11 Sven Efftinge CLA 2009-12-09 05:51:34 EST
Patch applied. Thanks!
Comment 12 Darius Jockel CLA 2009-12-09 08:28:31 EST
(In reply to comment #3)
> (In reply to comment #2)
> > Darius is working on it
> 
> great to hear this, because this blocks my move from 0.7.2 to 0.8.0
> 
> ekke

Hi,

the patch seems to be working with uml2.
Can you please verify this?

Regards
Darius
Comment 13 ekkehard gentz CLA 2009-12-09 08:40:11 EST
> 
> Hi,
> 
> the patch seems to be working with uml2.
> Can you please verify this?
latest N-Build is from N200912081945
so I'll try it tomorrow with the next one

ekke
Comment 14 Daniel Weber CLA 2009-12-11 01:55:54 EST
(In reply to comment #1)
> [...] I was able to track it down to the following change [...]

... and it only took me a few minutes :-) 

Just in case you're interested, read this: 

   http://danielweber.github.com/2009/12/10/bisecting-history.html
Comment 15 ekkehard gentz CLA 2009-12-12 09:35:44 EST
the good news:
performance problem is fixed -
runs same speed as before with 0.7.2

the bad news:
now I'm getting hundreds of those warnings:

15:25:52.299 WARN  [o.e.xtend.typesystem.emf.EClassType] Couldn't resolve type for EDiagnosticChain
15:25:52.299 WARN  [o.e.xtend.typesystem.emf.EClassType] Couldn't resolve type for EMap

but my workflow seems to be ok

I'm using N200912111914 MWE, Xpand, Xtext

shoukd I open a new bugzilla or reopen this one ?

ekke
Comment 16 ekkehard gentz CLA 2009-12-19 09:13:07 EST
(In reply to comment #15)
> now I'm getting hundreds of those warnings:
> 
> 15:25:52.299 WARN  [o.e.xtend.typesystem.emf.EClassType] Couldn't resolve type
> for EDiagnosticChain
> 15:25:52.299 WARN  [o.e.xtend.typesystem.emf.EClassType] Couldn't resolve type
> for EMap
> 
since 0.8.0.M4 this is fixed
Comment 17 Karsten Thoms CLA 2013-02-21 08:11:26 EST
Bug resolved before Xpand 1.2 release date => Closing