Docker-maven-plugin: Waiting for log entry then http status check not possible

Created on 5 Jun 2019  路  3Comments  路  Source: fabric8io/docker-maven-plugin

Description

It seems not to be possible to <wait> for a specific <log> output and afterwards check the applications health status via <http>. Furthermore there is always the need to set the <time> to increase the timeout, which i'm not interested in. I want to wait for the log output. At least the documentation should mention the default timeout of 10 seconds and also describe the need to set it (kinda mandatory)!

Info

  • Maven: 3.5.3
  • JAVA: jdk1.8.0_144
  • OS name: "windows 10", version: "10.0", arch: "amd64", family: "windows"
  • docker-maven-plugin: 0.30.0
  • Docker version: Windows Docker Desktop 2.0.0.3 (31259), Engine: 18.09.2

Plugin Config

<plugin>
    <groupId>io.fabric8</groupId>
    <artifactId>docker-maven-plugin</artifactId>
    <version>0.30.0</version>
    <configuration>
        <verbose/>
        <images>
            <image>
                <alias>app</alias>
                <name>foobar</name>
                <run>
                    <ports>
                        <port>docker.proxy.port:${application.port}</port>
                    </ports>
                    <wait>
                        <http>
                            <url>https://localhost:${docker.proxy.port}/app/status</url>
                            <method>GET</method>
                            <status>200</status>
                        </http>
                        <time>6666</time>
                    </wait>
                </run>
            </image>
        </images>
    </configuration>
    <executions>
        <execution>
            <id>start</id>
            <phase>pre-integration-test</phase>
            <goals>
                <goal>start</goal>
            </goals>
        </execution>
        <execution>
            <id>stop</id>
            <phase>post-integration-test</phase>
            <goals>
                <goal>stop</goal>
            </goals>
        </execution>
    </executions>
</plugin>

Most helpful comment

I think I'm experiencing the same issue under quite similar conditions. So I decided to do a bit
of analysis to the source code, and this is what I found. I hope this could help with solving
this issue

The issue:
The issue could be exactly here io.fabric8.maven.docker.access.hc.win.NamedPipe#close while trying to close the java.nio.channels.FileChannel after the io.fabric8.maven.docker.wait.WaitUtil has completed all the configured validations

The cause:
I'm far from being a Java expert on these subjects, but I think you have to be very careful on Windows OS while trying to close these kinds of objects if they have any associated stream that has not been properly closed first.

So, I guess this could be the reason why the execution of the plugin freezes at this point :)

The following stack trace could better illustrate how did I get to this point

