RE: [aspectj-users] Overall problem with AJDT performance

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
RE: [aspectj-users] Overall problem with AJDT performance
From: Thomas Hofmann <email@xxxxxxxxxxxxxxxxx>
Date: Sat, 10 Oct 2009 11:19:15 +0200
Accept-language: en-US, de-DE
Acceptlanguage: en-US, de-DE
Delivered-to: aspectj-users@xxxxxxxxxxx
List-archive: <https://dev.eclipse.org/mailman/private/aspectj-users>
List-help: <mailto:aspectj-users-request@eclipse.org?subject=help>
List-subscribe: <https://dev.eclipse.org/mailman/listinfo/aspectj-users>, <mailto:aspectj-users-request@eclipse.org?subject=subscribe>
List-unsubscribe: <https://dev.eclipse.org/mailman/listinfo/aspectj-users>, <mailto:aspectj-users-request@eclipse.org?subject=unsubscribe>
Thread-index: AcpJRgPeFC4kEj67SE6ecIwWyH98vAARF+aw
Thread-topic: [aspectj-users] Overall problem with AJDT performance
Here's the output of a complete workspace build (used to be 38 minutes the last time):


11:5:7 Startup information:
   AJDT version: 2.0.1.e35x-20091001-1600 for Eclipse 3.5
   AspectJ Compiler version: 1.6.6
   usingVisualiser=true
   usingXref=true
   usingCUprovider=true
   promptForAutoOpenCrossReference = false
   org.eclipse.ajdt.internal.ui.tracing.checked.filters = set: Compiler,Builder
   ajde.version.at.previous.startup = @AJDEVERSION@
