testground icon indicating copy to clipboard operation
testground copied to clipboard
verified publisher icon testground

docker build (sometimes?) times out

Open marten-seemann opened this issue 3 years ago • 3 comments

Version information:

Running on commit e02c78fcc11e8fa65929b3921c9e438c765523db on a M1 Macbook Pro.

Description:

Trying to run the new libp2p ping plan on my local machine, I sometimes get docker build timeouts. Sometimes I get other errors (will open a separate issue).

testground run composition -f ./_compositions/go-cross-versions.toml --collect --wait
Jul 26 12:58:25.792269	INFO	using home directory: /Users/marten/testground
Jul 26 12:58:25.792326	INFO	no .env.toml found at /Users/marten/testground/.env.toml; running with defaults
Jul 26 12:58:25.792329	INFO	testground client initialized	{"addr": "http://localhost:8042"}

>>> Result:

Jul 26 12:58:25.809826	INFO	run is queued with ID: cbfu9sev9mcd0j0l1ps0

>>> Server output:

Jul 26 12:58:25.921869	INFO	performing build for groups	{"plan": "ping", "groups": ["v0.19"], "builder": "docker:go"}
Jul 26 12:58:25.921885	INFO	performing build for groups	{"plan": "ping", "groups": ["v0.20"], "builder": "docker:go"}
Jul 26 12:58:25.921888	INFO	performing build for groups	{"plan": "ping", "groups": ["v0.11"], "builder": "docker:go"}
Jul 26 12:58:25.921850	INFO	performing build for groups	{"plan": "ping", "groups": ["master"], "builder": "docker:go"}
Jul 26 12:58:25.921849	INFO	performing build for groups	{"plan": "ping", "groups": ["v0.17"], "builder": "docker:go"}
Jul 26 12:58:25.922009	INFO	[go_proxy_mode=remote] using url: https://proxy.golang.org
Jul 26 12:58:25.922077	INFO	[go_proxy_mode=remote] using url: https://proxy.golang.org
Jul 26 12:58:25.922102	INFO	[go_proxy_mode=remote] using url: https://proxy.golang.org
Jul 26 12:58:25.922130	INFO	[go_proxy_mode=remote] using url: https://proxy.golang.org
Jul 26 12:58:25.922185	INFO	[go_proxy_mode=remote] using url: https://proxy.golang.org
Step 1/29 : ARG BUILD_BASE_IMAGE
Step 2/29 : ARG RUNTIME_IMAGE=busybox:1.31.1-glibc
Step 3/29 : FROM ${BUILD_BASE_IMAGE} AS builder
Step 1/29 : ARG BUILD_BASE_IMAGE
Step 2/29 : ARG RUNTIME_IMAGE=busybox:1.31.1-glibc
Step 3/29 : FROM ${BUILD_BASE_IMAGE} AS builder
 ---> 028d102f774a
Step 4/29 : ARG PLAN_PATH
Step 1/29 : ARG BUILD_BASE_IMAGE
Step 2/29 : ARG RUNTIME_IMAGE=busybox:1.31.1-glibc
Step 3/29 : FROM ${BUILD_BASE_IMAGE} AS builder
 ---> e2983818360c
Step 4/29 : ARG PLAN_PATH
 ---> Using cache
 ---> 025a517f6bf1
Step 5/29 : ENV PLAN_DIR /plan/${PLAN_PATH}
 ---> Using cache
 ---> 7b87b1bcce05
Step 6/29 : ENV SDK_DIR /sdk
 ---> Using cache
 ---> ee33b092edf1
Step 7/29 : RUN rm -rf ${PLAN_DIR} ${SDK_DIR} /testground_dep_list
 ---> Using cache
 ---> d4668b99589a
Step 8/29 : ARG TESTPLAN_EXEC_PKG="."
 ---> Using cache
 ---> 88d1b40f03d0
Step 9/29 : ARG GO_PROXY=direct
 ---> Using cache
 ---> 7cd507a5fc30
Step 10/29 : ARG BUILD_TAGS
 ---> Using cache
 ---> 49405356e31f
Step 11/29 : ENV TESTPLAN_EXEC_PKG ${TESTPLAN_EXEC_PKG}
 ---> Using cache
 ---> d07fe5e16207
