Bug 481417 - Several seconds freeze on "Verifying launch attributes" when running a test/main class
Summary: Several seconds freeze on "Verifying launch attributes" when running a test/m...
Status: RESOLVED FIXED
Alias: None
Product: m2e
Classification: Technology
Component: Core (show other bugs)
Version: 1.6.0   Edit
Hardware: PC Windows 7
: P3 normal with 1 vote (vote)
Target Milestone: 1.7.0/Neon RC3   Edit
Assignee: Project Inbox CLA Friend
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2015-11-04 09:50 EST by Kristoffer Erlandsson CLA Friend
Modified: 2017-08-04 08:23 EDT (History)
5 users (show)

See Also:


Attachments
Thread dumps (20.63 KB, text/plain)
2015-11-04 09:50 EST, Kristoffer Erlandsson CLA Friend
no flags Details
cpu profile (163.68 KB, image/png)
2016-04-07 16:16 EDT, Matej Spiller Muys CLA Friend
no flags Details
Reproducable sample for maven slowenes (56.18 KB, application/x-zip-compressed)
2016-05-26 08:02 EDT, Matej Spiller Muys CLA Friend
no flags Details
Run test cpu profile (187.73 KB, image/png)
2016-05-26 08:14 EDT, Matej Spiller Muys CLA Friend
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Kristoffer Erlandsson CLA Friend 2015-11-04 09:50:55 EST
Created attachment 257736 [details]
Thread dumps

When launching a main class or a test class we see a hang of several (about 10) seconds. Eclipse prints "Verifying launch attributes" in the progress bar.

I have seen this issue referenced on Stack overflow:

http://stackoverflow.com/questions/12396024/why-is-eclipse-hanging-at-57-with-the-status-verifying-launch-attributes-w

http://stackoverflow.com/questions/27781242/eclipse-hangs-on-verifying-launch-attributes-in-large-maven-projects

and the m2e-users mailing list:

http://dev.eclipse.org/mhonarc/lists/m2e-users/msg05095.html

but yet no solution that works for us.

Of note is that disabling workspace resolution hides the problem for us.

I have taken some thread dumps when Eclipse freezes in this stage. These van be viewed in this gist: https://gist.github.com/kerlandsson/ab90eaab440a17427c5a. Also attached to this issue.

All three dumps are running the same class.
Comment 1 Kristoffer Erlandsson CLA Friend 2015-11-04 10:14:04 EST
Another way to work around this problem is to close projects until we have only a few projects referenced under the Maven Dependencies classpath container. Obviously neither this nor disabling workspace resolution are good workarounds since we actually want these projects open and resolved in the workspace.
Comment 2 Jan Moennich CLA Friend 2016-02-16 07:54:02 EST
Ok, I think the main reason is written already to the mentioned mailing list.
We considered switching vom IntelliJ to Eclipse, but we have to wait 15s or more per launch start.

And I find it very disappointing if the root cause was identified (small cache size), all mails are answered and the the reaction is only "this works well for vast majority of users". No, it doesnt! The "vast majority" is silent or switchs to IntelliJ and is happy. Or will not even suggest it for enemies: http://blog.fealdia.org/2011/08/29/eclipse-m2e-launching-verifying-launch-attributes-stuck-on-57/.

Maybe it's the virus scanner of our company, but IntelliJ is fast with it.

So, please, try to understand your eclipse user and do not think that optimized developer machines are the reference environment. 

