Bug 41434 - [msic] Slow Down using classes with many methods
Summary: [msic] Slow Down using classes with many methods
Status: VERIFIED FIXED
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 2.1   Edit
Hardware: PC Windows 2000
: P2 critical (vote)
Target Milestone: 3.0 RC3   Edit
Assignee: Philipe Mulet CLA
QA Contact:
URL:
Whiteboard:
Keywords: performance
Depends on:
Blocks:
 
Reported: 2003-08-12 05:30 EDT by Mathias Supp CLA
Modified: 2004-06-18 11:09 EDT (History)
7 users (show)

See Also:


Attachments
RePro-Code creator including example RePro-Code (282.41 KB, application/octet-stream)
2003-08-12 05:38 EDT, Mathias Supp CLA
no flags Details
stack traces of the console during eclipse is working (3.94 KB, application/octet-stream)
2003-08-15 11:02 EDT, Mathias Supp CLA
no flags Details
trace of the ui thread (266.25 KB, text/html)
2003-11-17 15:08 EST, Kai-Uwe Maetzel CLA
no flags Details
trace of the reconciler thread (90.53 KB, text/html)
2003-11-17 15:08 EST, Kai-Uwe Maetzel CLA
no flags Details
Proposed fix (1.82 KB, patch)
2004-06-16 11:07 EDT, Philipe Mulet CLA
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Mathias Supp CLA 2003-08-12 05:30:28 EDT
I'm currently developing a class implementing a visitor-interface having many
methods and refering to many classes.
In my special case with about 300 methods I have to wait 10-30 seconds on my
PIII 866 (512MB RAM).
To enable a repro I wrote a class creating a set of classes/interfaces - to be
exactly 1000 classes and interface with 1000 methods and a class implementing
these 1000 methods.
Please try to open the class "MyVisitor" enter something and save and the
problem got clear.
Please replace the hardcoded destination directory for the creation.

package org.eclipse.slowdown;

import java.io.BufferedWriter;
import java.io.File;
import java.io.FileWriter;
import java.io.IOException;

public class SlowDownClassesCreator {

