Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Not able to work with testcontainer node 10.8.1 (was working on 10.6.0) #84

Closed
jonesbusy opened this issue Apr 3, 2024 · 5 comments
Closed

Not able to work with testcontainer node 10.8.1 (was working on 10.6.0) #84

jonesbusy opened this issue Apr 3, 2024 · 5 comments
Labels
testcontainers-node

Comments

@jonesbusy
Copy link

jonesbusy commented Apr 3, 2024 •
edited
Loading

Hi,

I'm not sure if it's something wrong on kubedock or a regression on testcontainer node.

I'm using kubedock 0.16.0 but I also try to downgrade it to 0.15.5 withtout success

I would like to upgrade from testcontainer node 10.6.0 to 10.8.1 but I'm not able to make it work with kubedock.

  • Upgrade work locally using a docker socket
  • I don't face the issue testcontainer java or testcontainer .NET. All latest version

Basically no container is created, not even ryuk. It's like nothing happen

I can only see on kubedock logs.

I0403 08:46:34.378339       1 main.go:29] kubedock 0.15.5 (20240304-113636) / kubedock.id=5bb12d7eee1b
I0403 08:46:34.380212       1 main.go:108] kubernetes config: namespace=*****, initimage=joyrex2001/kubedock:0.15.5, dindimage=joyrex2001/kubedock:0.15.5, ready timeout=1m0s
I0403 08:46:34.381674       1 main.go:160] reaper started with max container age 1h0m0s
I0403 08:46:34.381973       1 main.go:101] enabled reverse-proxy services via 0.0.0.0 on the kubedock host
I0403 08:46:34.382029       1 main.go:119] default memory request: 512Mi,512Mi
I0403 08:46:34.382089       1 main.go:124] default runas user: 0
I0403 08:46:34.382132       1 main.go:128] default image pull policy: ifnotpresent
I0403 08:46:34.382171       1 main.go:131] service account used in deployments: runas-anyuid
I0403 08:46:34.382225       1 main.go:135] using namespace: ***********
[GIN] 2024/04/03 - 08:47:53 | 200 |     764.138µs |             ::1 | GET      "/info"
[GIN] 2024/04/03 - 08:47:53 | 200 |     4.69629ms |             ::1 | GET      "/images/r-docker-registry-1-docker-io.artifactory******/wiremock/wiremock:3.3.1-2/json"
[GIN] 2024/04/03 - 08:47:53 | 200 |   75.499095ms |             ::1 | GET      "/containers/json"
[GIN] 2024/04/03 - 08:47:53 | 200 |     333.341µs |             ::1 | GET      "/images/r-docker-registry-1-docker-io.artifactory.*****/testcontainers/ryuk:0.5.1/json"

Then it "hang" here

If I check the logs using testcontainer node 10.6.0

