user3458
user3458

Reputation:

Eclipse hangs on "verifying launch attributes" in large Maven projects

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

Answers (5)

Pascal Heraud
Pascal Heraud

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

user3458
user3458

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

Tami Takamiya
Tami Takamiya

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

Aaron Digulla
Aaron Digulla

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:

  • Change the config of the POMs to check snapshots only once per day. Use mvn -U to upgrade them during the day. I think this change will bring the biggest gains.
  • Use a CI server to build everything with the latest snapshots, so you don't have to waste time
  • Pull all snapshot dependencies into a single Maven project; Maven only downloads snapshot dependencies if they aren't part of the current build.
  • upgrade your network and try to tune your Maven proxy server (where you download the snapshots from). My experience is that this step is expensive and doesn't give that much gain.
  • close as many projects as you can. This generally makes Eclipse faster but doesn't help with snapshot checks, obviously.
  • Avoid snapshots; work more with released builds. Come up with a fast release process so you can do many releases per day if the need arises.

[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:

  • something is broken in your setup (-> new workspace should fix this)
  • your local Maven repository is somehow corrupt. Try to delete $HOME/.m2/repository/
  • If you have "always update" enable, disable this. If it's now fast, then your network or the company Maven repo is slow. You will either have to disable the "always update" again, live with the slowness or talk to your admins.
  • Try to disable all plugins that you don't need. You may have to install a second Eclipse for this. Maybe one of the other plugins causes the delays. I've seen this with the eGit plugin which would sometimes go into an infinite loop trying to refresh the workspace state.
  • Windows: Do not create your workspace in your user's home folder or any folder which Windows indexes.

If closing projects helps, then you may have to close as many projects as you can.

Upvotes: 2

outdev
outdev

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

Related Questions