11:5:49 Compiler configuration for project com.dcx.ivkmds.fwk.common.spec.trace.aspectj doesn't know previous state, so assuming EVERYTHING has changed.
11:5:49 ===========================================================================================
11:5:49 Build kind = FULLBUILD
11:5:50 Project=com.dcx.ivkmds.fwk.common.spec.trace.aspectj, kind of build requested=Full AspectJ compilation
11:5:50 Timer event: 9ms: Flush included source file cache
11:5:50 Timer event: 0ms: Check delta
11:5:50 Builder: Tidied output folder(s), removed class files and derived resources
11:5:50 Timer event: 368ms: Pre compile
11:5:50 Compiler configuration for project com.dcx.ivkmds.fwk.common.spec.trace.aspectj has been read by compiler.  Resetting.
11:5:50      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:5:50 Resetting list of modified source files.  Was null
11:5:50 Preparing for build: not going to be incremental because no successful previous full build
11:5:52 Timer event: 2018ms: Time to first compiled message
11:5:52 Timer event: 2032ms: Time to first woven message
11:5:52 AspectJ reports build successful, build was: FULL
11:5:52 AJDE Callback: finish. Was full build: true
11:5:52 Timer event: 2022ms: Total time spent in AJDE
11:5:52 Timer event: 0ms: Refresh after build
11:5:52 Types affected during build = 2
11:5:52 Timer event: 2689ms: Total time spent in AJBuilder.build()
11:5:52 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.common.spec.trace.aspectj
11:6:10 Compiler configuration for project com.dcx.ivkmds.fwk.common.ass.persist doesn't know previous state, so assuming EVERYTHING has changed.
11:6:10 ===========================================================================================
11:6:10 Build kind = FULLBUILD
11:6:10 Project=com.dcx.ivkmds.fwk.common.ass.persist, kind of build requested=Full AspectJ compilation
11:6:10 Timer event: 0ms: Flush included source file cache
11:6:10 Timer event: 0ms: Check delta
11:6:10 Builder: Tidied output folder(s), removed class files and derived resources
11:6:10 Timer event: 55ms: Pre compile
11:6:10 Compiler configuration for project com.dcx.ivkmds.fwk.common.ass.persist has been read by compiler.  Resetting.
11:6:10      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:6:10 Resetting list of modified source files.  Was null
11:6:10 Preparing for build: not going to be incremental because no successful previous full build
11:6:11 Timer event: 735ms: Time to first compiled message
11:6:11 Timer event: 826ms: Time to first woven message
11:6:12 AspectJ reports build successful, build was: FULL
11:6:12 AJDE Callback: finish. Was full build: true
11:6:12 Timer event: 1805ms: Total time spent in AJDE
11:6:12 Timer event: 0ms: Refresh after build
11:6:12 Types affected during build = 47
11:6:12 Timer event: 1873ms: Total time spent in AJBuilder.build()
11:6:12 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.common.ass.persist
11:6:12 Compiler configuration for project com.dcx.ivkmds.fwk.common.businessobjects.persistent doesn't know previous state, so assuming EVERYTHING has changed.
11:6:12 ===========================================================================================
11:6:12 Build kind = FULLBUILD
11:6:12 Project=com.dcx.ivkmds.fwk.common.businessobjects.persistent, kind of build requested=Full AspectJ compilation
11:6:12 Timer event: 0ms: Flush included source file cache
11:6:12 Timer event: 0ms: Check delta
11:6:12 Builder: Tidied output folder(s), removed class files and derived resources
11:6:13 Timer event: 231ms: Pre compile
11:6:13 Compiler configuration for project com.dcx.ivkmds.fwk.common.businessobjects.persistent has been read by compiler.  Resetting.
11:6:13      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:6:13 Resetting list of modified source files.  Was null
11:6:13 Preparing for build: not going to be incremental because no successful previous full build
11:6:13 Timer event: 320ms: Time to first compiled message
11:6:13 Timer event: 324ms: Time to first woven message
11:6:13 AspectJ reports build successful, build was: FULL
11:6:13 AJDE Callback: finish. Was full build: true
11:6:13 Timer event: 401ms: Total time spent in AJDE
11:6:13 Timer event: 0ms: Refresh after build
11:6:13 Types affected during build = 6
11:6:13 Timer event: 635ms: Total time spent in AJBuilder.build()
11:6:13 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.common.businessobjects.persistent
11:6:14 Compiler configuration for project com.dcx.ivkmds.fwk.rcs doesn't know previous state, so assuming EVERYTHING has changed.
11:6:14 ===========================================================================================
11:6:14 Build kind = FULLBUILD
11:6:14 Project=com.dcx.ivkmds.fwk.rcs, kind of build requested=Full AspectJ compilation
11:6:14 Timer event: 0ms: Flush included source file cache
11:6:14 Timer event: 0ms: Check delta
11:6:14 Builder: Tidied output folder(s), removed class files and derived resources
11:6:14 Timer event: 199ms: Pre compile
11:6:14 Compiler configuration for project com.dcx.ivkmds.fwk.rcs has been read by compiler.  Resetting.
11:6:14      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:6:14 Resetting list of modified source files.  Was null
11:6:14 Preparing for build: not going to be incremental because no successful previous full build
11:6:16 Timer event: 1526ms: Time to first compiled message
11:6:16 Timer event: 1555ms: Time to first woven message
11:6:18 AspectJ reports build successful, build was: FULL
11:6:18 AJDE Callback: finish. Was full build: true
11:6:18 Timer event: 4167ms: Total time spent in AJDE
11:6:18 Timer event: 0ms: Refresh after build
11:6:18 Types affected during build = 87
11:6:19 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.rcs
11:6:19 Timer event: 4407ms: Total time spent in AJBuilder.build()
11:6:19 Compiler configuration for project com.dcx.ivkmds.csolver.cts doesn't know previous state, so assuming EVERYTHING has changed.
11:6:19 ===========================================================================================
11:6:19 Build kind = FULLBUILD
11:6:19 Project=com.dcx.ivkmds.csolver.cts, kind of build requested=Full AspectJ compilation
11:6:19 Timer event: 0ms: Flush included source file cache
11:6:19 Timer event: 0ms: Check delta
11:6:19 Builder: Tidied output folder(s), removed class files and derived resources
11:6:19 Timer event: 357ms: Pre compile
11:6:19 Compiler configuration for project com.dcx.ivkmds.csolver.cts has been read by compiler.  Resetting.
11:6:19      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:6:19 Resetting list of modified source files.  Was null
11:6:19 Preparing for build: not going to be incremental because no successful previous full build
11:6:25 Timer event: 6210ms: Time to first compiled message
11:6:25 Timer event: 6331ms: Time to first woven message
11:6:58 AspectJ reports build successful, build was: FULL
11:6:58 AJDE Callback: finish. Was full build: true
11:6:58 Timer event: 38858ms: Total time spent in AJDE
11:6:58 Timer event: 0ms: Refresh after build
11:6:58 Types affected during build = 343
11:6:58 Timer event: 39615ms: Total time spent in AJBuilder.build()
11:6:58 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.csolver.cts
11:7:0 Compiler configuration for project com.dcx.ivkmds.common.businessobjects.persistent doesn't know previous state, so assuming EVERYTHING has changed.
11:7:0 ===========================================================================================
11:7:0 Build kind = FULLBUILD
11:7:0 Project=com.dcx.ivkmds.common.businessobjects.persistent, kind of build requested=Full AspectJ compilation
11:7:0 Timer event: 0ms: Flush included source file cache
11:7:0 Timer event: 0ms: Check delta
11:7:0 Builder: Tidied output folder(s), removed class files and derived resources
11:7:8 Timer event: 7999ms: Pre compile
11:7:9 Compiler configuration for project com.dcx.ivkmds.common.businessobjects.persistent has been read by compiler.  Resetting.
11:7:9      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:7:9 Resetting list of modified source files.  Was null
11:7:9 Preparing for build: not going to be incremental because no successful previous full build
11:7:13 Timer event: 4315ms: Time to first compiled message
11:7:13 Timer event: 4319ms: Time to first woven message
11:7:23 AspectJ reports build successful, build was: FULL
11:7:27 AJDE Callback: finish. Was full build: true
11:7:27 Timer event: 18294ms: Total time spent in AJDE
11:7:27 Timer event: 0ms: Refresh after build
11:7:27 Types affected during build = 326
11:7:27 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.common.businessobjects.persistent
11:7:27 Timer event: 26606ms: Total time spent in AJBuilder.build()
11:7:30 Compiler configuration for project com.dcx.ivkmds.common.businessobjects.fwktest doesn't know previous state, so assuming EVERYTHING has changed.
11:7:30 ===========================================================================================
11:7:31 Build kind = FULLBUILD
11:7:31 Project=com.dcx.ivkmds.common.businessobjects.fwktest, kind of build requested=Full AspectJ compilation
11:7:31 Timer event: 0ms: Flush included source file cache
11:7:31 Timer event: 4ms: Check delta
11:7:31 Builder: Tidied output folder(s), removed class files and derived resources
11:7:31 Timer event: 327ms: Pre compile
11:7:31 Compiler configuration for project com.dcx.ivkmds.common.businessobjects.fwktest has been read by compiler.  Resetting.
11:7:31      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:7:31 Resetting list of modified source files.  Was null
11:7:31 Preparing for build: not going to be incremental because no successful previous full build
11:7:31 Timer event: 302ms: Time to first compiled message
11:7:31 Timer event: 330ms: Time to first woven message
11:7:32 AspectJ reports build successful, build was: FULL
11:7:32 AJDE Callback: finish. Was full build: true
11:7:32 Timer event: 1430ms: Total time spent in AJDE
11:7:32 Timer event: 0ms: Refresh after build
11:7:32 Types affected during build = 32
11:7:32 Timer event: 1792ms: Total time spent in AJBuilder.build()
11:7:32 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.common.businessobjects.fwktest
11:9:3 Compiler configuration for project com.dcx.ivkmds.fwk.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:9:3 ===========================================================================================
11:9:3 Build kind = FULLBUILD
11:9:3 Project=com.dcx.ivkmds.fwk.ass, kind of build requested=Full AspectJ compilation
11:9:3 Timer event: 0ms: Flush included source file cache
11:9:3 Timer event: 0ms: Check delta
11:9:3 Builder: Tidied output folder(s), removed class files and derived resources
11:9:3 Timer event: 504ms: Pre compile
11:9:4 Compiler configuration for project com.dcx.ivkmds.fwk.ass has been read by compiler.  Resetting.
11:9:4      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:9:4 Resetting list of modified source files.  Was null
11:9:4 Preparing for build: not going to be incremental because no successful previous full build
11:9:8 Timer event: 4175ms: Time to first compiled message
11:9:8 Timer event: 4351ms: Time to first woven message
11:9:14 AspectJ reports build successful, build was: FULL
11:9:14 AJDE Callback: finish. Was full build: true
11:9:14 Timer event: 10734ms: Total time spent in AJDE
11:9:14 Timer event: 0ms: Refresh after build
11:9:14 Types affected during build = 117
11:9:14 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.ass
11:9:14 Timer event: 11302ms: Total time spent in AJBuilder.build()
11:9:16 Compiler configuration for project com.dcx.ivkmds.application.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:9:16 ===========================================================================================
11:9:16 Build kind = FULLBUILD
11:9:16 Project=com.dcx.ivkmds.application.ass, kind of build requested=Full AspectJ compilation
11:9:16 Timer event: 0ms: Flush included source file cache
11:9:16 Timer event: 0ms: Check delta
11:9:16 Builder: Tidied output folder(s), removed class files and derived resources
11:9:17 Timer event: 1020ms: Pre compile
11:9:17 Compiler configuration for project com.dcx.ivkmds.application.ass has been read by compiler.  Resetting.
11:9:17      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:9:17 Resetting list of modified source files.  Was null
11:9:17 Preparing for build: not going to be incremental because no successful previous full build
11:9:20 Timer event: 2860ms: Time to first compiled message
11:9:20 Timer event: 2935ms: Time to first woven message
11:10:17 AspectJ reports build successful, build was: FULL
11:10:18 AJDE Callback: finish. Was full build: true
11:10:18 Timer event: 60802ms: Total time spent in AJDE
11:10:18 Timer event: 0ms: Refresh after build
11:10:18 Types affected during build = 292
11:10:18 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.application.ass
11:10:18 Timer event: 61863ms: Total time spent in AJBuilder.build()
11:10:18 Compiler configuration for project com.dcx.ivkmds.csolver.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:10:18 ===========================================================================================
11:10:18 Build kind = FULLBUILD
11:10:18 Project=com.dcx.ivkmds.csolver.ass, kind of build requested=Full AspectJ compilation
11:10:18 Timer event: 0ms: Flush included source file cache
11:10:18 Timer event: 0ms: Check delta
11:10:18 Builder: Tidied output folder(s), removed class files and derived resources
11:10:19 Timer event: 424ms: Pre compile
11:10:19 Compiler configuration for project com.dcx.ivkmds.csolver.ass has been read by compiler.  Resetting.
11:10:19      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:10:19 Resetting list of modified source files.  Was null
11:10:19 Preparing for build: not going to be incremental because no successful previous full build
11:10:21 Timer event: 2396ms: Time to first compiled message
11:10:21 Timer event: 2549ms: Time to first woven message
11:10:41 AspectJ reports build successful, build was: FULL
11:10:41 AJDE Callback: finish. Was full build: true
11:10:41 Timer event: 22602ms: Total time spent in AJDE
11:10:41 Timer event: 0ms: Refresh after build
11:10:41 Types affected during build = 83
11:10:41 Timer event: 23042ms: Total time spent in AJBuilder.build()
11:10:41 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.csolver.ass
11:10:54 Compiler configuration for project com.dcx.ivkmds._45_export_import.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:10:54 ===========================================================================================
11:10:54 Build kind = FULLBUILD
11:10:54 Project=com.dcx.ivkmds._45_export_import.ass, kind of build requested=Full AspectJ compilation
11:10:54 Timer event: 0ms: Flush included source file cache
11:10:54 Timer event: 0ms: Check delta
11:10:54 Builder: Tidied output folder(s), removed class files and derived resources
11:10:55 Timer event: 416ms: Pre compile
11:10:55 Compiler configuration for project com.dcx.ivkmds._45_export_import.ass has been read by compiler.  Resetting.
11:10:55      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:10:55 Resetting list of modified source files.  Was null
11:10:55 Preparing for build: not going to be incremental because no successful previous full build
11:11:3 Timer event: 8062ms: Time to first compiled message
11:11:3 Timer event: 8084ms: Time to first woven message
11:12:53 AspectJ reports build successful, build was: FULL
11:12:53 AJDE Callback: finish. Was full build: true
11:12:53 Timer event: 118398ms: Total time spent in AJDE
11:12:53 Timer event: 0ms: Refresh after build
11:12:53 Types affected during build = 425
11:12:53 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds._45_export_import.ass
11:12:53 Timer event: 118919ms: Total time spent in AJBuilder.build()
11:13:3 Compiler configuration for project com.dcx.ivkmds._00_fwktest.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:13:3 ===========================================================================================
11:13:3 Build kind = FULLBUILD
11:13:3 Project=com.dcx.ivkmds._00_fwktest.ass, kind of build requested=Full AspectJ compilation
11:13:3 Timer event: 0ms: Flush included source file cache
11:13:3 Timer event: 0ms: Check delta
11:13:3 Builder: Tidied output folder(s), removed class files and derived resources
11:13:3 Timer event: 82ms: Pre compile
11:13:4 Compiler configuration for project com.dcx.ivkmds._00_fwktest.ass has been read by compiler.  Resetting.
11:13:4      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:13:4 Resetting list of modified source files.  Was null
11:13:4 Preparing for build: not going to be incremental because no successful previous full build
11:13:4 Timer event: 316ms: Time to first compiled message
11:13:4 Timer event: 605ms: Time to first woven message
11:13:5 AspectJ reports build successful, build was: FULL
11:13:5 AJDE Callback: finish. Was full build: true
11:13:5 Timer event: 1840ms: Total time spent in AJDE
11:13:5 Timer event: 3ms: Refresh after build
11:13:5 Types affected during build = 4
11:13:5 Timer event: 1949ms: Total time spent in AJBuilder.build()
11:13:5 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds._00_fwktest.ass
11:13:5 Compiler configuration for project com.dcx.ivkmds.csolver.cts.standalone doesn't know previous state, so assuming EVERYTHING has changed.
11:13:5 ===========================================================================================
11:13:5 Build kind = FULLBUILD
11:13:5 Project=com.dcx.ivkmds.csolver.cts.standalone, kind of build requested=Full AspectJ compilation
11:13:5 Timer event: 0ms: Flush included source file cache
11:13:5 Timer event: 0ms: Check delta
11:13:5 Builder: Tidied output folder(s), removed class files and derived resources
11:13:6 Timer event: 261ms: Pre compile
11:13:6 Compiler configuration for project com.dcx.ivkmds.csolver.cts.standalone has been read by compiler.  Resetting.
11:13:6      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:13:6 Resetting list of modified source files.  Was null
11:13:6 Preparing for build: not going to be incremental because no successful previous full build
11:13:6 Timer event: 564ms: Time to first compiled message
11:13:6 Timer event: 574ms: Time to first woven message
11:13:7 AspectJ reports build successful, build was: FULL
11:13:7 AJDE Callback: finish. Was full build: true
11:13:7 Timer event: 1062ms: Total time spent in AJDE
11:13:7 Timer event: 0ms: Refresh after build
11:13:7 Types affected during build = 17
11:13:7 Timer event: 1326ms: Total time spent in AJBuilder.build()
11:13:7 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.csolver.cts.standalone
11:13:9 Compiler configuration for project com.dcx.ivkmds.application.rcs.standalone doesn't know previous state, so assuming EVERYTHING has changed.
11:13:9 ===========================================================================================
11:13:9 Build kind = FULLBUILD
11:13:9 Project=com.dcx.ivkmds.application.rcs.standalone, kind of build requested=Full AspectJ compilation
11:13:9 Timer event: 0ms: Flush included source file cache
11:13:9 Timer event: 0ms: Check delta
11:13:9 Builder: Tidied output folder(s), removed class files and derived resources
11:13:9 Timer event: 384ms: Pre compile
11:13:9 Compiler configuration for project com.dcx.ivkmds.application.rcs.standalone has been read by compiler.  Resetting.
11:13:9      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:13:9 Resetting list of modified source files.  Was null
11:13:9 Preparing for build: not going to be incremental because no successful previous full build
11:13:10 Timer event: 618ms: Time to first compiled message
11:13:10 Timer event: 620ms: Time to first woven message
11:13:10 AspectJ reports build successful, build was: FULL
11:13:10 AJDE Callback: finish. Was full build: true
11:13:10 Timer event: 983ms: Total time spent in AJDE
11:13:10 Timer event: 0ms: Refresh after build
11:13:10 Types affected during build = 9
11:13:10 Timer event: 1375ms: Total time spent in AJBuilder.build()
11:13:10 Compiler configuration for project com.dcx.ivkmds.testfwk doesn't know previous state, so assuming EVERYTHING has changed.
11:13:10 ===========================================================================================
11:13:10 Build kind = FULLBUILD
11:13:10 Project=com.dcx.ivkmds.testfwk, kind of build requested=Full AspectJ compilation
11:13:10 Timer event: 1ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.application.rcs.standalone
11:13:10 Timer event: 0ms: Flush included source file cache
11:13:10 Timer event: 0ms: Check delta
11:13:10 Builder: Tidied output folder(s), removed class files and derived resources
11:13:11 Timer event: 835ms: Pre compile
11:13:11 Compiler configuration for project com.dcx.ivkmds.testfwk has been read by compiler.  Resetting.
11:13:11      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:13:11 Resetting list of modified source files.  Was null
11:13:11 Preparing for build: not going to be incremental because no successful previous full build
11:13:16 Timer event: 4213ms: Time to first compiled message
11:13:16 Timer event: 4610ms: Time to first woven message
11:13:20 AspectJ reports build successful, build was: FULL
11:13:21 AJDE Callback: finish. Was full build: true
11:13:21 Timer event: 9234ms: Total time spent in AJDE
11:13:21 Timer event: 0ms: Refresh after build
11:13:21 Types affected during build = 45
11:13:21 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.testfwk
11:13:21 Timer event: 10147ms: Total time spent in AJBuilder.build()
11:13:21 Compiler configuration for project com.dcx.ivkmds.fwk.test.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:13:21 ===========================================================================================
11:13:21 Build kind = FULLBUILD
11:13:21 Project=com.dcx.ivkmds.fwk.test.ass, kind of build requested=Full AspectJ compilation
11:13:21 Timer event: 0ms: Flush included source file cache
11:13:21 Timer event: 0ms: Check delta
11:13:21 Builder: Tidied output folder(s), removed class files and derived resources
11:13:21 Timer event: 564ms: Pre compile
11:13:21 Compiler configuration for project com.dcx.ivkmds.fwk.test.ass has been read by compiler.  Resetting.
11:13:21      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:13:21 Resetting list of modified source files.  Was null
11:13:21 Preparing for build: not going to be incremental because no successful previous full build
11:13:22 Timer event: 678ms: Time to first compiled message
11:13:22 Timer event: 971ms: Time to first woven message
11:13:55 AspectJ reports build successful, build was: FULL
11:13:56 AJDE Callback: finish. Was full build: true
11:13:56 Timer event: 34438ms: Total time spent in AJDE
11:13:56 Timer event: 1ms: Refresh after build
11:13:56 Types affected during build = 24
11:13:56 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.test.ass
11:13:56 Timer event: 35031ms: Total time spent in AJBuilder.build()
11:13:56 Compiler configuration for project com.dcx.ivkmds.fwk.test.rcs doesn't know previous state, so assuming EVERYTHING has changed.
11:13:56 ===========================================================================================
11:13:56 Build kind = FULLBUILD
11:13:56 Project=com.dcx.ivkmds.fwk.test.rcs, kind of build requested=Full AspectJ compilation
11:13:56 Timer event: 0ms: Flush included source file cache
11:13:56 Timer event: 0ms: Check delta
11:13:56 Builder: Tidied output folder(s), removed class files and derived resources
11:13:56 Timer event: 140ms: Pre compile
11:13:56 Compiler configuration for project com.dcx.ivkmds.fwk.test.rcs has been read by compiler.  Resetting.
11:13:56      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:13:56 Resetting list of modified source files.  Was null
11:13:56 Preparing for build: not going to be incremental because no successful previous full build
11:13:56 Timer event: 382ms: Time to first compiled message
11:13:56 Timer event: 417ms: Time to first woven message
11:13:57 AspectJ reports build successful, build was: FULL
11:13:57 AJDE Callback: finish. Was full build: true
11:13:57 Timer event: 1145ms: Total time spent in AJDE
11:13:57 Timer event: 0ms: Refresh after build
11:13:57 Types affected during build = 4
11:13:57 Timer event: 1290ms: Total time spent in AJBuilder.build()
11:13:57 Compiler configuration for project com.dcx.ivkmds.fwk.test.common doesn't know previous state, so assuming EVERYTHING has changed.
11:13:57 ===========================================================================================
11:13:57 Build kind = FULLBUILD
11:13:57 Project=com.dcx.ivkmds.fwk.test.common, kind of build requested=Full AspectJ compilation
11:13:57 Timer event: 0ms: Flush included source file cache
11:13:57 Timer event: 0ms: Check delta
11:13:57 Builder: Tidied output folder(s), removed class files and derived resources
11:13:57 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.test.rcs
11:13:57 Timer event: 146ms: Pre compile
11:13:57 Compiler configuration for project com.dcx.ivkmds.fwk.test.common has been read by compiler.  Resetting.
11:13:57      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:13:57 Resetting list of modified source files.  Was null
11:13:57 Preparing for build: not going to be incremental because no successful previous full build
11:13:58 Timer event: 352ms: Time to first compiled message
11:13:58 Timer event: 353ms: Time to first woven message
11:13:58 AspectJ reports build successful, build was: FULL
11:13:58 AJDE Callback: finish. Was full build: true
11:13:58 Timer event: 442ms: Total time spent in AJDE
11:13:58 Timer event: 0ms: Refresh after build
11:13:58 Types affected during build = 2
11:13:58 Timer event: 593ms: Total time spent in AJBuilder.build()
11:13:58 Compiler configuration for project com.dcx.ivkmds.csolver.test.cts doesn't know previous state, so assuming EVERYTHING has changed.
11:13:58 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.test.common
11:13:58 ===========================================================================================
11:13:58 Build kind = FULLBUILD
11:13:58 Project=com.dcx.ivkmds.csolver.test.cts, kind of build requested=Full AspectJ compilation
11:13:58 Timer event: 0ms: Flush included source file cache
11:13:58 Timer event: 0ms: Check delta
11:13:58 Builder: Tidied output folder(s), removed class files and derived resources
11:13:58 Timer event: 275ms: Pre compile
11:13:58 Compiler configuration for project com.dcx.ivkmds.csolver.test.cts has been read by compiler.  Resetting.
11:13:58      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:13:58 Resetting list of modified source files.  Was null
11:13:58 Preparing for build: not going to be incremental because no successful previous full build
11:13:59 Timer event: 717ms: Time to first compiled message
11:13:59 Timer event: 770ms: Time to first woven message
11:14:0 AspectJ reports build successful, build was: FULL
11:14:0 AJDE Callback: finish. Was full build: true
11:14:0 Timer event: 2483ms: Total time spent in AJDE
11:14:0 Timer event: 0ms: Refresh after build
11:14:0 Types affected during build = 12
11:14:0 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.csolver.test.cts
11:14:0 Timer event: 2807ms: Total time spent in AJBuilder.build()
11:14:1 Compiler configuration for project com.dcx.ivkmds.application.test.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:14:1 ===========================================================================================
11:14:1 Build kind = FULLBUILD
11:14:1 Project=com.dcx.ivkmds.application.test.ass, kind of build requested=Full AspectJ compilation
11:14:1 Timer event: 0ms: Flush included source file cache
11:14:1 Timer event: 7ms: Check delta
11:14:1 Builder: Tidied output folder(s), removed class files and derived resources
11:14:1 Timer event: 756ms: Pre compile
11:14:1 Compiler configuration for project com.dcx.ivkmds.application.test.ass has been read by compiler.  Resetting.
11:14:1      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]

