Reputation:
I am using Eclipse to develop a large Maven project (dozens of dependencies). When I try to run a unit test, I see a pause of about a minute, while the status is showing "verifying launch attributes". Observing the Eclipse's activities in Process Monitor, I see a lot of file access to various locks and jars in Maven repository. Looks like Eclipse goes over every JAR that my project depends on. As soon as that file access is done, the actual test starts.
I am aware of advice offered in "Why is Eclipse hanging at 57% with the status “Verifying launch attributes…” when launching a run configuration?", and I followed the suggested fixes. I think Eclipse is doing what it's supposed to do by going over every single JAR. My question is, how can that behavior be disabled, either in Eclipse or in Maven?
I am using Eclipse Luna on Windows 7, m2e version 1.5.0.20140606
Edit:
Below a sample of what I see in Process Monitor:
In short, we spend some 10 seconds on reasonable activity such as checking the state of Java and JAR files, and then we spend ~40 seconds locking Maven repo and reading the POM files.
Why does eclipse do that? And what do I need to change to stop it?
11:31:48.1468054 AM eclipse.exe 3736 CreateFile C:\LAS\Maven\Repository\org\drools\drools-core\6.0.1.Final\drools-core-6.0.1.Final.jar SUCCESS Desired Access: Read Attributes, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
11:31:48.1469017 AM eclipse.exe 3736 QueryBasicInformationFile C:\LAS\Maven\Repository\org\drools\drools-core\6.0.1.Final\drools-core-6.0.1.Final.jar SUCCESS CreationTime: 7/21/2014 11:13:15 AM, LastAccessTime: 7/21/2014 11:13:15 AM, LastWriteTime: 7/21/2014 11:13:22 AM, ChangeTime: 7/21/2014 11:13:23 AM, FileAttributes: A
11:31:48.1469769 AM eclipse.exe 3736 CloseFile C:\LAS\Maven\Repository\org\drools\drools-core\6.0.1.Final\drools-core-6.0.1.Final.jar SUCCESS
11:31:50.0040011 AM eclipse.exe 3736 CreateFile C:\LAS\Maven\Repository\xpp3\xpp3_min\1.1.4c\xpp3_min-1.1.4c.jar SUCCESS Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
11:31:50.0040832 AM eclipse.exe 3736 QueryNetworkOpenInformationFile C:\LAS\Maven\Repository\xpp3\xpp3_min\1.1.4c\xpp3_min-1.1.4c.jar SUCCESS CreationTime: 7/21/2014 11:13:15 AM, LastAccessTime: 7/21/2014 11:13:15 AM, LastWriteTime: 7/21/2014 11:13:21 AM, ChangeTime: 7/21/2014 11:13:23 AM, AllocationSize: 28672, EndOfFile: 24956, FileAttributes: A
11:31:50.0041397 AM eclipse.exe 3736 CloseFile C:\LAS\Maven\Repository\xpp3\xpp3_min\1.1.4c\xpp3_min-1.1.4c.jar SUCCESS
(four seconds worth of this)
11:31:50.0700821 AM eclipse.exe 3736 CreateFile C:\LAS\Maven\Repository\.locks\com.lmax~disruptor~3.3.0.aetherlock SUCCESS Desired Access: Write Attributes, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
11:31:50.0701770 AM eclipse.exe 3736 SetBasicInformationFile C:\LAS\Maven\Repository\.locks\com.lmax~disruptor~3.3.0.aetherlock SUCCESS CreationTime: 0, LastAccessTime: 0, LastWriteTime: 0, ChangeTime: 0, FileAttributes: N
11:31:50.0703100 AM eclipse.exe 3736 CloseFile C:\LAS\Maven\Repository\.locks\com.lmax~disruptor~3.3.0.aetherlock SUCCESS
11:31:59.7990517 AM eclipse.exe 3736 CreateFile C:\LAS\Maven\Repository\.locks\xpp3~xpp3_min~1.1.4c.aetherlock SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
11:31:59.7991381 AM eclipse.exe 3736 QueryAttributeTagFile C:\LAS\Maven\Repository\.locks\xpp3~xpp3_min~1.1.4c.aetherlock SUCCESS Attributes: N, ReparseTag: 0x0
11:31:59.7991864 AM eclipse.exe 3736 SetDispositionInformationFile C:\LAS\Maven\Repository\.locks\xpp3~xpp3_min~1.1.4c.aetherlock SUCCESS Delete: True
11:31:59.7992609 AM eclipse.exe 3736 CloseFile C:\LAS\Maven\Repository\.locks\xpp3~xpp3_min~1.1.4c.aetherlock SUCCESS
(9 second worth of this)
11:31:59.8364794 AM eclipse.exe 3736 CreateFile C:\LAS\Maven\Repository\com\lmax\disruptor\3.3.0\disruptor-3.3.0-sources.jar SUCCESS Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
11:31:59.8367613 AM eclipse.exe 3736 QueryNetworkOpenInformationFile C:\LAS\Maven\Repository\com\lmax\disruptor\3.3.0\disruptor-3.3.0-sources.jar SUCCESS CreationTime: 11/18/2014 2:17:33 PM, LastAccessTime: 11/18/2014 2:17:33 PM, LastWriteTime: 11/18/2014 2:17:33 PM, ChangeTime: 11/18/2014 2:17:33 PM, AllocationSize: 81920, EndOfFile: 80291, FileAttributes: A
11:31:59.8367994 AM eclipse.exe 3736 CloseFile C:\LAS\Maven\Repository\com\lmax\disruptor\3.3.0\disruptor-3.3.0-sources.jar SUCCESS
11:32:02.0222874 AM eclipse.exe 3736 CreateFile C:\LAS\Maven\Repository\org\antlr\antlr-runtime\3.5\antlr-runtime-3.5.jar SUCCESS Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
11:32:02.0223541 AM eclipse.exe 3736 QueryNetworkOpenInformationFile C:\LAS\Maven\Repository\org\antlr\antlr-runtime\3.5\antlr-runtime-3.5.jar SUCCESS CreationTime: 7/21/2014 11:13:15 AM, LastAccessTime: 7/21/2014 11:13:15 AM, LastWriteTime: 7/21/2014 11:13:21 AM, ChangeTime: 7/21/2014 11:13:22 AM, AllocationSize: 167936, EndOfFile: 167735, FileAttributes: A
11:32:02.0223896 AM eclipse.exe 3736 CloseFile C:\LAS\Maven\Repository\org\antlr\antlr-runtime\3.5\antlr-runtime-3.5.jar SUCCESS
(3 seconds worth)
11:32:33.2963547 AM eclipse.exe 3736 CreateFile C:\LAS\Maven\Repository\.locks\commons-logging~commons-logging~1.1.aetherlock SUCCESS Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
11:32:33.2964727 AM eclipse.exe 3736 QueryAttributeTagFile C:\LAS\Maven\Repository\.locks\commons-logging~commons-logging~1.1.aetherlock SUCCESS Attributes: N, ReparseTag: 0x0
11:32:33.2965390 AM eclipse.exe 3736 SetDispositionInformationFile C:\LAS\Maven\Repository\.locks\commons-logging~commons-logging~1.1.aetherlock SUCCESS Delete: True
11:32:33.2966382 AM eclipse.exe 3736 CloseFile C:\LAS\Maven\Repository\.locks\commons-logging~commons-logging~1.1.aetherlock SUCCESS
11:32:33.2970685 AM eclipse.exe 3736 CreateFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS Desired Access: Synchronize, Disposition: Open, Options: , Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
11:32:33.2971806 AM eclipse.exe 3736 QueryNameInformationFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS Name: \LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom
11:32:33.2972430 AM eclipse.exe 3736 CloseFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS
11:32:33.2980275 AM eclipse.exe 3736 CreateFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened
11:32:33.2981528 AM eclipse.exe 3736 ReadFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS Offset: 0, Length: 4,096, Priority: Normal
11:32:33.2983145 AM eclipse.exe 3736 QueryStandardInformationFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS AllocationSize: 8,192, EndOfFile: 6,182, NumberOfLinks: 1, DeletePending: False, Directory: False
11:32:33.2983774 AM eclipse.exe 3736 ReadFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS Offset: 4,096, Length: 2,086
11:32:33.2984420 AM eclipse.exe 3736 QueryStandardInformationFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS AllocationSize: 8,192, EndOfFile: 6,182, NumberOfLinks: 1, DeletePending: False, Directory: False
11:32:33.2985057 AM eclipse.exe 3736 QueryStandardInformationFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS AllocationSize: 8,192, EndOfFile: 6,182, NumberOfLinks: 1, DeletePending: False, Directory: False
11:32:33.2987730 AM eclipse.exe 3736 CloseFile C:\LAS\Maven\Repository\commons-logging\commons-logging\1.1\commons-logging-1.1.pom SUCCESS
(30 seconds!)
Upvotes: 6
Views: 3809
Reputation: 373
For this reason, I had one of the maven repositories down causing m2e hanging. I just disable the host in my /etc/hosts and it worked.
Upvotes: 0
Reputation:
So far, the only thing that helps is closing a lot of projects in my workspace. When I have 30 Maven dependencies coming from my worksapce, the unit test take 30+ seconds to start. When I close those projects and forse Eclipse to go to local repository, the start of unit tests takes 5 seconds.
I see no correlation between start time and "external" dependencies. Only "internal" (in workspace and open) dependencies matter.
Upvotes: 2
Reputation: 11
If you can, would you try to use m2e 1.4.x with an older Eclipse release? According to a response I got from a m2e developer on the m2e-user mailing list (http://dev.eclipse.org/mhonarc/lists/m2e-users/msg05095.html), an limit of project cache size was introduced on m2e 1.5. When we upgraded m2e from 1.4 to 1.6 (with Eclipse version), we started seeing issues like yours. I would like to see whether your problem could be recreated with m2e 1.4.x. Thanks, Tami
Upvotes: 1
Reputation: 328760
From the chat:
mvn test spends ~ 20 seconds downloading maven-metadata.xml for our own packages from our own snapshot repository - something I don't see Eclipse doing. There is no large delay before mvn test starts showing output.
Closing all projects except the one you need brings build time down to 5s the POM is configured to check every build for changes in snapshot, so the download happens every time
The m2e plugin of Eclipse uses the same strategies as Maven. If you tell Maven to check snapshots for every build, then Eclipse will also do this. If mvn test
spends 20s checking dependencies, Eclipse will need the same time (you should be able to see this in the Maven Console in Eclipse; you can find this console in the same dropdown menu as the Stack Trace Console - look for the button with the little +
in the upper right corner in the Console View)
Suggestions to reduce build times:
mvn -U
to upgrade them during the day. I think this change will bring the biggest gains.[EDIT] Reading an XML file doesn't take 2 seconds unless you have not enough memory. Please check this (use "General / Heap status" in the preferences).
If it's still slow, then m2e does something in this "Read Maven project" step. My guess is that it recalculates the classpath. If this takes long, then either:
$HOME/.m2/repository/
If closing projects helps, then you may have to close as many projects as you can.
Upvotes: 2
Reputation: 5502
I don't think the excessive locks creation/access is the source of the problem. I also have thousands of those lines in the log on my system, and 100+ maven dependencies, but everything is lighting fast.
Try running the tests outside of Eclipse.To do that, go to the .pom directory and type
mvn test
If again everything is slow, then eclipse is not the source of the problem, may be its bad sectors on HDD or who knows what.
However, if its fast, then indeed Eclipse is the problem.
You can try to turn validation off globally, by going to Preferences>Validation and then click on Suspend all Validators, and make sure your project doesn't override the global validation settings.
Upvotes: 0