Artifact resolution is unreasonably slow for multi-module projects

[jwebb]

note from sbt team

This issue is now solved using cached resolution feature.

updateOptions := updateOptions.value.withConsolidatedResolution(true)

If anyone has further issues with dependency resolution performance, please provide more context and open a new Github issue.

original report

So I have a multi-module project - dozens of modules - in which many of the modules have very similar (transitive) dependencies. Each day, sbt (v0.11.2) decides it needs to re-check all those dependencies, and it does so independently for each module. So if I have, say, 20 modules depending on slf4j, sbt appears to hit the repository 20 times to re-download exactly the same pom.xml. Multiply that by a hundred-odd dependencies and the whole process is taking a couple of minutes. Seems like some caching or up-front reconciliation would be helpful here.

[nau]

Confirm, we have the same problem. It's the most annoying thing using sbt. We spend unreasonable amount of time just waiting for dependencies resolution. Any suggestion on how to improve this would be really appreciated.

[manuelbernhardt]

Same issue here. It takes 5-10 minutes to resolve artifacts, and it is really quite frustrating sometimes.

[manuelbernhardt]

I made a screen capture to illustrate how slow it is: http://vimeo.com/61423682

It often is much slower, when on a slower network connection. This is SBT 0.12.2

[everson]

I have the same issue. It is consistently slow, no matter how much times I run it. It takes more time resolving than building itself, even on a fast network connection. Using SBT 0.12.4.

[nau]

Guys, any progress on this? We spend horrifying amount of time just resolving same hundred dependencies for each of 20 sub-projects. It can take 10 minutes to resolve the same artifacts that didn't change. I tired of hearing "Maven does it better" and hearing suggestions to move back to Maven. Currently, for us, this is the most annoying, hence the most important issue. Please, help :)

[mtgto]

I affected same problem in my project using sbt multi-modules (more than 10). To solve this problem, I traced how HTTP requests called by sbt. I found below remarkable situations:

• When I use _SNAPSHOT VERSION library_, sbt might access to the resolver per every building of sub-projects.
• sbt might not memory any HTTP response (include 404 Not Found) on library resolution of another sub-project.

Now, I am using squid to cache sbt's wasteful requests. I successfully speed-up build-time 310 sec to 244 sec by squid. (write -Dhttp.proxyHost=<squid host> -Dhttp.proxyPort=<squid port> to SBT_OPTS in ~/.sbtconfig)

In addition, I shall recommend to avoid using _SNAPSHOT VERSION_ library ;-p

[diwa-zz]

+1 for a solution We have a play application split into multiple projects and encounter this behavior all the time

[dilbert69]

+1 for a solution We also have a small play application split into multiple small projects ... this gets especially annoying when fixing small issues in short iterations ... seems not too many people face this issue

[brikis98]

It's still slow for us with SBT 0.13. We have several large multi-project setups and they have become unusably slow.

[jsuereth]

This is kind of a known issue with -SNAPSHOT and Ivy. We'll see what we can do to workaround. I'm totally aware of the slowdown, sorry guys. Patches more than welcome.

[harrah]

Redownloading the metadata for -SNAPSHOTs and other dynamic revisions will only be a problem if explicitly running update as documented here: http://www.scala-sbt.org/release/docs/Detailed-Topics/Dependency-Management-Flow.html. When explicitly runningn update, there are many possible reasons for slow downloading, such as misconfigured repository managers or Ivy just being serial. Again, downloading should only happen as described by the above document. Things are already cached fairly well for stable revisions.

The hardest to address would be if it is slow even if there is no network access. No network access can be forced by having everything in the cache and using offline := true. (offline really tells Ivy not to update dynamic revisions.) In that case, it is likely Ivy's resolution computation itself which is slow.

[brikis98]

We aren't using any -SNAPSHOT versions - we even have a precommit hook to prevent them. One thing we noticed with multi-project setups is that adding the following speeds things up:

aggregate in update := false

If you aggregate several projects, is SBT redundantly (er, sequentially) updating all of them every single time?

That said, updating even a single project seems particularly slow: on the order of 1 minute for a few hundred dependencies, all in the local cache. Not sure what the issue is there.

[harrah]

If project root aggregates other projects, it just means when you run update on the root project from the command line, it also runs each aggregated project's update. If you depend on root/update programmatically, only root/update is called. It is strictly a command line convenience.

Each project's update runs once. There shouldn't be any redundant resolution done in the absence of snapshots. Ivy's not really safe for concurrent cache access (maybe if you tried hard you could make it so, but in practice it isn't), so yes, only one update runs at a time.