11:14:1 Resetting list of modified source files.  Was null
11:14:1 Preparing for build: not going to be incremental because no successful previous full build
11:14:5 Timer event: 3495ms: Time to first compiled message
11:14:5 Timer event: 3508ms: Time to first woven message
11:14:17 AspectJ reports build successful, build was: FULL
11:14:17 AJDE Callback: finish. Was full build: true
11:14:18 Timer event: 16175ms: Total time spent in AJDE
11:14:18 Timer event: 0ms: Refresh after build
11:14:18 Types affected during build = 152
11:14:18 Timer event: 17186ms: Total time spent in AJBuilder.build()
11:14:18 Compiler configuration for project com.dcx.ivkmds.csolver.test.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:14:18 ===========================================================================================
11:14:18 Build kind = FULLBUILD
11:14:18 Project=com.dcx.ivkmds.csolver.test.ass, kind of build requested=Full AspectJ compilation
11:14:18 Timer event: 0ms: Flush included source file cache
11:14:18 Timer event: 0ms: Check delta
11:14:18 Builder: Tidied output folder(s), removed class files and derived resources
11:14:18 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.application.test.ass
11:14:18 Timer event: 302ms: Pre compile
11:14:18 Compiler configuration for project com.dcx.ivkmds.csolver.test.ass has been read by compiler.  Resetting.
11:14:18      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:14:18 Resetting list of modified source files.  Was null
11:14:18 Preparing for build: not going to be incremental because no successful previous full build
11:14:20 Timer event: 1732ms: Time to first compiled message
11:14:20 Timer event: 1904ms: Time to first woven message
11:14:24 AspectJ reports build successful, build was: FULL
11:14:24 AJDE Callback: finish. Was full build: true
11:14:24 Timer event: 6237ms: Total time spent in AJDE
11:14:24 Timer event: 0ms: Refresh after build
11:14:24 Types affected during build = 31
11:14:25 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.csolver.test.ass
11:14:25 Timer event: 6696ms: Total time spent in AJBuilder.build()
11:14:25 Compiler configuration for project com.dcx.ivkmds.application.test.rcs.standalone doesn't know previous state, so assuming EVERYTHING has changed.
11:14:25 ===========================================================================================
11:14:25 Build kind = FULLBUILD
11:14:25 Project=com.dcx.ivkmds.application.test.rcs.standalone, kind of build requested=Full AspectJ compilation
11:14:25 Timer event: 0ms: Flush included source file cache
11:14:25 Timer event: 0ms: Check delta
11:14:25 Builder: Tidied output folder(s), removed class files and derived resources
11:14:25 Timer event: 77ms: Pre compile
11:14:25 Compiler configuration for project com.dcx.ivkmds.application.test.rcs.standalone has been read by compiler.  Resetting.
11:14:25      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:14:25 Resetting list of modified source files.  Was null
11:14:25 Preparing for build: not going to be incremental because no successful previous full build
11:14:25 Timer event: 335ms: Time to first compiled message
11:14:25 AspectJ reports build successful, build was: FULL
11:14:25 AJDE Callback: finish. Was full build: true
11:14:25 Timer event: 364ms: Total time spent in AJDE
11:14:25 Timer event: 0ms: Refresh after build
11:14:25 Types affected during build = 1
11:14:25 Timer event: 449ms: Total time spent in AJBuilder.build()
11:14:25 Compiler configuration for project com.dcx.ivkmds.application.test.common doesn't know previous state, so assuming EVERYTHING has changed.
11:14:25 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.application.test.rcs.standalone
11:14:25 ===========================================================================================
11:14:25 Build kind = FULLBUILD
11:14:25 Project=com.dcx.ivkmds.application.test.common, kind of build requested=Full AspectJ compilation
11:14:25 Timer event: 0ms: Flush included source file cache
11:14:25 Timer event: 0ms: Check delta
11:14:25 Builder: Tidied output folder(s), removed class files and derived resources
11:14:25 Timer event: 96ms: Pre compile
11:14:25 Compiler configuration for project com.dcx.ivkmds.application.test.common has been read by compiler.  Resetting.
11:14:25      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:14:25 Resetting list of modified source files.  Was null
11:14:25 Preparing for build: not going to be incremental because no successful previous full build
11:14:26 Timer event: 450ms: Time to first compiled message
11:14:26 Timer event: 459ms: Time to first woven message
11:14:26 AspectJ reports build successful, build was: FULL
11:14:26 AJDE Callback: finish. Was full build: true
11:14:26 Timer event: 558ms: Total time spent in AJDE
11:14:26 Timer event: 0ms: Refresh after build
11:14:26 Types affected during build = 1
11:14:26 Timer event: 739ms: Total time spent in AJBuilder.build()
11:14:26 Compiler configuration for project com.dcx.ivkmds._55_archive.test.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:14:26 ===========================================================================================
11:14:26 Build kind = FULLBUILD
11:14:26 Project=com.dcx.ivkmds._55_archive.test.ass, kind of build requested=Full AspectJ compilation
11:14:26 Timer event: 0ms: Flush included source file cache
11:14:26 Timer event: 0ms: Check delta
11:14:26 Builder: Tidied output folder(s), removed class files and derived resources
11:14:26 Timer event: 117ms: Pre compile
11:14:26 Compiler configuration for project com.dcx.ivkmds._55_archive.test.ass has been read by compiler.  Resetting.
11:14:26      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:14:26 Resetting list of modified source files.  Was null
11:14:26 Preparing for build: not going to be incremental because no successful previous full build
11:14:26 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.application.test.common
11:14:26 Timer event: 372ms: Time to first compiled message
11:14:26 Timer event: 414ms: Time to first woven message
11:14:26 AspectJ reports build successful, build was: FULL
11:14:26 AJDE Callback: finish. Was full build: true
11:14:26 Timer event: 585ms: Total time spent in AJDE
11:14:26 Timer event: 0ms: Refresh after build
11:14:26 Types affected during build = 2
11:14:27 Timer event: 716ms: Total time spent in AJBuilder.build()
11:14:27 Compiler configuration for project com.dcx.ivkmds._50_reports.test.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:14:27 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds._55_archive.test.ass
11:14:27 ===========================================================================================
11:14:27 Build kind = FULLBUILD
11:14:27 Project=com.dcx.ivkmds._50_reports.test.ass, kind of build requested=Full AspectJ compilation
11:14:27 Timer event: 0ms: Flush included source file cache
11:14:27 Timer event: 0ms: Check delta
11:14:27 Builder: Tidied output folder(s), removed class files and derived resources
11:14:27 Timer event: 428ms: Pre compile
11:14:27 Compiler configuration for project com.dcx.ivkmds._50_reports.test.ass has been read by compiler.  Resetting.
11:14:27      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:14:27 Resetting list of modified source files.  Was null
11:14:27 Preparing for build: not going to be incremental because no successful previous full build
11:14:27 Timer event: 422ms: Time to first compiled message
11:14:27 Timer event: 534ms: Time to first woven message
11:14:28 AspectJ reports build successful, build was: FULL
11:14:28 AJDE Callback: finish. Was full build: true
11:14:28 Timer event: 636ms: Total time spent in AJDE
11:14:28 Timer event: 0ms: Refresh after build
11:14:28 Types affected during build = 1
11:14:28 Timer event: 1106ms: Total time spent in AJBuilder.build()
11:14:28 Timer event: 1ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds._50_reports.test.ass
11:14:28 Compiler configuration for project com.dcx.ivkmds._45_export_import.test.ass doesn't know previous state, so assuming EVERYTHING has changed.
11:14:28 ===========================================================================================
11:14:28 Build kind = FULLBUILD
11:14:28 Project=com.dcx.ivkmds._45_export_import.test.ass, kind of build requested=Full AspectJ compilation
11:14:28 Timer event: 0ms: Flush included source file cache
11:14:28 Timer event: 7ms: Check delta
11:14:28 Builder: Tidied output folder(s), removed class files and derived resources
11:14:28 Timer event: 636ms: Pre compile
11:14:29 Compiler configuration for project com.dcx.ivkmds._45_export_import.test.ass has been read by compiler.  Resetting.
11:14:29      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
11:14:29 Resetting list of modified source files.  Was null
11:14:29 Preparing for build: not going to be incremental because no successful previous full build
11:14:30 Timer event: 1418ms: Time to first compiled message
11:14:30 Timer event: 1446ms: Time to first woven message
11:14:31 AspectJ reports build successful, build was: FULL
11:14:32 AJDE Callback: finish. Was full build: true
11:14:32 Timer event: 3287ms: Total time spent in AJDE
11:14:32 Timer event: 0ms: Refresh after build
11:14:32 Types affected during build = 25
11:14:32 Timer event: 3962ms: Total time spent in AJBuilder.build()
11:14:32 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds._45_export_import.test.ass
11:14:35 Timer event: 5ms: Delete markers: com.dcx.ivkmds.fwk.ass (Finished deleting markers for com.dcx.ivkmds.fwk.ass)
11:14:35 Timer event: 23ms: Delete markers: com.dcx.ivkmds.application.test.ass (Finished deleting markers for com.dcx.ivkmds.application.test.ass)
11:14:35 Timer event: 108ms: Delete markers: com.dcx.ivkmds.fwk.rcs (Finished deleting markers for com.dcx.ivkmds.fwk.rcs)
11:14:35 Timer event: 121ms: Delete markers: com.dcx.ivkmds.testfwk (Finished deleting markers for com.dcx.ivkmds.testfwk)
11:14:36 Timer event: 895ms: Delete markers: com.dcx.ivkmds.fwk.common.spec.trace.aspectj (Finished deleting markers for com.dcx.ivkmds.fwk.common.spec.trace.aspectj)
11:14:36 Timer event: 5ms: Create markers: com.dcx.ivkmds.fwk.common.spec.trace.aspectj (Finished creating markers for com.dcx.ivkmds.fwk.common.spec.trace.aspectj)
11:14:36 Created 0 markers in 2 files
11:14:36 Timer event: 921ms: Delete markers: com.dcx.ivkmds.csolver.test.cts (Finished deleting markers for com.dcx.ivkmds.csolver.test.cts)
11:14:36 Timer event: 939ms: Delete markers: com.dcx.ivkmds._45_export_import.ass (Finished deleting markers for com.dcx.ivkmds._45_export_import.ass)
11:14:36 Timer event: 1059ms: Delete markers: com.dcx.ivkmds.fwk.common.ass.persist (Finished deleting markers for com.dcx.ivkmds.fwk.common.ass.persist)
11:14:36 Timer event: 1079ms: Delete markers: com.dcx.ivkmds.csolver.ass (Finished deleting markers for com.dcx.ivkmds.csolver.ass)
11:14:36 Timer event: 1107ms: Delete markers: com.dcx.ivkmds._50_reports.test.ass (Finished deleting markers for com.dcx.ivkmds._50_reports.test.ass)
11:14:36 Timer event: 1109ms: Delete markers: com.dcx.ivkmds.application.ass (Finished deleting markers for com.dcx.ivkmds.application.ass)
11:14:36 Timer event: 1111ms: Delete markers: com.dcx.ivkmds.common.businessobjects.fwktest (Finished deleting markers for com.dcx.ivkmds.common.businessobjects.fwktest)
11:14:36 Timer event: 624ms: Create markers: com.dcx.ivkmds._50_reports.test.ass (Finished creating markers for com.dcx.ivkmds._50_reports.test.ass)
11:14:36 Created 4 markers in 1 files
11:14:39 Timer event: 3177ms: Create markers: com.dcx.ivkmds._45_export_import.ass (Finished creating markers for com.dcx.ivkmds._45_export_import.ass)
11:14:39 Created 14 markers in 425 files
11:14:42 Timer event: 6461ms: Create markers: com.dcx.ivkmds.csolver.test.cts (Finished creating markers for com.dcx.ivkmds.csolver.test.cts)
11:14:42 Created 30 markers in 12 files
11:14:46 Timer event: 9838ms: Create markers: com.dcx.ivkmds.fwk.common.ass.persist (Finished creating markers for com.dcx.ivkmds.fwk.common.ass.persist)
11:14:46 Created 55 markers in 47 files
11:14:46 Timer event: 10954ms: Create markers: com.dcx.ivkmds.fwk.rcs (Finished creating markers for com.dcx.ivkmds.fwk.rcs)
11:14:46 Created 57 markers in 87 files
11:14:50 Timer event: 14925ms: Create markers: com.dcx.ivkmds.testfwk (Finished creating markers for com.dcx.ivkmds.testfwk)
11:14:50 Created 93 markers in 45 files
11:14:50 Timer event: 14486ms: Create markers: com.dcx.ivkmds.csolver.ass (Finished creating markers for com.dcx.ivkmds.csolver.ass)
11:14:50 Created 98 markers in 83 files
11:14:51 Timer event: 15538ms: Create markers: com.dcx.ivkmds.common.businessobjects.fwktest (Finished creating markers for com.dcx.ivkmds.common.businessobjects.fwktest)
11:14:51 Created 111 markers in 32 files
11:14:54 Timer event: 19330ms: Create markers: com.dcx.ivkmds.fwk.ass (Finished creating markers for com.dcx.ivkmds.fwk.ass)
11:14:54 Created 160 markers in 117 files
11:15:17 Timer event: 42399ms: Create markers: com.dcx.ivkmds.application.test.ass (Finished creating markers for com.dcx.ivkmds.application.test.ass)
11:15:17 Created 818 markers in 152 files
11:15:53 Timer event: 76936ms: Create markers: com.dcx.ivkmds.application.ass (Finished creating markers for com.dcx.ivkmds.application.ass)
11:15:53 Created 2615 markers in 292 files
11:15:55 Timer event: 18ms: Delete markers: com.dcx.ivkmds.csolver.cts.standalone (Finished deleting markers for com.dcx.ivkmds.csolver.cts.standalone)
11:15:55 Timer event: 20ms: Delete markers: com.dcx.ivkmds._00_fwktest.ass (Finished deleting markers for com.dcx.ivkmds._00_fwktest.ass)
11:15:55 Timer event: 22ms: Delete markers: com.dcx.ivkmds.application.test.rcs.standalone (Finished deleting markers for com.dcx.ivkmds.application.test.rcs.standalone)
11:15:55 Timer event: 1ms: Create markers: com.dcx.ivkmds.application.test.rcs.standalone (Finished creating markers for com.dcx.ivkmds.application.test.rcs.standalone)
11:15:55 Created 0 markers in 1 files
11:15:55 Timer event: 23ms: Delete markers: com.dcx.ivkmds.fwk.test.rcs (Finished deleting markers for com.dcx.ivkmds.fwk.test.rcs)
11:15:55 Timer event: 33ms: Delete markers: com.dcx.ivkmds.csolver.cts (Finished deleting markers for com.dcx.ivkmds.csolver.cts)
11:15:55 Timer event: 36ms: Delete markers: com.dcx.ivkmds.application.test.common (Finished deleting markers for com.dcx.ivkmds.application.test.common)
11:15:55 Timer event: 0ms: Create markers: com.dcx.ivkmds.application.test.common (Finished creating markers for com.dcx.ivkmds.application.test.common)
11:15:55 Created 0 markers in 1 files
11:15:55 Timer event: 36ms: Delete markers: com.dcx.ivkmds.application.rcs.standalone (Finished deleting markers for com.dcx.ivkmds.application.rcs.standalone)
11:15:55 Timer event: 36ms: Delete markers: com.dcx.ivkmds._55_archive.test.ass (Finished deleting markers for com.dcx.ivkmds._55_archive.test.ass)
11:15:55 Timer event: 43ms: Delete markers: com.dcx.ivkmds.fwk.common.businessobjects.persistent (Finished deleting markers for com.dcx.ivkmds.fwk.common.businessobjects.persistent)
11:15:55 Timer event: 0ms: Create markers: com.dcx.ivkmds.fwk.common.businessobjects.persistent (Finished creating markers for com.dcx.ivkmds.fwk.common.businessobjects.persistent)
11:15:55 Created 0 markers in 6 files
11:15:55 Timer event: 43ms: Delete markers: com.dcx.ivkmds.common.businessobjects.persistent (Finished deleting markers for com.dcx.ivkmds.common.businessobjects.persistent)
11:15:55 Timer event: 47ms: Delete markers: com.dcx.ivkmds.fwk.test.common (Finished deleting markers for com.dcx.ivkmds.fwk.test.common)
11:15:55 Timer event: 1ms: Create markers: com.dcx.ivkmds.fwk.test.common (Finished creating markers for com.dcx.ivkmds.fwk.test.common)
11:15:55 Created 0 markers in 2 files
11:15:55 Timer event: 48ms: Delete markers: com.dcx.ivkmds._45_export_import.test.ass (Finished deleting markers for com.dcx.ivkmds._45_export_import.test.ass)
11:15:55 Timer event: 58ms: Delete markers: com.dcx.ivkmds.fwk.test.ass (Finished deleting markers for com.dcx.ivkmds.fwk.test.ass)
11:15:55 Timer event: 64ms: Delete markers: com.dcx.ivkmds.csolver.test.ass (Finished deleting markers for com.dcx.ivkmds.csolver.test.ass)
11:15:55 Timer event: 334ms: Create markers: com.dcx.ivkmds.application.rcs.standalone (Finished creating markers for com.dcx.ivkmds.application.rcs.standalone)
11:15:55 Created 2 markers in 9 files
11:15:56 Timer event: 1018ms: Create markers: com.dcx.ivkmds.csolver.cts.standalone (Finished creating markers for com.dcx.ivkmds.csolver.cts.standalone)
11:15:56 Created 7 markers in 17 files
11:15:56 Timer event: 1453ms: Create markers: com.dcx.ivkmds._55_archive.test.ass (Finished creating markers for com.dcx.ivkmds._55_archive.test.ass)
11:15:56 Created 12 markers in 2 files
11:15:59 Timer event: 3970ms: Create markers: com.dcx.ivkmds.fwk.test.rcs (Finished creating markers for com.dcx.ivkmds.fwk.test.rcs)
11:15:59 Created 44 markers in 4 files
11:16:0 Timer event: 4645ms: Create markers: com.dcx.ivkmds._45_export_import.test.ass (Finished creating markers for com.dcx.ivkmds._45_export_import.test.ass)
11:16:0 Created 53 markers in 25 files
11:16:4 Timer event: 9272ms: Create markers: com.dcx.ivkmds.csolver.cts (Finished creating markers for com.dcx.ivkmds.csolver.cts)
11:16:4 Created 134 markers in 343 files
11:16:6 Timer event: 10978ms: Create markers: com.dcx.ivkmds.csolver.test.ass (Finished creating markers for com.dcx.ivkmds.csolver.test.ass)
11:16:6 Created 174 markers in 31 files
11:16:6 Timer event: 11216ms: Create markers: com.dcx.ivkmds._00_fwktest.ass (Finished creating markers for com.dcx.ivkmds._00_fwktest.ass)
11:16:6 Created 179 markers in 4 files
11:16:14 Timer event: 19385ms: Create markers: com.dcx.ivkmds.fwk.test.ass (Finished creating markers for com.dcx.ivkmds.fwk.test.ass)
11:16:14 Created 572 markers in 24 files
11:16:20 Timer event: 24699ms: Create markers: com.dcx.ivkmds.common.businessobjects.persistent (Finished creating markers for com.dcx.ivkmds.common.businessobjects.persistent)
11:16:20 Created 996 markers in 326 files