Step 12/29 : ENV GOCACHE /go/cache
 ---> Using cache
 ---> 639cc4bc7e97
Step 13/29 : ARG MODFILE="go.mod"
 ---> Using cache
 ---> 9c169ad78649
Step 14/29 : ARG MODFILE_SUM="go.sum"
 ---> Using cache
 ---> 46515860a8f6
Step 15/29 : COPY /plan/${PLAN_PATH}/${MODFILE} ${PLAN_DIR}/go.mod
Step 1/29 : ARG BUILD_BASE_IMAGE
Step 2/29 : ARG RUNTIME_IMAGE=busybox:1.31.1-glibc
Step 3/29 : FROM ${BUILD_BASE_IMAGE} AS builder
Step 1/30 : ARG BUILD_BASE_IMAGE
Step 2/30 : ARG RUNTIME_IMAGE=busybox:1.31.1-glibc
Step 3/30 : FROM ${BUILD_BASE_IMAGE} AS builder
 ---> e2983818360c
Step 4/30 : ARG PLAN_PATH
 ---> Using cache
 ---> 025a517f6bf1
Step 5/30 : ENV PLAN_DIR /plan/${PLAN_PATH}
 ---> Using cache
 ---> 7b87b1bcce05
Step 6/30 : ENV SDK_DIR /sdk
 ---> Using cache
 ---> ee33b092edf1
Step 7/30 : RUN rm -rf ${PLAN_DIR} ${SDK_DIR} /testground_dep_list
 ---> Using cache
 ---> d4668b99589a
Step 8/30 : ARG TESTPLAN_EXEC_PKG="."
 ---> Using cache
 ---> 88d1b40f03d0
Step 9/30 : ARG GO_PROXY=direct
 ---> Using cache
 ---> 7cd507a5fc30
Step 10/30 : ARG BUILD_TAGS
 ---> Using cache
 ---> 49405356e31f
Step 11/30 : ENV TESTPLAN_EXEC_PKG ${TESTPLAN_EXEC_PKG}
 ---> Using cache
 ---> d07fe5e16207
Step 12/30 : ENV GOCACHE /go/cache
 ---> Using cache
 ---> 639cc4bc7e97
Step 13/30 : ARG MODFILE="go.mod"
 ---> Using cache
 ---> 9c169ad78649
Step 14/30 : ARG MODFILE_SUM="go.sum"
 ---> Using cache
 ---> 46515860a8f6
Step 15/30 : COPY /plan/${PLAN_PATH}/${MODFILE} ${PLAN_DIR}/go.mod
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in b55a0ba86a03
 ---> b47de0b8ea87
Step 16/29 : COPY /plan/${PLAN_PATH}/${MODFILE_SUM} ${PLAN_DIR}/go.sum
 ---> 7389501cba99
Step 5/29 : ENV PLAN_DIR /plan/${PLAN_PATH}
 ---> 7feedcf05e40
Step 16/30 : COPY /plan/${PLAN_PATH}/${MODFILE_SUM} ${PLAN_DIR}/go.sum
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in f5ad7855f698
 ---> 9605e07dbe47
Step 17/29 : RUN echo "Using go proxy: ${GO_PROXY}"     && cd ${PLAN_DIR}     && go env -w GOPROXY="${GO_PROXY}"     && go mod download
 ---> 3654d9a02bb3
Step 6/29 : ENV SDK_DIR /sdk
 ---> 7af21fa4c213
Step 17/30 : RUN echo "Using go proxy: ${GO_PROXY}"     && cd ${PLAN_DIR}     && go env -w GOPROXY="${GO_PROXY}"     && go mod download
 ---> Running in 08826adfbbf6
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 4dcd7818b0ff
 ---> Running in 68084d0e7ace
 ---> 75f64ac69f85
Step 7/29 : RUN rm -rf ${PLAN_DIR} ${SDK_DIR} /testground_dep_list
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 4adad9b7de18
Using go proxy: https://proxy.golang.org
Using go proxy: https://proxy.golang.org
 ---> 35056334da40
Step 8/29 : ARG TESTPLAN_EXEC_PKG="."
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 4373bda9145f
 ---> 86659c82e037
Step 9/29 : ARG GO_PROXY=direct
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 871e8d6567fb
1.14-buster:
1.17-buster:
 ---> bb43d50f405c
