[Bug]: redpanda testcontainer not fully ready to accept connections #1827

sbuliarca · 2023-10-27T11:27:11Z

Testcontainers version

0.26.0

Using the latest Testcontainers version?

Yes

Host OS

MacOS Ventura 13.6

Host arch

ARM(Apple M1)

Go version

1.21.3

Docker version

Client: Docker Engine - Community
 Version:           24.0.2
 API version:       1.42 (downgraded from 1.43)
 Go version:        go1.20.4
 Git commit:        cb74dfcd85
 Built:             Thu May 25 20:26:27 2023
 OS/Arch:           darwin/arm64
 Context:           default

Server:
 Engine:
  Version:          23.0.6
  API version:      1.42 (minimum version 1.12)
  Go version:       go1.20.8
  Git commit:       9dbdbd4b6d7681bd18c897a6ba0376073c2a72ff
  Built:            Thu Sep  7 06:11:07 2023
  OS/Arch:          linux/arm64
  Experimental:     false
 containerd:
  Version:          v1.7.2
  GitCommit:        0cae528dd6cb557f7201036e9f43420650207b58
 runc:
  Version:          1.1.7
  GitCommit:        860f061b76bb4fc671f0f9e900f7d80ff93d4eb7
 docker-init:
  Version:          0.19.0
  GitCommit:

Docker info

Client: Docker Engine - Community
 Version:    24.0.2
 Context:    default
 Debug Mode: false

Server:
 Containers: 0
  Running: 0
  Paused: 0
  Stopped: 0
 Images: 14
 Server Version: 23.0.6
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Using metacopy: false
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 1
 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: runc io.containerd.runc.v2
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 0cae528dd6cb557f7201036e9f43420650207b58
 runc version: 860f061b76bb4fc671f0f9e900f7d80ff93d4eb7
 init version:
 Security Options:
  seccomp
   Profile: builtin
 Kernel Version: 6.1.55-0-virt
 Operating System: Alpine Linux v3.18
 OSType: linux
 Architecture: aarch64
 CPUs: 4
 Total Memory: 5.789GiB
 Name: colima
 ID: baa1e7d9-eb28-4610-8ff4-d85177f0a3ea
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

What happened?

I tried using the redpanda module, but after staring, the client is getting connection refused.
It seems that, in my case, there is a delay in the port being exposed.
I am using Colima to start the docker server.

To validate, I tried running the tests in the redpanda module and the same happens.
I'm attaching the logs of the tests run below.

From my experience with testcontainers, it helps adding the condition wait.ForListeningPort(defaultKafkaAPIPort) when staring the container.
I tried this and now the tests are passing.
I am gonna raise a PR.

Relevant log output

Tests output:

➜  redpanda git:(main) make test                                                                                                                                                    (minikube/default)export
/Library/Developer/CommandLineTools/usr/bin/make test-redpanda
Running redpanda tests...
gotestsum \
                --format short-verbose \
                --rerun-fails=5 \
                --packages="./..." \
                --junitfile TEST-unit.xml \
                -- \
                -coverprofile=coverage.out \
                -timeout=30m
=== RUN   TestRedpanda
2023/10/27 14:01:24 github.com/testcontainers/testcontainers-go - Connected to docker: 
  Server Version: 23.0.6
  API Version: 1.42
  Operating System: Alpine Linux v3.18
  Total Memory: 5927 MB
  Resolved Docker Host: unix:///Users/sorinbuliarca/.colima/default/docker.sock
  Resolved Docker Socket Path: /var/run/docker.sock
  Test SessionID: 920cc7ec20d97611306b3844c31abbd917c54052a0b5cf7615d3a26ef15df921
  Test ProcessID: 146a97c7-ea6c-4583-a318-bec468535635
2023/10/27 14:01:24 🐳 Creating container for image docker.io/testcontainers/ryuk:0.5.1
2023/10/27 14:01:24 ✅ Container created: 93eea1eae144
2023/10/27 14:01:24 🐳 Starting container: 93eea1eae144
2023/10/27 14:01:24 ✅ Container started: 93eea1eae144
2023/10/27 14:01:24 🚧 Waiting for container id 93eea1eae144 image: docker.io/testcontainers/ryuk:0.5.1. Waiting for: &{Port:8080/tcp timeout:<nil> PollInterval:100ms}
2023/10/27 14:01:25 🐳 Creating container for image docker.redpanda.com/redpandadata/redpanda:v23.1.7
2023/10/27 14:01:25 ✅ Container created: af07accb214b
2023/10/27 14:01:25 🐳 Starting container: af07accb214b
2023/10/27 14:01:25 ✅ Container started: af07accb214b
    redpanda_test.go:46: 
                Error Trace:    /Users/sorinbuliarca/projects/gocode/src/github.com/utilitywarehouse/testcontainers-go/modules/redpanda/redpanda_test.go:46
                Error:          Received unexpected error:
                                unable to dial: dial tcp [::1]:32922: connect: connection refused
                Test:           TestRedpanda