And here the console timings:

Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=3ms
> weaving classes=0ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 0ms
> weaving normal itds=0ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 0ms
shadowWeaving = 0ms
postWeave = 0ms
Total =0ms

Kinded pointcut matchInternal(): 0ms
Kinded pointcut match calls: 0
Kinded pointcut xlinttime: 0ms
ThisTarget pointcut matchInternal: 0ms

Timing: time spent in pipeline weaving: 17ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=2ms
> verifying consistency=1ms
> weaving aspects=13ms
> weaving classes=172ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 2ms
> weaving normal itds=8ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 1ms
typeWeaving = 11ms
decaWeaving = 0ms
fastShadowMatching = 1ms
shadowMatching = 54ms
shadowWeaving = 14ms
postWeave = 2ms
Total =86ms

Kinded pointcut matchInternal(): 30ms
Kinded pointcut match calls: 2781
Kinded pointcut xlinttime: 0ms
ThisTarget pointcut matchInternal: 0ms

Timing: time spent in pipeline weaving: 546ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=15ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 0ms
> weaving normal itds=0ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 7ms
shadowWeaving = 0ms
postWeave = 0ms
Total =7ms

Kinded pointcut matchInternal(): 3ms
Kinded pointcut match calls: 554
Kinded pointcut xlinttime: 0ms
ThisTarget pointcut matchInternal: 0ms