(Sorry for my bitterness, but this is not the only show-stopper-bug of eclipse, see #485192)

Worker-11" #43 prio=5 os_prio=0 tid=0x488c6c00 nid=0x3098 runnable [0x4fd4e000]
  java.lang.Thread.State: RUNNABLE
       at java.io.WinNTFileSystem.delete0(Native Method)
       at java.io.WinNTFileSystem.delete(Unknown Source)
       at java.io.File.delete(Unknown Source)
       at io.takari.filemanager.internal.DefaultFileManager$LockFile.delete(DefaultFileManager.java:465)
       at io.takari.filemanager.internal.DefaultFileManager$LockFile.close(DefaultFileManager.java:458)
       at io.takari.filemanager.internal.DefaultFileManager$LockFile.unlock(DefaultFileManager.java:331)
       at io.takari.filemanager.internal.DefaultFileManager$IndirectFileLock.unlock(DefaultFileManager.java:269)
       - locked <0x07e18180> (a io.takari.filemanager.internal.DefaultFileManager$LockFile)
       at io.takari.filemanager.internal.DefaultFileManager$IndirectFileLock.close(DefaultFileManager.java:216)
       at io.takari.filemanager.internal.DefaultFileManager$IndirectFileLock.unlock(DefaultFileManager.java:159)
       - locked <0x07e17a50> (a io.takari.filemanager.internal.DefaultFileManager$IndirectFileLock)
       at io.takari.aether.concurrency.LockingSyncContext.close(LockingSyncContext.java:119)
       at org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts(DefaultArtifactResolver.java:250)
       at org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveDependencies(DefaultRepositorySystem.java:367)
       at org.apache.maven.project.DefaultProjectDependenciesResolver.resolve(DefaultProjectDependenciesResolver.java:205)
       at org.apache.maven.project.DefaultProjectBuilder.resolveDependencies(DefaultProjectBuilder.java:215)
       at org.apache.maven.project.DefaultProjectBuilder.build(DefaultProjectBuilder.java:188)
       at org.apache.maven.project.DefaultProjectBuilder.build(DefaultProjectBuilder.java:119)
       at org.eclipse.m2e.core.internal.embedder.MavenImpl.readMavenProject(MavenImpl.java:636)
       at org.eclipse.m2e.core.internal.project.registry.ProjectRegistryManager$5.call(ProjectRegistryManager.java:815)
       at org.eclipse.m2e.core.internal.project.registry.ProjectRegistryManager$5.call(ProjectRegistryManager.java:1)
       at org.eclipse.m2e.core.internal.embedder.MavenExecutionContext.executeBare(MavenExecutionContext.java:176)
       at org.eclipse.m2e.core.internal.embedder.MavenExecutionContext.execute(MavenExecutionContext.java:151)
       at org.eclipse.m2e.core.internal.embedder.MavenExecutionContext.execute(MavenExecutionContext.java:99)
       at org.eclipse.m2e.core.internal.project.registry.ProjectRegistryManager.execute(ProjectRegistryManager.java:956)
       at org.eclipse.m2e.core.internal.project.registry.ProjectRegistryManager.readProjectWithDependencies(ProjectRegistryManager.
ava:811)
       at org.eclipse.m2e.core.internal.project.registry.ProjectRegistryManager.readProjectWithDependencies(ProjectRegistryManager.
ava:794)
       at org.eclipse.m2e.core.internal.project.registry.ProjectRegistryManager$6.call(ProjectRegistryManager.java:999)
       at org.eclipse.m2e.core.internal.project.registry.ProjectRegistryManager$6.call(ProjectRegistryManager.java:1)
       at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4724)
       at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3522)
       at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2315)
       at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2278)
       - locked <0x078af850> (a com.google.common.cache.LocalCache$StrongAccessEntry)
       at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2193)
       at com.google.common.cache.LocalCache.get(LocalCache.java:3932)
       at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4721)
       at org.eclipse.m2e.core.internal.project.registry.ProjectRegistryManager.getMavenProject(ProjectRegistryManager.java:997)
       at org.eclipse.m2e.core.internal.project.registry.MavenProjectFacade.getMavenProject(MavenProjectFacade.java:242)
       at org.eclipse.m2e.jdt.AbstractClassifierClasspathProvider.addMainFolder(AbstractClassifierClasspathProvider.java:79)
       at org.eclipse.m2e.jdt.internal.launch.NullClassifierClasspathProvider.setRuntimeClasspath(NullClassifierClasspathProvider.j
va:53)
Comment 3 Matej Spiller Muys CLA Friend 2016-04-07 16:15:44 EDT
I have the same problem. We have 85 of maven modules in one larger project (imported in eclipse).
The problem is that every time we start class with main it stalls at verifying launch attributes for 45 seconds.

File monitor is showing me that m2e is constantly creating and deleting files in
C:\Users\[username]\.m2\repository\.locks
If I track the files it is creating/deleting around couple of 10k of locks.
I am using SSD disk so creating locks would be even more painful.
This happens each time I run the project.

Can this locking be disabled? I would prefer faster without the validation. Why does eclipse need to write locks to a disk? In case of what? Concurrent usage of the same project in two eclipses?

