[2.7.6] Logs w/ follow hangs, or finalizer error #125
Comments
|
I'm not sure if @rohansingh already figured out that this really is a bug. But couldn't it be the case that after the expected message was received, you indeed keep listening for new messages - which do not arrive and then lead to a socket timeout exception? By the way the timeouts can be set and even disabled. |
|
Sorry, I haven't looked very closely at this, just gave it the bug label while organizing things. |
|
Ah okay! I will try to come up with a test to proof this issue. Maybe the topic starter can provide some code? Edit; oops there is code, missed that Op 27 feb. 2015 om 01:33 heeft Rohan Singh <[email protected]mailto:[email protected]> het volgende geschreven: Sorry, I haven't looked very closely at this, just gave it the bug label while organizing things. — |
|
This actually is an issue. I used the following test for proof: (Basically I create a DockerClient with a 4000 ms timeout and a Docker container with a 5 second sleep) package com.spotify.docker.client;
import java.io.IOException;
import org.hamcrest.Matchers;
import org.junit.AfterClass;
import org.junit.BeforeClass;
import org.junit.Rule;
import org.junit.Test;
import com.spotify.docker.client.DockerClient.LogsParameter;
import com.spotify.docker.test.CreateContainer;
import com.spotify.docker.test.DockerContainer;
import static com.google.common.base.Charsets.UTF_8;
import static org.junit.Assert.assertThat;
public class PrematureLogsCloseCall {
private static DockerClient dockerClient;
@Rule
public DockerContainer dockerContainer = new DockerContainer(dockerClient);
@BeforeClass
public static void setUp() throws DockerCertificateException {
dockerClient = DefaultDockerClient
.fromEnv()
.readTimeoutMillis(3000)
.build();
}
@Test
@CreateContainer(image = "busybox", command = {"sh", "-c", "echo start && sleep 5 && echo stop"}, start = true)
public void testIt() throws IOException,
DockerException, InterruptedException {
String containerId = dockerContainer.getContainerId();
try(LogStream logStream = dockerClient.logs(containerId, LogsParameter.STDOUT, LogsParameter.FOLLOW)) {
assertThat(UTF_8.decode(logStream.next().content()).toString(),
Matchers.containsString("start"));
logStream.close();
}
}
@AfterClass
public static void cleanUp() {
dockerClient.close();
}
}The problem is that in the @Override
public void close() throws IOException {
closed = true;
// Jersey will close the stream and release the connection after we read all the data.
// We cannot call the stream's close method because it an instance of UncloseableInputStream,
// where close is a no-op.
copy(stream, nullOutputStream());
}So the remainder of the stream is being copied to a null output stream, but as no messages keep coming in an @Override
public void close() throws IOException {
closed = true;
stream.close()
} |
|
Noticed this today when trying to watch logs for a startup message and block until it is seen: private void waitUntilTomcatStarted() throws IOException, InterruptedException, DockerException {
logger.info("Blocking until Tomcat has started");
long start = System.currentTimeMillis();
try (LogStream logStream = dockerClient.logs(containerId, DockerClient.LogsParameter.STDERR, DockerClient.LogsParameter.FOLLOW)) {
boolean started = false;
while (!started) {
while(logStream.hasNext()) {
LogMessage next = logStream.next();
ByteBuffer content = next.content();
byte[] buffer = new byte[content.remaining()];
content.get(buffer);
String message = new String(buffer, "UTF-8");
System.out.print(message);
if (StringUtils.contains(message, "org.apache.catalina.startup.Catalina.start Server startup in ")) {
logger.info("Tomcat Server started after {}ms", (System.currentTimeMillis() - start));
started = true;
break;
}
}
logger.info("looped");
}
logger.info("I am stuck");
}
logger.info("Never reached");
}Admittedly this was implemented as a bit of a hack (seemed to be one of the easiest way of checking if the tomcat instance had started). I worked around it by not following the logs and running a |
|
I think, as the code within the close block is not fixed, this is probably worse. Now you just keep the socket open, until either the connection or container dies. If you don't need the logs anymore, it should just disconnect the socket on close. |
|
+1, no longer closing LogStream to work around issue |
|
just stumbled over this in v8.1.3, applied the fix from #125 (comment) and it works perfectly - can we please integrate this into master? |
|
This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions. |
davidxia
added
help wanted
pinned
|
Hi all, Since this project went on mature status, please re-open this issue (if it still stands) to https://github.com/dmandalidis/docker-client. Thanks |
My code is starting a Docker container with a Postgres instance inside, and waiting for the output to include the text "database system is ready to accept connections".
My code works fine ... but after I see the target text things go wonky.
If I close the LogStream, my process hangs for a while, then gets an exception:
(Obviously, I'm working in Clojure, but that should hopefully not be relevant).
On the other hand, if I skip the close step, things work fine ... but at some future point, I see this error in my console:
If it helps, here's the code:
The text was updated successfully, but these errors were encountered: