[Bug]: Attaching a LogConsumer to a container makes the test hang if the container exits #1669
Closed as not planned
Description
Testcontainers version
v0.24.1
Using the latest Testcontainers version?
Yes
Host OS
Linux
Host arch
x86
Go version
1.21
Docker version
Client:
Version: 24.0.5
API version: 1.43
Go version: go1.20.6
Git commit: ced0996600
Built: Wed Jul 26 21:44:58 2023
OS/Arch: linux/amd64
Context: default
Server:
Engine:
Version: 24.0.5
API version: 1.43 (minimum version 1.12)
Go version: go1.20.6
Git commit: a61e2b4c9c
Built: Wed Jul 26 21:44:58 2023
OS/Arch: linux/amd64
Experimental: false
containerd:
Version: v1.7.6
GitCommit: 091922f03c2762540fd057fba91260237ff86acb.m
runc:
Version: 1.1.9
GitCommit:
docker-init:
Version: 0.19.0
GitCommit: de40ad0Docker info
Client:
Version: 24.0.5
Context: default
Debug Mode: false
Plugins:
buildx: Docker Buildx (Docker Inc.)
Version: 0.11.2
Path: /usr/lib/docker/cli-plugins/docker-buildx
compose: Docker Compose (Docker Inc.)
Version: 2.20.3
Path: /usr/lib/docker/cli-plugins/docker-compose
Server:
Containers: 5
Running: 1
Paused: 0
Stopped: 4
Images: 51
Server Version: 24.0.5
Storage Driver: zfs
Zpool: zsstripe
Zpool Health: ONLINE
Parent Dataset: zsstripe/docker
Space Used By Parent: 30240198656
Space Available: 196123287552
Parent Quota: no
Compression: zstd-fast
Logging Driver: json-file
Cgroup Driver: systemd
Cgroup Version: 2
Plugins:
Volume: local
Network: bridge host ipvlan macvlan null overlay
Log: awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog
Swarm: inactive
Runtimes: io.containerd.runc.v2 runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 091922f03c2762540fd057fba91260237ff86acb.m
runc version:
init version: de40ad0
Security Options:
seccomp
Profile: builtin
cgroupns
Kernel Version: 6.1.53-1-lts
Operating System: Arch Linux
OSType: linux
Architecture: x86_64
CPUs: 6
Total Memory: 31.28GiB
Name: Archiroo
ID: 27XO:IXYL:U5CA:XTZQ:Y4BL:LF3Q:JRWK:WLYJ:2RNN:CCAE:NEBA:DJHF
Docker Root Dir: /var/lib/docker
Debug Mode: false
Username: roobre
Experimental: false
Insecure Registries:
127.0.0.0/8
Live Restore Enabled: falseWhat happened?
When running a GenericContainer c that terminates unexpectedly, if a LogConsumer has been attached to the container with c.FollowOutput and started with c.StartLogProducer, calls to c.StopLogProducer will block forever. As c.Terminate calls c.StopLogProducer, this will cause a test to hang indefinitely if c.Terminate is called in t.Cleanup.
See the following example:
package testcon_test
import (
"context"
"testing"
"time"
"github.com/testcontainers/testcontainers-go"
"github.com/testcontainers/testcontainers-go/wait"
)
// Mirror is a testcontainers log adapter that mirrors container output to testing.T.Log.
type Mirror struct {
T *testing.T
}
// Accept implements the testcontainers adapter interface by writing received output to the test logger.
func (m Mirror) Accept(log testcontainers.Log) {
m.T.Logf("%s: %s", log.LogType, log.Content)
}
func TestTerminates(t *testing.T) {
debian, err := testcontainers.GenericContainer(context.TODO(), testcontainers.GenericContainerRequest{
ProviderType: testcontainers.ProviderDocker,
ContainerRequest: testcontainers.ContainerRequest{
Image: "debian",
Cmd: []string{"/bin/sh", "-c", "echo ready && sleep 1 && exit 1"},
WaitingFor: wait.ForLog("ready"),
},
Started: true,
})
if err != nil {
t.Fatal(err)
}
t.Cleanup(func() {
debian.Terminate(context.TODO())
})
debian.FollowOutput(Mirror{T: t})
err = debian.StartLogProducer(context.TODO())
if err != nil {
t.Fatal(err)
}
time.Sleep(5 * time.Second)
}The test above produces the output below and never terminates unless I send and interrupt with C-c.
This happens regardless of the exit code of the container.
Relevant log output
11:22:57 ~/Staging/testcon-repro $> go test -v ./
=== RUN TestTerminates
2023/09/22 11:22:58 github.com/testcontainers/testcontainers-go - Connected to docker:
Server Version: 24.0.5
API Version: 1.43
Operating System: Arch Linux
Total Memory: 32030 MB
Resolved Docker Host: unix:///var/run/docker.sock
Resolved Docker Socket Path: /var/run/docker.sock
Test SessionID: 646e587aee8704cdd7fc09403c34e30f3267265314af5a43d98d4fd089daf4ca
Test ProcessID: 30ba444c-ee29-48ca-bdfb-26101b5291c7
2023/09/22 11:22:58 🐳 Creating container for image docker.io/testcontainers/ryuk:0.5.1
2023/09/22 11:22:59 ✅ Container created: f2393a6e5e8a
2023/09/22 11:22:59 🐳 Starting container: f2393a6e5e8a
2023/09/22 11:22:59 ✅ Container started: f2393a6e5e8a
2023/09/22 11:22:59 🚧 Waiting for container id f2393a6e5e8a image: docker.io/testcontainers/ryuk:0.5.1. Waiting for: &{Port:8080/tcp timeout:<nil> PollInterval:100ms}
2023/09/22 11:22:59 🐳 Creating container for image debian
2023/09/22 11:22:59 ✅ Container created: 7909c158052a
2023/09/22 11:22:59 🐳 Starting container: 7909c158052a
2023/09/22 11:23:00 ✅ Container started: 7909c158052a
2023/09/22 11:23:00 🚧 Waiting for container id 7909c158052a image: debian. Waiting for: &{timeout:<nil> Log:ready IsRegexp:false Occurrence:1 PollInterval:100ms}
testcon_test.go:19: STDOUT: ready
container log error: EOF. Stopping log consumer: Headers out of sync2023/09/22 11:23:05 🐳 Terminating container: 7909c158052a
^Csignal: interrupt
FAIL testconrepro 24.862sAdditional information
No response