Bug: can't connect to container: canceled after error: %!w(<nil>)

Question

Bug: can't connect to container: canceled after error: %!w(<nil>)

Closed this issue 3 years ago · 12 comments

Describe the bug
Gnomock fails to connect to containers. I've forked this repo and ran the tests in it and I receive the same error as my own tests.
I suspect it has something to do with docker but i'm not sure what, these tests were working before i updated to the newest docker (prior to that I was a few major versions behind).
To Reproduce
For me, and another colleague just running any tests that call gnomock.Start() causes the error.

Screenshots
Here are some scerens of attempting to run the postgres preset tests, they take forever but eventually they do fail with the following error:
=== RUN TestPreset/10.15
preset_test.go:37:
Error Trace: preset_test.go:37
Error: Received unexpected error:
can't connect to container: canceled after error: %!w()
Test: TestPreset/10.15
--- FAIL: TestPreset/10.15 (312.93s)

System (please complete the following information):

OS: [e.g. MacOS]
Windows 10 Professional
Version [e.g. 0.9.2]

	github.com/orlangure/gnomock v0.12.0

Docker version

Client: Docker Engine - Community
Cloud integration: 1.0.9
Version:           20.10.5
API version:       1.41
Go version:        go1.13.15
Git commit:        55c4c88
Built:             Tue Mar  2 20:14:53 2021
OS/Arch:           windows/amd64
Context:           default
Experimental:      true

Server: Docker Engine - Community
Engine:
 Version:          20.10.5
 API version:      1.41 (minimum version 1.12)
 Go version:       go1.13.15
 Git commit:       363e9a8
 Built:            Tue Mar  2 20:15:47 2021
 OS/Arch:          linux/amd64
 Experimental:     false
containerd:
 Version:          1.4.3
 GitCommit:        269548fa27e0089a8b8278fc4fc781d7f65a939b
runc:
 Version:          1.0.0-rc92
 GitCommit:        ff819c7e9184c13b7c2607fe6c30ae19403a7aff
docker-init:
 Version:          0.19.0
 GitCommit:        de40ad0

Answer 1 · 2021-03-25T21:01:09.000Z

Hi and thanks for the report.

Can you try running the tests using gnomock.WithDebugMode() and gnomock.WithLogWriter(os.Stdout)?
It should allow to see what exactly goes wrong.

Also, there is a bug I'm working on that I thought was related only to gnomock running inside its own container, so just to eliminate this possibility, can you also try running the tests using #99?

Answer 2 · 2021-03-25T22:15:56.000Z

I found the issue.

Apparently ports on host machine are not immediately allocated to the new containers. Most of the time when gnomock inspects fresh containers they already are assigned random ports on the host. It appears that sometimes docker needs a bit of extra time to setup the network, so I'm working on adding an internal retry mechanism that will wait until all the ports are ready.

Please try the code from #101 and let me know if it helped. I will release the fix as soon as it is no longer night time here, after I take another look at this😼

Answer 3 · 2021-03-26T14:02:38.000Z

I just tested the fixes your fixes and it worked, Thanks so much for the quick response. 💯

I also may have a preset to contribute that i'm using for a project i'll open a new issue for that.

Answer 4 · 2021-03-26T17:15:44.000Z

