Problem
When using testcontainers 1.15.2, a call to ContainerState.getLogs() for a container with TTY set to true returns a string that has no line separators at all between log rows. Reverting to testcontainers 1.15.1 makes it work again.
$ docker -v
Docker version 20.10.6, build 370c289
Analysis
I'm not that familiar with testcontainer internals (yet) and not the Docker API at all (yet), so bear with me 😁 I have been debugging this for the past hours, and just need to start writing down my findings.
First of all, this change of behaviour seems to come from #3752 (which fixed #1763 and #1854). So the immediate cause of this change is quite clear. But I doubt that just reverting #3752 is the right path forward.
So, I have a custom Tomcat container. Stepping through a call to ContainerState.getLogs() on that container, I end up in org.testcontainers.shaded.com.github.dockerjava.core.FramedInputStreamConsumer with StreamType set to RAW (probably because it was started with TTY?).
This in turn means I end up in org.testcontainers.containers.output.FrameConsumerResultCallback.processRawFrame(OutputFrame outputFrame, Consumer<OutputFrame> consumer) and .normalizeLogLines(String utf8String, Consumer<OutputFrame> consumer). The normalizeLogLines method splits the frame on any newline separators, and passes it on to the Consumer<OuputFrame> WITHOUT any newline on the end of a line (even if the raw frame had one).
As long as ToStringConsumer made sure that newlines were added, this worked fine. However, it probably also meant that with testcontainer versions before 1.15.2 and non-TTY containers (with streams of type STDOUT or STDERR), log rows ended up with two \n between them.
Might be worth adding some context on why we're using TTY as well. We previously had some spurious test failures with the Tomcat container. We never really found a way of reliably reproducing it outside CI (maybe even not at all?), but we believe that it was caused by a WaitStrategy that looked for a certain row logged by Tomcat when it had successfully started, and that that log row was sometimes split up on two different lines in the log output. After adding..
withCreateContainerCmdModifier( cmd -> cmd.withTty( true ) );
..we have not seen a single failure of the same kind. On the face of it, it sounds a tiny little bit similar to #455.
Solution
As I said, I don't think reverting #3752 is necessarily the right thing to do, because it solved a real issue. Should FrameConsumerResultCallback.normalizeLogLines be fixed to retain newlines? OTOH, Slf4jLogConsumer already seems to take care of any trailing newlines internally, which may be a hint that the fix in ToStringConsumer should instead have been to check if a trailing newline exists, and just add one if not. Or something completely different?
Problem
When using testcontainers 1.15.2, a call to
ContainerState.getLogs()for a container with TTY set totruereturns a string that has no line separators at all between log rows. Reverting to testcontainers 1.15.1 makes it work again.Analysis
I'm not that familiar with testcontainer internals (yet) and not the Docker API at all (yet), so bear with me 😁 I have been debugging this for the past hours, and just need to start writing down my findings.
First of all, this change of behaviour seems to come from #3752 (which fixed #1763 and #1854). So the immediate cause of this change is quite clear. But I doubt that just reverting #3752 is the right path forward.
So, I have a custom Tomcat container. Stepping through a call to
ContainerState.getLogs()on that container, I end up inorg.testcontainers.shaded.com.github.dockerjava.core.FramedInputStreamConsumerwithStreamTypeset toRAW(probably because it was started with TTY?).This in turn means I end up in
org.testcontainers.containers.output.FrameConsumerResultCallback.processRawFrame(OutputFrame outputFrame, Consumer<OutputFrame> consumer)and.normalizeLogLines(String utf8String, Consumer<OutputFrame> consumer). ThenormalizeLogLinesmethod splits the frame on any newline separators, and passes it on to theConsumer<OuputFrame>WITHOUT any newline on the end of a line (even if the raw frame had one).As long as
ToStringConsumermade sure that newlines were added, this worked fine. However, it probably also meant that with testcontainer versions before 1.15.2 and non-TTY containers (with streams of typeSTDOUTorSTDERR), log rows ended up with two\nbetween them.Might be worth adding some context on why we're using TTY as well. We previously had some spurious test failures with the Tomcat container. We never really found a way of reliably reproducing it outside CI (maybe even not at all?), but we believe that it was caused by a
WaitStrategythat looked for a certain row logged by Tomcat when it had successfully started, and that that log row was sometimes split up on two different lines in the log output. After adding....we have not seen a single failure of the same kind. On the face of it, it sounds a tiny little bit similar to #455.
Solution
As I said, I don't think reverting #3752 is necessarily the right thing to do, because it solved a real issue. Should
FrameConsumerResultCallback.normalizeLogLinesbe fixed to retain newlines? OTOH,Slf4jLogConsumeralready seems to take care of any trailing newlines internally, which may be a hint that the fix inToStringConsumershould instead have been to check if a trailing newline exists, and just add one if not. Or something completely different?