Step 10/29 : ARG BUILD_TAGS
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 05d366e9fc6f
 ---> 64ecce1dfc45
Step 11/29 : ENV TESTPLAN_EXEC_PKG ${TESTPLAN_EXEC_PKG}
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 847693a5b994
 ---> 192148ddae2e
Step 12/29 : ENV GOCACHE /go/cache
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in c51cfa4efa13
c78c297fb0d0:
06af62193c25:
8b846e1b7390:
fb44d26a138a:
d638b6994818:
c83562ffe1b7:
6dab3a1d9481:
d638b6994818:
c83562ffe1b7:
6dab3a1d9481:
fb44d26a138a:
891a1587d364:
 ---> 97408e8c6bd1
Step 13/29 : ARG MODFILE="go.mod"
6a5d1ed6a27d:
1186afd5d5e8:
a5359768b018:
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 2b1f6c712fe8
faa18f8501e4:
b9ea777faa3b:
9d5577adfe44:
b9ea777faa3b:
9d5577adfe44:
 ---> d1dc6afea23e
Step 14/29 : ARG MODFILE_SUM="go.sum"
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 99249f7568ac
 ---> b2e0d9241732
Step 15/29 : COPY /plan/${PLAN_PATH}/${MODFILE} ${PLAN_DIR}/go.mod
 ---> 3873aa1871f2
Step 16/29 : COPY /plan/${PLAN_PATH}/${MODFILE_SUM} ${PLAN_DIR}/go.sum
 ---> 270ba049a83e
Step 17/29 : RUN echo "Using go proxy: ${GO_PROXY}"     && cd ${PLAN_DIR}     && go env -w GOPROXY="${GO_PROXY}"     && go mod download
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in bf1e3b410706
Using go proxy: https://proxy.golang.org
 ---> 0158e6deded2
Step 18/30 : RUN cp ${PLAN_DIR}/go.mod ${PLAN_DIR}/go.sum /tmp/
 ---> Running in 035a8d856069
 ---> 370b0d716012
Step 19/30 : COPY . /
 ---> a907b2476524
Step 20/30 : RUN cp /tmp/go.mod /tmp/go.sum ${PLAN_DIR}/
 ---> Running in 6c3dcc830d22
 ---> 45d81034ae25
Step 21/30 : RUN cd ${PLAN_DIR} && go mod download github.com/libp2p/go-libp2p && go mod tidy -compat=1.18
 ---> Running in 9ae209c57714
go: downloading github.com/stretchr/testify v1.8.0
go: downloading gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c
go: downloading go.uber.org/goleak v1.1.12
go: downloading github.com/libp2p/go-libp2p-testing v0.11.0
go: downloading github.com/golang/mock v1.6.0
go: downloading gopkg.in/yaml.v2 v2.4.0
go: downloading github.com/gin-gonic/gin v1.6.3
go: downloading github.com/gobwas/ws v1.0.2
go: downloading github.com/google/uuid v1.3.0
go: downloading github.com/davecgh/go-spew v1.1.1
go: downloading github.com/coreos/go-semver v0.3.0
go: downloading github.com/mikioh/tcp v0.0.0-20190314235350-803a9b46060c
go: downloading github.com/kr/pretty v0.2.1
go: downloading github.com/onsi/gomega v1.13.0
go: downloading github.com/pmezard/go-difflib v1.0.0
go: downloading gopkg.in/yaml.v3 v3.0.1
go: downloading github.com/google/go-cmp v0.5.5
go: downloading github.com/decred/dcrd/crypto/blake256 v1.0.0
go: downloading github.com/ipfs/go-detect-race v0.0.1
go: downloading github.com/gin-contrib/sse v0.1.0
go: downloading github.com/gobwas/httphead v0.0.0-20180130184737-2c6c146eadee
go: downloading github.com/gobwas/pool v0.2.0
go: downloading github.com/kr/text v0.2.0
go: downloading github.com/go-playground/validator/v10 v10.3.0
go: downloading github.com/json-iterator/go v1.1.12
go: downloading github.com/ugorji/go/codec v1.1.7
go: downloading github.com/marten-seemann/qtls-go1-19 v0.1.0-beta.1
go: downloading golang.org/x/text v0.3.7
go: downloading github.com/ugorji/go v1.1.7
go: downloading github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd
go: downloading github.com/modern-go/reflect2 v1.0.2
go: downloading github.com/go-playground/universal-translator v0.17.0
go: downloading github.com/leodido/go-urn v1.2.0
go: downloading github.com/go-playground/locales v0.13.0
 ---> 2a4bb0517010