Thanks for confirming.
I released the fix under v0.12.1 (https://github.com/orlangure/gnomock/releases/tag/v0.12.1)

Answer 5 · 2021-09-26T08:16:55.000Z

Hi @orlangure, I still meet the issue. I'm using Jenkins to run the test and mount docker.sock from localhost.

Here is the error msg:

    suite.go:63: test panicked: can't connect to container: canceled after error: %!w(<nil>)
        goroutine 6 [running]:
        runtime/debug.Stack()
        	/usr/local/go/src/runtime/debug/stack.go:24 +0x65
        github.com/stretchr/testify/suite.failOnPanic(0xc0001eaea0)
        	/root/go/pkg/mod/github.com/stretchr/testify@v1.7.0/suite/suite.go:63 +0x3e
        panic({0xbd2ae0, 0xc000426e00})
        	/usr/local/go/src/runtime/panic.go:1038 +0x215
        gitlab.com/balance-eod.createContainers()
        	/balance-eod/main_test.go:33 +0x1a5
        gitlab.com/balance-eod.(*TestSuite).SetupSuite(0xc00045a460)
        	/balance-eod/main_test.go:58 +0x77
        github.com/stretchr/testify/suite.Run(0xc0001eaea0, {0xe317c8, 0xc00045a460})
        	/root/go/pkg/mod/github.com/stretchr/testify@v1.7.0/suite/suite.go:118 +0x39b
        gitlab.com/balance-eod.TestEOD(0x0)
        	/balance-eod/main_test.go:223 +0x39
        testing.tRunner(0xc0001eaea0, 0xcca908)
        	/usr/local/go/src/testing/testing.go:1259 +0x102
        created by testing.(*T).Run
        	/usr/local/go/src/testing/testing.go:1306 +0x35a

Answer 6 · 2021-09-26T19:38:53.000Z

Hey @lesywix, thanks for your report.

Can you try adding debugging options to your tests just to see what exactly fails?

Use gnomock.WithDebugMode() option to print state updates and gnomock.WithLogWriter(os.Stdout) to print internal container logs.

Answer 7 · 2021-09-27T06:10:07.000Z

Thanks for replying, here is my test script, it seems that the output is the same as before. Please enlighten me.

root@jenkins-7d9f5df876-pt9nh:/balance-eod# go run test.go
###1
###2
###3 can't connect to container: canceled after error: %!w(<nil>)
root@jenkins-7d9f5df876-pt9nh:/balance-eod# cat test.go
package main

import (
    "fmt"
    "github.com/orlangure/gnomock"
    mysqlmock "github.com/orlangure/gnomock/preset/mysql"
    "os"
)

func main() {
    fmt.Println("###1")
    gnomock.WithDebugMode()
    gnomock.WithLogWriter(os.Stdout)
    mysqlPreset := mysqlmock.Preset()
    fmt.Println("###2")
    _, err := gnomock.Start(mysqlPreset)
    fmt.Println("###3", err)
}

Answer 8 · 2021-09-27T07:01:14.000Z

This code is a bit off, both options need to be passed as arguments to gnomock.Start:

func main() {
    fmt.Println("###1")    
    mysqlPreset := mysqlmock.Preset()
    fmt.Println("###2")
    _, err := gnomock.Start(mysqlPreset, gnomock.WithDebugMode(), gnomock.WithLogWriter(os.Stdout))
    fmt.Println("###3", err)
}

Answer 9 · 2021-09-27T09:48:18.000Z

Oh, sorry. I got the log.

{"L":"INFO","T":"2021-09-27T07:24:34.876Z","M":"starting","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1","image":"docker.io/library/mysql:8.0.22","ports":{"default":{"protocol":"tcp","port":3306,"host_port":0}}}
{"L":"INFO","T":"2021-09-27T07:24:34.876Z","M":"using config","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1","image":"docker.io/library/mysql:8.0.22","ports":{"default":{"protocol":"tcp","port":3306,"host_port":0}},"config":{"timeout":300000000000,"env":["MYSQL_USER=gnomock","MYSQL_PASSWORD=gnomick","MYSQL_DATABASE=mydb","MYSQL_RANDOM_ROOT_PASSWORD=yes"],"debug":true,"privileged":false,"container_name":"","cmd":null,"host_mounts":null,"disable_cleanup":false,"auth":""}}
{"L":"INFO","T":"2021-09-27T07:24:34.876Z","M":"connecting to docker engine","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:24:34.876Z","M":"connected to docker engine","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:24:34.876Z","M":"starting container","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:24:34.876Z","M":"pulling image","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:24:45.086Z","M":"image pulled","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:24:45.621Z","M":"waiting for container network","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1","container":"4496b4b198ba2653e512bc3a65922a763945cec1a9b30e0233c7279166068eb3"}
{"L":"INFO","T":"2021-09-27T07:24:45.872Z","M":"waiting for port allocation","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1","container":"4496b4b198ba2653e512bc3a65922a763945cec1a9b30e0233c7279166068eb3"}
{"L":"INFO","T":"2021-09-27T07:24:45.872Z","M":"container started","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1","container":{"id":"4496b4b198ba2653e512bc3a65922a763945cec1a9b30e0233c7279166068eb3","host":"127.0.0.1","ports":{"default":{"protocol":"tcp","port":49169,"host_port":0}}}}
{"L":"INFO","T":"2021-09-27T07:24:45.872Z","M":"starting container logs forwarder","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:24:45.873Z","M":"container logs forwarder ready","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:24:45.873Z","M":"waiting for healthcheck to pass","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27 07:24:45+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.22-1debian10 started.
2021-09-27 07:24:45+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
2021-09-27 07:24:45+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.22-1debian10 started.
2021-09-27 07:24:45+00:00 [Note] [Entrypoint]: Initializing database files
2021-09-27T07:24:45.729475Z 0 [System] [MY-013169] [Server] /usr/sbin/mysqld (mysqld 8.0.22) initializing of server in progress as process 44
2021-09-27T07:24:45.734399Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
{"L":"INFO","T":"2021-09-27T07:24:46.123Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:24:46.373Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:02.623Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27 07:25:02+00:00 [Note] [Entrypoint]: Database files initialized
2021-09-27 07:25:02+00:00 [Note] [Entrypoint]: Starting temporary server
{"L":"INFO","T":"2021-09-27T07:25:02.873Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27T07:25:03.092016Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.22) starting as process 90
2021-09-27T07:25:03.113098Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
{"L":"INFO","T":"2021-09-27T07:25:03.123Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27T07:25:03.349753Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
{"L":"INFO","T":"2021-09-27T07:25:03.373Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27T07:25:03.457543Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: /var/run/mysqld/mysqlx.sock
{"L":"INFO","T":"2021-09-27T07:25:03.623Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27T07:25:03.675544Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2021-09-27T07:25:03.675742Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2021-09-27T07:25:03.683821Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2021-09-27T07:25:03.699047Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.22'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  MySQL Community Server - GPL.
2021-09-27 07:25:03+00:00 [Note] [Entrypoint]: Temporary server started.
{"L":"INFO","T":"2021-09-27T07:25:03.874Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:04.123Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:04.373Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
Warning: Unable to load '/usr/share/zoneinfo/iso3166.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/leap-seconds.list' as time zone. Skipping it.
{"L":"INFO","T":"2021-09-27T07:25:04.623Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:04.874Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:05.123Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:05.374Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:05.623Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
Warning: Unable to load '/usr/share/zoneinfo/zone.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/zone1970.tab' as time zone. Skipping it.
2021-09-27 07:25:05+00:00 [Note] [Entrypoint]: GENERATED ROOT PASSWORD: oJidai0tha7aiboo3PhaiJaezu6aich5
2021-09-27 07:25:05+00:00 [Note] [Entrypoint]: Creating database mydb
2021-09-27 07:25:05+00:00 [Note] [Entrypoint]: Creating user gnomock
{"L":"INFO","T":"2021-09-27T07:25:05.874Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27 07:25:05+00:00 [Note] [Entrypoint]: Giving user gnomock access to schema mydb

2021-09-27 07:25:05+00:00 [Note] [Entrypoint]: Stopping temporary server
2021-09-27T07:25:05.937084Z 13 [System] [MY-013172] [Server] Received SHUTDOWN from user root. Shutting down mysqld (Version: 8.0.22).
{"L":"INFO","T":"2021-09-27T07:25:06.123Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:06.373Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:06.623Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:06.874Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:07.123Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:07.373Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:07.623Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:07.873Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:08.123Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:08.373Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:08.623Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:08.874Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:09.123Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:09.374Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:09.623Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27T07:25:09.670962Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.22)  MySQL Community Server - GPL.
{"L":"INFO","T":"2021-09-27T07:25:09.873Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27 07:25:09+00:00 [Note] [Entrypoint]: Temporary server stopped

2021-09-27 07:25:09+00:00 [Note] [Entrypoint]: MySQL init process done. Ready for start up.

{"L":"INFO","T":"2021-09-27T07:25:10.124Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27T07:25:10.169634Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.22) starting as process 1
2021-09-27T07:25:10.180255Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
{"L":"INFO","T":"2021-09-27T07:25:10.373Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27T07:25:10.432895Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2021-09-27T07:25:10.539436Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
{"L":"INFO","T":"2021-09-27T07:25:10.624Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
2021-09-27T07:25:10.689981Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2021-09-27T07:25:10.690169Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2021-09-27T07:25:10.699055Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2021-09-27T07:25:10.714957Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.22'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server - GPL.
{"L":"INFO","T":"2021-09-27T07:25:10.873Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:11.124Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:11.373Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}
{"L":"INFO","T":"2021-09-27T07:25:11.624Z","M":"healthcheck failed: dial tcp 127.0.0.1:49169: connect: connection refused","id":"9bf8c47a-3961-491e-8ef0-28eacb226ae1"}

Answer 10 · 2021-09-27T09:50:32.000Z

I noticed that there have an env args: GNOMOCK_ENV=gnomockd.
After I added this env args, it seems still fail.

 GNOMOCK_ENV=gnomockd go run test.go
###1
###2
{"L":"INFO","T":"2021-09-27T07:33:48.995Z","M":"starting","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349","image":"docker.io/library/mysql:8.0.22","ports":{"default":{"protocol":"tcp","port":3306,"host_port":0}}}
{"L":"INFO","T":"2021-09-27T07:33:48.995Z","M":"using config","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349","image":"docker.io/library/mysql:8.0.22","ports":{"default":{"protocol":"tcp","port":3306,"host_port":0}},"config":{"timeout":300000000000,"env":["MYSQL_USER=gnomock","MYSQL_PASSWORD=gnomick","MYSQL_DATABASE=mydb","MYSQL_RANDOM_ROOT_PASSWORD=yes"],"debug":true,"privileged":false,"container_name":"","cmd":null,"host_mounts":null,"disable_cleanup":false,"auth":""}}
{"L":"INFO","T":"2021-09-27T07:33:48.995Z","M":"connecting to docker engine","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
{"L":"INFO","T":"2021-09-27T07:33:48.995Z","M":"connected to docker engine","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
{"L":"INFO","T":"2021-09-27T07:33:48.995Z","M":"starting container","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
{"L":"INFO","T":"2021-09-27T07:33:48.995Z","M":"pulling image","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
{"L":"INFO","T":"2021-09-27T07:33:58.959Z","M":"image pulled","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
{"L":"INFO","T":"2021-09-27T07:33:59.508Z","M":"waiting for container network","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349","container":"8b8b383e686ecc10081771a14b025dbd0fc7214e1df784794541649d1ac4ebee"}
{"L":"INFO","T":"2021-09-27T07:33:59.760Z","M":"waiting for port allocation","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349","container":"8b8b383e686ecc10081771a14b025dbd0fc7214e1df784794541649d1ac4ebee"}
{"L":"INFO","T":"2021-09-27T07:33:59.760Z","M":"container started","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349","container":{"id":"8b8b383e686ecc10081771a14b025dbd0fc7214e1df784794541649d1ac4ebee","host":"127.0.0.1","ports":{"default":{"protocol":"tcp","port":49180,"host_port":0}}}}
{"L":"INFO","T":"2021-09-27T07:33:59.760Z","M":"starting container logs forwarder","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
{"L":"INFO","T":"2021-09-27T07:33:59.760Z","M":"container logs forwarder ready","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
{"L":"INFO","T":"2021-09-27T07:33:59.760Z","M":"waiting for healthcheck to pass","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
2021-09-27 07:33:59+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.22-1debian10 started.
2021-09-27 07:33:59+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
2021-09-27 07:33:59+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server 8.0.22-1debian10 started.
2021-09-27 07:33:59+00:00 [Note] [Entrypoint]: Initializing database files
2021-09-27T07:33:59.618725Z 0 [System] [MY-013169] [Server] /usr/sbin/mysqld (mysqld 8.0.22) initializing of server in progress as process 44
2021-09-27T07:33:59.623796Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2021-09-27T07:34:01.641876Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2021-09-27T07:34:07.146672Z 6 [Warning] [MY-010453] [Server] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
2021-09-27 07:34:17+00:00 [Note] [Entrypoint]: Database files initialized
2021-09-27 07:34:17+00:00 [Note] [Entrypoint]: Starting temporary server
2021-09-27T07:34:17.800389Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.22) starting as process 90
2021-09-27T07:34:17.821710Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2021-09-27T07:34:18.065853Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2021-09-27T07:34:18.172921Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: /var/run/mysqld/mysqlx.sock
2021-09-27T07:34:18.389340Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2021-09-27T07:34:18.389501Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2021-09-27T07:34:18.397616Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2021-09-27T07:34:18.413194Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.22'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  MySQL Community Server - GPL.
2021-09-27 07:34:18+00:00 [Note] [Entrypoint]: Temporary server started.
Warning: Unable to load '/usr/share/zoneinfo/iso3166.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/leap-seconds.list' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/zone.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/zone1970.tab' as time zone. Skipping it.
2021-09-27 07:34:20+00:00 [Note] [Entrypoint]: GENERATED ROOT PASSWORD: ael3rief4vie6uph2eeNg8pev1ooPha6
2021-09-27 07:34:20+00:00 [Note] [Entrypoint]: Creating database mydb
2021-09-27 07:34:20+00:00 [Note] [Entrypoint]: Creating user gnomock
2021-09-27 07:34:20+00:00 [Note] [Entrypoint]: Giving user gnomock access to schema mydb

2021-09-27 07:34:20+00:00 [Note] [Entrypoint]: Stopping temporary server
2021-09-27T07:34:20.683705Z 13 [System] [MY-013172] [Server] Received SHUTDOWN from user root. Shutting down mysqld (Version: 8.0.22).
2021-09-27T07:34:24.421551Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.22)  MySQL Community Server - GPL.
2021-09-27 07:34:24+00:00 [Note] [Entrypoint]: Temporary server stopped

2021-09-27 07:34:24+00:00 [Note] [Entrypoint]: MySQL init process done. Ready for start up.

2021-09-27T07:34:24.909007Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.22) starting as process 1
2021-09-27T07:34:24.919865Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2021-09-27T07:34:25.153884Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2021-09-27T07:34:25.265870Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
2021-09-27T07:34:25.415918Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2021-09-27T07:34:25.416083Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2021-09-27T07:34:25.424764Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2021-09-27T07:34:25.440971Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.22'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server - GPL.
{"L":"INFO","T":"2021-09-27T07:36:09.739Z","M":"healthcheck failed: dial tcp 198.18.18.98:49180: connect: connection timed out","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
{"L":"INFO","T":"2021-09-27T07:38:20.811Z","M":"healthcheck failed: dial tcp 198.18.18.98:49180: connect: connection timed out","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
{"L":"INFO","T":"2021-09-27T07:40:31.883Z","M":"healthcheck failed: dial tcp 198.18.18.98:49180: connect: connection timed out","id":"9fbbc85c-e4d9-45e1-9056-a83ba1644349"}
###3 can't connect to container: canceled after error: dial tcp 198.18.18.98:49180: connect: connection timed out

Answer 11 · 2021-09-27T13:32:43.000Z

You shouldn't use GNOMOCK_ENV=gnomockd, it is an internal variable to indicate that gnomock itself runs inside a container.

To further debug the problem, can you try to connect to the running container using mysql client (or even telnet) using the address from the logs (e.g 127.0.0.1:49169 from the first example) from inside your jenkins instance?

Can you tell what is the address of docker host that is used inside a jenkins job?

Answer 12 · 2021-10-12T09:42:42.000Z

I try using DOCKER_HOST=tcp://172.17.0.1:2375 go test, it's ok now. Thx