2023/10/27 14:01:26 🐳 Terminating container: af07accb214b
2023/10/27 14:01:27 🚫 Container terminated: af07accb214b
--- FAIL: TestRedpanda (3.25s)
FAIL TestRedpanda (3.25s)
PASS TestRedpandaWithAuthentication (2.97s)
PASS TestRedpandaProduceWithAutoCreateTopics (2.20s)
=== RUN   TestRedpandaWithTLS
2023/10/27 14:01:32 🐳 Creating container for image docker.redpanda.com/redpandadata/redpanda:v23.1.7
2023/10/27 14:01:32 ✅ Container created: 54368616bd0a
2023/10/27 14:01:32 🐳 Starting container: 54368616bd0a
2023/10/27 14:01:32 ✅ Container started: 54368616bd0a
    redpanda_test.go:251: 
                Error Trace:    /Users/sorinbuliarca/projects/gocode/src/github.com/utilitywarehouse/testcontainers-go/modules/redpanda/redpanda_test.go:251
                Error:          Received unexpected error:
                                Get "https://localhost:32930/v1/cluster/health_overview": dial tcp [::1]:32930: connect: connection refused
                Test:           TestRedpandaWithTLS
2023/10/27 14:01:33 🐳 Terminating container: 54368616bd0a
2023/10/27 14:01:34 🚫 Container terminated: 54368616bd0a
--- FAIL: TestRedpandaWithTLS (1.77s)
FAIL TestRedpandaWithTLS (1.77s)
=== RUN   ExampleRunContainer
2023/10/27 14:01:34 🐳 Creating container for image docker.redpanda.com/redpandadata/redpanda:v23.1.7
2023/10/27 14:01:34 ✅ Container created: 5873fb69535b
2023/10/27 14:01:34 🐳 Starting container: 5873fb69535b
2023/10/27 14:01:34 ✅ Container started: 5873fb69535b
--- FAIL: ExampleRunContainer (1.08s)
FAIL ExampleRunContainer (1.08s)
coverage: 79.3% of statements
panic: failed to create service account with username "superuser-2": request failed: Post "http://localhost:32933/v1/security/users": dial tcp [::1]:32933: connect: connection refused [recovered]
        panic: failed to create service account with username "superuser-2": request failed: Post "http://localhost:32933/v1/security/users": dial tcp [::1]:32933: connect: connection refused

goroutine 1 [running]:
testing.(*InternalExample).processRunResult(0x1400039bbb8, {0x0, 0x0}, 0x0?, 0x0, {0x102f189a0, 0x1400007c760})
        /opt/homebrew/opt/go/libexec/src/testing/example.go:95 +0x4b0
testing.runExample.func2()
        /opt/homebrew/opt/go/libexec/src/testing/run_example.go:59 +0xfc
panic({0x102f189a0?, 0x1400007c760?})
        /opt/homebrew/opt/go/libexec/src/runtime/panic.go:914 +0x218
github.com/testcontainers/testcontainers-go/modules/redpanda_test.ExampleRunContainer()
        /Users/sorinbuliarca/projects/gocode/src/github.com/utilitywarehouse/testcontainers-go/modules/redpanda/examples_test.go:24 +0x41c
testing.runExample({{0x102d51827, 0x13}, 0x103010f70, {0x102d4948d, 0x5}, 0x0})
        /opt/homebrew/opt/go/libexec/src/testing/run_example.go:63 +0x244
testing.runExamples(0x1400039bd80, {0x1034d5100?, 0x1, 0x4?})
        /opt/homebrew/opt/go/libexec/src/testing/example.go:44 +0x13c
testing.(*M).Run(0x140003492c0)
        /opt/homebrew/opt/go/libexec/src/testing/testing.go:1927 +0x5bc
main.main()
        _testmain.go:91 +0x1c8
FAIL .

=== Failed
=== FAIL: . TestRedpanda (3.25s)
2023/10/27 14:01:24 github.com/testcontainers/testcontainers-go - Connected to docker: 
  Server Version: 23.0.6
  API Version: 1.42
  Operating System: Alpine Linux v3.18
  Total Memory: 5927 MB
  Resolved Docker Host: unix:///Users/sorinbuliarca/.colima/default/docker.sock
  Resolved Docker Socket Path: /var/run/docker.sock
  Test SessionID: 920cc7ec20d97611306b3844c31abbd917c54052a0b5cf7615d3a26ef15df921
  Test ProcessID: 146a97c7-ea6c-4583-a318-bec468535635
2023/10/27 14:01:24 🐳 Creating container for image docker.io/testcontainers/ryuk:0.5.1
2023/10/27 14:01:24 ✅ Container created: 93eea1eae144
2023/10/27 14:01:24 🐳 Starting container: 93eea1eae144
2023/10/27 14:01:24 ✅ Container started: 93eea1eae144
2023/10/27 14:01:24 🚧 Waiting for container id 93eea1eae144 image: docker.io/testcontainers/ryuk:0.5.1. Waiting for: &{Port:8080/tcp timeout:<nil> PollInterval:100ms}
2023/10/27 14:01:25 🐳 Creating container for image docker.redpanda.com/redpandadata/redpanda:v23.1.7
2023/10/27 14:01:25 ✅ Container created: af07accb214b
2023/10/27 14:01:25 🐳 Starting container: af07accb214b
2023/10/27 14:01:25 ✅ Container started: af07accb214b
    redpanda_test.go:46: 
                Error Trace:    /Users/sorinbuliarca/projects/gocode/src/github.com/utilitywarehouse/testcontainers-go/modules/redpanda/redpanda_test.go:46
                Error:          Received unexpected error:
                                unable to dial: dial tcp [::1]:32922: connect: connection refused
                Test:           TestRedpanda
