Gradle (2.12) stalls forever trying to resolve dependencies if anything had to be fetched via HTTP

issue-resolved
gradle-3518

(Trejkaz (pen name)) #1

I try to run a Gradle build today and it stalls for minutes before I realise it’s never going to complete.

When I run jstack on gradle, it looks like it’s trying to get an object from a pool and never getting one:

"main" #1 prio=5 os_prio=31 tid=0x00007fb134801800 nid=0x1703 waiting on condition [0x0000700000132000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007773cb958> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at org.apache.http.pool.PoolEntryFuture.await(PoolEntryFuture.java:138)
        at org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:306)
        at org.apache.http.pool.AbstractConnPool.access$000(AbstractConnPool.java:64)
        at org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:192)
        at org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:185)
        at org.apache.http.pool.PoolEntryFuture.get(PoolEntryFuture.java:107)
        at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:276)
        at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:263)
        at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)
        at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
        at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
        at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
        at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
        at org.gradle.internal.resource.transport.http.HttpClientHelper.performHttpRequest(HttpClientHelper.java:102)
        at org.gradle.internal.resource.transport.http.HttpClientHelper.executeGetOrHead(HttpClientHelper.java:79)
        at org.gradle.internal.resource.transport.http.HttpClientHelper.performRequest(HttpClientHelper.java:70)
        at org.gradle.internal.resource.transport.http.HttpClientHelper.performRawHead(HttpClientHelper.java:50)
        at org.gradle.internal.resource.transport.http.HttpClientHelper.performHead(HttpClientHelper.java:54)
        at org.gradle.internal.resource.transport.http.HttpResourceAccessor.getMetaData(HttpResourceAccessor.java:85)
        at org.gradle.internal.resource.transfer.DefaultExternalResourceConnector.getMetaData(DefaultExternalResourceConnector.java:47)
        at org.gradle.internal.resource.transport.DefaultExternalResourceRepository.getResourceMetaData(DefaultExternalResourceRepository.java:68)
        at org.gradle.internal.resource.transfer.DefaultCacheAwareExternalResourceAccessor.getResource(DefaultCacheAwareExternalResourceAccessor.java:84)
        at org.gradle.api.internal.artifacts.repositories.resolver.DefaultExternalResourceArtifactResolver.downloadStaticResource(DefaultExternalResourceArtifactResolver.java:90)
        at org.gradle.api.internal.artifacts.repositories.resolver.DefaultExternalResourceArtifactResolver.resolveArtifact(DefaultExternalResourceArtifactResolver.java:58)

I assume that something has retrieved objects from a pool and never returned them, so when the next caller comes along, it is waiting for someone else to return one but it never happens because nobody else is running anymore.

Version:

------------------------------------------------------------
Gradle 2.12
------------------------------------------------------------

Build time:   2016-03-14 08:32:03 UTC
Build number: none
Revision:     b29fbb64ad6b068cb3f05f7e40dc670472129bc0

Groovy:       2.4.4
Ant:          Apache Ant(TM) version 1.9.3 compiled on December 23 2013
JVM:          1.8.0_51 (Oracle Corporation 25.51-b03)
OS:           Mac OS X 10.11.4 x86_64

(Lari Hotari) #2

The HttpClient connection pool seems to be “leaking” and filling up. Did you get any errors/exceptions before this happened? Perhaps some code using HttpClient is not closing resources in a try-finally block and that’s why an exception triggers the leak. Getting a stack trace could help locate where the leak is happening.


(Trejkaz (pen name)) #3

I didn’t see any errors, no. It stalled the first thing after “Not using buildInfo properties file for this build”…


(Trejkaz (pen name)) #4

Getting this one again today. The previous times, it was downloading some files and then stalling, so I was able to interrupt the process and keep retrying over and over until eventually it downloaded the last couple of jars.

This time, it isn’t even downloading any jars before it hits the issue, so it’s like it is failing at the first HTTP request now. I don’t have any obvious workarounds for that one.

This also happens whether using the daemon or not, as initially I was using the daemon and people thought that the daemon was causing this sort of hang. I guess it isn’t.

$ gradle idea
[buildinfo] Not using buildInfo properties file for this build.
:bootstrap:ideaModule
:bootstrap:idea
:common:ideaModule
:common:idea
:eml-fixer:ideaModule
:eml-fixer:idea
> Building 22% > :engine-api:ideaModule > Resolving dependencies ':engine-api:compileClasspath'

