search

joyrex2001 / kubedock

Kubedock is a minimal implementation of the docker api that will orchestrate containers on a Kubernetes cluster, rather than running containers locally.
MIT License
212 stars 32 forks source link

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

Closed jonesbusy closed 5 months ago

jonesbusy commented 5 months ago

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.

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 commented 5 months ago

Possible related to https://github.com/testcontainers/testcontainers-node/pull/729

jonesbusy commented 5 months ago

I think there are other issue related to https://github.com/testcontainers/testcontainers-node/pull/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
joyrex2001 commented 5 months ago

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 commented 5 months ago

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:

(edited)

jonesbusy commented 5 months ago

Fixed by https://github.com/testcontainers/testcontainers-node/issues/747