Timing: time spent in pipeline weaving: 33ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=1ms
> verifying consistency=0ms
> weaving aspects=52ms
> weaving classes=511ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 28ms
> weaving normal itds=25ms
> weaving structural itds=3ms

Breakdown of time spent in type weaver instances:
class prep = 3ms
typeWeaving = 24ms
decaWeaving = 0ms
fastShadowMatching = 2ms
shadowMatching = 285ms
shadowWeaving = 56ms
postWeave = 7ms
Total =380ms

Kinded pointcut matchInternal(): 131ms
Kinded pointcut match calls: 3098
Kinded pointcut xlinttime: 3ms
ThisTarget pointcut matchInternal: 37ms

Timing: time spent in pipeline weaving: 1339ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=4ms
> verifying consistency=3ms
> weaving aspects=65ms
> weaving classes=17818ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 88ms
> weaving normal itds=57ms
> weaving structural itds=14ms

Breakdown of time spent in type weaver instances:
class prep = 14ms
typeWeaving = 36ms
decaWeaving = 3ms
fastShadowMatching = 10ms
shadowMatching = 16826ms
shadowWeaving = 95ms
postWeave = 81ms
Total =17068ms

Kinded pointcut matchInternal(): 2371ms
Kinded pointcut match calls: 150144
Kinded pointcut xlinttime: 571ms
ThisTarget pointcut matchInternal: 10277ms

