testcontainers / testcontainers-node

Testcontainers is a NodeJS library that supports tests, providing lightweight, throwaway instances of common databases, Selenium web browsers, or anything else that can run in a Docker container.
https://testcontainers.com
MIT License
1.94k stars 195 forks source link

"Failed to connect to Reaper" when "Reusing existing Reaper for session ..." #870

Open pmysinski opened 6 days ago

pmysinski commented 6 days ago

Expected Behaviour Testcontainers will try to create new Reaper instance after failed connection and the Reaper is actualy down.

Actual Behaviour There is race condition, a very small chance but still affects us once in ~10 test suites, when uping and downing testcontainers in sequence for many microsevices tests.

After every test suite it is very likely for next suite setting up the test containers to reuse reaper container instance. When it happens, sometimes I get "Failed to connect to Reaper" message and it fails.

I think there is small window when testcontainers check if current reaper exists but it is about to shutdown so we cannot connect to it. https://github.com/testcontainers/testcontainers-node/blob/main/packages/testcontainers/src/reaper/reaper.ts#L30-L36

Next suite after the failed one starts with no problems with new Reaper. Testcontainer Logs Previous test suite:

...
2024-11-18T16:43:07.077Z testcontainers [DEBUG] Container runtime strategy "ConfigurationStrategy" works
2024-11-18T16:43:07.083Z testcontainers [DEBUG] Acquiring lock file "/tmp/testcontainers-node.lock"...
2024-11-18T16:43:07.094Z testcontainers [DEBUG] Acquired lock file "/tmp/testcontainers-node.lock"
2024-11-18T16:43:07.095Z testcontainers [DEBUG] Listing containers...
2024-11-18T16:43:07.101Z testcontainers [DEBUG] Listed containers
2024-11-18T16:43:07.101Z testcontainers [DEBUG] Creating new Reaper for session "965bbfcf656b" with socket path "/var/run/docker.sock"...
2024-11-18T16:43:07.104Z testcontainers [DEBUG] Checking if image exists "testcontainers/ryuk:0.5.1"...
2024-11-18T16:43:07.113Z testcontainers [DEBUG] Checked if image exists "testcontainers/ryuk:0.5.1"
2024-11-18T16:43:07.114Z testcontainers [DEBUG] Image "testcontainers/ryuk:0.5.1" already exists
2024-11-18T16:43:07.115Z testcontainers [DEBUG] Creating container for image "testcontainers/ryuk:0.5.1"...
2024-11-18T16:43:07.755Z testcontainers [DEBUG] [3630164e4ae8] Created container for image "testcontainers/ryuk:0.5.1"
2024-11-18T16:43:07.755Z testcontainers [INFO] [3630164e4ae8] Starting container for image "testcontainers/ryuk:0.5.1"...
2024-11-18T16:43:07.755Z testcontainers [DEBUG] [3630164e4ae8] Starting container...
2024-11-18T16:43:08.113Z testcontainers [DEBUG] [3630164e4ae8] Started container
2024-11-18T16:43:08.113Z testcontainers [INFO] [3630164e4ae8] Started container for image "testcontainers/ryuk:0.5.1"
2024-11-18T16:43:08.114Z testcontainers [DEBUG] [3630164e4ae8] Inspecting container...
2024-11-18T16:43:08.122Z testcontainers [DEBUG] [3630164e4ae8] Inspected container
2024-11-18T16:43:08.125Z testcontainers [DEBUG] [3630164e4ae8] Waiting for container to be ready...
2024-11-18T16:43:08.126Z testcontainers [DEBUG] [3630164e4ae8] Waiting for log message "/.+ Started!/"...
2024-11-18T16:43:08.126Z testcontainers [DEBUG] [3630164e4ae8] Fetching container logs...
2024-11-18T16:43:08.140Z testcontainers [DEBUG] [3630164e4ae8] Demuxing stream...
2024-11-18T16:43:08.141Z testcontainers [DEBUG] [3630164e4ae8] Demuxed stream
2024-11-18T16:43:08.142Z testcontainers [DEBUG] [3630164e4ae8] Fetched container logs
2024-11-18T16:43:08.153Z testcontainers [DEBUG] [3630164e4ae8] Log wait strategy complete
2024-11-18T16:43:08.157Z testcontainers [INFO] [3630164e4ae8] Container is ready
2024-11-18T16:43:08.159Z testcontainers [DEBUG] [3630164e4ae8] Connecting to Reaper (attempt 1) on "docker:32770"...
2024-11-18T16:43:08.162Z testcontainers [DEBUG] [3630164e4ae8] Connected to Reaper
...

