Second execution failed if two projects use the plugin

[gsoing]

Hello,
I have a maven project with two sub-modules which use the docker plugin and the second start failed with the following error : io.fabric8:docker-maven-plugin:0.16.5:start failed: Connection not obtained from this manager

If I understand well it's because it try to clean up an http connection which was used by the precedent plugin executions.

The complete stacktrace is here :

org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal io.fabric8:docker-maven-plugin:0.16.5:start (start-mongo-scop) on project scop-server: Execution start-mongo-scop of goal io.fabric8:docker-maven-plugin:0.16.5:start failed: Connection not obtained from this manager
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:212)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
        at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:116)
        at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:80)
        at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)
        at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
        at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:307)
        at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:193)
        at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:106)
        at org.apache.maven.cli.MavenCli.execute(MavenCli.java:863)
        at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:288)
        at org.apache.maven.cli.MavenCli.main(MavenCli.java:199)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:289)
        at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)
        at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)
        at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)
Caused by: org.apache.maven.plugin.PluginExecutionException: Execution start-mongo-scop of goal io.fabric8:docker-maven-plugin:0.16.5:start failed: Connection not obtained from this manager
        at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:145)
        at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:207)
        ... 20 more
Caused by: java.lang.IllegalStateException: Connection not obtained from this manager
        at org.apache.http.util.Asserts.check(Asserts.java:34)
        at org.apache.http.impl.conn.BasicHttpClientConnectionManager.releaseConnection(BasicHttpClientConnectionManager.java:286)
        at org.apache.http.impl.execchain.ConnectionHolder.abortConnection(ConnectionHolder.java:134)
        at org.apache.http.impl.execchain.ConnectionHolder.cancel(ConnectionHolder.java:145)
        at org.apache.http.client.methods.AbstractExecutionAwareRequest.abort(AbstractExecutionAwareRequest.java:90)
        at io.fabric8.maven.docker.access.log.LogRequestor.finish(LogRequestor.java:215)
        at io.fabric8.maven.docker.StartMojo$2.cleanUp(StartMojo.java:423)
        at io.fabric8.maven.docker.util.WaitUtil.cleanup(WaitUtil.java:102)
        at io.fabric8.maven.docker.util.WaitUtil.wait(WaitUtil.java:95)
        at io.fabric8.maven.docker.StartMojo.waitIfRequested(StartMojo.java:298)
        at io.fabric8.maven.docker.StartMojo.access$000(StartMojo.java:42)
        at io.fabric8.maven.docker.StartMojo$1.call(StartMojo.java:175)
        at io.fabric8.maven.docker.StartMojo$1.call(StartMojo.java:164)
        at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:108)
        at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:41)
        at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:77)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at com.google.common.util.concurrent.MoreExecutors$DirectExecutorService.execute(MoreExecutors.java:310)
        at java.util.concurrent.ExecutorCompletionService.submit(ExecutorCompletionService.java:181)
        at io.fabric8.maven.docker.StartMojo.executeInternal(StartMojo.java:164)
        at io.fabric8.maven.docker.AbstractDockerMojo.execute(AbstractDockerMojo.java:193)
        at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:134)
        ... 21 more

I'm trying to find where this stale connection come from, but it's not a big success for the moment.

Regards

Guillaume

[rhuss]

Some questions:

• Which kind of connection to the Docker daemon are you using ? TCP or Unix socket ?
• Could you post the end of maven -X ..., too ? Maybe there is a better indication of the problem.

[gsoing]

Hello,
I use the unix socket and the docker version is 1.12.1 (i'm on a mac). I also join the full maven output.
maven.txt

[albers]

I'm getting the same error message in a slightly different context:

• only one module uses docker-maven-plugin
• The error occurs just after successful start of the first container and before starting the second one
• I use a tcp remote connection to a Ubuntu host running Docker 1.12.1.

It works with docker-maven-plugin 0.15.16 and 0.16.1, but not with 0.16.2, 0.16.3, 0.16.4 and 0.16.5.

I tried to provide the -X output. But sadly, this seems to be a Heisenbug: As soon as I execute the build in debug mode, the problem disappears. It only occurs in non-debug mode.

[rhuss]

@gsoing there are some sever concurrency issues with unix socket library we are using. This is tracked in #344. I don't know whether it applies here, and as @albers indicates, it might be a problem with TCP socket, too.

@albers would it be possible to have access to the project so that I could reproduce it (and e.g. bisect between the versions) ?

@gsoing does it work for you with an older version like 0.15.16 or 0.16.1 ?

In the meantime I'll try too look at the difference between 0.16.1 and 0.16.2

[albers]

I will try to create a trimmed-down version that I can share tomorrow. Thanks for looking into it.

[albers]

Good news: I was able to create a minimal project that only uses public images. And: I could capture the debug output (once).

To reproduce: create an empty project with just this POM (renamed): pom.xml.txt

Running

mvn verify -DdockerHost=https://my.internal.docker-server:2376 -Ddocker.showLogs | tee maven.txt

produced this output: maven.txt

Running

mvn verify -DdockerHost=https://my.internal.docker-server:2376 -Ddocker.showLogs -X | tee maven-debug.txt

produced this debug output: maven-debug.txt

I tested against two remote Docker hosts. I always get the error. In most cases it occurs after successful startup of the first container, sometimes after successful start of the second container.

[rhuss]

thanks !

will try to reproduce it now myself, too.

[gsoing]

Hello,
it works fine with the version 0.16.1.

[rhuss]

Thanks a lot for the test case, I could nail it down with a git bisect. and indeed it was already detected.

Now going to fix it ...

[rhuss]

Added some locks which should prevent this error. Please feel free to test it or reopen the issue in case. I will do a new d-m-p this evening probably or tomorrow.

thanks for all your help ;-)

[albers]

Thanks for the quick fix, @rhuss.
I won't be at work next week but will check the new release as soon as I return.

[gsoing]

Thanks a lot as soon as you released i will test.

Regards

[rhuss]

0.16.6 is out

[gsoing]

I just test the new release and it works fine. Thanks for the quick fix.

[albers]

0.16.6 resolves my issues, too. Thanks!