I0403 08:49:24.657981       1 main.go:29] kubedock 0.16.0 (20240402-190512) / kubedock.id=fd451f453704
I0403 08:49:24.659791       1 main.go:109] kubernetes config: namespace=***, initimage=joyrex2001/kubedock:0.16.0, dindimage=joyrex2001/kubedock:0.16.0, ready timeout=1m0s
I0403 08:49:24.752858       1 main.go:165] reaper started with max container age 1h0m0s
I0403 08:49:24.753365       1 main.go:101] enabled reverse-proxy services via 0.0.0.0 on the kubedock host
I0403 08:49:24.753469       1 main.go:119] default memory request: 512Mi,512Mi
I0403 08:49:24.753496       1 main.go:124] default runas user: 0
I0403 08:49:24.753531       1 main.go:128] default image pull policy: ifnotpresent
I0403 08:49:24.753550       1 main.go:131] service account used in deployments: runas-anyuid
I0403 08:49:24.753611       1 main.go:134] pod name prefix: kubedock
I0403 08:49:24.753660       1 main.go:138] using namespace: ****
[GIN] 2024/04/03 - 08:50:46 | 200 |     277.107µs |             ::1 | GET      "/info"
[GIN] 2024/04/03 - 08:50:46 | 200 |      203.35µs |             ::1 | GET      "/images/wiremock/wiremock:3.3.1-2/json"
[GIN] 2024/04/03 - 08:50:46 | 200 |     217.426µs |             ::1 | GET      "/containers/json"
[GIN] 2024/04/03 - 08:50:46 | 200 |     171.577µs |             ::1 | GET      "/images/testcontainers/ryuk:0.5.1/json"
[GIN] 2024/04/03 - 08:50:46 | 201 |    1.234363ms |             ::1 | POST     "/containers/create?Image=testcontainers%2Fryuk%3A0.5.1&name=testcontainers-ryuk-06ecddb4de0a&ExposedPorts=%7B%228080%22%3A%7B%7D%7D&Labels=%7B%22org.testcontainers%22%3A%22true%22%2C%22org.testcontainers.lang%22%3A%22node%22%2C%22org.testcontainers.version%22%3A%2210.6.0%22%2C%22org.testcontainers.session-id%22%3A%2206ecddb4de0a%22%7D&HostConfig=%7B%22AutoRemove%22%3Atrue%2C%22PortBindings%22%3A%7B%228080%22%3A%5B%7B%22HostPort%22%3A%220%22%7D%5D%7D%2C%22Binds%22%3A%5B%22%2Fvar%2Frun%2Fdocker.sock%3A%2Fvar%2Frun%2Fdocker.sock%3Arw%22%5D%7D"
[GIN] 2024/04/03 - 08:50:57 | 200 |      54.481µs |    10.128.8.182 | HEAD     "/_ping"
[GIN] 2024/04/03 - 08:50:57 | 200 |      17.332µs |    10.128.8.182 | HEAD     "/_ping"
I0403 08:50:59.154147       1 deploy.go:211] reverse proxy for 42667 to 8080
I0403 08:50:59.154396       1 tcpproxy.go:37] start reverse-proxy 0.0.0.0:42667->10.128.8.182:8080
[GIN] 2024/04/03 - 08:50:59 | 204 | 12.947581044s |             ::1 | POST     "/containers/b0cb691aa0da587706a37e9964b0887c1b095bf6bf9c64e7c4bdb249b7ae3e6a/start"

The only 2 difference I see is the GET requests

On testcontainer node 10.6.1

- [GIN] 2024/04/03 - 08:50:46 | 200 |      203.35µs |             ::1 | GET      "/images/wiremock/wiremock:3.3.1-2/json"

On testcontainer node 10.8.1

[GIN] 2024/04/03 - 08:47:53 | 200 |     4.69629ms |             ::1 | GET      "/images/r-docker-registry-1-docker-io.artifactory******/wiremock/wiremock:3.3.1-2/json"

The seconds contains my environment variable

TESTCONTAINERS_HUB_IMAGE_NAME_PREFIX  = 'r-docker-registry-1-docker-io.artifactory.*******/'

Using logs

[11:23:05.306+02:00] - 2024-04-03T09:23:05.270Z testcontainers [DEBUG] Image "r-docker-registry-1-docker-io.artifactory.*********//testcontainers/ryuk:0.5.1" already exists
[11:23:05.306+02:00] - 2024-04-03T09:23:05.270Z testcontainers [DEBUG] Acquiring lock file "/tmp/testcontainers-node.lock"...
[11:24:41.996+02:00] -  ❯ src/ts/api.test.ts  (5 tests) 90133ms

This get stucks on Acquiring lock file
@jonesbusy
Copy link
Author

Possible related to testcontainers/testcontainers-node#729

@jonesbusy jonesbusy mentioned this issue Apr 3, 2024
Merged
@jonesbusy
Copy link
Author

I think there are other issue related to testcontainers/testcontainers-node#712 on the 10.7.0 release

Because If I remove the TESTCONTAINERS_HUB_IMAGE_NAME_PREFIX

Containers are also preventing to start