Timing: time spent in pipeline weaving: 24214ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=2ms
> verifying consistency=2ms
> weaving aspects=3ms
> weaving classes=3988ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 96ms
> weaving normal itds=203ms
> weaving structural itds=14ms

Breakdown of time spent in type weaver instances:
class prep = 8ms
typeWeaving = 1301ms
decaWeaving = 2ms
fastShadowMatching = 7ms
shadowMatching = 837ms
shadowWeaving = 666ms
postWeave = 28ms
Total =2852ms

Kinded pointcut matchInternal(): 463ms
Kinded pointcut match calls: 54917
Kinded pointcut xlinttime: 0ms
ThisTarget pointcut matchInternal: 15ms

Timing: time spent in pipeline weaving: 7745ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=1ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=367ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 1ms
> weaving normal itds=28ms
> weaving structural itds=1ms

Breakdown of time spent in type weaver instances:
class prep = 1ms
typeWeaving = 98ms
decaWeaving = 0ms
fastShadowMatching = 4ms
shadowMatching = 80ms
shadowWeaving = 45ms
postWeave = 2ms
Total =232ms

Kinded pointcut matchInternal(): 47ms
Kinded pointcut match calls: 4680
Kinded pointcut xlinttime: 0ms
ThisTarget pointcut matchInternal: 1ms

Timing: time spent in pipeline weaving: 605ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=2ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=171ms
> weaving classes=3649ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 403ms
> weaving normal itds=54ms
> weaving structural itds=1ms

Breakdown of time spent in type weaver instances:
class prep = 4ms
typeWeaving = 43ms
decaWeaving = 0ms
fastShadowMatching = 2ms
shadowMatching = 2984ms
shadowWeaving = 104ms
postWeave = 9ms
Total =3150ms

Kinded pointcut matchInternal(): 520ms
Kinded pointcut match calls: 23907
Kinded pointcut xlinttime: 114ms
ThisTarget pointcut matchInternal: 1142ms

