Re: [aspectj-users] Bad performance of 1.6.4 opposed to 1.6.3

[Andy Clement <andrew.clement@xxxxxxxxx>]

A whitespace change should trigger a build of a few hundred milliseconds at most.

If the project you changed was 'com.dcx.ivkmds.fwk.common.ass.persist' then that build time looks too long - i see it is 1937ms with 1.6.4 and was 1078ms with 1.6.3. Both of those look far too long.  But I don't know precisely what you changed - a file affected by many aspects?  You can turn on other debugging in the AJDT event trace view to get more feedback on decisions made during compilation - try that and see if you get diagnostics that indicate what is happening.

Some of the later times in the 1.6.4 list look like full builds have been performed rather than incremental builds.  Again, turning on the extra diagnostics may indicate why.  I think it is worth you raising a bug with those extra diagnostics in.

Andy.

2009/3/16 Thomas M. Hofmann <email@xxxxxxxxxxxxxxxxx>

Hi,

 

As I’ve already written here before, I am planning for a migration from RSA 7.0 to RSA 7.5. One of the issues we are having with AJDT 1.4.x in eclipse 3.2.x (RSA 7.5) is performance.

I test AJDT 1.6.3 in both eclipse 3.4 and RSA 7.5. The performance improvement in 1.6 is considerable comparing to 1.4.

 

Now, when I installed 1.6.4 dev build I noticed that much of the performance improvement is no longer there.

 

Let me explain what I am testing to judge performance. I pick a file in a project on which a number of other projects depend and just add a blank line. In my opinion, this should not lead to workspace builds that take more than a few seconds. Otherwise it is very tedious to make changes to projects that lots of other projects depend on.

 

I’ve extracted the relevant parts from the AJDT trace (taken with AJDT 1.6.3 and AJDT 1.6.4 RC). The time spent in AJBuilder is considerably longer in 1.6.4. One explanation I have for this is that the crosscutting model is checked when the AJDT trace is on (the view is opened). The problem is that is doesn’t get noticeable faster when the AJDT trace view is closed!

 

Is it absolutely sure that the crosscutting model isn’t checked when the view is closed?

 

I’m not sure if attachments work on the list but I’m including both traces. There are many warnings relating to the crosscutting model sanity checks which I would like to get explained too.

 

 

Here is the trace comparison:

 

 

List of projects built by AJDT 1.6.3:

 

11:10:34 Project=com.dcx.ivkmds.fwk.common.ass.persist, kind of build requested=Incremental AspectJ compilation

11:10:34 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:34 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:10:35 Timer event: 1078ms: Total time spent in AJBuilder.build()

 

11:10:40 Project=com.dcx.ivkmds.fwk.common.businessobjects.persistent, kind of build requested=Incremental AspectJ compilation

11:10:40 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.common.businessobjects.persistent

11:10:40 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:40 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:10:40 Timer event: 328ms: Total time spent in AJBuilder.build()

 

11:10:41 Project=com.dcx.ivkmds.fwk.rcs, kind of build requested=Incremental AspectJ compilation

11:10:41 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.rcs

11:10:41 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:41 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:10:42 Timer event: 1500ms: Total time spent in AJBuilder.build()

 

11:10:42 Project=com.dcx.ivkmds.csolver.cts, kind of build requested=Incremental AspectJ compilation

11:10:42 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.csolver.cts

11:10:42 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:42 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:10:44 Timer event: 1500ms: Total time spent in AJBuilder.build()

 

11:10:44 Project=com.dcx.ivkmds.common.businessobjects.persistent, kind of build requested=Incremental AspectJ compilation

11:10:44 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.common.businessobjects.persistent

11:10:44 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:44 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:10:45 Timer event: 984ms: Total time spent in AJBuilder.build()

 

11:10:45 Project=com.dcx.ivkmds.common.businessobjects.fwktest, kind of build requested=Incremental AspectJ compilation

11:10:45 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.common.businessobjects.fwktest

11:10:45 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:45 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:10:46 Timer event: 360ms: Total time spent in AJBuilder.build()

 

