Community
Participate
Working Groups
This is regarding some of the problems being investigated by an IBM support member at customer. There aren't alot of specifics yet so this question is a 'feeler' that will hopefully help the investigative process along. Is it possible to trace build activity? It is not much to go on and is the context of WSAD. I am just hunting for directions at this point. Specifically, if you have any information concerning what is occurring internally when the customer does the incremental compile and what specifically is occurring when the "Reading resource change information for: <Project Name>" message appears. A user had WSAD 4.0 installed on their machine and was seeing forty minute compile times after changing a single file (i.e. the user had the "Perform build automatically on resource modification" option checked in WSAD and was hitting CTRL - B to do an incremental compile). The user then migrated to WSAD 4.02 and is now seeing either very short build times (approximately 20 seconds) or longer times (between four to six minutes). So far a pattern has not been discovered regarding when the problem does or does not occur. The customer has the "Perform build automatically on resource modification" option checked in WSAD, was changing and saving a single file Java file, and was then hitting CTRL - B to do the incremental compile. Note: when the long build scenario occurs, the progress dialog appears to move through the dependent projects multiple times and the following text appears in the progress dialog: "Reading resource change information for: <Project Name>". The customer noticed this issue when compiling a class in a Java project. The projects on the 'Java Build Path' are correct and complete. The ClearCase 'cc-meta' file matches the dependencies on the 'Java Build Path' (there was a previous WSAD 4.0 issue concerning the ClearCase meta-data becoming corrupt).
The Java builder displays "Reading resource change information for: <Project Name>" for the duration of the computation of project deltas by Platform/Core. These deltas are then used to compute the set of affected compilation units then thrown into the recompilation loop. If all the time is in this operation, then this might rather expose a platform defect.
To answer the question on build activity tracing, there is unfortunately no trace available for jdtcore 1.0 (these where added in 2.0 only). We would have to produce a jdtcore patch to add these traces. This is doable if critical.
John - does the slow delta retrieval ring any bell to you ? If so, please acquire this bug.
I've never seen anything like this -- forty minute compile times is unbelievable!! I have some questions/comments: - It's strange that the customer had autobuild turned on, but was hitting Ctrl+B. It was my understanding that Ctrl+B had no effect at all when autobuild is on. - Can anyone give the corresponding Eclipse platform build numbers for WSAD 4.0 and 4.02? - There was minimal build trace support in 1.0, see the .options file under org.eclipse.core.resources. Turning those options on will provide debug info only if there was a failure to compute deltas. - Rough information on the size of the customer's workspace might be interesting: number of projects, approx number of resources/project. Also, is it just the Java builder that is running in WSAD, or are there other builders involved? - We can also generate a trace-enabled patch of Platform/Core if required.
I am importing an 8Meg source file and it has been grinding away for over 6hours so far and its not done yet. I believe I have the 4.02 version and I'll verify that once the import is done. I'll ask for the build numbers from IBM support. They should have that information.
I am guessing that 4.0 is our SDK1.0, and 4.02 is our SDK1.0 Rollup ?
Latest from support at customer: Regarding: Reading resource change information for: <Project Name>" customer has reported and I have seen (once) a situation where an incremental build went very slowly and most of the time the the build progress monitor stated this msg. It restated it for the same project multiple times. Have not been able to reproduce. I sent John Wiegand the customer workspace to experiment with (as I have). I am waiting for sufficient face time with the customer to observe first hand what their build experiences are. Their mode now is to run with incr. build off and invoke with control-B when they want a build. If that is taking too long they cancel it and do a Rebuild All. As I mentioned to John W, getting a handle on this will require more diagnostic information. Barry Searle, WSAD IBM Toronto, has a headless version of WSAD that allows him to run the workspace builds via the console using ANT. He claims that quite of bit of build info is captured there. He is refining his code and will share with me. It might be a useful diagnostic aid. I anticipate getting something from him Thursday. Here is a quick profile of the customer workspace. If you think you can make use of the customer workspace let me know.
Here are some raw timings collected while observing the customer. I plan to follow up and put these in context using my notes (ran out of time Friday). In each log his resource changes were confined to one or two classes. Some findings: Log: Mario_WSAD_1.txt: workbench internal error ocurred debugging servlet. Had to restart WSAD In file Mario_URLServiceImpl.txt (class he was working on). There is an entry: build done 249531. This an instance of the very long build where not much work occurs and the progress monitor only reports that is: Updating resource changes <project> (or something like that). I believe it occurred immediatly following a CC connection using CC plugin. Full builds ran about between 50-60 seconds. Incremental builds for the same resource had variances. Hope to add commentary into the logs where I can using my notes. (It is hard to keep the user context synced up with the build timings. I don't know that these entries mean: Snapshot took: 187 milliseconds. Snapshot took: 453 milliseconds. Snapshot took: 203 milliseconds. Snapshot took: 187 milliseconds. Snapshot took: 203 milliseconds. Snapshot took: 187 milliseconds. Any feedback would be helpful.
Moving to Platform/Core since it rather seems delta retrieval related. We can help upon request.
The snapshot timings you see are unrelated to build. The snapshot is an incremental save routine that runs rougly every hundred operations. The only interesting thing about this output is the frequency of the messages, which gives an indication of how many operations are being executed. The message you see in the progress bar is an important hint though. In the original problem report it was a, "Reading resource change information" message, but in the latest entry you noted an "Updating" message. Please clarify the message if you can, because the "Reading" message and the "Updating" message happen at two different points in the build.
Rollup2 and the latest 2.0 integration builds contain code which fixes a bug related to collapsing the element tree during snapshots when a lot of no-ops occurred. It has been verified that this has fixed the problems with the really slow incremental build times. As well more debug options for build tracing have been added to the 2.0 builds. Closing PR.
For reference, there are also new trace options (2.0 stream only) provided by core to aid in debugging build times. The file plugins/org.eclipse.core.resources/.options in any build will always give an up to date list of these options. For convenience, the current set of options (as of build 20020215), is included below: # Turn on debugging for the org.eclipse.core.resources plugin. # Also displays snapshot (incremental save) times. org.eclipse.core.resources/debug=true # Debug build failure cases such as failure to retrieve deltas. org.eclipse.core.resources/build/failure=true # Reports the start and end of all builder invocations org.eclipse.core.resources/build/invoking=true # Reports the start and end of build delta calculations org.eclipse.core.resources/build/delta=true # For incremental builds, displays which builder is being run # and because of changes in which project. org.eclipse.core.resources/build/needbuild=false # Reports configuration and deconfiguration of project natures org.eclipse.core.resources/natures=false