Timing: time spent in pipeline weaving: 4897ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=1ms
> verifying consistency=0ms
> weaving aspects=56ms
> weaving classes=49172ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 367ms
> weaving normal itds=59ms
> weaving structural itds=6ms

Breakdown of time spent in type weaver instances:
class prep = 5ms
typeWeaving = 0ms
decaWeaving = 1ms
fastShadowMatching = 5ms
shadowMatching = 44983ms
shadowWeaving = 2494ms
postWeave = 31ms
Total =47524ms

Kinded pointcut matchInternal(): 32737ms
Kinded pointcut match calls: 183193
Kinded pointcut xlinttime: 29964ms
ThisTarget pointcut matchInternal: 8316ms

Timing: time spent in pipeline weaving: 52142ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=1ms
> verifying consistency=0ms
> weaving aspects=125ms
> weaving classes=17332ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 37ms
> weaving normal itds=21ms
> weaving structural itds=3ms

Breakdown of time spent in type weaver instances:
class prep = 1ms
typeWeaving = 33ms
decaWeaving = 0ms
fastShadowMatching = 1ms
shadowMatching = 16995ms
shadowWeaving = 153ms
postWeave = 10ms
Total =17196ms

Kinded pointcut matchInternal(): 14924ms
Kinded pointcut match calls: 33642
Kinded pointcut xlinttime: 14290ms
ThisTarget pointcut matchInternal: 1469ms

Timing: time spent in pipeline weaving: 18458ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=1ms
> reweavable processing=5ms
> verifying consistency=1ms
> weaving aspects=61ms
> weaving classes=99206ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 120ms
> weaving normal itds=88ms
> weaving structural itds=7ms

Breakdown of time spent in type weaver instances:
class prep = 6ms
typeWeaving = 1ms
decaWeaving = 3ms
fastShadowMatching = 7ms
shadowMatching = 98519ms
shadowWeaving = 23ms
postWeave = 53ms
Total =98614ms

Kinded pointcut matchInternal(): 86801ms
Kinded pointcut match calls: 161602
Kinded pointcut xlinttime: 84133ms
ThisTarget pointcut matchInternal: 8420ms

Timing: time spent in pipeline weaving: 103611ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=1371ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 17ms
> weaving normal itds=6ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 1164ms
shadowWeaving = 149ms
postWeave = 0ms
Total =1315ms

Kinded pointcut matchInternal(): 748ms
Kinded pointcut match calls: 4975
Kinded pointcut xlinttime: 441ms
ThisTarget pointcut matchInternal: 305ms

Timing: time spent in pipeline weaving: 1395ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=151ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 3ms
> weaving normal itds=6ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 3ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 122ms
shadowWeaving = 6ms
postWeave = 0ms
Total =134ms

Kinded pointcut matchInternal(): 29ms
Kinded pointcut match calls: 2128
Kinded pointcut xlinttime: 8ms
ThisTarget pointcut matchInternal: 62ms

Timing: time spent in pipeline weaving: 262ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=2ms
> weaving classes=8ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 0ms
> weaving normal itds=0ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 1ms
shadowWeaving = 0ms
postWeave = 0ms
Total =3ms

Kinded pointcut matchInternal(): 0ms
Kinded pointcut match calls: 65
Kinded pointcut xlinttime: 0ms
ThisTarget pointcut matchInternal: 0ms

Timing: time spent in pipeline weaving: 73ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=531ms
> weaving classes=3206ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 58ms
> weaving normal itds=13ms
> weaving structural itds=2ms

Breakdown of time spent in type weaver instances:
class prep = 4ms
typeWeaving = 8ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 3471ms
shadowWeaving = 116ms
postWeave = 3ms
Total =3605ms

Kinded pointcut matchInternal(): 2970ms
Kinded pointcut match calls: 25310
Kinded pointcut xlinttime: 2623ms
ThisTarget pointcut matchInternal: 190ms

Timing: time spent in pipeline weaving: 4143ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=279ms
> weaving classes=32017ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 28ms
> weaving normal itds=12ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 30701ms
shadowWeaving = 1380ms
postWeave = 3ms
Total =32087ms

Kinded pointcut matchInternal(): 26972ms
Kinded pointcut match calls: 201545
Kinded pointcut xlinttime: 24339ms
ThisTarget pointcut matchInternal: 2234ms

Timing: time spent in pipeline weaving: 32857ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=516ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 4ms
> weaving normal itds=0ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 425ms
shadowWeaving = 72ms
postWeave = 1ms
Total =500ms

Kinded pointcut matchInternal(): 307ms
Kinded pointcut match calls: 12801
Kinded pointcut xlinttime: 95ms
ThisTarget pointcut matchInternal: 52ms

Timing: time spent in pipeline weaving: 549ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=1ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 0ms
> weaving normal itds=0ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 0ms
shadowWeaving = 0ms
postWeave = 0ms
Total =0ms

Kinded pointcut matchInternal(): 0ms
Kinded pointcut match calls: 0
Kinded pointcut xlinttime: 0ms
ThisTarget pointcut matchInternal: 0ms

Timing: time spent in pipeline weaving: 19ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=373ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 13ms
> weaving normal itds=2ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 280ms
shadowWeaving = 59ms
postWeave = 1ms
Total =342ms

Kinded pointcut matchInternal(): 183ms
Kinded pointcut match calls: 11484
Kinded pointcut xlinttime: 88ms
ThisTarget pointcut matchInternal: 24ms

Timing: time spent in pipeline weaving: 582ms
Timing ------------

!ENTRY org.tigris.subversion.subclipse.core 4 0 2009-10-10 11:14:02.468
!MESSAGE org.tigris.subversion.javahl.ClientException: Working copy not locked;
this is probably a bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

!STACK 1
org.tigris.subversion.subclipse.core.SVNException: org.tigris.subversion.javahl.
ClientException: Working copy not locked; this is probably a bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

        at org.tigris.subversion.subclipse.core.SVNException.wrapException(SVNEx
ception.java:85)
        at org.tigris.subversion.subclipse.core.status.StatusCacheManager.refres
hStatus(StatusCacheManager.java:289)
        at org.tigris.subversion.subclipse.core.resourcesListeners.FileModificat
ionManager.refreshStatusInfitite(FileModificationManager.java:149)
        at org.tigris.subversion.subclipse.core.resourcesListeners.FileModificat
ionManager.resourceChanged(FileModificationManager.java:133)
        at org.eclipse.core.internal.events.NotificationManager$2.run(Notificati
onManager.java:291)
        at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42)
        at org.eclipse.core.internal.events.NotificationManager.notify(Notificat
ionManager.java:285)
        at org.eclipse.core.internal.events.NotificationManager.broadcastChanges
(NotificationManager.java:149)
        at org.eclipse.core.internal.resources.Workspace.broadcastPostChange(Wor
kspace.java:313)
        at org.eclipse.core.internal.resources.Workspace.endOperation(Workspace.
java:1022)
        at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:1809
)
        at org.eclipse.core.internal.events.NotificationManager$NotifyJob.run(No
tificationManager.java:40)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)
Caused by: org.tigris.subversion.subclipse.core.SVNException: org.tigris.subvers
ion.javahl.ClientException: Working copy not locked; this is probably a bug, ple
ase report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

        at org.tigris.subversion.subclipse.core.SVNException.wrapException(SVNEx
ception.java:75)
        at org.tigris.subversion.subclipse.core.status.RecursiveStatusUpdateStra
tegy.statusesToUpdate(RecursiveStatusUpdateStrategy.java:64)
        at org.tigris.subversion.subclipse.core.status.StatusCacheManager.refres
hStatus(StatusCacheManager.java:264)
        ... 11 more
Caused by: org.tigris.subversion.svnclientadapter.SVNClientException: org.tigris
.subversion.javahl.ClientException: Working copy not locked; this is probably a
bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:495)
        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:467)
        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:460)
        at org.tigris.subversion.subclipse.core.status.RecursiveStatusUpdateStra
tegy.statusesToUpdate(RecursiveStatusUpdateStrategy.java:62)
        ... 12 more
Caused by: org.tigris.subversion.javahl.ClientException: Working copy not locked
; this is probably a bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

        at org.tigris.subversion.javahl.SVNClient.status(Native Method)
        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:481)
        ... 15 more
!SUBENTRY 1 org.tigris.subversion.subclipse.core 4 -6 2009-10-10 11:14:02.480
!MESSAGE org.tigris.subversion.javahl.ClientException: Working copy not locked;
this is probably a bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

!STACK 1
org.tigris.subversion.subclipse.core.SVNException: org.tigris.subversion.javahl.
ClientException: Working copy not locked; this is probably a bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

        at org.tigris.subversion.subclipse.core.SVNException.wrapException(SVNEx
ception.java:75)
        at org.tigris.subversion.subclipse.core.status.RecursiveStatusUpdateStra