Failed test suite:

2024-11-18T16:44:23.307Z testcontainers [DEBUG] Acquiring lock file "/tmp/testcontainers-node.lock"...
2024-11-18T16:44:23.317Z testcontainers [DEBUG] Acquired lock file "/tmp/testcontainers-node.lock"
2024-11-18T16:44:23.318Z testcontainers [DEBUG] Listing containers...
2024-11-18T16:44:23.326Z testcontainers [DEBUG] Listed containers
2024-11-18T16:44:23.326Z testcontainers [DEBUG] Reusing existing Reaper for session "965bbfcf656b"...
2024-11-18T16:44:23.328Z testcontainers [DEBUG] [3630164e4ae8] Connecting to Reaper (attempt 1) on "docker:32770"...
2024-11-18T16:44:23.334Z testcontainers [ERROR] Reaper 3630164e4ae883e829dafcbae1b437da848e0999b3eeac1f3190c0f6defe27ee socket error: Error: connect ECONNREFUSED 172.21.0.2:32770
2024-11-18T16:44:23.335Z testcontainers [ERROR] [3630164e4ae8] Connection to Reaper closed with error
2024-11-18T16:44:24.336Z testcontainers [DEBUG] [3630164e4ae8] Connecting to Reaper (attempt 2) on "docker:32770"...
2024-11-18T16:44:24.339Z testcontainers [ERROR] Reaper 3630164e4ae883e829dafcbae1b437da848e0999b3eeac1f3190c0f6defe27ee socket error: Error: connect ECONNREFUSED 172.21.0.2:32770
2024-11-18T16:44:24.339Z testcontainers [ERROR] [3630164e4ae8] Connection to Reaper closed with error
2024-11-18T16:44:25.340Z testcontainers [DEBUG] [3630164e4ae8] Connecting to Reaper (attempt 3) on "docker:32770"...
2024-11-18T16:44:25.344Z testcontainers [ERROR] Reaper 3630164e4ae883e829dafcbae1b437da848e0999b3eeac1f3190c0f6defe27ee socket error: Error: connect ECONNREFUSED 172.21.0.2:32770
2024-11-18T16:44:25.344Z testcontainers [ERROR] [3630164e4ae8] Connection to Reaper closed with error
2024-11-18T16:44:26.345Z testcontainers [DEBUG] [3630164e4ae8] Connecting to Reaper (attempt 4) on "docker:32770"...
2024-11-18T16:44:26.348Z testcontainers [ERROR] Reaper 3630164e4ae883e829dafcbae1b437da848e0999b3eeac1f3190c0f6defe27ee socket error: Error: connect ECONNREFUSED 172.21.0.2:32770
2024-11-18T16:44:26.348Z testcontainers [ERROR] [3630164e4ae8] Connection to Reaper closed with error
2024-11-18T16:44:27.349Z testcontainers [DEBUG] [3630164e4ae8] Connecting to Reaper (attempt 5) on "docker:32770"...
2024-11-18T16:44:27.353Z testcontainers [ERROR] Reaper 3630164e4ae883e829dafcbae1b437da848e0999b3eeac1f3190c0f6defe27ee socket error: Error: connect ECONNREFUSED 172.21.0.2:32770
2024-11-18T16:44:27.353Z testcontainers [ERROR] [3630164e4ae8] Connection to Reaper closed with error
2024-11-18T16:44:27.353Z testcontainers [ERROR] [3630164e4ae8] Failed to connect to Reaper
2024-11-18T16:44:27.354Z testcontainers [DEBUG] Releasing lock file "/tmp/testcontainers-node.lock"...
2024-11-18T16:44:27.357Z testcontainers [DEBUG] Released lock file "/tmp/testcontainers-node.lock"
...