	public static void main(String[] args) throws IOException {
		int  i;
		BufferedWriter currentClassWriter;			
		BufferedWriter interfaceWriter;			
		BufferedWriter implemetorWriter;			
		String         packageDeclaration  = "package org.eclipse.slowdown.repro;\n";
		File           baseDir             = new
File("C:\\Java\\Eclipse2.1\\workspace\\ZZZ Tests
Mathias\\source\\org\\eclipse\\slowdown\\repro");

		currentClassWriter = new BufferedWriter(new FileWriter(new File(baseDir,
"NodeInterface.java")));
		currentClassWriter.write(packageDeclaration);
		currentClassWriter.write("public interface NodeInterface {\n}\n");
		currentClassWriter.close();
		
		currentClassWriter = new BufferedWriter(new FileWriter(new File(baseDir,
"BaseNode.java")));
		currentClassWriter.write(packageDeclaration);
		currentClassWriter.write("public class BaseNode implements NodeInterface {\n}\n");
		currentClassWriter.close();
		
		interfaceWriter = new BufferedWriter(new FileWriter(new File(baseDir,
"Visitor.java")));
		interfaceWriter.write(packageDeclaration);
		interfaceWriter.write("public interface Visitor {\n\n");
		
		implemetorWriter = new BufferedWriter(new FileWriter(new File(baseDir,
"MyVisitor.java")));
		implemetorWriter.write(packageDeclaration);
		implemetorWriter.write("public class MyVisitor implements Visitor {\n");
		
		for( i = 0; i < 1000; i++ ) {
			currentClassWriter = new BufferedWriter(new FileWriter(new File(baseDir,
"Node" + i + ".java")));
			currentClassWriter.write(packageDeclaration);
			currentClassWriter.write("public class Node" + i + " extends BaseNode {\n\n");
			currentClassWriter.write("\tpublic Object accept(Visitor v, Object data) {\n");
			currentClassWriter.write("\t\treturn v.visit(this, data);\n"); 
			currentClassWriter.write("\t}\n"); 
			currentClassWriter.write("\n}\n");
			
			interfaceWriter.write("\tObject visit(Node" + i + " n, Object data);\n");
			implemetorWriter.write("\tpublic Object visit(Node" + i + " n, Object data)
{\n");
			implemetorWriter.write("\t\treturn null;\n"); 
			implemetorWriter.write("\t}\n"); 
			
			currentClassWriter.close();
		}
		
		implemetorWriter.write("\n}\n");
		interfaceWriter.write("\n}\n");
		
		implemetorWriter.close();
		interfaceWriter.close();
	}
	
}
Comment 1 Mathias Supp CLA 2003-08-12 05:33:35 EDT
Sorry for the inplace-repro-code :-(
I just didn't know there is a way to attach files.
Comment 2 Mathias Supp CLA 2003-08-12 05:38:26 EDT
Created attachment 5719 [details]
RePro-Code creator including example RePro-Code

Attached repro-code for simple import into eclipse.
Comment 3 Kai-Uwe Maetzel CLA 2003-08-13 03:32:05 EDT
Please describe which operations take 10 - 30 seconds. Also please give some 
details about your perspective, i.e., open views, editors, etc.
Thanks.
Comment 4 Mathias Supp CLA 2003-08-13 07:37:08 EDT
> Please describe which operations take 10 - 30 seconds.

- opening the given example class MyVisitor takes about 1 minute on my machine
- changes on any method within MyVisitor plus Save takes about 1minute until
  I can enter something again
  (it seems compiling is quite fast, because if I make changes on the
   file externally and perform a refresh in Eclipse without having
   the source in the editor compiling takes about some seconds)

> Also please give some details about your perspective,
> i.e., open views, editors, etc.

I've used the Java-Perspective with the views:
- Package Explorer/Navigator
- Outline/Bookmarks
- Console/Search/Tasks/CVS Repositories
- Java Editor

I disabled the Package Explorer to show members of classes.
I turned off Annotations to ensure that's not the problem. Even closing
the Outline-View didn't help.

Hope this helped a bit.
Thanks for your efforts.

Mathias
Comment 5 Dani Megert CLA 2003-08-15 10:20:33 EDT
Please start Eclipse with the following line (all on 1 line):

%SDK% %VMOptions% -verify -cp startup.jar org.eclipse.core.launcher.Main -update
-application org.eclipse.ui.workbench -showlocation -data %TARGET%

%SDK%= the JRE (full path)
%VMOptions%= VM options
%TARGET%= workspace location (full path)

You can then press Ctrl+Break in the console to get a stack trace.
Comment 6 Mathias Supp CLA 2003-08-15 11:02:33 EDT
Created attachment 5784 [details]
stack traces of the console during eclipse is working

This ZIP contains two stack traces:
1. OpeningFile.txt
   This shows the stack trace when I'm waiting for eclipse to open
   the file and make it editable
2. SaveFile.txt
   This shows the stack trace when I'm waiting for eclipse to be
   ready after saving the source code after adding one empty line
Comment 7 Dani Megert CLA 2003-08-18 03:53:54 EDT
OpeningFile.txt contains the save dump and SaveFile.txt contains the open dump.

Adding a J Core member to comment: I assume that parsing and populating the Java
Model takes some time.

Later (on save)  the override indicator label decorators seem to take some time.
Mathias can you check whether closing the Outline view has some inpact.
Comment 8 Mathias Supp CLA 2003-08-18 04:02:21 EDT
> Later (on save)  the override indicator label decorators seem to take some time.
> Mathias can you check whether closing the Outline view has some inpact.

I can.
Do you want me to create a new stack dump?
Because I already checked if there are significant performance improvements
when I close the outline: about 10-20%.
Comment 9 Mathias Supp CLA 2003-08-19 04:24:58 EDT
New insights:
When I disucussed the performance issue with me collegues we had an idea
and tested something about overloading against different method names.
Currently we have 1000 methods with the same name and different parameter
types. Opening this class costs 300secs on my PIII 866/512MB.
When I create 1000 different method names (visit1, visit2, ...) instead of
overloading it costs only 2secs to open!
Even save of changes is significant faster:
- overloaded version: 25secs
- different names version: 2secs

Was my description understandable?
Comment 10 Dani Megert CLA 2003-08-25 09:23:13 EDT
Yes. thanks a lot for the info. We will have to investigate this post M3.

Comment 11 Kai-Uwe Maetzel CLA 2003-11-17 15:08:02 EST
Created attachment 6817 [details]
trace of the ui thread
Comment 12 Kai-Uwe Maetzel CLA 2003-11-17 15:08:56 EST
Created attachment 6818 [details]
trace of the reconciler thread
Comment 13 Kai-Uwe Maetzel CLA 2003-11-17 15:09:49 EST
Seems that we spend most of the type computing and resolving type hierarchies.
Comment 14 Tom Hofmann CLA 2004-06-16 04:17:49 EDT
On a fairly fast (2.4 GHz) Linux / RH9 machine (GTK), I observe the following
numbers:

press Enter in the package explorer on MyVisitor.java: 0  s
opening MyVisitor.java:                                6  s
'implements' decorations show up in the outline:       16 s (+10 after opening)
Comment 15 Christof Marti CLA 2004-06-16 09:10:53 EDT
SourceMethod does not override hashCode() which means that overloaded methods
have the same hash code and end up in the same bucket in hash tables. Running
with a SourceMethod#hashCode() implementation like:

public int hashCode() {
	int h= super.hashCode();
	if (this.parent != null)
		for (int i= 0, n= fParameterTypes.length; i < n; i++)
			h= Util.combineHashCodes(h, fParameterTypes[i].hashCode());
	return h;
}

resolves this regression.

Moving to JDT/Core.
Comment 16 Philipe Mulet CLA 2004-06-16 10:26:59 EDT
Excellent find, I was just looking at it as well (glancing at the trace you 
had attached).
Comment 17 Philipe Mulet CLA 2004-06-16 10:54:15 EDT
Kai - are you supporting fixing it for RC3 ?
Comment 18 Philipe Mulet CLA 2004-06-16 11:06:09 EDT
BinaryMethod needs same fix as well. 
Proposed fix:
/**
 * @see org.eclipse.jdt.internal.core.JavaElement#hashCode()
 */
public int hashCode() {
   int hash = super.hashCode();
	for (int i = 0, length = fParameterTypes.length; i < length; i++) {
	    hash = Util.combineHashCodes(fParameterTypes[i].hashCode(), hash);
	}
	return hash;
}
Comment 19 Philipe Mulet CLA 2004-06-16 11:06:29 EDT
Jerome - pls verify change.
Comment 20 Philipe Mulet CLA 2004-06-16 11:07:44 EDT
Created attachment 12254 [details]
Proposed fix
Comment 21 Darin Wright CLA 2004-06-16 11:20:38 EDT
+1 for RC3
Comment 22 Jerome Lanneluc CLA 2004-06-16 11:33:13 EDT
Patch is good.
Comment 23 Philipe Mulet CLA 2004-06-16 11:33:54 EDT
Releasing fix.
Comment 24 Philipe Mulet CLA 2004-06-16 12:26:36 EDT
From Christoph: I just found that the parameters to Util.combineHashCodes(..) 
should be swapped. Otherwise test(Object, String) and test(String, Object) 
would have the same hashCode().
Comment 25 Philipe Mulet CLA 2004-06-16 12:26:57 EDT
From Christoph: I just found that the parameters to Util.combineHashCodes(..) 
should be swapped. Otherwise test(Object, String) and test(String, Object) 
would have the same hashCode().
Comment 26 Philipe Mulet CLA 2004-06-16 12:30:16 EDT
Indeed, I should have followed your original suggestion. Will fix that, it is 
a minor improvement, but still interesting.
Comment 27 David Audel CLA 2004-06-18 11:09:34 EDT
Verified for 3.0RC3 I200406180800