Building project with multiple grabs in different files takes an extremely long time to build (sometimes 3-5 min and sometimes eclipse just gets stuck at buildingWorkspace)

[visch]

Our grapes/grab looks like this

@Grapes([
	@GrabResolver(name='package', root='file://localRepo/Repository'),
	@Grab(group='group', module='module', version='[1.6.0,1.7.0)'),
	@GrabExclude('org.codehaus.groovy:groovy-all')
])

Our folder structure looks like
-Project1
--SubProject1
---SourceMainClass (Includes a Grape/Grab)
---MiscFiles
--SubProject2
---SourceMainClass (Includes a Grape/Grab)
---MiscFiles
--SubProject3
---SourceMainClass ((Includes a Grape/Grab)
---MiscFiles

Our projects do build/run properly after they are built, but once in a while our "Building Workspace" process in eclipse takes an extremely long time. We have found that it will take seemingly longer per SubProject that we have as we defined subproject above. We've worked around this by doing one of two things.

• Exclude the subprojects we're not working on in the buildPath section in eclipse. If we're only doing one grab statement everything is pretty speedy.

• Remove grab statements during development as our .classpath as all of the references we need, but when we deploy we rely on the grab statements to pull in our dependencies (We do think we made a bad choice not going with a build.gradle per subproject, but this has been working for us so far)

Notes:
*We are running the latest snapshot and this happens on Mars and Neon

[eric-milles]

Can you open the Groovy Event Console and see if there is anything being written at the time of the blockage? Also, are there any entries in your workspace/.metadata/.log file at the time of this or just prior?

[visch]

During one of the eclipse workspace lockups I had the groovy event console opened and caught this.

The timing of ~2 minutes is about the time that eclipse was locked up

           DSL : 14:17:32 Event complete: 13ms: Script creation for NonJavaResource[groovy18.dsld]
           DSL : 14:17:32 Event complete: 405ms: Refreshing inferencing scripts: FolderNameRemoved
   Code select : 14:17:51 Code select starting on ClassNameRemoved.groovy at [ 0,0 ]
   Code select : 14:17:51 Event complete: 0ms: Code select: ClassNameRemoved.groovy
      Compiler : 14:17:51 Build Structure starting for ClassNameRemoved.groovy
      Compiler : 14:17:51 Event complete: 205ms: Build structure: ClassNameRemoved.groovy : Text Viewer Hover Presenter
   Code select : 14:17:51 ClassNameRemoved.groovy at [123,6]
   Code select : 14:17:51 Event complete: 99ms: Code select: ClassNameRemoved.groovy
   Code select : 14:17:52 Code select starting on ClassNameRemoved.groovy at [ 2,0 ]
   Code select : 14:17:52 ClassNameRemoved.groovy at [123,6]
   Code select : 14:17:52 Event complete: 1ms: Code select: ClassNameRemoved.groovy
   Code select : 14:17:54 Code select starting on ClassNameRemoved.groovy at [ 0,0 ]
   Code select : 14:17:54 Event complete: 0ms: Code select: ClassNameRemoved.groovy
      Compiler : 14:18:12 Build Structure starting for ClassNameRemoved.groovy
      Compiler : 14:18:12 Build Structure starting for ClassNameRemoved.groovy
      Compiler : 14:18:12 D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\ClassNameRemoved.groovy: 3: Error grabbing Grapes -- [unresolved dependency: com.leveldata.LibraryNameRemoved#LibraryNameRemoved;[1.6.0,1.7.0): java.util.ConcurrentModificationException at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:901)]
 @ line 3, column 3.
   	@Grab(group='com.leveldata.LibraryNameRemoved', module='LibraryNameRemoved', version='[1.6.0,1.7.0)'),
     ^
AST Transforms : 14:20:24 Global transform groovy.grape.GrabAnnotationTransformation on D:\***\***\****\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\ClassNameRemoved.groovy = 131858ms
      Compiler : 14:20:25 Event complete: 132126ms: Build structure: ClassNameRemoved.groovy : org.eclipse.jdt.internal.ui.text.JavaReconciler

[eric-milles]

In your workspace/.metadata/.log file, is there any more of the ConcurrentModificationException stack?

It appears Ivy is trying to grab you library and is failing. Do you have the jar and whatnot added to ~/.groovy/grapes/com.leveldata?

[visch]

Here's me adjusting the version a bit just to see what happens. groovy event log dump:

   Code select : 14:55:29 Code select starting on ClassNameRemoved.groovy at [ 770,0 ]
   Code select : 14:55:29 Event complete: 0ms: Code select: ClassNameRemoved.groovy
   Code select : 14:55:32 Code select starting on ClassNameRemoved.groovy at [ 394,0 ]
   Code select : 14:55:32 Event complete: 0ms: Code select: ClassNameRemoved.groovy
AST Transforms : 14:55:32 Local transform org.codehaus.groovy.transform.LogASTTransformation on FolderNameRemoved.SubFolderNameRemoved.SubFolderNameRemoved:FolderNameRemoved.SubFolderNameRemoved.SubFolderNameRemoved = 6ms
AST Transforms : 14:55:32 Global transform geb.transform.AttributeAccessingMetaClassRegisteringTransformation on D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\SubFolderNameRemoved.groovy = 9ms
AST Transforms : 14:55:32 Global transform geb.transform.implicitassertions.ImplicitAssertionsTransformation on D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\GoogleInject\DifferentClassNameRemoved.groovy = 4ms
AST Transforms : 14:55:32 Global transform geb.transform.implicitassertions.ImplicitAssertionsTransformation on D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\SubFolderNameRemoved.groovy = 2ms
AST Transforms : 14:55:32 Global transform geb.transform.implicitassertions.ImplicitAssertionsTransformation on D:\***\***\***\FolderNameRemoved\src\DifferentFolderNameRemoved\DifferentSubFolderNameRemoved\DifferentClassNameRemoved2.groovy = 4ms
   Code select : 14:55:33 Code select starting on ClassNameRemoved.groovy at [ 334,0 ]
   Code select : 14:55:33 Event complete: 0ms: Code select: ClassNameRemoved.groovy
   Code select : 14:55:45 Code select starting on ClassNameRemoved.groovy at [ 124,0 ]
   Code select : 14:55:45 Event complete: 1ms: Code select: ClassNameRemoved.groovy
      Compiler : 14:55:47 Build Structure starting for ClassNameRemoved.groovy
      Compiler : 14:55:48 Build Structure starting for ClassNameRemoved.groovy
      Compiler : 14:55:48 D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\ClassNameRemoved.groovy: 3: Error grabbing Grapes -- [unresolved dependency: com.leveldata.GrabClassNameRemoved#GrabClassNameRemoved;[1.5.0,1.7.0): java.util.ConcurrentModificationException at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:901)]
 @ line 3, column 3.
   	@Grab(group='com.leveldata.GrabClassNameRemoved', module='GrabClassNameRemoved', version='[1.5.0,1.7.0)'),
     ^
AST Transforms : 14:56:45 Global transform groovy.grape.GrabAnnotationTransformation on D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\ClassNameRemoved.groovy = 57860ms
      Compiler : 14:56:45 Event complete: 58221ms: Build structure: ClassNameRemoved.groovy : main
   Code select : 14:56:45 ClassNameRemoved.groovy at [12,12]
   Code select : 14:56:45 Event complete: 2ms: Code select: ClassNameRemoved.groovy
   Code select : 14:56:46 ClassNameRemoved.groovy at [162,4]
   Code select : 14:56:46 Event complete: 2ms: Code select: ClassNameRemoved.groovy
AST Transforms : 14:56:49 Global transform groovy.grape.GrabAnnotationTransformation on D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\ClassNameRemoved.groovy = 61504ms
      Compiler : 14:56:49 Event complete: 61818ms: Build structure: ClassNameRemoved.groovy : org.eclipse.jdt.internal.ui.text.JavaReconciler
   Code select : 14:56:49 ClassNameRemoved.groovy at [162,4]
   Code select : 14:56:49 Code select starting on ClassNameRemoved.groovy at [ 13,0 ]
   Code select : 14:56:49 Event complete: 1ms: Code select: ClassNameRemoved.groovy
   Code select : 14:56:52 ClassNameRemoved.groovy at [803,4]
   Code select : 14:56:52 Event complete: 2ms: Code select: ClassNameRemoved.groovy
   Code select : 14:56:52 ClassNameRemoved.groovy at [803,4]
   Code select : 14:56:52 Event complete: 2ms: Code select: ClassNameRemoved.groovy
   Code select : 14:56:57 ClassNameRemoved.groovy at [162,4]
   Code select : 14:56:57 Event complete: 0ms: Code select: ClassNameRemoved.groovy
   Code select : 14:56:57 ClassNameRemoved.groovy at [162,4]
   Code select : 14:56:57 Event complete: 1ms: Code select: ClassNameRemoved.groovy
   Code select : 14:56:58 ClassNameRemoved.groovy at [244,11]
   Code select : 14:56:58 Event complete: 2ms: Code select: ClassNameRemoved.groovy
   Code select : 14:56:58 ClassNameRemoved.groovy at [244,11]
   Code select : 14:56:58 Event complete: 4ms: Code select: ClassNameRemoved.groovy
   Code select : 14:56:58 Code select starting on ClassNameRemoved.groovy at [ 11,0 ]
   Code select : 14:56:58 Event complete: 0ms: Code select: ClassNameRemoved.groovy
      Compiler : 14:56:59 Build Structure starting for ClassNameRemoved.groovy
      Compiler : 14:56:59 Build Structure starting for ClassNameRemoved.groovy
      Compiler : 14:57:00 D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\ClassNameRemoved.groovy: 3: Error grabbing Grapes -- [unresolved dependency: com.leveldata.GrabClassNameRemoved#GrabClassNameRemoved;[1.5.0,1.7.0): java.util.ConcurrentModificationException at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:901)]
 @ line 3, column 3.
   	@Grab(group='com.leveldata.GrabClassNameRemoved', module='GrabClassNameRemoved', version='[1.5.0,1.7.0)'),
     ^
AST Transforms : 14:57:14 Global transform groovy.grape.GrabAnnotationTransformation on D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\ClassNameRemoved.groovy = 14565ms
      Compiler : 14:57:14 Event complete: 14865ms: Build structure: ClassNameRemoved.groovy : main
AST Transforms : 14:57:15 Global transform groovy.grape.GrabAnnotationTransformation on D:\***\***\***\FolderNameRemoved\src\FolderNameRemoved\SubFolderNameRemoved\ClassNameRemoved.groovy = 15568ms
      Compiler : 14:57:15 Event complete: 15883ms: Build structure: ClassNameRemoved.groovy : org.eclipse.jdt.internal.ui.text.JavaReconciler
   Code select : 14:57:15 Code select starting on ClassNameRemoved.groovy at [ 12,0 ]
   Code select : 14:57:15 Event complete: 1ms: Code select: ClassNameRemoved.groovy
   Code select : 14:59:52 ClassNameRemoved.groovy at [1198,3]
   Code select : 14:59:52 Event complete: 1ms: Code select: ClassNameRemoved.groovy
   Code select : 14:59:53 ClassNameRemoved.groovy at [1115,4]
   Code select : 14:59:53 Event complete: 12ms: Code select: ClassNameRemoved.groovy
   Code select : 14:59:53 ClassNameRemoved.groovy at [1115,4]
   Code select : 14:59:53 Event complete: 9ms: Code select: ClassNameRemoved.groovy

In the workspace/.metadata/.log I don't see anything around that time frame, and overall there are only few traces but they were hours before and look to be something to do with eclipse updates. Just in case it's still useful https://gist.github.com/visch/0c5b6d6201fcc53244571e2670584bf3

The ~/.groovy/grapes/com.leveldata does have the latest version of our library pulled down. And the date modified on the ivydata-* files looks to be correct.

[eric-milles]

Whatever is behind that co-mo exception seems to be the thing that is blocking. Too bad it is not logged better. You can try enabling Grab logging to see if that gives a better picture.

http://docs.groovy-lang.org/latest/html/documentation/grape.html#Grape-Logging

[visch]

Haven't verified this yet but from some quick testing this might be much faster when we point to a mapped drive instead of to the DNS/ShareName (Facepalm) . I'll look at the additional Grape logging and let you know.

Thanks for the help thus far!

[eric-milles]

Ivy and by extension Grab can be very tricky at times. Once it is up and running it is quite nice to have, but as you have experienced, it can fight you to the finish.

[visch]

I enabled the extra Grape logging, but could only get output in my main console when I would run one of my applications. The lock happens not only when running a script, but also when changing the grab statements. I checked the workspace/.metadata/.log and didn't see any output.

Here's another groovy event log output when we have multiple packages with grabs https://gist.github.com/visch/f86c2281cff885dea88942328212e230 instead of with just one.

Is there anyway to disable grapes/grabs happening with the groovy-eclipse plugin? We're working on migrating away from this anyways and it might be easier for us in this case.

Probably irrelevant but thought I'd share:
Dug a little bit deeper https://groups.google.com/forum/#!msg/job-dsl-plugin/6JIQyUKBVSI/qSWR1dCf-sMJ is the only similar reference I can find.

[eric-milles]

You can also try adding "-console -debug" to the command line of eclipse and see if the error is written to stdout or stderr.

[eric-milles]

From the linked thread, the concurrent modification exception appears to be in Groovy and not Greclipse. Could you use a specific revision instead of a range to confirm that Greclipse is fine as long as resolve is fine?

[eric-milles]

I can look a little further into the Grab with range, but it appears to be a Groovy issue that is showing though in Greclipse.