close:261, NamedPipe (io.fabric8.maven.docker.access.hc.win)
shutdown:309, BHttpConnectionBase (org.apache.http.impl)
shutdown:95, DefaultManagedHttpClientConnection (org.apache.http.impl.conn)
shutdown:98, LoggingManagedHttpClientConnection (org.apache.http.impl.conn)
abortConnection:128, ConnectionHolder (org.apache.http.impl.execchain)
cancel:146, ConnectionHolder (org.apache.http.impl.execchain)
abort:90, AbstractExecutionAwareRequest (org.apache.http.client.methods)
finish:211, LogRequestor (io.fabric8.maven.docker.access.log)
cleanUp:45, LogWaitChecker (io.fabric8.maven.docker.wait)
cleanup:80, WaitUtil (io.fabric8.maven.docker.wait)
wait:64, WaitUtil (io.fabric8.maven.docker.wait)
wait:65, WaitService (io.fabric8.maven.docker.service)
waitAndPostExec:100, StartContainerExecutor (io.fabric8.maven.docker.service.helper)
startContainers:51, StartContainerExecutor (io.fabric8.maven.docker.service.helper)
lambda$startImage$0:304, StartMojo (io.fabric8.maven.docker)
call:-1, 901224896 (io.fabric8.maven.docker.StartMojo$$Lambda$588)
runInterruptibly:117, TrustedListenableFutureTask$TrustedFutureInterruptibleTask (com.google.common.util.concurrent)
run:38, InterruptibleTask (com.google.common.util.concurrent)
run:77, TrustedListenableFutureTask (com.google.common.util.concurrent)
call:511, Executors$RunnableAdapter (java.util.concurrent)
run:266, FutureTask (java.util.concurrent)
execute:260, MoreExecutors$DirectExecutorService (com.google.common.util.concurrent)
submit:181, ExecutorCompletionService (java.util.concurrent)
startImage:298, StartMojo (io.fabric8.maven.docker)
executeInternal:166, StartMojo (io.fabric8.maven.docker)
execute:230, AbstractDockerMojo (io.fabric8.maven.docker)
executeMojo:137, DefaultBuildPluginManager (org.apache.maven.plugin)
execute:210, MojoExecutor (org.apache.maven.lifecycle.internal)
execute:156, MojoExecutor (org.apache.maven.lifecycle.internal)
execute:148, MojoExecutor (org.apache.maven.lifecycle.internal)
buildProject:117, LifecycleModuleBuilder (org.apache.maven.lifecycle.internal)
buildProject:81, LifecycleModuleBuilder (org.apache.maven.lifecycle.internal)
build:56, SingleThreadedBuilder (org.apache.maven.lifecycle.internal.builder.singlethreaded)
execute:128, LifecycleStarter (org.apache.maven.lifecycle.internal)
doExecute:305, DefaultMaven (org.apache.maven)
doExecute:192, DefaultMaven (org.apache.maven)
execute:105, DefaultMaven (org.apache.maven)
execute:956, MavenCli (org.apache.maven.cli)
doMain:288, MavenCli (org.apache.maven.cli)
main:192, MavenCli (org.apache.maven.cli)
invoke0:-1, NativeMethodAccessorImpl (sun.reflect)
invoke:62, NativeMethodAccessorImpl (sun.reflect)
invoke:43, DelegatingMethodAccessorImpl (sun.reflect)
invoke:498, Method (java.lang.reflect)
launchEnhanced:289, Launcher (org.codehaus.plexus.classworlds.launcher)
launch:229, Launcher (org.codehaus.plexus.classworlds.launcher)
mainWithExitCode:415, Launcher (org.codehaus.plexus.classworlds.launcher)
main:356, Launcher (org.codehaus.plexus.classworlds.launcher)

All 3 comments

I think I'm experiencing the same issue under quite similar conditions. So I decided to do a bit
of analysis to the source code, and this is what I found. I hope this could help with solving
this issue

The issue:
The issue could be exactly here io.fabric8.maven.docker.access.hc.win.NamedPipe#close while trying to close the java.nio.channels.FileChannel after the io.fabric8.maven.docker.wait.WaitUtil has completed all the configured validations

The cause:
I'm far from being a Java expert on these subjects, but I think you have to be very careful on Windows OS while trying to close these kinds of objects if they have any associated stream that has not been properly closed first.

So, I guess this could be the reason why the execution of the plugin freezes at this point :)

The following stack trace could better illustrate how did I get to this point

