testcontainers-java icon indicating copy to clipboard operation
testcontainers-java copied to clipboard

[Bug]: LogMessageWaitStrategy erroneously assumes each log frame contains a complete log line

Open SgtSilvio opened this issue 3 years ago • 1 comments
trafficstars

Module

Core

Testcontainers version

1.17.3

Using the latest Testcontainers version?

Yes

Host OS

Linux CentOS

Host Arch

x86_64

Docker version

Docker version 20.10.18, build b40c2f6

What happened?

LogMessageWaitStrategy uses a LogContainerCmd to follow logs. The regex is applied to every OutputFrame that is processed by FrameConsumerResultCallback. FrameConsumerResultCallback consumes STDOUT or STDERR stream types via processOtherFrame.

Problem: processOtherFrame passes the content of the com.github.dockerjava.api.model.Frame 1-to-1 to the consumer without doing any processing of log lines (like processRawFrame > normalizeLogLines). This would only work if the Frame contains a complete log message and not a partial log message.

We reproduced this multiple times. See the log output for one example.

When using a WaitAllStrategy with more LogMessageWaitStrategy, this is more likely to happen because the second log wait strategy only attaches to the log after the first finished, and then of course gets a lot more data at once.

Relevant log output

2022-09-13 00:34:58,297 DEBUG - STDOUT: 2022-09-12 22:34:56,408 INFO  - Extension "HiveMQ Enterprise Extension for Kafka" version 4.9.0-SNAPSHOT started succes
2022-09-13 00:34:58,313 DEBUG - STDOUT: sfully.

from this log statement: https://github.com/testcontainers/testcontainers-java/blob/de1324ed2800eff4da326d0c23d281399d006bc0/core/src/main/java/org/testcontainers/containers/output/WaitingConsumer.java#L89

Additional Information

No response

SgtSilvio avatar Sep 13 '22 16:09 SgtSilvio

Related: #643

SgtSilvio avatar Sep 18 '22 14:09 SgtSilvio