Repository navigation
Fix Kafka container starting before the broker is ready - #1605
Merged
Merged
Conversation
After the starter script is copied, the second wait fell back to the placeholder "Waiting for script..." log wait whenever no wait strategy was configured, so start() resolved before Kafka was listening. Restore the configured wait strategy before selecting the second wait.
An explicit undefined fell back to this.waitStrategy, so the argument could not express "no strategy configured". Kafka and Redpanda now restore the configured strategy and call it with two arguments.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
new KafkaContainer(image).start()resolved before the broker was listening, unless the caller had set a wait strategy withwithWaitStrategy.Root cause
KafkaContainerstarts in two phases.beforeContainerCreatedsavesthis.waitStrategyinoriginalWaitStrategyand replaces it with a placeholderWait.forLogMessage("Waiting for script...").containerStartedthen copies the real starter script and waits a second time withthis.selectWaitStrategy(client, inspectResult, this.originalWaitStrategy).GenericContainer.selectWaitStrategydeclares that third parameter aswaitStrategy = this.waitStrategy. Since #1096,GenericContainer.waitStrategydefaults toundefinedinstead ofWait.forListeningPorts(). With no user strategy,originalWaitStrategyisundefined, the default parameter applies, and the second wait is the placeholder again, which the container's log already satisfies.The failed
Tests (kafka, 24.x, podman)job onmainshows it for container5627189f189a:Copied content to container(starter script)Waiting for log message "Waiting for script..."...Container is ready, sostart()resolvesauthorizerStart completed for endpoint PLAINTEXT. Endpoint is now READYstart()resolved 61 seconds before the broker opened its port. The job log has 7362Connection refusedlines from the clients.Fix
The third parameter of
selectWaitStrategycould not express "no strategy configured", which is the only thing it was added for in #1096, so it is removed. The method now always readsthis.waitStrategy.KafkaContainer.containerStartedputs the saved strategy back onthis.waitStrategyand callsthis.selectWaitStrategy(client, inspectResult). The second wait is the user's strategy, or what the selector picks when there is none: a health check if the container or image defines one, otherwise listening ports. It can no longer be the placeholder.RedpandaContainergets the same two lines. It was not affected by the bug (below), but it was the only other caller of the third parameter.Restoring
this.waitStrategyalso means a secondstart()on the same builder saves the user's strategy again instead of the placeholder left over from the first start.Is listening ports a deterministic readiness signal for Kafka?
Yes. With a fixed port, Kafka opens the listener socket in
Acceptor.start(), which runs only after the endpoint is ready, not when theSocketServeris constructed (4.1, 3.9). Local timelines with this change:Internal port 9093/tcp readycp-kafka:8.3.2(KRaft)Endpoint is now READYforPLAINTEXT, thenKafka Server startedcp-kafka:7.9.1(ZooKeeper)Awaiting socket connections on 0.0.0.0:9093, then[KafkaServer id=1] startedOther implementations
Java and Go copy the starter script the same way and then wait for a broker log line:
Transitioning from RECOVERY to RUNNINGin KRaft mode (KafkaHelper.WAIT_STRATEGY) and[KafkaServer id=\d+] startedin ZooKeeper mode (KafkaContainer).Transitioning from RECOVERY to RUNNING, in the same post-start hook that copies the script (kafka.go).I borrowed the ordering (copy the script, then wait on a signal that the broker itself produces) and did not adopt the log line as this module's default. Listening ports was the default here before #1096, the tables above show the port opens within the same few milliseconds as those log lines, and a log-based default would hang for users who lower Kafka's log level.
Redpanda
RedpandaContainerwas not starting early. Its constructor setsWait.forLogMessage("Successfully started Redpanda!"), andwithWaitStrategyonly accepts a strategy, so itsoriginalWaitStrategywas neverundefinedthrough the public API. Its change here only follows the removed parameter.Expected conflicts
#1584 changes
generic-container.ts,kafka-container.tsandredpanda-container.ts, including the lines next to these in bothcontainerStartedmethods. #1597 changeskafka-container.ts. Whichever merges second will need a small rebase. This PR depends on neither.Verification
Regression test
should be listening when startedinkafka-container-latest.test.ts: right afterstart()resolves it opens one TCP connection to the broker's port, with no polling.The probe runs inside the container (
bash -c '</dev/tcp/localhost/9093', the same checkWait.forListeningPorts()uses) because a host-side connect cannot fail on Docker Desktop: with nothing listening on the container port, a connect to the published port was accepted after 1 ms and closed after 2 ms.Red, on
main(npx vitest run packages/modules/kafka/src/kafka-container-latest.test.ts -t "should be listening when started"):Green, same command with the fix:
The original red evidence is the failed CI job linked above.
Both Kafka test files and the Redpanda test file, on Docker Desktop with retries off (
npx vitest run packages/modules/kafka/src/kafka-container-latest.test.ts packages/modules/kafka/src/kafka-container-7.test.ts packages/modules/redpanda/src/redpanda-container.test.ts):Not run locally: Podman.
npm run format,npm run lint,npm run knipandnpm run check-compilespass.Not breaking
One signature changes: the protected
GenericContainer.selectWaitStrategy(client, inspectResult, waitStrategy?)loses its optional third parameter. It is not documented, and Kafka and Redpanda were its only callers in this repository.this.waitStrategyis used.withWaitStrategyis used exactly as before.KafkaContainer.start()now waits for the exposed ports to be listening, which is what it did before Use configured health checks as the default wait strategy #1096. It takes longer to resolve only because it used to resolve too early.Labelled
patchon that basis. If the removed parameter should count as breaking, this needsmajorinstead.