Community
Participate
Working Groups
Comment removed by droy 2009-03-31 13:05 as requested by the submitter via webmaster inbox.
Here are my comments on the log: 1) Are you on 1.6 or 1.7? 2) there are 3 builds in this log. The middle build is a bit strange. Is this something that you caused by editing a file, or is this a build triggered by some internal state being changed? I wonder if this is something that shouldn't be happening. It only took 31 ms, so not so bad, but would be better if we didn't have to do this. Do you have any dependencies on binary folders (not jars)? 3) After both full builds, the line "Created 3 markers in 101 files" is there. This means that 3 markers were added to your source files (stuff in binaries are not included here). Does this make sense? Presumably, the 1330 info markers you are seeing are the weave-info messages into your jar file. 4) Can you copy and paste your problems/markers view contents here (or add as attachment)? Before and after full and before and after incremental builds? Hopefully, I can have some more detailed information after seeing this.
Wonder why it did not explain the reason for this: > 14:24:41 Dropping back to full build Possibly due to lack of incremental awareness in what has changed in the .aj files (presumably those are aspects). There might well be some wierdness with incremental builds that drop back to full builds after starting - there is minimal testing on my side of that scenario.
(In reply to comment #1) > 1) Are you on 1.6 or 1.7? 1.6 > 2) there are 3 builds in this log. The middle build is a bit strange. Is this > something that you caused by editing a file, or is this a build triggered by > some internal state being changed? I wonder if this is something that > shouldn't be happening. This seems to be internal state. That AUTOBUILD happens after every clean build. > Do you have any dependencies on binary folders (not jars)? Only have these two. Interesting to note that the lib is within the inpath given a src. /base is a jdt project. <classpathentry kind="src" path="/base"> <attributes> <attribute name="org.eclipse.ajdt.inpath" value="org.eclipse.ajdt.inpath"/> </attributes> </classpathentry> <classpathentry kind="lib" path="/base/all/lib/ide/itext.jar"> <attributes> <attribute name="org.eclipse.ajdt.inpath" value="org.eclipse.ajdt.inpath"/> </attributes> </classpathentry> > 3) After both full builds, the line "Created 3 markers in 101 files" is there. > This means that 3 markers were added to your source files (stuff in binaries > are not included here). Does this make sense? Presumably, the 1330 info > markers you are seeing are the weave-info messages into your jar file. Not entirely. There's only 1 joinpoint in the jar getting woven, so I should be seeing markers for the 1329 others. The three that I am seeing are all in base-facade. I don't see any in base (which is a JDT project). If I convert base to an AJ project, I still get no markers there: 9:54:14 Created 0 markers in 1627 files (base) 9:54:14 Created 3 markers in 101 files (base-facade) > 4) Can you copy and paste your problems/markers view contents here (or add as > attachment)? Before and after full and before and after incremental builds? > Hopefully, I can have some more detailed information after seeing this. > advised by CacheDbQueries.afterReturning(String): executeSqlCall.. DBUtils.java base-facade/all/src/main/java/com/xxx/cat/util/db line 53 After Advice Marker declared on base.java.<build to view structure> WeaveSuccessMarker.aj base-facade/all/src/main/aspectj/com/xxx/cat/db line 19 Intertype Declaration Source Marker advises DBUtils: method-call(boolean java.sql.Statement.execute(java.lang.String)) CacheDbQueries.aj base-facade/all/src/main/aspectj/com/xxx/cat/db line 89 Source of After Advice Marker
For the repeated build (the middle of the three mentioned) I've created bug 270752.
I created a simple project that exhibited the same situation as I mentioned in comment 2 (dropping back to full build after initial incremental). The only peculiarity with markers is that the weaveinfo ones come and go during the build (at the end of the build they are gone) - Andrew is taking a look at this.
Here is the project (2 files): B.aj public aspect B { before(): staticinitialization(*) {} } A.aj public aspect A pertypewithin(*) { before(): staticinitialization(*) {} }
Did some looking in to this. Here's what I found: 1. There has been a problem with the AJBuilder.clean() method in that it wasn't deleting the weave info messages at all (however, these weave info messages were being deleted during full builds). 2. Weave info messages only show the stuff woven for this particular build. So, after an incremental build, only the files affected by the incremental build will have weave info messages for them (all others will be removed). I fixed #1 (but not yet committed), but #2 seems almost to be a feature, not a bug. Weave info messages, from my understanding, are only meant for compiler diagnostics. So, we can know what the compiler has done during the most recent build. Your desired use of weave info messages (as a proxy for missing markers) is not supported. This explains why you don't see any changes to the number of weave info messages after a clean, and why you do see changes to weave info messages after an incremental build. However, the one missing piece here is that in your original email to us, you had mentioned that after a full build you see *no* weave info messages, but after an incremental, whitespace build, you see the expected 1330 weave info messages. I have not looked at weave info messages and how they are affected by in path. That is the next place I should look.
Obfuscated message log: 13:53:53 =========================================================================================== 13:53:53 Build kind = FULLBUILD 13:53:53 Project=base-facade, kind of build requested=Full AspectJ compilation 13:53:53 Timer event: 0ms: Flush included source file cache 13:53:53 Timer event: 0ms: Check delta 13:53:53 Builder: Tidied output folder(s), removed class files and derived resources 13:53:53 Classpath = C:\Dev\cat-all-eclipse-inpath\base-facade\bin;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/collections-generic.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-beanutils.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-collections.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-lang.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/jaxb-api.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/jaxb-impl.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/junit.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/proteus-util-all.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/resources.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/rt.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/jsse.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/jce.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/charsets.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/dnsns.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/localedata.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/sunjce_provider.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/sunmscapi.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/sunpkcs11.jar;C:\Dev\cat-all-eclipse-inpath\ccl-base\bin;C:/apps/eclipse/plugins/org.aspectj.runtime_1.6.4.20090329215800/aspectjrt.jar;C:/Dev/cat-all-eclipse-inpath/ccl-base/all/lib/ide/itext.jar;C:/Dev/cat-all-eclipse-inpath/ccl-base/all/lib/ide/jbcl.jar;C:/Dev/cat-all-eclipse-inpath/ccl-base/all/lib/ide/jcommon.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-io.jar; 13:53:53 Timer event: 46ms: Pre compile 13:53:53 Compiler configuration for project base-facade has been read by compiler. Resetting. 13:53:53 Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED] 13:53:53 Resetting list of modified source files. Was null 13:53:53 Preparing for build: not going to be incremental because no successful previous full build 13:53:54 Timer event: 1360ms: Time to first compiled message 13:53:55 Timer event: 1891ms: Time to first woven message 13:54:44 AspectJ reports build successful, build was: FULL 13:54:44 AJDE Callback: finish. Was full build: true 13:54:44 Timer event: 51418ms: Total time spent in AJDE 13:54:44 Timer event: 0ms: Refresh after build 13:54:44 Types affected during build = 2658 13:54:45 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): base-facade 13:54:45 Timer event: 51636ms: Total time spent in AJBuilder.build() 13:54:45 Timer event: 0ms: Delete markers: base-facade (Finished deleting markers for base-facade) 13:54:45 Timer event: 0ms: Create markers: base-facade (Finished creating markers for base-facade) 13:54:45 Created 3 markers in 101 files 13:54:45 =========================================================================================== 13:54:45 Build kind = AUTOBUILD 13:54:45 Project=base-facade, kind of build requested=Incremental AspectJ compilation 13:54:45 Timer event: 0ms: Flush included source file cache 13:54:45 Timer event: 16ms: Check delta 13:54:45 Timer event: 0ms: Looking for and marking configurartion changes in base-facade 13:54:45 Configuration changes found: false 13:54:45 build: Examined delta - no source file or classpath changes for project base-facade 13:54:45 Timer event: 0ms: Looking for and marking configurartion changes in base-facade 13:54:45 Configuration changes found: false 13:54:45 Timer event: 0ms: Looking for and marking configurartion changes in ccl-base 13:54:45 Configuration changes found: false 13:54:45 Timer event: 0ms: Look for source/resource changes 13:54:45 No source/resource changes found, exiting build 13:54:45 Timer event: 31ms: Total time spent in AJBuilder.build() 14:24:38 =========================================================================================== 14:24:38 Build kind = AUTOBUILD 14:24:38 Project=base-facade, kind of build requested=Incremental AspectJ compilation 14:24:38 Timer event: 0ms: Flush included source file cache 14:24:38 Timer event: 0ms: Check delta 14:24:38 File: C:\Dev\cat-all-eclipse-inpath\base-facade\all\src\main\aspectj\com\XXX\cat\db\CacheDbQueries.aj has changed. 14:24:38 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project base-facade 14:24:38 Timer event: 0ms: Looking for and marking configurartion changes in base-facade 14:24:38 Configuration changes found: true 14:24:38 Timer event: 0ms: Look for source/resource changes 14:24:38 Setting list of classpath elements with modified contents: 14:24:38 [C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/collections-generic.jar, C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-beanutils.jar, C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-collections.jar, C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-lang.jar, C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/jaxb-api.jar, C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/jaxb-impl.jar, C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/junit.jar, C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/proteus-util-all.jar, C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-io.jar, C:\Dev\cat-all-eclipse-inpath\ccl-base\bin, C:\Dev\cat-all-eclipse-inpath\ccl-base\all\lib\ide\itext.jar] 14:24:38 Classpath = C:\Dev\cat-all-eclipse-inpath\base-facade\bin;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/collections-generic.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-beanutils.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-collections.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-lang.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/jaxb-api.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/jaxb-impl.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/junit.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/proteus-util-all.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/resources.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/rt.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/jsse.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/jce.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/charsets.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/dnsns.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/localedata.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/sunjce_provider.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/sunmscapi.jar;C:/Program Files/Java/jdk1.6.0_11/jre/lib/ext/sunpkcs11.jar;C:\Dev\cat-all-eclipse-inpath\ccl-base\bin;C:/apps/eclipse/plugins/org.aspectj.runtime_1.6.4.20090329215800/aspectjrt.jar;C:/Dev/cat-all-eclipse-inpath/ccl-base/all/lib/ide/itext.jar;C:/Dev/cat-all-eclipse-inpath/ccl-base/all/lib/ide/jbcl.jar;C:/Dev/cat-all-eclipse-inpath/ccl-base/all/lib/ide/jcommon.jar;C:/Dev/cat-all-eclipse-inpath/base-facade/all/lib/ide/commons-io.jar; 14:24:38 Timer event: 78ms: Pre compile 14:24:38 Sending the following configuration changes to the compiler: [] 14:24:38 1 source file changes since last build 14:24:38 Compiler configuration for project base-facade has been read by compiler. Resetting. 14:24:38 Configuration was [] 14:24:38 Resetting list of modified source files. Was [C:\Dev\cat-all-eclipse-inpath\base-facade\all\src\main\aspectj\com\XXX\cat\db\CacheDbQueries.aj] 14:24:38 ClassFileChangeChecking: failed to find a state instance managing output location : C:\Dev\cat-all-eclipse-inpath\ccl-base\bin 14:24:38 ClassFileChangeChecking: queried JDT and 'C:\Dev\cat-all-eclipse-inpath\ccl-base\bin' is apparently unchanged so not performing timestamp check 14:24:38 Preparing for build: planning to be an incremental build 14:24:39 Examining whether any other files now need compilation based on just compiling: '{C:\Dev\cat-all-eclipse-inpath\base-facade\all\src\main\aspectj\com\XXX\cat\db\CacheDbQueries.aj}' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.aj' 14:24:39 Need to recompile 'XXX.aj' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.aj' 14:24:39 Need to recompile 'XXX.aj' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.aj' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.aj' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.aj' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Need to recompile 'XXX.aj' 14:24:39 Need to recompile 'XXX.aj' 14:24:39 Need to recompile 'XXX.java' 14:24:39 Starting incremental compilation loop 1 of possibly 5 14:24:40 Timer event: 1469ms: Time to first compiled message 14:24:41 Dropping back to full build 14:24:41 Preparing for build: not going to be incremental because no successful previous full build 14:24:56 Timer event: 17390ms: Time to first woven message 14:25:43 AspectJ reports build successful, build was: FULL 14:25:43 AJDE Callback: finish. Was full build: true 14:25:43 Timer event: 64935ms: Total time spent in AJDE 14:25:43 Timer event: 0ms: Refresh after build 14:25:43 Types affected during build = 2658 14:25:43 Timer event: 65185ms: Total time spent in AJBuilder.build() 14:25:43 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): base-facade 14:25:46 Timer event: 15ms: Delete markers: base-facade (Finished deleting markers for base-facade) 14:25:46 Timer event: 16ms: Create markers: base-facade (Finished creating markers for base-facade) 14:25:46 Created 3 markers in 101 files
> However, the one missing piece here is that in your original email to us, > you had mentioned that after a full build you see *no* weave info messages That is kind of what I was seeing on Windows wasn't it. Anyway, although everything is working as designed - we should look to at least supply some kind of support in the absence of markers targetting inpath resources, so i have been looking at bug 268309 which adds a source location to the weaveinfo messages - once their location is known they won't have to be maintained as project level markers. A cursory look at 268309 looks like it will miss AspectJ 1.6.4. Also building weaveinfo messages is extremely expensive due to the lovely formatting they contain - I don't plan to address the cost in the short term. As Andrew says, they are designed as a compiler diagnostics under AJDT. We should have a better solution for inpath marking and navigation.
I'll check it out when it's in a build. Agree on the showWeaveInfo stuff in comment 9. Still missing 1329(ish) markers for all the stuff in base that should be appearing. I think I may have to set up AJ dev project at work and set some breakpoints... That, or progressively trim down the projects until I find the other markers appearing.
Now that bug 271269 has largely been addressed, have you been able to revisit this again to see if the markers are appearing properly?
Move to the 2.0.2 release.
No longer slated for the next release.