I assume a few hundred dependencies is the number of ultimately selected dependencies. That's useful to know and is correlated to the next number, but the direct variable is probably the total number of considered dependencies. (Probably not a major distinction, but figured I'd mention it.) Typically, I'd expect < 10 s for that size, so perhaps something is off. It sounds like it might be in the resolution algorithm, so it is probably hard to say anything without inspecting the actual project.

[brikis98]

The impression I got was that when we used the run command on the root project, it ran update on each of the projects that root aggregates. This was extremely slow and stopped being a problem when we added aggregate in update := false.

The number of direct dependencies, judging by show libraryDependencies is 10-15; there are several hundred once you fan out to all the transitive dependencies.

We've noticed some other oddities:

1. Even if everything is in the local ivy cache, running update is still slow: on the order of ~40 seconds. Most of the checks seem fast, but the occasional artifact takes 2-3 seconds. With several hundred dependencies in the entire graph, this adds up quickly. No idea why reading a tiny XML file on the hard drive would take that long.
2. If we change the version setting on a project, it results in update running again. There is likely something else at play here, so we're still digging into it.

[harrah]

I believe you've seen http://www.scala-sbt.org/release/docs/Detailed-Topics/Dependency-Management-Flow.html#caching-and-configuration, so to apply some of the points from that section to what you are saying:

1. "Normally, if no dependency management configuration has changed since the last successful resolution and the retrieved files are still present, sbt does not ask Ivy to perform resolution."

   When you run run, this is generally the situation. If you have not modified the configuration since the last successful update or run update directly from the command line, there should be zero (< 20 ms) time spent in update.

2. "Changing the configuration, such as adding or removing dependencies or changing the version or other attributes of a dependency, will automatically cause resolution to be performed."

   Changing version changes the project's dependency configuration, so it is expected that update reruns in this case.

3. "Directly running the update task (as opposed to a task that depends on it) will force resolution to run, whether or not configuration changed. This should be done in order to refresh remote SNAPSHOT dependencies."

   The SNAPSHOT part also applies to version ranges, since they are both dynamic revisions. Again, this situation should not apply to running run, however. This is only when explicitly running update from the command line. If you are seeing dependencies getting resolved when running run (after a previous run with no configuration changes, etc...), that's unexpected.

Just a comment on "No idea why reading a tiny XML file on the hard drive would take that long." I've previously profiled reading from the cache and it takes a negligible amount of time. If there is no network access, it is very likely the time is spent in pure computation. (In theory, dependency resolution is NP-hard. I'd be surprised if that is the root problem here, though.)

Also, what I meant by "number of ultimately selected dependencies" is that you might transitively visit multiple versions for each module and the dependency manager has to resolve those different versions. Depending on the graph, the total number of visited nodes might be much larger than the final number of nodes.

[brikis98]

Ah, I think point number 2 about the version changes may explain the behavior we're seeing. Based on the strange way we publish artifacts internally, we automatically bump the version number for each checkin; therefore, it changes very frequently when you update your git/svn repo. Is there an easy way to skip that?

I can't imagine what computation it could possibly be doing that takes multiple 2-3 second pauses while resolving a few hundred items. We should probably bust out a profiler on our end and see where we're spending our time.

[harrah]

I apologize for quoting almost the whole linked section at this point, but I'd probably summarize it less clearly or miss something:

"5. Overriding all of the above, skip in update := true will tell sbt to never perform resolution. Note that this can cause dependent tasks to fail. For example, compilation may fail if jars have been deleted from the cache (and so needed classes are missing) or a dependency has been added (but will not be resolved because skip is true). Also, update itself will immediately fail if resolution has not been allowed to run since the last clean."

More control over caching, such as never updating based on version but updating on every other change, would require changes to sbt.

[dk14]

There is a lot of time wasted on ivy's resolveConflicts() execution for my project. I used custom resolver to cache resolved dependencies - updating time decreased by only 10-20%. So, I believe, Ivy spent most of time analyzing dependency graph conflicts after resolution.

[jrudolph]

There was (at least) one notable appearance of version ranges. It was a common dependency which transitively depended on jackson with a version range:

"com.codahale" % "jerkson_2.9.1" % "0.5.0"

http://repo.codahale.com/com/codahale/jerkson_2.9.1/0.5.0/jerkson_2.9.1-0.5.0.pom

I've seen this dependency in many projects and it attributed a big share of the total time sbt spent during update. Another common one is commons-logging. This is especially bad when having a big multi-module project where every single subproject retries to find out what the concrete version for this version range is. Even worse: having to use a VPN to access a private repository mirror decreasing roundtrip times even more.

From my experience sbt works as @harrah says. However, there are those remaining problems:

• caching helps less if you have a workflow that includes switching branches often which makes it more likely that details of the dependency configuration change (hard to solve?, possible solution: cache multiple update results by dpendency configuration?)
• finding out the most recent version for a version range happens for each subproject anew (possible solution: cache the results of those requests, e.g. by registering a custom org.apache.ivy.util.url.URLHandler that intercepts and caches version listing (or any?) requests)

[manuelbernhardt]

+1 on @jrudolph 's comment about switching branches: indeed, even minor changes in the build configuration / dependency configuration trigger a completely new resolution process, having multiple dependency configurations being cached would be very much welcome, especially for larger multi-module builds.

One thing I wonder about is whether these caches survive a reload (or even, leaving SBT) - since switching a branch with dependency changes more often than not requires a reload.

[tutufool]

To harrah:

I'd suggest you to try to add a module with about 10 dependencies and copy this module for 99 times

When you try to run update from the root, those "exactly the same" 100 modules will take a long time.

From my understanding, running update at the root level should be something like open a session which is stateful. It should be able to remember/cache something when processing modules from 1 to 100.

But now, it seems that the root level update just trigger each module's update 1 by 1, stateless.

[jsuereth]

Right now we aren't sharing the in-memory cache between projects. I have an experimental branch which does this, but haven't evaluated the improvement yet: https://github.com/sbt/sbt/tree/wip/shared-memory-cache-ivy

Feel free to try that branch out and see if you notice a speed up. Most likely, stabilizing that branch will loose some of the speed up, but I'm curious if you notice anything.

My $$$ right now is on some kind of horrid performance when Ivy reads values out of its own cache. Some combination of flags has caused us to ALWAYS re-resolve.

[tutufool]

Hi, Josh

I'm very new to sbt, could you give some instructions/wikis on how to build a sbt deliverable for your branch wip/shared-memory-cache-ivy, so I can give it a try.

Thanks

[tutufool]

Btw, from my observation, the bottleneck is org.apache.ivy.core.resolve.ResolveData.mediate

I saw debug messages like below: (exactly match)

dependency descriptor has been mediated: dependency: log4j#log4j;1.2.17 {compile=[compile(), master()], runtime=[runtime()]} => dependency: log4j#log4j;1.2.13 {compile=[compile(), master()], runtime=[runtime()]}

For over 11000 times in my update log.

And:

dependency descriptor has been mediated: dependency: commons-lang#commons-lang;2.6 {compile=[compile(), master()], runtime=[runtime()]} => dependency: commons-lang#commons-lang;2.5 {compile=[compile(), master()], runtime=[runtime()]

for around 3000 times.

The deeper node seems to have more chances to get re-mediate.

Is there any cache to keep the mediate result like from DependencyDescriptor DD1 to DD2 within some certain context?

[jsuereth]

I'm not sure. The cache fix I have is for the descriptor, but I think perhaps the wrong one. That's some really good information for us to dig into though, thanks.

For using sbt locally:

Checkout that branch:

sbt> publishLocal

Then in your project/build.properties, set the version to 0.13.2-SNAPSHOT (or whatever you just pushed). Note: You'll have to clean your ~/.sbt/boot directory every time you push a new -SNAPSHOT version. We don't have -SNPSHOT working in the launcher.

On Wed, Mar 26, 2014 at 10:21 PM, tutufool notifications@github.com wrote:

Btw, from my observation, the bottleneck is org.apache.ivy.core.resolve.ResolveData.mediate

I saw debug messages like below: (exactly match)

dependency descriptor has been mediated: dependency: log4j#log4j;1.2.17 {compile=[compile(), master()], runtime=[runtime()]} => dependency: log4j#log4j;1.2.13 {compile=[compile(), master()], runtime=[runtime()]}

For over 11000 times in my update log.

And:

dependency descriptor has been mediated: dependency: commons-lang#commons-lang;2.6 {compile=[compile(), master()], runtime=[runtime()]} => dependency: commons-lang#commons-lang;2.5 {compile=[compile(), master()], runtime=[runtime()]

for around 3000 times.

The deeper node seems to have more chances to get re-mediate.

Is there any cache to keep the mediate result like from DependencyDescriptor DD1 to DD2 within some certain context?

Reply to this email directly or view it on GitHubhttps://github.com/sbt/sbt/issues/413#issuecomment-38762853 .

[tutufool]

1 more finding:

DefaultRepositoryCacheManager will be created many times across modules, hence ModuleDescriptorMemoryCache can't be re-used across modules.

Does that mean if multiple modules depends on artifact A, A's ivy.xml will be parsed multiple times?

[jsuereth]

Yes, but when I created a branch which shared the memory cache between all the CacheManagers it didn't actually solve the performance issues on a "real-world" project (something that depends on a decent amount of maven-artifacts), so I think it's a red herring.

[jsuereth]

Also, check out: https://github.com/sbt/sbt/pull/1226

[jsuereth]

I think we've isolated some solid performance issues with O(N!) graph traversal in Ivy, however we won't be able to get/stabilize a fix in time for 0.13.5. Pushing this back to sbt 0.13.6

[shikhar]

@jsuereth thank you for your work on this!

our ant+ivy build went from 30s to 1.5-2mins after a Solr4.6->4.7 upgrade, all time spent in ivy:resolve

i just switched out to sbt's ivy 2.4 pre-release jar from #1226, and it's back down!

[jsuereth]

awesome news! We have more we'd like to do here, so it's good to hear you're back down. 30s is still longer than we'd like :)

[nau]

Cool, thank you :+1:

[fommil]

:+1:

[fommil]

btw, I have unreasonably slow resolution even when we're not using snapshots, from a clean start.

I realise this is an ivy problem... are there plans to scrap ivy and do something internally that doesn't have an insane file-based, single threaded, blocking approach?

[copumpkin]

:+1: excited to see this improve. Super painful right now.

[magro]

For us artifact resolution in our multimodule project is also a major pain. According to this issue this should be improved in 0.13.6. Is there an ETA for 0.13.6?

[eed3si9n]

Good news on the multi-project Ivy resolution front. I've implemented an option to consolidate Ivy resolution for the same managed dependencies (#1454), and it will be merged soon.

[wchen9911]

Excited to see the consolidated resolution is coming.

[fommil]

@eed3si9n this is genuine improvement to the typesafe stack, thank you for your work on this. It will have a positive impact on a lot of developers.

[ghost]

Eager to see this improvement. Any timelines for a milestone release ?

[eed3si9n]

0.13.6-M1 is out - https://groups.google.com/d/msg/sbt-dev/LjYfBIPiB5M/z39twf_jKgAJ

[fommil]

some timings for the update step on our project (which uses https://github.com/cage433/maker because sbt is prohibitively slow, but I created a branch to keep an eye on sbt performance) after a git clean -xfd and all files available locally in the ivy cache. Basically ivy has nothing to do because everything should already be available in the local cache and we don't use SNAPSHOTS:

0.12.4
real    7m33.324s
user    10m48.282s
sys 0m26.658s

0.13.5
real    3m18.850s
user    5m42.377s
sys 0m15.501s

0.13.6-M1
real    3m26.318s
user    6m15.016s
sys 0m16.433s

0.13.6-M1 with  updateOptions := updateOptions.value.withConsolidatedResolution(true)
real    3m31.023s
user    6m25.025s
sys 0m16.066s

I can create an obfuscated version of the project build with no source code if you have plans to use it to improve sbt.

In comparison, a maker update takes about 5 seconds. We basically cannot justify using sbt with this kind of resolution overhead to decide to do nothing :-(

[wchen9911]

@fommil the new consolidated resolution caching only helps if you have multiple projects that all share exactly the same dependencies. In the past, each project will resolve the same thing over and over again, with this enhancement, there will be just one ivy resolution, and the others will just reuse the same result.

I guess your project also have multiple projects, but they don't share the exact dependencies.

Out of curiosity, how many subprojects do you have in your build?

[fommil]

About 20.

[jsuereth]

@fommil We do realize that ivy resolution, even with nothing to do, can be slow, especially if you have a lot of evicted dependencies or exclusions. Sbt SHOULD be caching your updates, but certain things can invalidate sbt's cache (basically anything which alters ivy configuration).

We're still investigating better improvements to Ivy resolution in general. The shared resolution between projects we have now is more of a band-aide, as is the caching of the update task which we add.

[fommil]

@jsuereth we have a lot of CI runs which always start from a clean tree. The ~/.ivy2 remains in place between builds (and across branches) but we can't even rely on user-level caching.

I have to say that ivy resolution would be the single biggest bottleneck if we were not using maker. It takes longer for ivy to do nothing than to compile the project (we can throw a lot of CPU and memory at the compile stage).

[jsuereth]

Yeah, Ivy is pretty good at wasting CPU cycles. Again, we're looking at it. I see Ivy performance as one of the top 3 user-issues in sbt.

[eed3si9n]

@fommil Happy builds are all alike; every unhappy dependency resolution is unhappy in its own way. It would be helpful to see what your dependency graph looks like.

[charleso]

@eed3si9n Not sure if this helps but I've just tried updating to 0.13.6-M1 and our resolution times of ~60s looks roughly the same, if not worse:

https://github.com/ambiata/ivory

[eed3si9n]

@charleso Consolidated resolution is not enabled by default. See 0.13.6.md for details. Currently this is how you enable it (This is M1 so the following is subject to change):

updateOptions := updateOptions.value.withConsolidatedResolution(true)

Before it took 69s to update. After 40s ymmv.