11:10:54 Project=com.dcx.ivkmds.fwk.ass, kind of build requested=Incremental AspectJ compilation

11:10:54 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.ass

11:10:54 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:54 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:10:54 Timer event: 563ms: Total time spent in AJBuilder.build()

 

11:10:55 Project=com.dcx.ivkmds.application.ass, kind of build requested=Incremental AspectJ compilation

11:10:55 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.application.ass

11:10:55 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:55 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:10:57 Timer event: 2797ms: Total time spent in AJBuilder.build()

 

11:10:57 Project=com.dcx.ivkmds.csolver.ass, kind of build requested=Incremental AspectJ compilation

11:10:57 Timer event: 125ms: Post compile

11:10:57 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.csolver.ass

11:10:57 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:57 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:10:58 Timer event: 515ms: Total time spent in AJBuilder.build()

 

11:10:59 Project=com.dcx.ivkmds._45_export_import.ass, kind of build requested=Incremental AspectJ compilation

11:10:59 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds._45_export_import.ass

11:10:59 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:10:59 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:11:0 Timer event: 1094ms: Total time spent in AJBuilder.build()

 

11:11:2 Project=com.dcx.ivkmds._00_fwktest.ass, kind of build requested=Incremental AspectJ compilation

11:11:2 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds._00_fwktest.ass

11:11:2 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:11:2 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:11:2 Timer event: 235ms: Total time spent in AJBuilder.build()

 

11:11:2 Project=com.dcx.ivkmds.testfwk, kind of build requested=Incremental AspectJ compilation

11:11:2 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.testfwk

11:11:2 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:11:2 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist                                                                                                                              

11:11:3 Timer event: 969ms: Total time spent in AJBuilder.build()

 

11:11:3 Project=com.dcx.ivkmds.fwk.test.rcs, kind of build requested=Incremental AspectJ compilation

11:11:3 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.test.rcs

11:11:3 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:11:3 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:11:4 Timer event: 906ms: Total time spent in AJBuilder.build()

 

11:11:4 Project=com.dcx.ivkmds.fwk.test.ass, kind of build requested=Incremental AspectJ compilation

11:11:4 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.test.ass

11:11:4 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:11:4 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:11:5 Timer event: 1125ms: Total time spent in AJBuilder.build()

 

11:11:5 Project=com.dcx.ivkmds.fwk.test.common, kind of build requested=Incremental AspectJ compilation

11:11:5 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.test.common

11:11:5 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:11:5 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

11:11:6 Timer event: 813ms: Total time spent in AJBuilder.build()

 

11:11:6 Project=com.dcx.ivkmds._45_export_import.test.ass, kind of build requested=Incremental AspectJ compilation

11:11:6 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds._45_export_import.test.ass

11:11:6 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

11:11:7 Timer event: 781ms: Total time spent in AJBuilder.build()

 

 

 

 

 

 

List of projects built by AJDT 1.6.4:

 

14:54:56 Project=com.dcx.ivkmds.fwk.common.ass.persist, kind of build requested=Incremental AspectJ compilation

14:54:56 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:54:56 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:54:58 Timer event: 1937ms: Total time spent in AJBuilder.build()

 

14:55:4 Project=com.dcx.ivkmds.fwk.common.businessobjects.persistent, kind of build requested=Incremental AspectJ compilation

14:55:4 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.common.businessobjects.persistent

14:55:4 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:55:4 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:55:6 Timer event: 1266ms: Total time spent in AJBuilder.build()

 

14:55:7 Project=com.dcx.ivkmds.fwk.rcs, kind of build requested=Incremental AspectJ compilation

14:55:7 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.rcs

14:55:7 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:55:7 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:55:11 Timer event: 4953ms: Total time spent in AJBuilder.build()

 

14:55:11 Project=com.dcx.ivkmds.csolver.cts, kind of build requested=Incremental AspectJ compilation

14:55:11 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.csolver.cts

14:55:11 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:55:11 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:55:13 Timer event: 2469ms: Total time spent in AJBuilder.build()

 