Step 18/29 : RUN cp ${PLAN_DIR}/go.mod ${PLAN_DIR}/go.sum /tmp/
 ---> Running in 917de0ecd6b3
 ---> 3e5c2c3284b4
Step 19/29 : COPY . /
 ---> 788806e92fe2
Step 20/29 : RUN cp /tmp/go.mod /tmp/go.sum ${PLAN_DIR}/
 ---> Running in 64c1c3dda286
 ---> 46aaa4f53251
Step 21/29 : RUN cd ${PLAN_DIR}     && go env -w GOPROXY="${GO_PROXY}"     && CGO_ENABLED=${CgoEnabled} GOOS=linux go build -o ${PLAN_DIR}/testplan.bin ${BUILD_TAGS} ${TESTPLAN_EXEC_PKG}
 ---> Running in 59ca9e62db89
 ---> 3e6c88ff66b1
Step 22/30 : RUN cd ${PLAN_DIR}     && go env -w GOPROXY="${GO_PROXY}"     && CGO_ENABLED=${CgoEnabled} GOOS=linux go build -o ${PLAN_DIR}/testplan.bin ${BUILD_TAGS} ${TESTPLAN_EXEC_PKG}
 ---> Running in f5d7286d4ff1
 ---> d0f75b04851f
Step 22/29 : RUN cd ${PLAN_DIR}   && go list -m all > /testground_dep_list
 ---> Running in dae00a573ba2
 ---> e6e6556e3fe3
Step 23/30 : RUN cd ${PLAN_DIR}   && go list -m all > /testground_dep_list
 ---> Running in 6ead3bb45cff
 ---> 69636b128609
 ---> 69636b128609
Step 23/29 : FROM ${RUNTIME_IMAGE} AS runtime
 ---> 7a2331af2292
Step 24/29 : ARG PLAN_PATH
 ---> Using cache
 ---> b96442bb4b0c
Step 25/29 : ENV PLAN_DIR /plan/${PLAN_PATH}
 ---> Using cache
 ---> 4813b1f51303
Step 26/29 : COPY --from=builder /testground_dep_list /
 ---> 83c7dbcd801e
Step 27/29 : COPY --from=builder ${PLAN_DIR}/testplan.bin /testplan
 ---> 8f7c3f7059dd
Step 28/29 : EXPOSE 6060
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in cb3deae36b44
 ---> d7155a05f950
Step 29/29 : ENTRYPOINT [ "/testplan"]
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 8aa02fd623f1
 ---> d15650c10ddf
 ---> d15650c10ddf
Successfully built d15650c10ddf
Successfully tagged b8460e16f66f:latest
Jul 26 13:02:25.891780	INFO	build completed	{"default_tag": "b8460e16f66f:latest", "took": "3m59s"}
Jul 26 13:02:25.944596	INFO	got docker image id	{"image_id": "d15650c10ddf"}
Jul 26 13:02:26.117148	INFO	tagging image	{"image_id": "d15650c10ddf", "tag": "tg-plan-ping:d15650c10ddf"}
Jul 26 13:02:26.124112	INFO	build succeeded	{"plan": "ping", "groups": ["v0.20"], "builder": "docker:go", "artifact": "d15650c10ddf"}
 ---> 4301b1539af3
 ---> 4301b1539af3
Step 24/30 : FROM ${RUNTIME_IMAGE} AS runtime
 ---> 7a2331af2292
Step 25/30 : ARG PLAN_PATH
 ---> Using cache
 ---> b96442bb4b0c
Step 26/30 : ENV PLAN_DIR /plan/${PLAN_PATH}
 ---> Using cache
 ---> 4813b1f51303
Step 27/30 : COPY --from=builder /testground_dep_list /
 ---> f4ff0a9c3873
Step 28/30 : COPY --from=builder ${PLAN_DIR}/testplan.bin /testplan
 ---> 626ccea09100