[11:33:21.885+02:00] - 2024-04-03T09:33:20.978Z testcontainers [DEBUG] [283b40bf8ce7] Fetched container logs
[11:33:21.885+02:00] - 2024-04-03T09:33:20.978Z testcontainers [DEBUG] [283b40bf8ce7] Waiting for container to be ready...
[11:33:21.885+02:00] - 2024-04-03T09:33:20.979Z testcontainers [DEBUG] [283b40bf8ce7] Waiting for log message "/.+ Started!/"...
[11:33:21.885+02:00] - 2024-04-03T09:33:20.979Z testcontainers [DEBUG] [283b40bf8ce7] Fetching container logs...
[11:33:21.885+02:00] - 2024-04-03T09:33:20.982Z testcontainers [DEBUG] [283b40bf8ce7] Demuxing stream...
[11:33:21.885+02:00] - 2024-04-03T09:33:20.982Z testcontainers [DEBUG] [283b40bf8ce7] Demuxed stream
[11:33:21.885+02:00] - 2024-04-03T09:33:20.982Z testcontainers [DEBUG] [283b40bf8ce7] Fetched container logs
[11:33:21.886+02:00] - 2024-04-03T09:33:21.058Z testcontainers [ERROR] [283b40bf8ce7] Log stream ended and message "/.+ Started!/" was not received
[11:33:21.886+02:00] - 2024-04-03T09:33:21.059Z testcontainers [ERROR] [283b40bf8ce7] Container failed to be ready: Error: Log stream ended and message "/.+ Started!/" was not received
[11:33:21.886+02:00] - 2024-04-03T09:33:21.059Z testcontainers [DEBUG] [283b40bf8ce7] Stopping container...
[11:33:21.886+02:00] - 2024-04-03T09:33:21.202Z testcontainers [DEBUG] [283b40bf8ce7] Stopped container
[11:33:21.886+02:00] - 2024-04-03T09:33:21.202Z testcontainers [DEBUG] [283b40bf8ce7] Removing container...
[11:33:21.886+02:00] - 2024-04-03T09:33:21.205Z testcontainers [DEBUG] [283b40bf8ce7] Removed container
[11:33:21.886+02:00] - 2024-04-03T09:33:21.205Z testcontainers [DEBUG] Releasing lock file "/tmp/testcontainers-node.lock"...
[11:33:21.886+02:00] - 2024-04-03T09:33:21.206Z testcontainers [DEBUG] Released lock file "/tmp/testcontainers-node.lock"
[11:33:21.886+02:00] -  ❯ src/ts/api.test.ts  (5 tests) 12039ms
[11:33:21.886+02:00] - 
[11:33:21.886+02:00] - ⎯⎯⎯⎯⎯⎯ Failed Suites 1 ⎯⎯⎯⎯⎯⎯⎯
[11:33:21.886+02:00] - 
[11:33:21.886+02:00] -  FAIL  src/ts/api.test.ts > api
[11:33:21.886+02:00] - Error: Log stream ended and message "/.+ Started!/" was not received

@jonesbusy jonesbusy mentioned this issue Apr 3, 2024
Closed
@joyrex2001
Copy link
Owner

With the TESTCONTAINERS_HUB_IMAGE_NAME_PREFIX environment set, testcontainers-node tries to lock itself twice. Since it had locked itself already, the second lock attempt fails (and the timeout occurs). Not sure, why this scenario is happening.

@joyrex2001
Copy link
Owner

joyrex2001 commented Apr 6, 2024 •
edited
Loading

It fails because of this constant:
https://github.com/testcontainers/testcontainers-node/blob/v10.8.1/packages/testcontainers/src/reaper/reaper.ts#L9

Being compared with a rewritten image:
https://github.com/testcontainers/testcontainers-node/blob/v10.8.1/packages/testcontainers/src/generic-container/generic-container.ts#L70

This is a bug in testcontainers-node. Workarounds are:

  • TESTCONTAINERS_RYUK_DISABLED=true
  • RYUK_CONTAINER_IMAGE="${TESTCONTAINERS_HUB_IMAGE_NAME_PREFIX}/testcontainers/ryuk:0.5.1"

(edited)

@jonesbusy
Copy link
Author

Fixed by testcontainers/testcontainers-node#747

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
testcontainers-node
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@jonesbusy @joyrex2001