2023/10/27 14:01:26 🐳 Terminating container: af07accb214b
2023/10/27 14:01:27 🚫 Container terminated: af07accb214b

=== FAIL: . TestRedpandaWithTLS (1.77s)
2023/10/27 14:01:32 🐳 Creating container for image docker.redpanda.com/redpandadata/redpanda:v23.1.7
2023/10/27 14:01:32 ✅ Container created: 54368616bd0a
2023/10/27 14:01:32 🐳 Starting container: 54368616bd0a
2023/10/27 14:01:32 ✅ Container started: 54368616bd0a
    redpanda_test.go:251: 
                Error Trace:    /Users/sorinbuliarca/projects/gocode/src/github.com/utilitywarehouse/testcontainers-go/modules/redpanda/redpanda_test.go:251
                Error:          Received unexpected error:
                                Get "https://localhost:32930/v1/cluster/health_overview": dial tcp [::1]:32930: connect: connection refused
                Test:           TestRedpandaWithTLS
2023/10/27 14:01:33 🐳 Terminating container: 54368616bd0a
2023/10/27 14:01:34 🚫 Container terminated: 54368616bd0a

=== FAIL: . ExampleRunContainer (1.08s)
=== RUN   ExampleRunContainer
2023/10/27 14:01:34 🐳 Creating container for image docker.redpanda.com/redpandadata/redpanda:v23.1.7
2023/10/27 14:01:34 ✅ Container created: 5873fb69535b
2023/10/27 14:01:34 🐳 Starting container: 5873fb69535b
2023/10/27 14:01:34 ✅ Container started: 5873fb69535b

DONE 5 tests, 3 failures in 28.068s
ERROR rerun aborted because previous run had a suspected panic and some test may not have run
make[1]: *** [test-redpanda] Error 3
make: *** [test] Error 2

Additional information

No response

The text was updated successfully, but these errors were encountered:

mdelapenya · 2023-10-27T11:33:39Z

Hey @sbuliarca have you played around with the startup time of redpanda container? I ask because I've working with this module the entire week preparing a workshop and did not notice any timeout 🤔

I wonder if colima is doing anything under the hood. Could you please try to override the wait strategy with something you control, like this https://golang.testcontainers.org/modules/redpanda/#wait-strategies?

sbuliarca · 2023-10-27T12:05:03Z

Hey @sbuliarca have you played around with the startup time of redpanda container? I ask because I've working with this module the entire week preparing a workshop and did not notice any timeout 🤔

I wonder if colima is doing anything under the hood. Could you please try to override the wait strategy with something you control, like this https://golang.testcontainers.org/modules/redpanda/#wait-strategies?

Unfortunatelly it doesn't work, as the wait strategy is applied to the initially started container, that is started without actually starting the redpanda process inside the container, just to get the local port that the clients will be able to connect:
https://github.com/testcontainers/testcontainers-go/blob/main/modules/redpanda/redpanda.go#L150

Afterwards, the actual redpanda process will start when copying the redpanda.yml file into the container: https://github.com/testcontainers/testcontainers-go/blob/main/modules/redpanda/redpanda.go#L173
And then the wait condition for redpanda is used:
https://github.com/testcontainers/testcontainers-go/blob/main/modules/redpanda/redpanda.go#L179

I created this simple PR that adds to the redpanda condition: #1828
I see the cassandra and mongo testcontainers are doing the same, and I don't think this wait.ForListeningPort(defaultKafkaAPIPort) hurts anyway.

sbuliarca added the bug An issue with the library label Oct 27, 2023

sbuliarca mentioned this issue Oct 27, 2023

fix(redpanda): add wait for listening port condition on startup #1828

Merged

mdelapenya closed this as completed in #1828 Oct 27, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Bug]: redpanda testcontainer not fully ready to accept connections #1827

[Bug]: redpanda testcontainer not fully ready to accept connections #1827

sbuliarca commented Oct 27, 2023

mdelapenya commented Oct 27, 2023

sbuliarca commented Oct 27, 2023

[Bug]: redpanda testcontainer not fully ready to accept connections #1827

[Bug]: redpanda testcontainer not fully ready to accept connections #1827

Comments

sbuliarca commented Oct 27, 2023

Testcontainers version

Using the latest Testcontainers version?

Host OS

Host arch

Go version

Docker version

Docker info

What happened?

Relevant log output

Additional information

mdelapenya commented Oct 27, 2023

sbuliarca commented Oct 27, 2023