Step 29/30 : EXPOSE 6060
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 9b040b6d2051
 ---> 717bf5e52bec
Step 30/30 : ENTRYPOINT [ "/testplan"]
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 532088a7fd81
 ---> 42626839eabf
 ---> 42626839eabf
Successfully built 42626839eabf
Successfully tagged c771eeba2d87:latest
Jul 26 13:02:29.669228	INFO	build completed	{"default_tag": "c771eeba2d87:latest", "took": "4m3s"}
Jul 26 13:02:29.716431	INFO	got docker image id	{"image_id": "42626839eabf"}
Jul 26 13:02:29.831830	INFO	tagging image	{"image_id": "42626839eabf", "tag": "tg-plan-ping:42626839eabf"}
Jul 26 13:02:29.838255	INFO	build succeeded	{"plan": "ping", "groups": ["master"], "builder": "docker:go", "artifact": "42626839eabf"}
 ---> d4ec34c22831
Step 18/29 : RUN cp ${PLAN_DIR}/go.mod ${PLAN_DIR}/go.sum /tmp/
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 0bb25a8fea4e
 ---> 49a9f2158a72
Step 19/29 : COPY . /
 ---> 8eb9d6d3db5f
Step 20/29 : RUN cp /tmp/go.mod /tmp/go.sum ${PLAN_DIR}/
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in ce37ac7521cf
 ---> 96d73631f600
Step 21/29 : RUN cd ${PLAN_DIR}     && go env -w GOPROXY="${GO_PROXY}"     && CGO_ENABLED=${CgoEnabled} GOOS=linux go build -o ${PLAN_DIR}/testplan.bin ${BUILD_TAGS} ${TESTPLAN_EXEC_PKG}
 ---> [Warning] The requested image's platform (linux/amd64) does not match the detected host platform (linux/arm64/v8) and no specific platform was requested
 ---> Running in 3a78a7745488
Jul 26 13:08:25.919631	INFO	build failed	{"plan": "ping", "groups": ["v0.19"], "builder": "docker:go", "error": "docker build failed: context deadline exceeded"}
Jul 26 13:08:25.926013	INFO	build failed	{"plan": "ping", "groups": ["v0.11"], "builder": "docker:go", "error": "docker build failed: context deadline exceeded"}
Jul 26 13:08:25.926008	INFO	build failed	{"plan": "ping", "groups": ["v0.17"], "builder": "docker:go", "error": "docker build failed: context deadline exceeded"}

>>> Result:

docker build failed: context deadline exceeded

marten-seemann avatar Jul 26 '22 13:07 marten-seemann

That might be a timeout due to downloading the dependencies, could you try with a longer timeout and let me know if that solves the issue?

In ~/testground/.env.toml add:

[daemon.scheduler]
task_timeout_min  = 40

