Race condition when chaining tests that use sshd make 2nd test fail

[lbroudoux]

Expected Behaviour

My application contains 2 Jest tests that pop out containers that must access the host on different ports (I start and stop the application on a random free port in both tests).

As I'm stopping all containers and networks in afterAll() method of my 2 tests, I expect those 2 tests to pass when run in sequence (each test launched independently pass).

Actual Behaviour

I face an error when running the 2nd test. This error occurs whatever the order of tests:

(HTTP code 409) unexpected - Conflict. The container name "/testcontainers-port-forwarder-3590a01bd23a" is already in use by container "12da1dd140b3c1db82b6b6fb1a06a9c6bfaa99a18bc6c0345657ece569fc96e0". You have to remove (or rename) that container to be able to reuse that name.

      at ../node_modules/docker-modem/lib/modem.js:343:17
      at getCause (../node_modules/docker-modem/lib/modem.js:373:7)
      at Modem.Object.<anonymous>.Modem.buildPayload (../node_modules/docker-modem/lib/modem.js:342:5)
      at IncomingMessage.<anonymous> (../node_modules/docker-modem/lib/modem.js:310:16)

It seems the sshd container is still attached to the previously running container in 1st test. Maybe it's not killed fast enough by ryuk at the end of first test...

Testcontainer Logs

When setting export DEBUG=testcontainers* before running my tests, I got following relevant logs - from the end of previous end to the failure when starting the second one:

[...]
  testcontainers [DEBUG] [a2fd73d26a53] Stopped container +176ms
  testcontainers [DEBUG] [a2fd73d26a53] Removing container... +0ms
  testcontainers [DEBUG] [a2fd73d26a53] Removed container +11ms
  testcontainers [INFO] [a2fd73d26a53] Stopped container +0ms
 PASS  test/orders.api.e2e-spec.ts (8.288 s)
  ● Console

    console.log
      {"id":"655c95c83d00cf01f6fb3798","version":2,"testNumber":1,"testDate":1700566472226,"testedEndpoint":"http://host.testcontainers.internal:3000","serviceId":"655c95c73d00cf01f6fb377f","timeout":3000,"elapsedTime":76,"success":true,"inProgress":false,"runnerType":"OPEN_API_SCHEMA","testCaseResults":[{"success":true,"elapsedTime":76,"operationName":"POST /orders","testStepResults":[{"success":true,"elapsedTime":65,"requestName":"invalid_order","message":""},{"success":true,"elapsedTime":11,"requestName":"valid_order","message":""}]}]}

      at Object.<anonymous> (orders.api.e2e-spec.ts:69:15)

  testcontainers [DEBUG] Creating new Port Forwarder... +0ms
  testcontainers [DEBUG] Testing container runtime strategy "TestcontainersHostStrategy"... +0ms
  testcontainers [DEBUG] Loading ".testcontainers.properties" file... +0ms
  testcontainers [DEBUG] Loaded ".testcontainers.properties" file +1ms
  testcontainers [DEBUG] Found custom configuration: tcHost: "tcp://127.0.0.1:49964", dockerHost: "tcp://127.0.0.1:49964" +0ms
  testcontainers [DEBUG] Container runtime strategy "TestcontainersHostStrategy" works +89ms
  testcontainers [DEBUG] Acquiring lock file "/var/folders/n9/_hd3r9c13sz76379nr9lg3p40000gn/T/testcontainers-node.lock"... +3ms
  testcontainers [DEBUG] Acquired lock file "/var/folders/n9/_hd3r9c13sz76379nr9lg3p40000gn/T/testcontainers-node.lock" +1ms
  testcontainers [DEBUG] Listing containers... +0ms
  testcontainers [DEBUG] Listed containers +6ms
  testcontainers [DEBUG] Reusing existing Reaper for session "7516d459e5ef"... +0ms
  testcontainers [DEBUG] [a58a341100e3] Connecting to Reaper (attempt 1) on "127.0.0.1:33345"... +0ms
  testcontainers [DEBUG] [a58a341100e3] Connected to Reaper +1ms
  testcontainers [DEBUG] Releasing lock file "/var/folders/n9/_hd3r9c13sz76379nr9lg3p40000gn/T/testcontainers-node.lock"... +0ms
  testcontainers [DEBUG] Released lock file "/var/folders/n9/_hd3r9c13sz76379nr9lg3p40000gn/T/testcontainers-node.lock" +0ms
  testcontainers [DEBUG] Checking if image exists "testcontainers/sshd:1.1.0"... +0ms
  testcontainers:containers [a58a341100e3] 2023/11/21 11:34:33 New client connected: 172.17.0.1:47852 +678ms
  testcontainers:containers [a58a341100e3] 2023/11/21 11:34:33 Adding {"label":{"org.testcontainers.session-id=7516d459e5ef":true}} +0ms
  testcontainers [DEBUG] Checked if image exists "testcontainers/sshd:1.1.0" +6ms
  testcontainers [DEBUG] Image "testcontainers/sshd:1.1.0" already exists +0ms
  testcontainers [DEBUG] Creating container for image "testcontainers/sshd:1.1.0"... +0ms
  testcontainers [ERROR] Failed to create container for image "testcontainers/sshd:1.1.0": Error: (HTTP code 409) unexpected - Conflict. The container name "/testcontainers-port-forwarder-7516d459e5ef" is already in use by container "adcbe20ddbac8b2dca120921ed2b7f505f67ca20e26aff0024e34ceb36ea77e9". You have to remove (or rename) that container to be able to reuse that name.  +10ms
 FAIL  test/orders.api.postman.e2e-spec.ts