tegy.statusesToUpdate(RecursiveStatusUpdateStrategy.java:64)
        at org.tigris.subversion.subclipse.core.status.StatusCacheManager.refres
hStatus(StatusCacheManager.java:264)
        at org.tigris.subversion.subclipse.core.resourcesListeners.FileModificat
ionManager.refreshStatusInfitite(FileModificationManager.java:149)
        at org.tigris.subversion.subclipse.core.resourcesListeners.FileModificat
ionManager.resourceChanged(FileModificationManager.java:133)
        at org.eclipse.core.internal.events.NotificationManager$2.run(Notificati
onManager.java:291)
        at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42)
        at org.eclipse.core.internal.events.NotificationManager.notify(Notificat
ionManager.java:285)
        at org.eclipse.core.internal.events.NotificationManager.broadcastChanges
(NotificationManager.java:149)
        at org.eclipse.core.internal.resources.Workspace.broadcastPostChange(Wor
kspace.java:313)
        at org.eclipse.core.internal.resources.Workspace.endOperation(Workspace.
java:1022)
        at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:1809
)
        at org.eclipse.core.internal.events.NotificationManager$NotifyJob.run(No
tificationManager.java:40)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)
Caused by: org.tigris.subversion.svnclientadapter.SVNClientException: org.tigris
.subversion.javahl.ClientException: Working copy not locked; this is probably a
bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:495)
        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:467)
        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:460)
        at org.tigris.subversion.subclipse.core.status.RecursiveStatusUpdateStra
tegy.statusesToUpdate(RecursiveStatusUpdateStrategy.java:62)
        ... 12 more
Caused by: org.tigris.subversion.javahl.ClientException: Working copy not locked
; this is probably a bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

        at org.tigris.subversion.javahl.SVNClient.status(Native Method)
        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:481)
        ... 15 more
!SUBENTRY 2 org.tigris.subversion.subclipse.core 4 -6 2009-10-10 11:14:02.495
!MESSAGE org.tigris.subversion.javahl.ClientException: Working copy not locked;
this is probably a bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

!STACK 0
org.tigris.subversion.svnclientadapter.SVNClientException: org.tigris.subversion
.javahl.ClientException: Working copy not locked; this is probably a bug, please
 report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:495)
        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:467)
        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:460)
        at org.tigris.subversion.subclipse.core.status.RecursiveStatusUpdateStra
tegy.statusesToUpdate(RecursiveStatusUpdateStrategy.java:62)
        at org.tigris.subversion.subclipse.core.status.StatusCacheManager.refres
hStatus(StatusCacheManager.java:264)
        at org.tigris.subversion.subclipse.core.resourcesListeners.FileModificat
ionManager.refreshStatusInfitite(FileModificationManager.java:149)
        at org.tigris.subversion.subclipse.core.resourcesListeners.FileModificat
ionManager.resourceChanged(FileModificationManager.java:133)
        at org.eclipse.core.internal.events.NotificationManager$2.run(Notificati
onManager.java:291)
        at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:42)
        at org.eclipse.core.internal.events.NotificationManager.notify(Notificat
ionManager.java:285)
        at org.eclipse.core.internal.events.NotificationManager.broadcastChanges
(NotificationManager.java:149)
        at org.eclipse.core.internal.resources.Workspace.broadcastPostChange(Wor
kspace.java:313)
        at org.eclipse.core.internal.resources.Workspace.endOperation(Workspace.
java:1022)
        at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:1809
)
        at org.eclipse.core.internal.events.NotificationManager$NotifyJob.run(No
tificationManager.java:40)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)
Caused by: org.tigris.subversion.javahl.ClientException: Working copy not locked
; this is probably a bug, please report
svn: Directory 'C:\ws\ivk- eclipse 3.5\com.dcx.ivkmds.application.test.ass\bin\c
om\.svn' containing working copy admin area is missing

        at org.tigris.subversion.javahl.SVNClient.status(Native Method)
        at org.tigris.subversion.svnclientadapter.javahl.AbstractJhlClientAdapte
r.getStatus(AbstractJhlClientAdapter.java:481)
        ... 15 more
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=2ms
> verifying consistency=0ms
> weaving aspects=1ms
> weaving classes=8499ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 115ms
> weaving normal itds=32ms
> weaving structural itds=2ms

Breakdown of time spent in type weaver instances:
class prep = 1ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 1ms
shadowMatching = 6465ms
shadowWeaving = 1518ms
postWeave = 13ms
Total =8002ms

Kinded pointcut matchInternal(): 4587ms
Kinded pointcut match calls: 242696
Kinded pointcut xlinttime: 1729ms
ThisTarget pointcut matchInternal: 799ms

Timing: time spent in pipeline weaving: 9778ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=1ms
> weaving classes=3496ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 32ms
> weaving normal itds=2ms
> weaving structural itds=4ms

Breakdown of time spent in type weaver instances:
class prep = 1ms
typeWeaving = 0ms
decaWeaving = 1ms
fastShadowMatching = 0ms
shadowMatching = 3073ms
shadowWeaving = 292ms
postWeave = 3ms
Total =3372ms

Kinded pointcut matchInternal(): 2398ms
Kinded pointcut match calls: 72263
Kinded pointcut xlinttime: 509ms
ThisTarget pointcut matchInternal: 225ms

Timing: time spent in pipeline weaving: 3774ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=0ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 0ms
> weaving normal itds=0ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 0ms
shadowWeaving = 0ms
postWeave = 0ms
Total =0ms

Kinded pointcut matchInternal(): 0ms
Kinded pointcut match calls: 0
Kinded pointcut xlinttime: 0ms
ThisTarget pointcut matchInternal: 0ms

Timing: time spent in pipeline weaving: 0ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=3ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 0ms
> weaving normal itds=1ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 1ms
shadowWeaving = 0ms
postWeave = 0ms
Total =1ms

Kinded pointcut matchInternal(): 1ms
Kinded pointcut match calls: 30
Kinded pointcut xlinttime: 0ms
ThisTarget pointcut matchInternal: 0ms

Timing: time spent in pipeline weaving: 11ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=70ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 0ms
> weaving normal itds=1ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 55ms
shadowWeaving = 10ms
postWeave = 0ms
Total =66ms

Kinded pointcut matchInternal(): 45ms
Kinded pointcut match calls: 1354
Kinded pointcut xlinttime: 20ms
ThisTarget pointcut matchInternal: 4ms

Timing: time spent in pipeline weaving: 97ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=107ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 0ms
> weaving normal itds=1ms
> weaving structural itds=0ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 87ms
shadowWeaving = 7ms
postWeave = 0ms
Total =95ms

Kinded pointcut matchInternal(): 54ms
Kinded pointcut match calls: 1961
Kinded pointcut xlinttime: 28ms
ThisTarget pointcut matchInternal: 21ms

Timing: time spent in pipeline weaving: 117ms
Timing ------------
Timing ------------
Entire time spent in the weaver instance created for this build:
> performing model repairs=0ms
> reweavable processing=0ms
> verifying consistency=0ms
> weaving aspects=0ms
> weaving classes=227ms
  for those two weave steps, time spent pre-post calling the individual type wea
ver instance: 14ms
> weaving normal itds=3ms
> weaving structural itds=2ms

Breakdown of time spent in type weaver instances:
class prep = 0ms
typeWeaving = 0ms
decaWeaving = 0ms
fastShadowMatching = 0ms
shadowMatching = 150ms
shadowWeaving = 18ms
postWeave = 1ms
Total =171ms

Kinded pointcut matchInternal(): 113ms
Kinded pointcut match calls: 4628
Kinded pointcut xlinttime: 60ms
ThisTarget pointcut matchInternal: 13ms

Timing: time spent in pipeline weaving: 536ms
Timing ------------
References:
- [aspectj-users] Overall problem with AJDT performance
  - From: Thomas Hofmann
- Re: [aspectj-users] Overall problem with AJDT performance
  - From: Andy Clement
- RE: [aspectj-users] Overall problem with AJDT performance
  - From: Thomas Hofmann
- Re: [aspectj-users] Overall problem with AJDT performance
  - From: Andy Clement
- RE: [aspectj-users] Overall problem with AJDT performance
  - From: Thomas Hofmann
- Re: [aspectj-users] Overall problem with AJDT performance
  - From: Andy Clement
- Re: [aspectj-users] Overall problem with AJDT performance
  - From: Andy Clement
- Re: [aspectj-users] Overall problem with AJDT performance
  - From: Andy Clement
Prev by Date: RE: [aspectj-users] Overall problem with AJDT performance
Next by Date: Re: [aspectj-users] A little pointcut help please
Previous by thread: Re: [aspectj-users] Overall problem with AJDT performance
Next by thread: RE: [aspectj-users] Overall problem with AJDT performance
Index(es):
- Date
- Thread
Breadcrumbs