If it does, then we need to improve (https://github.com/testground/testground/issues/1403). else it might be a step in the build process that hangs, we'll need to investigate further.

If the timeout fixes the issue, you can also use a local proxy, in the composition file, there is a field go_proxy_mode replace remote with local (related issue https://github.com/testground/testground/issues/1404)

laurentsenta avatar Jul 27 '22 08:07 laurentsenta

I can confirm this on an M1 Macbook Pro. Docker build timed out 3-4 times before I was able to build all. It timed out in various locations in the build process.

Docker's image layer cache and rerunning make install 3-4 times solved the build problem, but of course this is not the right solution. native arm64 docker images would be the right solution I suppose.

cskiraly avatar Jul 29 '22 16:07 cskiraly

Going through logs, it was just 2 fails in the build process. The others were

  • a port collision on port 3000 (I had a grafana instance already running, and port 3000 is hardcoded in Testground)
  • a fail in the ping-pong test, since on Mac M1 in Intel emulation the RTT limit seems to be too tight.

1st fail

632458e542a1: Step 17/29 : RUN echo "Using go proxy: ${GO_PROXY}"     && cd ${PLAN_DIR}     && go env -w GOPROXY="${GO_PROXY}"     && go mod download632458e542a1: 
632458e542a1:  ---> Running in 4bab9e401c3b
632458e542a1: Using go proxy: http://testground-goproxy:8081
Jul 28 14:39:28.662354	INFO	build failed	{"plan": "network", "groups": ["single"], "builder": "docker:go", "error": "docker build failed: context deadline exceeded"}
Jul 28 14:39:28.663397	ERROR	doRun returned err	{"err": "docker build failed: context deadline exceeded"}
Jul 28 14:39:28.671656	INFO	worker completed task	{"worker_id": 1, "task_id": "cbh9qi6labs3g5uvr1ng"}

2nd fail

Step 23/29 : FROM ${RUNTIME_IMAGE} AS runtime
1.31.1-glibc: 
b641f6d0f804: 
Jul 28 14:54:33.249506	INFO	build completed	{"default_tag": "7158b204b4e8:latest", "took": "3m14s"}
Jul 28 14:54:33.262359	INFO	got docker image id	{"image_id": "6b798acb0406"}
Jul 28 14:54:33.329612	INFO	tagging image	{"image_id": "6b798acb0406", "tag": "tg-plan-network:6b798acb0406"}
Jul 28 14:54:33.334912	INFO	build succeeded	{"plan": "network", "groups": ["single"], "builder": "docker:go", "artifact": "6b798acb0406"}
Jul 28 14:54:33.335095	INFO	performing healthcheck on runner
Jul 28 14:54:33.405765	INFO	container not found; creating	{"container_name": "testground-grafana"}
latest: Pulling from bitnami/grafana
3b5e91f25ce6: Pulling fs layer
325844641550: Pulling fs layer
66fdfb8b8c60: Pulling fs layer
b48052e680ee: Pulling fs layer
1e6f55779d1d: Pulling fs layer
72c2be85445b: Pulling fs layer
cf8546cf2ff1: Pulling fs layer
cfb07ed0bd7f: Pulling fs layer
3fa30718556f: Pulling fs layer
1e6f55779d1d: Waiting
72c2be85445b: Waiting
cf8546cf2ff1: Waiting
cfb07ed0bd7f: Waiting
3fa30718556f: Waiting
b48052e680ee: Waiting
Jul 28 14:55:21.948964	INFO	created container	{"container_name": "testground-grafana", "id": "c847df83daacd3b9f8885beb3ea9481a9a272529030da7495a21f422a3d075f4"}
Jul 28 14:55:21.949475	INFO	starting container	{"container_name": "testground-grafana", "id": "c847df83daacd3b9f8885beb3ea9481a9a272529030da7495a21f422a3d075f4"}
Jul 28 14:55:21.985181	INFO	container not found; creating	{"container_name": "testground-redis"}
latest: Pulling from library/redis
60197a4c18d4: Pulling fs layer
649d52ef4fd9: Pulling fs layer
15708d2d5b0f: Pulling fs layer
c33972024e1d: Pulling fs layer
ffe60d1fc652: Pulling fs layer
3d00ba1406a8: Pulling fs layer
c33972024e1d: Waiting
ffe60d1fc652: Waiting
3d00ba1406a8: Waiting
Jul 28 14:55:39.047283	INFO	created container	{"container_name": "testground-redis", "id": "973d7465c8350e4e946b48b302dbc5b9be2668fd003547c2a4ebae21347450c3"}
Jul 28 14:55:39.047646	INFO	starting container	{"container_name": "testground-redis", "id": "973d7465c8350e4e946b48b302dbc5b9be2668fd003547c2a4ebae21347450c3"}
Jul 28 14:55:39.456612	INFO	started container	{"container_name": "testground-redis", "id": "973d7465c8350e4e946b48b302dbc5b9be2668fd003547c2a4ebae21347450c3"}
Jul 28 14:55:39.479492	INFO	container not found; creating	{"container_name": "testground-sync-service"}
Jul 28 14:55:39.493114	INFO	found existing image: iptestground/sync-service:latest	{"container_name": "testground-sync-service"}
Jul 28 14:55:39.522262	INFO	created container	{"container_name": "testground-sync-service", "id": "0add1072f0e4b182e1aa2247064c103331786d9ed0e2dae517116e03dd5ad2b0"}
Jul 28 14:55:39.522417	INFO	starting container	{"container_name": "testground-sync-service", "id": "0add1072f0e4b182e1aa2247064c103331786d9ed0e2dae517116e03dd5ad2b0"}
Jul 28 14:55:39.903829	INFO	started container	{"container_name": "testground-sync-service", "id": "0add1072f0e4b182e1aa2247064c103331786d9ed0e2dae517116e03dd5ad2b0"}
Jul 28 14:55:39.920594	INFO	container not found; creating	{"container_name": "testground-influxdb"}
1.8: Pulling from library/influxdb
cfc947b533a3: Pulling fs layer
9ca36aa4204d: Pulling fs layer
1fdcd2014de7: Pulling fs layer
9290256476f3: Pulling fs layer
5549d5314831: Pulling fs layer
06c423e8c126: Pulling fs layer
30cffb10af9b: Pulling fs layer
d4b3ec964cfe: Pulling fs layer
9290256476f3: Waiting
5549d5314831: Waiting
06c423e8c126: Waiting
30cffb10af9b: Waiting
d4b3ec964cfe: Waiting
Jul 28 14:56:19.979027	INFO	created container	{"container_name": "testground-influxdb", "id": "ddb25e1ec99ff97157899b30ea14cb1f41945eac5868aa27bb8b1210c6595940"}
Jul 28 14:56:19.979524	INFO	starting container	{"container_name": "testground-influxdb", "id": "ddb25e1ec99ff97157899b30ea14cb1f41945eac5868aa27bb8b1210c6595940"}
Jul 28 14:56:20.337519	INFO	started container	{"container_name": "testground-influxdb", "id": "ddb25e1ec99ff97157899b30ea14cb1f41945eac5868aa27bb8b1210c6595940"}
Jul 28 14:56:20.367941	INFO	container not found; creating	{"container_name": "testground-sidecar"}
Jul 28 14:56:20.378611	INFO	found existing image: iptestground/sidecar:edge	{"container_name": "testground-sidecar"}
Jul 28 14:56:20.409741	INFO	created container	{"container_name": "testground-sidecar", "id": "dae1ef2a01c7b106769100967de1a6491996a9f4125a54e8f284f1fa72a9d774"}
Jul 28 14:56:20.409796	INFO	starting container	{"container_name": "testground-sidecar", "id": "dae1ef2a01c7b106769100967de1a6491996a9f4125a54e8f284f1fa72a9d774"}
Jul 28 14:56:20.684337	INFO	started container	{"container_name": "testground-sidecar", "id": "dae1ef2a01c7b106769100967de1a6491996a9f4125a54e8f284f1fa72a9d774"}
Jul 28 14:56:20.694244	ERROR	doRun returned err	{"err": "healthcheck fixes failed; aborting:\nChecks:\n- local-outputs-dir: failed; directory does not exist. can recreate.\n- control-network: failed; network does not exist.\n- local-grafana: failed; container not found.\n- local-redis: failed; container not found.\n- local-sync-service: failed; container not found.\n- local-influxdb: failed; container not found.\n- sidecar-container: failed; container not found.\nFixes:\n- local-outputs-dir: ok; directory created successfully.\n- control-network: ok; network created.\n- local-grafana: failed; failed to start container.\n- local-redis: ok; container started\n- local-sync-service: ok; container started\n- local-influxdb: ok; container started\n- sidecar-container: ok; container started\n"}
Jul 28 14:56:20.704600	INFO	worker completed task	{"worker_id": 1, "task_id": "cbha4pmlabs3lp36snn0"}

Grafana port 3000 collision

Jul 28 15:04:01.003595	INFO	container isn't running; starting	{"container_name": "testground-grafana"}
Jul 28 15:04:01.026950	ERROR	starting container failed	{"container_name": "testground-grafana", "container_name": "testground-grafana", "error": "Error response from daemon: Ports are not available: exposing port TCP 0.0.0.0:3000 -> 0.0.0.0:0: listen tcp 0.0.0.0:3000: bind: address already in use"}

limit too tight in ping-pong (might need it's own issue). Easy to bump the limit, but again, solution would be to have native arm64 builds I think.

Jul 29 16:12:05.804905	INFO	2.1519s    MESSAGE << single[000] (b7d7e1) >> done
Jul 29 16:12:05.807927	INFO	2.1542s       FAIL << single[000] (b7d7e1) >> expected an RTT between 200ms and 215ms, got 230.681541ms

cskiraly avatar Jul 29 '22 16:07 cskiraly