Steps to Reproduce

1. Demo in this repository: https://github.com/microcks/api-lifecycle
2. Go to shift-left-demo/nest-order-service folder and run npm install
3. Run 'npm run test:e2e'
4. See above error

I've tried adding --runInBand to Jest configuration to force serialization of tests but doesn't solve the problem

Environment Information

• Operating System: Mac OS Ventura 13.5.2
• Docker Version: Docker Desktop 4.21.1 (114176)
• Node version: v18.16.0
• Testcontainers version: 10.2.2

[javierlopezdeancos]

I will take a look but yep, looks like a race condition, thanks and advance to all your explanations and great context.

[cristianrgreco]

Hi @lbroudoux, thanks for raising such a detailed issue.

The idea behind the current implementation of a session ID is that it is shared across processes, including test processes. You can see in the Resource Reaper implementation for example that it checks for the existence of an existing container for the given session ID and reuses that if it exists:

testcontainers-node/packages/testcontainers/src/reaper/reaper.ts

Lines 33 to 36 in 824cd8d

	} else if (reaperContainer) {
	return await useExistingReaper(reaperContainer, sessionId, client.info.containerRuntime.host);
	} else {
	return await createNewReaper(sessionId, client.info.containerRuntime.remoteSocketPath);

If the session ID implementation remains the same (I need to have a chat with the other Testcontainers maintainers about this), the correct fix would be to implement a similar check in the Port Forwarder, so that the existing container is reused instead of a conflict being thrown.

[lbroudoux]

Thanks for the heads-up and commenting on the progression!

I think reuse is fine, but we should also be able to change the host port the sshd is bound to. On my 2 subsequent tests, I may use 2 different ports as those are randomly chosen when starting the main NestJS/Express application.

Also, I have used the --runInBand flag on the Jest command line to see if serialization would help. Does reusing/sharing sshd also mean that serialization becomes mandatory if it can only expose one host port at a time?

[cristianrgreco]

I think reuse is fine, but we should also be able to change the host port the sshd is bound to

If we change the existing host port that SSHD is bound to then we will break parallel testing, e.g if test suite 1 exposes port 8080 and is in progress, and test suite 2 then exposes port 8081, then test suite 1 will fail.

What I think makes sense is to append a host port whenever Testcontainers.exposeHortPorts(...) is called. Exposing a host port should be idempotent so in the case where you randomly generate the same port there's no issue. With this done I don't see why you would need to serialise your test runs

[cristianrgreco]

@lbroudoux please try version 10.3.2

[lbroudoux]

I've checked with 10.3.2, and it works like a charm! I've tried both with and without --runInBand and it works each time even when the 2 tests are run in parallel with different ports. Great! 🎉

Thanks!