Suite after the failed one:

2024-11-18T16:45:12.234Z testcontainers [DEBUG] Container runtime strategy "ConfigurationStrategy" works
2024-11-18T16:45:12.241Z testcontainers [DEBUG] Acquiring lock file "/tmp/testcontainers-node.lock"...
2024-11-18T16:45:12.256Z testcontainers [DEBUG] Acquired lock file "/tmp/testcontainers-node.lock"
2024-11-18T16:45:12.256Z testcontainers [DEBUG] Listing containers...
2024-11-18T16:45:12.266Z testcontainers [DEBUG] Listed containers
2024-11-18T16:45:12.269Z testcontainers [DEBUG] Creating new Reaper for session "a3eab67b5d73" with socket path "/var/run/docker.sock"...
2024-11-18T16:45:12.273Z testcontainers [DEBUG] Checking if image exists "testcontainers/ryuk:0.5.1"...
2024-11-18T16:45:12.281Z testcontainers [DEBUG] Checked if image exists "testcontainers/ryuk:0.5.1"
2024-11-18T16:45:12.281Z testcontainers [DEBUG] Image "testcontainers/ryuk:0.5.1" already exists
2024-11-18T16:45:12.283Z testcontainers [DEBUG] Creating container for image "testcontainers/ryuk:0.5.1"...
2024-11-18T16:45:58.204Z testcontainers [DEBUG] [ff737d38c0dc] Created container for image "testcontainers/ryuk:0.5.1"
2024-11-18T16:45:58.205Z testcontainers [INFO] [ff737d38c0dc] Starting container for image "testcontainers/ryuk:0.5.1"...
2024-11-18T16:45:58.205Z testcontainers [DEBUG] [ff737d38c0dc] Starting container...
2024-11-18T16:45:58.765Z testcontainers [DEBUG] [ff737d38c0dc] Started container
2024-11-18T16:45:58.765Z testcontainers [INFO] [ff737d38c0dc] Started container for image "testcontainers/ryuk:0.5.1"
2024-11-18T16:45:58.765Z testcontainers [DEBUG] [ff737d38c0dc] Inspecting container...
2024-11-18T16:45:58.772Z testcontainers [DEBUG] [ff737d38c0dc] Inspected container
2024-11-18T16:45:58.775Z testcontainers [DEBUG] [ff737d38c0dc] Waiting for container to be ready...
2024-11-18T16:45:58.776Z testcontainers [DEBUG] [ff737d38c0dc] Waiting for log message "/.+ Started!/"...
2024-11-18T16:45:58.776Z testcontainers [DEBUG] [ff737d38c0dc] Fetching container logs...
2024-11-18T16:45:58.782Z testcontainers [DEBUG] [ff737d38c0dc] Demuxing stream...
2024-11-18T16:45:58.783Z testcontainers [DEBUG] [ff737d38c0dc] Demuxed stream
2024-11-18T16:45:58.783Z testcontainers [DEBUG] [ff737d38c0dc] Fetched container logs
2024-11-18T16:45:58.797Z testcontainers [DEBUG] [ff737d38c0dc] Log wait strategy complete
2024-11-18T16:45:58.800Z testcontainers [INFO] [ff737d38c0dc] Container is ready
2024-11-18T16:45:58.801Z testcontainers [DEBUG] [ff737d38c0dc] Connecting to Reaper (attempt 1) on "docker:32771"...
2024-11-18T16:45:58.804Z testcontainers [DEBUG] [ff737d38c0dc] Connected to Reaper

Environment Information