Today’s stack trace:

"main" #1 prio=5 os_prio=31 tid=0x00007fc2aa00b000 nid=0x1703 waiting on condition [0x0000700000132000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x0000000777fa4210> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at org.apache.http.pool.PoolEntryFuture.await(PoolEntryFuture.java:138)
	at org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:306)
	at org.apache.http.pool.AbstractConnPool.access$000(AbstractConnPool.java:64)
	at org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:192)
	at org.apache.http.pool.AbstractConnPool$2.getPoolEntry(AbstractConnPool.java:185)
	at org.apache.http.pool.PoolEntryFuture.get(PoolEntryFuture.java:107)
	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:276)
	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:263)
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
	at org.gradle.internal.resource.transport.http.HttpClientHelper.performHttpRequest(HttpClientHelper.java:102)
	at org.gradle.internal.resource.transport.http.HttpClientHelper.executeGetOrHead(HttpClientHelper.java:79)
	at org.gradle.internal.resource.transport.http.HttpClientHelper.performRequest(HttpClientHelper.java:70)
	at org.gradle.internal.resource.transport.http.HttpClientHelper.performRawHead(HttpClientHelper.java:50)
	at org.gradle.internal.resource.transport.http.HttpClientHelper.performHead(HttpClientHelper.java:54)
	at org.gradle.internal.resource.transport.http.HttpResourceAccessor.getMetaData(HttpResourceAccessor.java:85)
	at org.gradle.internal.resource.transfer.DefaultExternalResourceConnector.getMetaData(DefaultExternalResourceConnector.java:63)
	at org.gradle.internal.resource.transport.DefaultExternalResourceRepository.getResourceMetaData(DefaultExternalResourceRepository.java:68)
	at org.gradle.internal.resource.transfer.DefaultCacheAwareExternalResourceAccessor.getResource(DefaultCacheAwareExternalResourceAccessor.java:85)
	at org.gradle.api.internal.artifacts.repositories.resolver.DefaultExternalResourceArtifactResolver.downloadStaticResource(DefaultExternalResourceArtifactResolver.java:86)
	at org.gradle.api.internal.artifacts.repositories.resolver.DefaultExternalResourceArtifactResolver.resolveArtifact(DefaultExternalResourceArtifactResolver.java:54)
	at org.gradle.api.internal.artifacts.repositories.resolver.ExternalResourceResolver.parseMetaDataFromArtifact(ExternalResourceResolver.java:164)
	at org.gradle.api.internal.artifacts.repositories.resolver.ExternalResourceResolver.resolveStaticDependency(ExternalResourceResolver.java:143)
	at org.gradle.api.internal.artifacts.repositories.resolver.MavenResolver.doResolveComponentMetaData(MavenResolver.java:93)
	at org.gradle.api.internal.artifacts.repositories.resolver.ExternalResourceResolver$RemoteRepositoryAccess.resolveComponentMetaData(ExternalResourceResolver.java:409)
	at org.gradle.api.internal.artifacts.ivyservice.ivyresolve.CacheLockReleasingModuleComponentsRepository$LockReleasingRepositoryAccess$2.run(CacheLockReleasingModuleComponentsRepository.java:71)
	at org.gradle.internal.Factories$1.create(Factories.java:22)
	at org.gradle.cache.internal.DefaultCacheAccess.longRunningOperation(DefaultCacheAccess.java:242)
	at org.gradle.cache.internal.DefaultCacheAccess.longRunningOperation(DefaultCacheAccess.java:313)
	at org.gradle.cache.internal.DefaultPersistentDirectoryStore.longRunningOperation(DefaultPersistentDirectoryStore.java:114)
	at org.gradle.cache.internal.DefaultCacheFactory$ReferenceTrackingCache.longRunningOperation(DefaultCacheFactory.java:179)
	at org.gradle.api.internal.artifacts.ivyservice.DefaultCacheLockingManager.longRunningOperation(DefaultCacheLockingManager.java:56)
	at org.gradle.api.internal.artifacts.ivyservice.ivyresolve.CacheLockReleasingModuleComponentsRepository$LockReleasingRepositoryAccess.resolveComponentMetaData(CacheLockReleasingModuleComponentsRepository.java:69)
	at org.gradle.api.internal.artifacts.ivyservice.ivyresolve.CachingModuleComponentRepository$ResolveAndCacheRepositoryAccess.resolveComponentMetaData(CachingModuleComponentRepository.java:297)
	at org.gradle.api.internal.artifacts.ivyservice.ivyresolve.BaseModuleComponentRepositoryAccess.resolveComponentMetaData(BaseModuleComponentRepositoryAccess.java:42)
	at org.gradle.api.internal.artifacts.ivyservice.ivyresolve.memcache.InMemoryCachedModuleComponentRepository$CachedAccess.resolveComponentMetaData(InMemoryCachedModuleComponentRepository.java:75)
	at org.gradle.api.internal.artifacts.ivyservice.ivyresolve.ErrorHandlingModuleComponentRepository$ErrorHandlingModuleComponentRepositoryAccess.resolveComponentMetaData(ErrorHandlingModuleComponentRepository.java:89)
	at org.gradle.api.internal.artifacts.ivyservice.ivyresolve.ComponentMetaDataResolveState.process(ComponentMetaDataResolveState.java:66)
	at org.gradle.api.internal.artifacts.ivyservice.ivyresolve.ComponentMetaDataResolveState.resolve(ComponentMetaDataResolveState.java:58)