close:261, NamedPipe (io.fabric8.maven.docker.access.hc.win)
shutdown:309, BHttpConnectionBase (org.apache.http.impl)
shutdown:95, DefaultManagedHttpClientConnection (org.apache.http.impl.conn)
shutdown:98, LoggingManagedHttpClientConnection (org.apache.http.impl.conn)
abortConnection:128, ConnectionHolder (org.apache.http.impl.execchain)
cancel:146, ConnectionHolder (org.apache.http.impl.execchain)
abort:90, AbstractExecutionAwareRequest (org.apache.http.client.methods)
finish:211, LogRequestor (io.fabric8.maven.docker.access.log)
cleanUp:45, LogWaitChecker (io.fabric8.maven.docker.wait)
cleanup:80, WaitUtil (io.fabric8.maven.docker.wait)
wait:64, WaitUtil (io.fabric8.maven.docker.wait)
wait:65, WaitService (io.fabric8.maven.docker.service)
waitAndPostExec:100, StartContainerExecutor (io.fabric8.maven.docker.service.helper)
startContainers:51, StartContainerExecutor (io.fabric8.maven.docker.service.helper)
lambda$startImage$0:304, StartMojo (io.fabric8.maven.docker)
call:-1, 901224896 (io.fabric8.maven.docker.StartMojo$$Lambda$588)
runInterruptibly:117, TrustedListenableFutureTask$TrustedFutureInterruptibleTask (com.google.common.util.concurrent)
run:38, InterruptibleTask (com.google.common.util.concurrent)
run:77, TrustedListenableFutureTask (com.google.common.util.concurrent)
call:511, Executors$RunnableAdapter (java.util.concurrent)
run:266, FutureTask (java.util.concurrent)
execute:260, MoreExecutors$DirectExecutorService (com.google.common.util.concurrent)
submit:181, ExecutorCompletionService (java.util.concurrent)
startImage:298, StartMojo (io.fabric8.maven.docker)
executeInternal:166, StartMojo (io.fabric8.maven.docker)
execute:230, AbstractDockerMojo (io.fabric8.maven.docker)
executeMojo:137, DefaultBuildPluginManager (org.apache.maven.plugin)
execute:210, MojoExecutor (org.apache.maven.lifecycle.internal)
execute:156, MojoExecutor (org.apache.maven.lifecycle.internal)
execute:148, MojoExecutor (org.apache.maven.lifecycle.internal)
buildProject:117, LifecycleModuleBuilder (org.apache.maven.lifecycle.internal)
buildProject:81, LifecycleModuleBuilder (org.apache.maven.lifecycle.internal)
build:56, SingleThreadedBuilder (org.apache.maven.lifecycle.internal.builder.singlethreaded)
execute:128, LifecycleStarter (org.apache.maven.lifecycle.internal)
doExecute:305, DefaultMaven (org.apache.maven)
doExecute:192, DefaultMaven (org.apache.maven)
execute:105, DefaultMaven (org.apache.maven)
execute:956, MavenCli (org.apache.maven.cli)
doMain:288, MavenCli (org.apache.maven.cli)
main:192, MavenCli (org.apache.maven.cli)
invoke0:-1, NativeMethodAccessorImpl (sun.reflect)
invoke:62, NativeMethodAccessorImpl (sun.reflect)
invoke:43, DelegatingMethodAccessorImpl (sun.reflect)
invoke:498, Method (java.lang.reflect)
launchEnhanced:289, Launcher (org.codehaus.plexus.classworlds.launcher)
launch:229, Launcher (org.codehaus.plexus.classworlds.launcher)
mainWithExitCode:415, Launcher (org.codehaus.plexus.classworlds.launcher)
main:356, Launcher (org.codehaus.plexus.classworlds.launcher)

@svenhaag yes, wait is a bit simplistic and you can't chain wait conditions (e.g. is equally not possible to first wait on an HTTPort and then on a log file). The timeout parameter is probably not very well documented, happy for any improvement here. Could you provide an internal healthcheck for your images which does all the logic that you want and then exposes this over an HTTP port which you can use then for dmp ?

@garodriguezlp for me it's not cleary how the issue that you describe is related to the OP.

@rhuss You're right, I'm sorry. Now that I reread it, I can see they might not be related at all. I don't know what was I thinking when I decided to associate it with this. 馃槄馃槀

Nevertheless, I'm pretty sure did have some trouble in Windows trying to wait for a particular output in the log.

I guess I should have to create a new issue for that. Am I right?

Was this page helpful?
0 / 5 - 0 ratings

Related issues

leonardinius picture leonardinius  路  5Comments

mixaaaa picture mixaaaa  路  5Comments

maximilian-schott picture maximilian-schott  路  3Comments

flungo picture flungo  路  10Comments

chanjarster picture chanjarster  路  7Comments