@bsideup Any progress on this? We are seeing some intermittent failures in our CI tests, and it would be interesting to see if this (the extra newline being added after each logging frame) could be a potential root cause. Thanks in advance. 🙇

@perlun we're currently at low capacity and trying to catch up with some old PRs first, unless something is broken. Since there is a workaround (including a custom consumer), I am afraid we need a bit more time to get to this PR, but eventually we will, I promise! :D

@bsideup Thanks, that's perfectly understandable. I know how it can be at times. 👍

For my particular use case (using a WaitingConsumer), I unfortunately don't have any workaround. (and looking at the WaitingConsumer code I wonder if it's even affected by this issue; its accept method doesn't do any strange newline adding at all)

So, my problem is: We have a WaitingConsumer which intermittently fails in CI. Even in cases where the log message it's waiting for is actually printed, it sometimes fails. Any ideas? (We have a fairly high timeout in this case, 120 seconds)

@perlun have you tried adjusting the pattern so that it ignores newlines?

@perlun have you tried adjusting the pattern so that it ignores newlines?

To make things more complex, I have my own WaitStrategy to avoid having to write regexps for this; it uses a String.contains()-based approach instead. Below is the full code for it.

One ugly workaround I thought about: use the retryUntilSuccess-approach and get the whole log every time (instead of waiting for one frame, then continuing). Unsure if it would help though, if the extra newlines are still there. 😅 Any suggestions in any directions whatsoever would be highly appreciated.

public class LogMessageContainsWaitStrategy extends AbstractWaitStrategy {

    private static final int TIMES = 1;

    private final String needle;

    public LogMessageContainsWaitStrategy( String needle ) {
        this.needle = needle;
    }

    @Override
    protected void waitUntilReady() {
        WaitingConsumer waitingConsumer = new WaitingConsumer();

        LogContainerCmd cmd = DockerClientFactory.instance().client().logContainerCmd( waitStrategyTarget.getContainerId() )
                .withFollowStream( true )
                .withSince( 0 )
                .withStdOut( true )
                .withStdErr( true );

        try ( FrameConsumerResultCallback callback = new FrameConsumerResultCallback() ) {
            callback.addConsumer( STDOUT, waitingConsumer );
            callback.addConsumer( STDERR, waitingConsumer );

            cmd.exec( callback );

            // This is the actual predicate that gets checked each time a new output frame is received
            Predicate<OutputFrame> waitPredicate = outputFrame ->
                    outputFrame.getUtf8String().contains( needle );

            try {
                waitingConsumer.waitUntil( waitPredicate, startupTimeout.getSeconds(), TimeUnit.SECONDS, TIMES );
            }
            catch ( TimeoutException e ) {
                throw new ContainerLaunchException( "Timed out waiting for log output including '" + needle + "'" );
            }
        }
        catch ( IOException e ) {
            throw new UncheckedIOException( e );
        }
    }

    @Override
    public String toString() {
        return getClass().getSimpleName() + ", looking for log output including '" + needle + "'";
    }
}

@perlun I just applied some fixes and added more tests. Will merge once green 👍

@perlun I just applied some fixes and added more tests. Will merge once green +1

Thanks a lot for this. 🙏 Let me know if/when we get a new release including this, and I'll happily test it on our code base to see it it resolves the intermittent issues we're seeing.

@perlun the release engines are running now :)

FWIW: this fix did not help me in my original problem (briefly described in #3752 (comment)). What did seem to help, at least to the point of removing spurious newlines in the Docker output is to create the container like this.

(In our particular case, the Docker output comes from a Tomcat container running a bunch of Java web applications, with SLF4J + Logback writing to stdout.)

        withCreateContainerCmdModifier( cmd -> cmd.withTty( true ) );

With this in place, I am no longer getting any spurious newlines in the middle of the logs. Posting this here in the help that it might help others as well.

Now this sounds more like a bug with Docker :D Anyways, I am glad that you were able to fix it 👍

Now this sounds more like a bug with Docker :D

It could very well be. I get the feeling that there is some kind of output buffering (auto-flushing disabled) going on, which is weird since the Logback ConsoleAppender does call System.out.flush() after each log line being written.

I even attached a debugger to the Tomcat inside the Docker container, with the Tomcat sources loaded so I could debug it. SystemLogHandler (in Tomcat) has an out field which is a PrintStream, with autoFlush enabled. So it's really weird.

(If anyone runs into the same problem and figures this out, please post the details here so we can all learn from it and benefit. 🙏)