(truncated because this site won’t let me post the whole thing)


(Lari Hotari) #5

@trejkaz Thanks for reporting the issue. I’ve created GRADLE-3518 for tracking it.


(Stefan Wolf) #6

@trejkaz We think we fixed this for Gradle 3.1. Could you try the latest nightly to confirm?

Thanks,
Stefan


(Trejkaz (pen name)) #7

I tried to reproduce again just now and even on 2.12, it isn’t happening the way I experienced it anymore.

So I checked out an old copy of our stuff from the time I hit this issue, and built that using 2.12 as well - and that failed, but not in the same way. But this new error may point to the real issue that was causing it to run out of clients, I suspect.

* What went wrong:
Could not resolve all dependencies for configuration ':compileClasspath'.
> Could not resolve jline:jline:2.12.custom1.0.
  Required by:
      :http_issues:unspecified
   > Could not resolve jline:jline:2.12.custom1.0.
      > Could not parse POM http://repository:8081/artifactory/plugins-release/jline/jline/2.12.custom1.0/jline-2.12.custom1.0.pom
         > Could not resolve jline:jline:2.12.custom1.0.
            > Could not resolve jline:jline:2.12.custom1.0.
               > Could not parse POM http://repository:8081/artifactory/plugins-release/jline/jline/2.12.custom1.0/jline-2.12.custom1.0.pom
                  > Could not resolve jline:jline:2.12.custom1.0.
                     > Could not resolve jline:jline:2.12.custom1.0.
                        > Could not parse POM http://repository:8081/artifactory/plugins-release/jline/jline/2.12.custom1.0/jline-2.12.custom1.0.pom
                           > Could not resolve jline:jline:2.12.custom1.0.
                              > Could not resolve jline:jline:2.12.custom1.0.

And this continues until I eventually get

java.lang.StackOverflowError (no error message)

Just for good measures, I ran on the nightly and got basically the same result.

I have no idea why today it returns one result and the other day it returned another, but maybe some plugin changed their behaviour between then and now. One of the things I like the least about build systems like Maven and Gradle is that the results are not deterministic. I guess this is just one of those moments.


(Stefan Wolf) #8

Hi @trejkaz,

that looks very strange and seems like a different problem altogether. Could you provide a stacktrace or a build scan?

Thanks,
Stefan


(Benjamin Muschko) #9

The issue you are seeing is likely related to GRADLE-3485. It’s probably happening due to some incorrect metadata. Gradle should handle the situation more gracefully. Would you be interested in working on a pull request for this issue? It would be great to see the issue fixed.

I have no idea why today it returns one result and the other day it returned another, but maybe some plugin changed their behaviour between then and now.

The reason you might be running into the issue is that a new version of a plugin was released which provided incorrect metadata. Gradle will therefore have to resolve it first because it wasn’t in the Gradle cache yet. Another reason might be that the local cache was manually deleted.


(Lari Hotari) #10

What caught my eye is the version number “2.12.custom1.0” . I’ve seen strange behaviour in Gradle when the version number is not parseable by VersionNumber’s default scheme. I filed GRADLE-3396 some time ago. That particular issue was solved by properly defining the dependencies. I just want to point to that one because the unparseable version number was somehow causing the behaviour in that case.