I am attaching the screenshot of cpu profile.

TrackingFileManager:
Manages potentially concurrent accesses to a properties file.
Comment 4 Matej Spiller Muys CLA Friend 2016-04-07 16:16:54 EDT
Created attachment 260782 [details]
cpu profile
Comment 5 Matej Spiller Muys CLA Friend 2016-05-26 08:01:20 EDT
I have created anonymous version from our real project.
Replacing all our project names with module_XXX.
Replacing all custom dependecies with similar from maven central.
Delete all java code except one java sample class.
This is module_25 containing: com.test: Test.java.
End WAR has around 200 JARS inside it (it's a bit bigger enterprise project).

With attached version you can see how slow maven for eclipse is.

From CMD line (pure maven):
mvn clean - 1.5 SEC
mvn clean compile - 9 SEC
mvn compile - 9 sec
mvn package - 13 sec
mvn clean package - 20 sec

Inside eclipse: Mars.2 and Neon.RC1 (6GB for heap memory)
1.
import projects (first try): hangs at Building workspace (Sleeping) - killed the job after 10 minutes
import projects (seconds try): hangs again at Building workspace (Sleeping) - killed the job after 15 minutes
Actually the import was successfull taking only 90 seconds (seen from log), but compile after import failed every time (some weird deadlocks).

2.
update maven project: 2 min 40 seconds 
update maven project: 3 min
update maven project offline: 2 min 40 seconds 

3.
run Test.java from eclipse: 27 seconds
run Test.java from eclipse: 25 seconds
run Test.java from eclipse: 30 seconds


The last issue is showing that maven is constantly creating and deleting aetherlock (from my count using process monitor more than couple of tousands). In our case the application is launched in 45-60 seconds due to some differences from our internal and maven central dependencies.

The same bug was closed numerous times as works for me. But the bug still remains opened even after 5 years!!! And is absolute production kill.

I was checking for the next maven hangouts but it seems that there are none anymore? I would really like to hear what is the architectural reason for this file based locking. Because pure maven is doing nothing of this kind.
Can we just get rid of it (perhaps at least for non snapshot versioned artifacts)?
Comment 6 Matej Spiller Muys CLA Friend 2016-05-26 08:02:31 EDT
Created attachment 262023 [details]
Reproducable sample for maven slowenes
Comment 7 Matej Spiller Muys CLA Friend 2016-05-26 08:14:49 EDT
Created attachment 262024 [details]
Run test cpu profile

Note that cpu is not so heavily used because of excessive IO usage. But it is still the top item (ignoring the sleep method).
And this is happening on SSD disk.
Comment 8 Matej Spiller Muys CLA Friend 2016-05-31 12:48:56 EDT
I think I have solved the issue. The main problem is indeed the locking.
If I delete takari-local-repository and takari-filemanager jars from:
C:\eclipse46RC1\plugins\org.eclipse.m2e.maven.runtime_1.7.0.20160524-1811\jars then the functionality starts to work as in official maven.

After this run from the attached sample takes only 5 seconds.
This means that 20-25 seconds is lost every time just because of "busted" file based locking.

This fix actually replaces the TakariLocalRepositoryManager to a EnhancedLocalRepositoryManager from aether (it supports the same enchanced structure). Also the locking is replaced from LockingSyncContextFactory to Aehter's DefaultSyncContextFactory (does not lock).

I know this is not perhaps safest solution, however official maven is already working exactly like this.

Can somebody confirm this?
Comment 9 Fred Bricon CLA Friend 2016-05-31 15:18:54 EDT
Removing these jars make the time to execute go from ~20s down to 8s on my macbook pro.
Apparently they were planned to be removed anyway, since they didn't bring any apparent benefit, so I made it official in http://git.eclipse.org/c/m2e/m2e-core.git/commit/?id=a216aad800082fcf7c8243c8faf470ecb6a3f407
Comment 10 Carsten Pfeiffer CLA Friend 2017-04-04 05:49:08 EDT
Thanks Matej for the test scenario!

I believe that the actual cause for the performance problem is fixed with bug 509362 rather than by the removal of takari-local-repository.

I believe the latter should be re-added, since we experience jar corruption in the ~/.m2 repository without it (see bug 514691, where I also posted timings of your test scenario
- with takari-local-repository
- and with the patch from bug 509362