14:55:14 Project=com.dcx.ivkmds.common.businessobjects.persistent, kind of build requested=Incremental AspectJ compilation

14:55:14 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.common.businessobjects.persistent

14:55:14 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:55:14 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:55:23 Timer event: 9266ms: Total time spent in AJBuilder.build()

 

14:55:24 Project=com.dcx.ivkmds.common.businessobjects.fwktest, kind of build requested=Incremental AspectJ compilation

14:55:24 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.common.businessobjects.fwktest

14:55:24 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:55:24 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:55:25 Timer event: 1265ms: Total time spent in AJBuilder.build()

 

14:56:28 Project=com.dcx.ivkmds.fwk.ass, kind of build requested=Incremental AspectJ compilation

14:56:28 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.ass

14:56:28 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:56:28 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:56:32 Timer event: 3844ms: Total time spent in AJBuilder.build()

 

14:56:32 Project=com.dcx.ivkmds.application.ass, kind of build requested=Incremental AspectJ compilation

14:56:32 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.application.ass

14:56:32 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:56:32 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:57:9 Timer event: 36640ms: Total time spent in AJBuilder.build()

 

14:57:9 Project=com.dcx.ivkmds.csolver.ass, kind of build requested=Incremental AspectJ compilation

14:57:9 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.csolver.ass

14:57:9 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:57:9 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:57:11 Timer event: 2031ms: Total time spent in AJBuilder.build()

 

14:57:15 Project=com.dcx.ivkmds._45_export_import.ass, kind of build requested=Incremental AspectJ compilation

14:57:15 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds._45_export_import.ass

14:57:15 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:57:15 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:57:25 Timer event: 9578ms: Total time spent in AJBuilder.build()

 

14:57:34 Project=com.dcx.ivkmds._00_fwktest.ass, kind of build requested=Incremental AspectJ compilation

14:57:34 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds._00_fwktest.ass

14:57:34 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:57:34 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:57:36 Timer event: 1985ms: Total time spent in AJBuilder.build()

 

14:57:36 Project=com.dcx.ivkmds.testfwk, kind of build requested=Incremental AspectJ compilation

14:57:36 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.testfwk

14:57:36 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:57:36 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:57:51 Timer event: 14984ms: Total time spent in AJBuilder.build()

 

14:57:51 Project=com.dcx.ivkmds.fwk.test.rcs, kind of build requested=Incremental AspectJ compilation

14:57:51 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.test.rcs

14:57:51 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:57:51 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:57:54 Timer event: 3516ms: Total time spent in AJBuilder.build()

 

14:57:54 Project=com.dcx.ivkmds.fwk.test.ass, kind of build requested=Incremental AspectJ compilation

14:57:54 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.test.ass

14:57:54 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:57:54 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:58:12 Timer event: 17453ms: Total time spent in AJBuilder.build()

 

14:58:12 Project=com.dcx.ivkmds.fwk.test.common, kind of build requested=Incremental AspectJ compilation

14:58:12 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds.fwk.test.common

14:58:12 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:58:12 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:58:14 Timer event: 2094ms: Total time spent in AJBuilder.build()

 

14:58:14 Project=com.dcx.ivkmds._45_export_import.test.ass, kind of build requested=Incremental AspectJ compilation

14:58:14 build: Examined delta - no source file or classpath changes for project com.dcx.ivkmds._45_export_import.test.ass

14:58:14 File: C:\ws\ivk rsa 7.5\com.dcx.ivkmds.fwk.common.ass.persist\src\com\dcx\ivkmds\fwk\common\ass\persist\NlTextProperty.java has changed.

14:58:14 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project com.dcx.ivkmds.fwk.common.ass.persist

14:58:22 Timer event: 7766ms: Total time spent in AJBuilder.build()

 

 

 

Thank you very much,

Thomas

 

 

 

 

 

 

 

 

 

 

 

 

 

 

_______________________________________________
aspectj-users mailing list
aspectj-users@xxxxxxxxxxx
https://dev.eclipse.org/mailman/listinfo/aspectj-users