Re: [ajdt-dev] Delete and update Markers taking long time

[Andrew Eisenberg <andrew@xxxxxxxxxxxx>]

I spent some time looking into this recently and I believe that the
problem occurs because of how AJDT looks up source locations for
aspects on the aspect path that come from other projects.  I haven't
opened a bug for this yet.

Since AspectJ does not provide source start and end information for
advice and other program elements in these aspects, AJDT has to
calculate them from line number information (which AspectJ does
provide).  The problem comes when there are a small number of advices
from a separate project being applied many times to the target
project, thus requiring source positions to be recalculated multiple
times.

A possible fix is to have AJDT calculate source positions once and
then cache the result.  This is already done in the latest dev build.
I haven't been able to try this out on any big projects to see if this
makes a difference, but I hope to get to this tomorrow.

Probably the long term fix is to have AspectJ calculate the source
positions during compilation, but first I'd like to see if caching
source locations has a significant affect on marker generation.

If you'd like to try this out, please update to the latest dev build
of AJDT and let me know your experience.

--a

On Wed, Sep 16, 2009 at 11:36 AM, Andy Clement <andrew.clement@xxxxxxxxx> wrote:
> Tom - have you raised either of these problems as bugs? I haven't seen
> any bugzilla email to confirm they are in the system?
>
> cheers,
> Andy
>
> 2009/9/7 Andy Clement <andrew.clement@xxxxxxxxx>:
>> Marker handling is done in a separate job so although painful it
>> shouldn't impact the responsiveness since it will be running in the
>> background.  However, I agree that marker handling should not be
>> anywhere near as expensive as full compilation of a codebase - I
>> believe some work is being done on this but that is AJDT changes,
>> whereas I am concentrating on AspectJ compiler work (incremental
>> issues).  So, yes, that would be a separate bug.
>>
>> cheers,
>> Andy
>>
>> 2009/9/7 Dunstan, Tom (SACE Board) <TomD@xxxxxxxxxxxxxxxxxxx>:
>>> Hi Andy
>>>
>>> Here's a trace from a scenario that probably should have been a full build, but took really quite a long time:
>>>
>>> 13:16:5 Preparing for build: not going to be incremental because path change detected (one of classpath/aspectpath/inpath/injars)
>>> 13:16:5 Falling back to batch compilation
>>> 13:16:5 Preparing for build: not going to be incremental because no successful previous full build
>>> 13:16:12 Timer event: 18219ms: Time to first compiled message
>>> 13:16:12 Timer event: 18219ms: Time to first woven message
>>> 13:16:34 AspectJ reports build successful, build was: FULL
>>> 13:16:36 AJDE Callback: finish. Was full build: true
>>> 13:16:36 Timer event: 42437ms: Total time spent in AJDE
>>> 13:16:36 Timer event: 0ms: Refresh after build
>>> 13:16:36 Types affected during build = 312
>>> 13:16:46 Timer event: 51687ms: Total time spent in AJBuilder.build()
>>> 13:16:46 Timer event: 47ms: Update visualizer, xref, advice listeners for (separate thread): ssabsa-plugin-reports
>>> 13:16:47 Timer event: 1000ms: Delete markers: ssabsa-lib-swing (Finished deleting markers for ssabsa-lib-swing)
>>> 13:16:47 Timer event: 15ms: Create markers: ssabsa-lib-swing (Finished creating markers for ssabsa-lib-swing)
>>> 13:16:47 Created 0 markers in 13 files
>>> 13:17:0 Timer event: 13844ms: Delete markers: ssabsa-plugin-reports (Finished deleting markers for ssabsa-plugin-reports)
>>> 13:17:24 Timer event: 23640ms: Create markers: ssabsa-plugin-reports (Finished creating markers for ssabsa-plugin-reports)
>>> 13:17:24 Created 309 markers in 312 files
>>>
>>>
>>> Combined time of 37 seconds to create markers in 300 files? FYI the ssabsa-lib-swing project has a couple of aspects (mixins) that get applied both to itself and the ssabsa-plugin-reports project mentioned here (it's in the aspectpath).
>>>
>>> This one probably isn't related to the incremental vs full build that I mentioned, so would probably go in a separate bug. It might make the other bug more apparent if full builds are going so slowly, though.
>>>
>>> Thanks
>>>
>>> Tom
>>>
>>> Tom Dunstan
>>> Senior Analyst/Programmer
>>>
>>> SACE Board of South Australia
>>> P   +61 8 8372 7576
>>>
>>>> -----Original Message-----
>>>> From: ajdt-dev-bounces@xxxxxxxxxxx
>>>> [mailto:ajdt-dev-bounces@xxxxxxxxxxx] On Behalf Of Andy Clement
>>>> Sent: Tuesday, 8 September 2009 1:05 PM
>>>> To: ajdt-dev@xxxxxxxxxxx
>>>> Subject: Re: [ajdt-dev] Delete and update Markers taking long time
>>>>
>>>> Tom - I'm happy to work with you to resolve this, please open
>>>> an AspectJ bug, and include the AJDT event trace log (with
>>>> everything turned on) for a build that you believe should not
>>>> be a full build.
>>>> If you can't attach it due to some of the information in it,
>>>> please email it to me.  Kartik - if you haven't heard
>>>> anything on your situation, please also open a bug.  Problems
>>>> that don't get bug reports tend to get lost on the mailing list.
>>>>
>>>> We have numerous testcases for these situations so I
>>>> currently don't really know what problem you are seeing, but
>>>> I'm sure we can get to the bottom of it.  An AspectJ release
>>>> is due at the end of the month, so it would be good to get
>>>> these fixes into that release.
>>>>
>>>> cheers,
>>>> Andy
>>>>
>>>> 2009/9/7 Dunstan, Tom (SACE Board) <TomD@xxxxxxxxxxxxxxxxxxx>:
>>>> > We are also hitting issues with what I believe are full
>>>> builds getting
>>>> > triggered when only changing a class or two, not editing aspects or
>>>> > anything. Sometimes it's modifying a junit class as Kartik was,
>>>> > sometimes not. Currently running AJDT 2.0.0.e35x-20090624-1600.
>>>> >
>>>> > I can provide the output from the trace window or whatever
>>>> else might
>>>> > be helpful..
>>>> >
>>>> > Cheers
>>>> >
>>>> > Tom
>>>> >
>>>> >
>>>> > Tom Dunstan
>>>> > Senior Analyst/Programmer
>>>> >
>>>> > SACE Board of South Australia
>>>> > P   +61 8 8372 7576
>>>> >
>>>> >
>>>> >
>>>> > ________________________________
>>>> > From: ajdt-dev-bounces@xxxxxxxxxxx
>>>> > [mailto:ajdt-dev-bounces@xxxxxxxxxxx] On Behalf Of Kartik Shah
>>>> > Sent: Wednesday, 12 August 2009 8:19 AM
>>>> > To: ajdt-dev@xxxxxxxxxxx
>>>> > Subject: Re: [ajdt-dev] Delete and update Markers taking long time
>>>> >
>>>> > Thanks for your response.
>>>> >
>>>> > File being changed is NOT an aspect. It is JUnit Test Class. The
>>>> > method being changed (trivial change, e.g. delete a line)
>>>> has a aspect
>>>> > applied to it.
>>>> > This aspect is applied across multiple eclipse project
>>>> >
>>>> > The advice implemented on the method is "after returning"
>>>> and "after
>>>> > throwing"
>>>> >
>>>> > Let me know if you need any other information.
>>>> >
>>>> > Thanks,
>>>> > Kartik
>>>> >
>>>> >
>>>> > On Tue, Aug 11, 2009 at 5:22 PM, Andrew Eisenberg
>>>> > <andrew@xxxxxxxxxxxx>
>>>> > wrote:
>>>> >>
>>>> >> There is no way to disable the marker functionality.
>>>> >>
>>>> >> However, it looks like you have hit some unoptimized corner of the
>>>> >> compiler.  You are changing one line in a file and the
>>>> compiler drops
>>>> >> down to a full build for some reason.
>>>> >>
>>>> >> I need to know more about the file you are changing.  Is
>>>> it an aspect?
>>>> >>  Or a class?  Does it have ITDs applied to it?  Are these aspects
>>>> >> being applied cross projects?
>>>> >>
>>>> >> So, I would call this a bug, and the more information that you can
>>>> >> provide will help us be able to fix it better.
>>>> >>
>>>> >> --a
>>>> >>
>>>> >>
>>>> >>
>>>> >> On Tue, Aug 11, 2009 at 2:23 PM, Kartik
>>>> Shah<shahkartikr@xxxxxxxxx> wrote:
>>>> >> > Hi,
>>>> >> >
>>>> >> > After I upgraded to Eclipse 3.5, I am seeing long time taken on
>>>> >> > each compile by action "Delete and update markers.."
>>>> >> >
>>>> >> > For example, in the trace below, all I have done is
>>>> remove one line
>>>> >> > from the Test Class and it take about 5-6 minutes to compile.
>>>> >> >
>>>> >> > Is there a way to reduce this time?
>>>> >> > Why is it deleting/creating markers for all files? Is
>>>> there a way
>>>> >> > to prevent that from happening Can I disable/enable marker
>>>> >> > functionality?
>>>> >> >
>>>> >> > Thanks,
>>>> >> > Kartik
>>>> >> >
>>>> >> >
>>>> >> > 15:48:36
>>>> >> >
>>>> >> >
>>>> ===================================================================
>>>> >> > ========================
>>>> >> > 15:48:36 Build kind = AUTOBUILD
>>>> >> > 15:48:36 Project=commvoice-sigma-adapter, kind of build
>>>> >> > requested=Incremental AspectJ compilation
>>>> >> > 15:48:36 Timer event: 0ms: Flush included source file cache
>>>> >> > 15:48:36 Timer event: 0ms: Check delta
>>>> >> > 15:48:36 File:
>>>> >> >
>>>> >> >
>>>> C:\dev\workspace35\commvoice-sigma-adapter\test\com\suddenlink\sigm
>>>> >> > a\handlers\ordcom1st\TestOrderCommitHandlers.java
>>>> >> > has changed.
>>>> >> > 15:48:36 build: Examined delta - 1 changed, 0 added, and
>>>> 0 deleted
>>>> >> > source files in required project commvoice-sigma-adapter
>>>> >> > 15:48:36 Timer event: 16ms: Looking for and marking
>>>> configuration
>>>> >> > changes in commvoice-sigma-adapter
>>>> >> > 15:48:36     Configuration changes found: true
>>>> >> > 15:48:36 Timer event: 16ms: Look for source/resource changes
>>>> >> > 15:48:36 Setting list of classpath elements with
>>>> modified contents:
>>>> >> > 15:48:36
>>>> >> > [C:/dev/workspace35/commvoice-sigma-adapter/build/classes]
>>>> >> > 15:48:36 Timer event: 188ms: Pre compile
>>>> >> > 15:48:36 Sending the following configuration changes to the
>>>> >> > compiler: []
>>>> >> > 15:48:36 1 source file changes since last build
>>>> >> > 15:48:36 Compiler configuration for project
>>>> commvoice-sigma-adapter
>>>> >> > has been read by compiler.  Resetting.
>>>> >> > 15:48:36      Configuration was []
>>>> >> > 15:48:36 Resetting list of modified source files.  Was
>>>> >> >
>>>> >> >
>>>> [C:\dev\workspace35\commvoice-sigma-adapter\test\com\suddenlink\sig
>>>> >> > ma\handlers\ordcom1st\TestOrderCommitHandlers.java]
>>>> >> > 15:48:36 ClassFileChangeChecking: found state instance managing
>>>> >> > output location :
>>>> >> > C:\dev\workspace35\commvoice-sigma-adapter\build\classes
>>>> >> > 15:48:36 ClassFileChangeChecking: no reported changes in
>>>> that state
>>>> >> > 15:48:36 Preparing for build: planning to be an incremental build
>>>> >> > 15:48:37 Starting incremental compilation loop 1 of possibly 5
>>>> >> > 15:48:38 Timer event: 2094ms: Time to first compiled message
>>>> >> > 15:48:38 Timer event: 2125ms: Time to first woven message
>>>> >> > 15:48:38 AspectJ reports build successful, build was: INCREMENTAL
>>>> >> > 15:48:38 AJDE Callback: finish. Was full build: false
>>>> >> > 15:48:38 Timer event: 2109ms: Total time spent in AJDE
>>>> >> > 15:48:38 Timer event: 0ms: Refresh after build
>>>> >> > 15:48:38 Types affected during build = 1
>>>> >> > 15:48:38 Timer event: 2360ms: Total time spent in
>>>> AJBuilder.build()
>>>> >> > 15:48:38 Timer event: 15ms: Update visualizer, xref, advice
>>>> >> > listeners for (separate thread): commvoice-sigma-adapter
>>>> 15:48:50
>>>> >> > Timer event: 6438ms: Delete markers: commvoice-sigma-adapter
>>>> >> > (Finished deleting markers for commvoice-sigma-adapter) 15:53:10
>>>> >> > Timer event: 259489ms: Create markers: commvoice-sigma-adapter
>>>> >> > (Finished creating markers for commvoice-sigma-adapter) 15:53:10
>>>> >> > Created 1660 markers in 243 files
>>>> >> > --
>>>> >> > "The information transmitted is intended only for the person or
>>>> >> > entity to which it is addressed and may contain proprietary,
>>>> >> > confidential and/or legally privileged material. Any review,
>>>> >> > retransmission, dissemination or other use of, or taking of any
>>>> >> > action in reliance upon, this information by persons or entities
>>>> >> > other than the intended recipient is prohibited. If you received
>>>> >> > this in error, please contact the sender and delete the material
>>>> >> > from all computers."
>>>> >> >
>>>> >> > _______________________________________________
>>>> >> > ajdt-dev mailing list
>>>> >> > ajdt-dev@xxxxxxxxxxx
>>>> >> > https://dev.eclipse.org/mailman/listinfo/ajdt-dev
>>>> >> >
>>>> >> >
>>>> >> _______________________________________________
>>>> >> ajdt-dev mailing list
>>>> >> ajdt-dev@xxxxxxxxxxx
>>>> >> https://dev.eclipse.org/mailman/listinfo/ajdt-dev
>>>> >
>>>> >
>>>> >
>>>> > --
>>>> > "The information transmitted is intended only for the
>>>> person or entity
>>>> > to which it is addressed and may contain proprietary, confidential
>>>> > and/or legally privileged material. Any review, retransmission,
>>>> > dissemination or other use of, or taking of any action in reliance
>>>> > upon, this information by persons or entities other than
>>>> the intended
>>>> > recipient is prohibited. If you received this in error,
>>>> please contact
>>>> > the sender and delete the material from all computers."
>>>> >
>>>> > _______________________________________________
>>>> > ajdt-dev mailing list
>>>> > ajdt-dev@xxxxxxxxxxx
>>>> > https://dev.eclipse.org/mailman/listinfo/ajdt-dev
>>>> >
>>>> >
>>>> _______________________________________________
>>>> ajdt-dev mailing list
>>>> ajdt-dev@xxxxxxxxxxx
>>>> https://dev.eclipse.org/mailman/listinfo/ajdt-dev
>>>> _______________________________________________
>>> ajdt-dev mailing list
>>> ajdt-dev@xxxxxxxxxxx
>>> https://dev.eclipse.org/mailman/listinfo/ajdt-dev
>>>
>>
> _______________________________________________
> ajdt-dev mailing list
> ajdt-dev@xxxxxxxxxxx
> https://dev.eclipse.org/mailman/listinfo/ajdt-dev
>