8000 Bump go 1.13.0 by thaJeztah · Pull Request #39549 · moby/moby · GitHub
[go: up one dir, main page]

Skip to content

Conversation

thaJeztah
Copy link
Member
@thaJeztah thaJeztah commented Jul 17, 2019

Based on top of / depends on (when backporting, these are also needed):

I'll rebase once those are merged

testing if things work or break

Dockerfile Outdated
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

opened checkpoint-restore/criu#743 for this as well

@thaJeztah
Copy link
Member Author

Windows build is failing, but no details what exactly is failing 😞

14:19:46 ERROR: make.ps1 failed:
14:19:46 Failed to compile daemon
14:19:46 At C:\go\src\github.com\docker\docker\hack\make.ps1:193 char:32
14:19:46 +     if ($LASTEXITCODE -ne 0) { Throw "Failed to compile $type" }
14:19:46 +                                ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

@thaJeztah
Copy link
Member Author
thaJeztah commented Jul 17, 2019

And new gofmt rules again 😞

14:26:04 pkg/parsers/kernel/kernel_windows.go:1::warning: file is not gofmted with -s (gofmt)
14:26:07 Build step 'Execute shell' marked build as failure

LOL, I don't see a difference;

diff --git a/pkg/parsers/kernel/kernel_windows.go b/pkg/parsers/kernel/kernel_windows.go
index b7b15a1fd2..a0712ce633 100644
--- a/pkg/parsers/kernel/kernel_windows.go
+++ b/pkg/parsers/kernel/kernel_windows.go
@@ -44,7 +44,7 @@ func GetKernelVersion() (*VersionInfo, error) {
        }
 
        KVI.major = int(dwVersion & 0xFF)
-       KVI.minor = int((dwVersion & 0XFF00) >> 8)
+       KVI.minor = int((dwVersion & 0xFF00) >> 8)
        KVI.build = int((dwVersion & 0xFFFF0000) >> 16)
 
        return KVI, nil

Oh! lowercase 0X -> 0x

@thaJeztah
Copy link
Member Author

Failures on Experimental, Janky, PowerPC, and s390x:

https://jenkins.dockerproject.org/job/Docker-PRs/54911/console

15:13:06 --- FAIL: TestRenameAnonymousContainer (3.37s)
15:13:06     rename_test.go:168: assertion failed: 0 (int) != 1 (inspect.State.ExitCode int): container a7fe866d588d65f353f42ffc5ea5288e52700384e1d90850e9c3d4dce8657666 exited with the wrong exitcode: 

15:13:38 --- FAIL: TestHostnameDnsResolution (2.23s)
15:13:38     run_linux_test.go:128: assertion failed: 
15:13:38         --- ←
15:13:38         +++ →
15:13:38         @@ -1 +1,2 @@
15:13:38         +ping: bad address 'foobar'
15:13:38          
15:13:38         
15:13:38     run_linux_test.go:129: assertion failed: 0 (int) != 1 (res.ExitCode int)

Failures on Windows RS1 (fails to b 10BC0 uild) https://jenkins.dockerproject.org/job/Docker-PRs-WoW-RS1/25943/console

4:48:59 INFO: Building the test binaries at 07/17/2019 14:48:59...
14:49:12 INFO: make.ps1 starting at 07/17/2019 14:49:12
14:49:12 INFO: Git commit (916b9ec487) assumed from DOCKER_GITCOMMIT environment variable
14:49:12 INFO: Invoking autogen...
14:49:13 INFO: Building daemon...
14:49:15 build github.com/docker/docker/cmd/dockerd: cannot load cloud.google.com/go/compute/metadata: open C:\go\src\cloud.google.com\go\compute\metadata: The system cannot find the path specified.
14:49:15 
14:49:15 ERROR: make.ps1 failed:
14:49:15 Failed to compile daemon
14:49:15 At C:\go\src\github.com\docker\docker\hack\make.ps1:193 char:32
14:49:15 +     if ($LASTEXITCODE -ne 0) { Throw "Failed to compile $type" }



14:49:15 INFO: make.ps1 ended at 07/17/2019 14:49:15
14:49:15 Failed to compile daemon
14:49:15 At C:\go\src\github.com\docker\docker\hack\make.ps1:193 char:32
14:49:15 +     if ($LASTEXITCODE -ne 0) { Throw "Failed to compile $type" }
14:49:15 +                                ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
14:49:15     + CategoryInfo          : OperationStopped: (Failed to compile daemon:Stri 
14:49:15    ng) [], RuntimeException
14:49:15     + FullyQualifiedErrorId : Failed to compile daemon
14:49:15  
14:49:17 
14:49:17 
14:49:17 ERROR: Failed 'ERROR: Failed to build binary' at 07/17/2019 14:49:17
14:49:17 At C:\gopath\src\github.com\docker\docker\hack\ci\windows.ps1:492 char:13
14:49:17 +             Throw "ERROR: Failed to build binary"
14:49:17 +             ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Failures on Windows RS5 (fails to build) https://jenkins.dockerproject.org/job/Docker-PRs-WoW-RS5-Process/3036/console

14:48:57 INFO: make.ps1 starting at 07/17/2019 14:48:57
14:48:57 INFO: Git commit (916b9ec487) assumed from DOCKER_GITCOMMIT environment variable
14:48:57 INFO: Invoking autogen...
14:48:58 INFO: Building daemon...
14:49:00 
14:49:00 ERROR: make.ps1 failed:
14:49:00 Failed to compile daemon
14:49:00 At C:\go\src\github.com\docker\docker\hack\make.ps1:193 char:32
14:49:00 +     if ($LASTEXITCODE -ne 0) { Throw "Failed to compile $type" }
14:49:00 +                                ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


14:49:00 INFO: make.ps1 ended at 07/17/2019 14:49:00
14:49:01 
14:49:01 
14:49:01 ERROR: Failed 'ERROR: Failed to build binary' at 07/17/2019 14:49:01
14:49:01 At C:\gopath\src\github.com\docker\docker\hack\ci\windows.ps1:492 char:13
14:49:01 +             Throw "ERROR: Failed to build binary"
14:49:01 +             ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
14:49:01 
14:49:01 

@thaJeztah
Copy link
Member Author

This one passes locally;

make TESTFLAGS='-test.run ^TestHostnameDnsResolution$' test-integration
Running /go/src/github.com/docker/docker/integration/container
INFO: Testing against a local daemon
=== RUN   TestHostnameDnsResolution
--- PASS: TestHostnameDnsResolution (7.74s)
PASS

@thaJeztah
Copy link
Member Author

Logs for the failing TestHostnameDnsResolution test for https://jenkins.dockerproject.org/job/Docker-PRs/54911/console

TestHostnameDnsResolution.log

And all logs of the tests and daemon:
docker.log
test.log

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

forcing IPv4 for the ping; see if that's making a difference

@thaJeztah
Copy link
Member Author

One thing I noticed on my machine (Docker for Mac) is that starting the daemon is really, really slow; looks like creating iptables rules takes a lot longer;

root@95d424b04e03:/go/src/github.com/docker/docker# dockerd --debug
INFO[2019-07-20T13:36:00.811314615Z] Starting up                                  
..
INFO[2019-07-20T13:36:07.010240136Z] API listen on /var/run/docker.sock 

That's almost 7 seconds!

If I start the daemon with --iptables=false, it's instantaneous (short of);

root@f58a9da11307:/go/src/github.com/docker/docker# dockerd --iptables=false 
INFO[2019-07-20T13:37:29.162712726Z] Starting up        
...
INFO[2019-07-20T13:37:29.324192555Z] API listen on /var/run/docker.sock 
root@95d424b04e03:/go/src/github.com/docker/docker# dockerd --debug
INFO[2019-07-20T13:36:00.811314615Z] Starting up                                  
DEBU[2019-07-20T13:36:00.812309473Z] Listener created for HTTP on unix (/var/run/docker.sock) 
DEBU[2019-07-20T13:36:00.812377780Z] Containerd not running, starting daemon managed containerd 
INFO[2019-07-20T13:36:00.814307037Z] libcontainerd: started new containerd process  pid=264
INFO[2019-07-20T13:36:00.814670897Z] parsed scheme: "unix"                         module=grpc
INFO[2019-07-20T13:36:00.814721227Z] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2019-07-20T13:36:00.814803020Z] ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }  module=grpc
INFO[2019-07-20T13:36:00.814823886Z] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2019-07-20T13:36:00.814991144Z] pickfirstBalancer: HandleSubConnStateChange: 0xc00017d9c0, CONNECTING  module=grpc
INFO[2019-07-20T13:36:00.834574973Z] starting containerd                           revision=85f6aa58b8a3170aec9824568f7a31832878b603 version=v1.2.7
DEBU[2019-07-20T13:36:00.834653292Z] changing OOM score to -500                   
INFO[2019-07-20T13:36:00.834993972Z] loading plugin "io.containerd.content.v1.content"...  type=io.containerd.content.v1
INFO[2019-07-20T13:36:00.835038473Z] loading plugin "io.containerd.snapshotter.v1.btrfs"...  type=io.containerd.snapshotter.v1
WARN[2019-07-20T13:36:00.835331786Z] failed to load plugin io.containerd.snapshotter.v1.btrfs  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter"
INFO[2019-07-20T13:36:00.835470645Z] loading plugin "io.containerd.snapshotter.v1.aufs"...  type=io.containerd.snapshotter.v1
WARN[2019-07-20T13:36:00.835598136Z] failed to load plugin io.containerd.snapshotter.v1.aufs  error="modprobe aufs failed: "": exec: "modprobe": executable file not found in $PATH"
INFO[2019-07-20T13:36:00.835650545Z] loading plugin "io.containerd.snapshotter.v1.native"...  type=io.containerd.snapshotter.v1
INFO[2019-07-20T13:36:00.835734690Z] loading plugin "io.containerd.snapshotter.v1.overlayfs"...  type=io.containerd.snapshotter.v1
INFO[2019-07-20T13:36:00.835851477Z] loading plugin "io.containerd.snapshotter.v1.zfs"...  type=io.containerd.snapshotter.v1
WARN[2019-07-20T13:36:00.836132218Z] failed to load plugin io.containerd.snapshotter.v1.zfs  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter"
INFO[2019-07-20T13:36:00.836277941Z] loading plugin "io.containerd.metadata.v1.bolt"...  type=io.containerd.metadata.v1
WARN[2019-07-20T13:36:00.836292390Z] could not use snapshotter btrfs in metadata plugin  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter"
WARN[2019-07-20T13:36:00.836297610Z] could not use snapshotter aufs in metadata plugin  error="modprobe aufs failed: "": exec: "modprobe": executable file not found in $PATH"
WARN[2019-07-20T13:36:00.836324555Z] could not use snapshotter zfs in metadata plugin  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter"
INFO[2019-07-20T13:36:00.836441441Z] loading plugin "io.containerd.differ.v1.walking"...  type=io.containerd.differ.v1
INFO[2019-07-20T13:36:00.836541346Z] loading plugin "io.containerd.gc.v1.scheduler"...  type=io.containerd.gc.v1
INFO[2019-07-20T13:36:00.836605927Z] loading plugin "io.containerd.service.v1.containers-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:36:00.836672234Z] loading plugin "io.containerd.service.v1.content-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:36:00.836711025Z] loading plugin "io.containerd.service.v1.diff-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:36:00.836785220Z] loading plugin "io.containerd.service.v1.images-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:36:00.836796203Z] loading plugin "io.containerd.service.v1.leases-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:36:00.836892307Z] loading plugin "io.containerd.service.v1.namespaces-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:36:00.836961633Z] loading plugin "io.containerd.service.v1.snapshots-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:36:00.837022116Z] loading plugin "io.containerd.runtime.v1.linux"...  type=io.containerd.runtime.v1
INFO[2019-07-20T13:36:00.837435089Z] loading plugin "io.containerd.runtime.v2.task"...  type=io.containerd.runtime.v2
INFO[2019-07-20T13:36:00.837590425Z] loading plugin "io.containerd.monitor.v1.cgroups"...  type=io.containerd.monitor.v1
INFO[2019-07-20T13:36:00.838262005Z] loading plugin "io.containerd.service.v1.tasks-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:36:00.838306554Z] loading plugin "io.containerd.internal.v1.restart"...  type=io.containerd.internal.v1
INFO[2019-07-20T13:36:00.838362555Z] loading plugin "io.containerd.grpc.v1.containers"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838386521Z] loading plugin "io.containerd.grpc.v1.content"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838420202Z] loading plugin "io.containerd.grpc.v1.diff"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838454624Z] loading plugin "io.containerd.grpc.v1.events"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838489210Z] loading plugin "io.containerd.grpc.v1.healthcheck"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838524119Z] loading plugin "io.containerd.grpc.v1.images"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838564662Z] loading plugin "io.containerd.grpc.v1.leases"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838610421Z] loading plugin "io.containerd.grpc.v1.namespaces"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838627092Z] loading plugin "io.containerd.internal.v1.opt"...  type=io.containerd.internal.v1
INFO[2019-07-20T13:36:00.838665313Z] loading plugin "io.containerd.grpc.v1.snapshots"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838696365Z] loading plugin "io.containerd.grpc.v1.tasks"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838705446Z] loading plugin "io.containerd.grpc.v1.version"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.838712473Z] loading plugin "io.containerd.grpc.v1.introspection"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:36:00.839122466Z] serving...                                    address="/var/run/docker/containerd/containerd-debug.sock"
INFO[2019-07-20T13:36:00.839240355Z] serving...                                    address="/var/run/docker/containerd/containerd.sock"
INFO[2019-07-20T13:36:00.839295009Z] containerd successfully booted in 0.005346s  
INFO[2019-07-20T13:36:00.847079374Z] pickfirstBalancer: HandleSubConnStateChange: 0xc00017d9c0, READY  module=grpc
DEBU[2019-07-20T13:36:00.848189030Z] Started daemon managed containerd            
DEBU[2019-07-20T13:36:00.848828193Z] Golang's threads limit set to 14130          
INFO[2019-07-20T13:36:00.849175955Z] parsed scheme: "unix"                         module=grpc
INFO[2019-07-20T13:36:00.849206361Z] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2019-07-20T13:36:00.849220847Z] ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }  module=grpc
INFO[2019-07-20T13:36:00.849226520Z] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2019-07-20T13:36:00.849261201Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0007bc7e0, CONNECTING  module=grpc
INFO[2019-07-20T13:36:00.849703059Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0007bc7e0, READY  module=grpc
INFO[2019-07-20T13:36:00.850210027Z] parsed scheme: "unix"                         module=grpc
INFO[2019-07-20T13:36:00.850240777Z] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2019-07-20T13:36:00.850254780Z] ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }  module=grpc
INFO[2019-07-20T13:36:00.850280041Z] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2019-07-20T13:36:00.850312384Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0008fa020, CONNECTING  module=grpc
INFO[2019-07-20T13:36:00.850595772Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0008fa020, READY  module=grpc
DEBU[2019-07-20T13:36:00.851215387Z] Using default logging driver json-file       
DEBU[2019-07-20T13:36:00.851286433Z] [graphdriver] priority list: [btrfs zfs overlay2 aufs overlay devicemapper vfs] 
DEBU[2019-07-20T13:36:00.851464611Z] backingFs=extfs, projectQuotaSupported=false, indexOff=""  storage-driver=overlay2
INFO[2019-07-20T13:36:00.851494413Z] [graphdriver] using prior storage driver: overlay2 
DEBU[2019-07-20T13:36:00.851508891Z] Initialized graph driver overlay2            
DEBU[2019-07-20T13:36:00.851933993Z] processing event stream                       module=libcontainerd namespace=plugins.moby
DEBU[2019-07-20T13:36:00.854318757Z] Max Concurrent Downloads: 3                  
DEBU[2019-07-20T13:36:00.854350162Z] Max Concurrent Uploads: 5                    
INFO[2019-07-20T13:36:00.854369748Z] Loading containers: start.                   
DEBU[2019-07-20T13:36:00.854427783Z] Option Experimental: false                   
DEBU[2019-07-20T13:36:00.854456855Z] Option DefaultDriver: bridge                 
DEBU[2019-07-20T13:36:00.854462742Z] Option DefaultNetwork: bridge                
DEBU[2019-07-20T13:36:00.854466360Z] Network Control Plane MTU: 1500              
WARN[2019-07-20T13:36:00.854615562Z] Running modprobe bridge br_netfilter failed with message: , error: exec: "modprobe": executable file not found in $PATH 
WARN[2019-07-20T13:36:00.854664984Z] Running modprobe nf_nat failed with message: ``, error: exec: "modprobe": executable file not found in $PATH 
WARN[2019-07-20T13:36:00.854706702Z] Running modprobe xt_conntrack failed with message: ``, error: exec: "modprobe": executable file not found in $PATH 
DEBU[2019-07-20T13:36:00.854773973Z] Fail to initialize firewalld: Failed to connect to D-Bus system bus: dial unix /var/run/dbus/system_bus_socket: connect: no such file or directory, using raw iptables instead 
DEBU[2019-07-20T13:36:00.855143615Z] processing event stream                       module=libcontainerd namespace=moby
DEBU[2019-07-20T13:36:00.942953282Z] garbage collected                             d=4.176374ms
DEBU[2019-07-20T13:36:01.093166315Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION] 
DEBU[2019-07-20T13:36:01.100013127Z] /usr/sbin/iptables, [--wait -t nat -D PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:36:01.101588545Z] /usr/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL ! --dst 127.0.0.0/8 -j DOCKER] 
DEBU[2019-07-20T13:36:01.102841503Z] /usr/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:36:01.104119651Z] /usr/sbin/iptables, [--wait -t nat -D PREROUTING] 
DEBU[2019-07-20T13:36:01.105428352Z] /usr/sbin/iptables, [--wait -t nat -D OUTPUT] 
DEBU[2019-07-20T13:36:01.106571757Z] /usr/sbin/iptables, [--wait -t nat -F DOCKER] 
DEBU[2019-07-20T13:36:01.190953543Z] /usr/sbin/iptables, [--wait -t nat -X DOCKER] 
DEBU[2019-07-20T13:36:01.193839697Z] /usr/sbin/iptables, [--wait -t filter -F DOCKER] 
DEBU[2019-07-20T13:36:01.291949878Z] /usr/sbin/iptables, [--wait -t filter -X DOCKER] 
DEBU[2019-07-20T13:36:01.294107982Z] /usr/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:36:01.390351505Z] /usr/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:36:01.392435261Z] /usr/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:01.470056693Z] /usr/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:01.472141500Z] /usr/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION] 
DEBU[2019-07-20T13:36:01.599995512Z] /usr/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION] 
DEBU[2019-07-20T13:36:01.602142643Z] /usr/sbin/iptables, [--wait -t nat -n -L DOCKER] 
DEBU[2019-07-20T13:36:01.721562603Z] /usr/sbin/iptables, [--wait -t nat -N DOCKER] 
DEBU[2019-07-20T13:36:01.830113249Z] /usr/sbin/iptables, [--wait -t filter -n -L DOCKER] 
DEBU[2019-07-20T13:36:01.930447820Z] /usr/sbin/iptables, [--wait -t filter -N DOCKER] 
DEBU[2019-07-20T13:36:02.051554495Z] /usr/sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:36:02.201433553Z] /usr/sbin/iptables, [--wait -t filter -N DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:36:02.289937753Z] /usr/sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:02.409926601Z] /usr/sbin/iptables, [--wait -t filter -N DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:02.501910823Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -j RETURN] 
DEBU[2019-07-20T13:36:02.504106261Z] /usr/sbin/iptables, [--wait -A DOCKER-ISOLATION-STAGE-1 -j RETURN] 
DEBU[2019-07-20T13:36:02.590205073Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -j RETURN] 
DEBU[2019-07-20T13:36:02.592916107Z] /usr/sbin/iptables, [--wait -A DOCKER-ISOLATION-STAGE-2 -j RETURN] 
DEBU[2019-07-20T13:36:02.721948175Z] /usr/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP] 
DEBU[2019-07-20T13:36:02.724114069Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:02.725762930Z] /usr/sbin/iptables, [--wait -I FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:02.840833322Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:02.843106840Z] /usr/sbin/iptables, [--wait -I FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:02.951479941Z] /usr/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:36:02.953579623Z] /usr/sbin/iptables, [--wait -t nat -A PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:36:03.071023670Z] /usr/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8] 
DEBU[2019-07-20T13:36:03.073019245Z] /usr/sbin/iptables, [--wait -t nat -A OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8] 
DEBU[2019-07-20T13:36:03.181550361Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:36:03.184372552Z] /usr/sbin/iptables, [--wait -I FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:36:03.289483312Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:36:03.292120061Z] /usr/sbin/iptables, [--wait -I FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:36:03.381898585Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:36:03.385090176Z] /usr/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:36:03.469512386Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:03.471903916Z] /usr/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:03.581699406Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
DEBU[2019-07-20T13:36:03.583525392Z] /usr/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
DEBU[2019-07-20T13:36:03.681814839Z] Network (e081776) restored                   
DEBU[2019-07-20T13:36:03.684030441Z] Allocating IPv4 pools for network bridge (e08177688934183c3073d0bb9c72adf186083d0191fe2e426bb9a72f307f4b4f) 
DEBU[2019-07-20T13:36:03.684081982Z] RequestPool(LocalDefault, 172.18.0.0/16, , map[], false) 
DEBU[2019-07-20T13:36:03.684115793Z] RequestAddress(LocalDefault/172.18.0.0/16, 172.18.0.1, map[RequestAddressType:com.docker.network.gateway]) 
DEBU[2019-07-20T13:36:03.684155474Z] Request address PoolID:172.18.0.0/16 App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65534, Sequence: (0x80000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 Serial:false PrefAddress:172.18.0.1  
DEBU[2019-07-20T13:36:03.689557366Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:03.781952085Z] /usr/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:03.901262339Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:03.981012269Z] /usr/sbin/iptables, [--wait -D FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:04.072079907Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:36:04.200783710Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:36:04.299528716Z] /usr/sbin/iptables, [--wait -D FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:36:04.409824570Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:36:04.499531091Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:36:04.592023795Z] /usr/sbin/iptables, [--wait -D FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:36:04.711606030Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:04.800054427Z] /usr/sbin/iptables, [--wait -t filter -D DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:04.931517691Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
DEBU[2019-07-20T13:36:05.050189874Z] /usr/sbin/iptables, [--wait -t filter -D DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
DEBU[2019-07-20T13:36:05.174357396Z] releasing IPv4 pools from network bridge (e08177688934183c3073d0bb9c72adf186083d0191fe2e426bb9a72f307f4b4f) 
DEBU[2019-07-20T13:36:05.174403915Z] ReleaseAddress(LocalDefault/172.18.0.0/16, 172.18.0.1) 
DEBU[2019-07-20T13:36:05.174455127Z] Released address PoolID:LocalDefault/172.18.0.0/16, Address:172.18.0.1 Sequence:App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65533, Sequence: (0xc0000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 
DEBU[2019-07-20T13:36:05.174463816Z] ReleasePool(LocalDefault/172.18.0.0/16)      
DEBU[2019-07-20T13:36:05.176092219Z] cleanupServiceDiscovery for network:e08177688934183c3073d0bb9c72adf186083d0191fe2e426bb9a72f307f4b4f 
INFO[2019-07-20T13:36:05.178280230Z] Default bridge (docker0) is assigned with an IP address 172.18.0.0/16. Daemon option --bip can be used to set a preferred IP address 
DEBU[2019-07-20T13:36:05.178326000Z] Allocating IPv4 pools for network bridge (d3c437b7ae598de3ba39550c6180501da7407a91288208de1bf48c8ae8bcc1b2) 
DEBU[2019-07-20T13:36:05.178393495Z] RequestPool(LocalDefault, 172.18.0.0/16, , map[], false) 
DEBU[2019-07-20T13:36:05.178412868Z] RequestAddress(LocalDefault/172.18.0.0/16, 172.18.0.1, map[RequestAddressType:com.docker.network.gateway]) 
DEBU[2019-07-20T13:36:05.178631924Z] Request address PoolID:172.18.0.0/16 App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65534, Sequence: (0x80000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 Serial:false PrefAddress:172.18.0.1  
DEBU[2019-07-20T13:36:05.179235718Z] /usr/sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.18.0.0/16 ! -o docker0 -j MASQUERADE] 
DEBU[2019-07-20T13:36:05.181248560Z] /usr/sbin/iptables, [--wait -t nat -I POSTROUTING -s 172.18.0.0/16 ! -o docker0 -j MASQUERADE] 
DEBU[2019-07-20T13:36:05.281554617Z] /usr/sbin/iptables, [--wait -t nat -C DOCKER -i docker0 -j RETURN] 
DEBU[2019-07-20T13:36:05.283585198Z] /usr/sbin/iptables, [--wait -t nat -I DOCKER -i docker0 -j RETURN] 
DEBU[2019-07-20T13:36:05.379886063Z] /usr/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP] 
DEBU[2019-07-20T13:36:05.381951525Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:05.383510349Z] /usr/sbin/iptables, [--wait -I FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:05.501549943Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:05.503651151Z] /usr/sbin/iptables, [--wait -I FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:36:05.600393345Z] /usr/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:36:05.691973252Z] /usr/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:36:05.811708075Z] /usr/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8] 
DEBU[2019-07-20T13:36:05.910220586Z] /usr/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8] 
DEBU[2019-07-20T13:36:06.019485156Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:36:06.021844219Z] /usr/sbin/iptables, [--wait -I FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:36:06.141332681Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:36:06.143121910Z] /usr/sbin/iptables, [--wait -I FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:36:06.241714634Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:36:06.391405073Z] /usr/sbin/iptables, [--wait -D FORWARD -j DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:36:06.481405085Z] /usr/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:36:06.631291429Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:06.633529815Z] /usr/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:36:06.742059405Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
DEBU[2019-07-20T13:36:06.744378345Z] /usr/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
INFO[2019-07-20T13:36:06.908062886Z] Loading containers: done.                    
INFO[2019-07-20T13:36:06.982187400Z] Docker daemon                                 commit=4dc163ef31 graphdriver(s)=overlay2 version=dev
INFO[2019-07-20T13:36:06.982267462Z] Daemon has completed initialization          
DEBU[2019-07-20T13:36:06.994181370Z] Registering routers                          
DEBU[2019-07-20T13:36:06.994240491Z] Registering GET, /containers/{name:.*}/checkpoints 
DEBU[2019-07-20T13:36:06.994331540Z] Registering POST, /containers/{name:.*}/checkpoints 
DEBU[2019-07-20T13:36:06.994459909Z] Registering DELETE, /containers/{name}/checkpoints/{checkpoint} 
DEBU[2019-07-20T13:36:06.994677118Z] Registering HEAD, /containers/{name:.*}/archive 
DEBU[2019-07-20T13:36:06.994913043Z] Registering GET, /containers/json            
DEBU[2019-07-20T13:36:06.994995705Z] Registering GET, /containers/{name:.*}/export 
DEBU[2019-07-20T13:36:06.995371248Z] Registering GET, /containers/{name:.*}/changes 
DEBU[2019-07-20T13:36:06.995451756Z] Registering GET, /containers/{name:.*}/json  
DEBU[2019-07-20T13:36:06.995538912Z] Registering GET, /containers/{name:.*}/top   
DEBU[2019-07-20T13:36:06.995624924Z] Registering GET, /containers/{name:.*}/logs  
DEBU[2019-07-20T13:36:06.995698809Z] Registering GET, /containers/{name:.*}/stats 
DEBU[2019-07-20T13:36:06.996002585Z] Registering GET, /containers/{name:.*}/attach/ws 
DEBU[2019-07-20T13:36:06.996128045Z] Registering GET, /exec/{id:.*}/json          
DEBU[2019-07-20T13:36:06.996195438Z] Registering GET, /containers/{name:.*}/archive 
DEBU[2019-07-20T13:36:06.996302847Z] Registering POST, /containers/create         
DEBU[2019-07-20T13:36:06.996373576Z] Registering POST, /containers/{name:.*}/kill 
DEBU[2019-07-20T13:36:06.996670089Z] Registering POST, /containers/{name:.*}/pause 
DEBU[2019-07-20T13:36:06.996761955Z] Registering POST, /containers/{name:.*}/unpause 
DEBU[2019-07-20T13:36:06.996825849Z] Registering POST, /containers/{name:.*}/restart 
DEBU[2019-07-20T13:36:06.996909831Z] Registering POST, /containers/{name:.*}/start 
DEBU[2019-07-20T13:36:06.996989244Z] Registering POST, /containers/{name:.*}/stop 
DEBU[2019-07-20T13:36:06.997276344Z] Registering POST, /containers/{name:.*}/wait 
DEBU[2019-07-20T13:36:06.997377596Z] Registering POST, /containers/{name:.*}/resize 
DEBU[2019-07-20T13:36:06.997447868Z] Registering POST, /containers/{name:.*}/attach 
DEBU[2019-07-20T13:36:06.997782052Z] Registering POST, /containers/{name:.*}/copy 
DEBU[2019-07-20T13:36:06.997855437Z] Registering POST, /containers/{name:.*}/exec 
DEBU[2019-07-20T13:36:06.997940464Z] Registering POST, /exec/{name:.*}/start      
DEBU[2019-07-20T13:36:06.998352239Z] Registering POST, /exec/{name:.*}/resize     
DEBU[2019-07-20T13:36:06.998494479Z] Registering POST, /containers/{name:.*}/rename 
DEBU[2019-07-20T13:36:06.998611362Z] Registering POST, /containers/{name:.*}/update 
DEBU[2019-07-20T13:36:06.998716413Z] Registering POST, /containers/prune          
DEBU[2019-07-20T13:36:06.998946830Z] Registering POST, /commit                    
DEBU[2019-07-20T13:36:06.999112772Z] Registering PUT, /containers/{name:.*}/archive 
DEBU[2019-07-20T13:36:06.999372689Z] Registering DELETE, /containers/{name:.*}    
DEBU[2019-07-20T13:36:06.999463462Z] Registering GET, /images/json                
DEBU[2019-07-20T13:36:06.999772110Z] Registering GET, /images/search              
DEBU[2019-07-20T13:36:06.999886520Z] Registering GET, /images/get                 
DEBU[2019-07-20T13:36:06.999958983Z] Registering GET, /images/{name:.*}/get       
DEBU[2019-07-20T13:36:07.000030664Z] Registering GET, /images/{name:.*}/history   
DEBU[2019-07-20T13:36:07.000477223Z] Registering GET, /images/{name:.*}/json      
DEBU[2019-07-20T13:36:07.000622958Z] Registering POST, /images/load               
DEBU[2019-07-20T13:36:07.001022811Z] Registering POST, /images/create             
DEBU[2019-07-20T13:36:07.001092377Z] Registering POST, /images/{name:.*}/push     
DEBU[2019-07-20T13:36:07.001195996Z] Registering POST, /images/{name:.*}/tag      
DEBU[2019-07-20T13:36:07.001822326Z] Registering POST, /images/prune              
DEBU[2019-07-20T13:36:07.001905577Z] Registering DELETE, /images/{name:.*}        
DEBU[2019-07-20T13:36:07.001991034Z] Registering OPTIONS, /{anyroute:.*}          
DEBU[2019-07-20T13:36:07.002094462Z] Registering GET, /_ping                      
DEBU[2019-07-20T13:36:07.002380737Z] Registering HEAD, /_ping                     
DEBU[2019-07-20T13:36:07.002440300Z] Registering GET, /events                     
DEBU[2019-07-20T13:36:07.002509606Z] Registering GET, /info                       
DEBU[2019-07-20T13:36:07.002668146Z] Registering GET, /version                    
DEBU[2019-07-20T13:36:07.002854858Z] Registering GET, /system/df                  
DEBU[2019-07-20T13:36:07.002910250Z] Registering POST, /auth                      
DEBU[2019-07-20T13:36:07.002960231Z] Registering GET, /volumes                    
DEBU[2019-07-20T13:36:07.003027594Z] Registering GET, /volumes/{name:.*}          
DEBU[2019-07-20T13:36:07.003107751Z] Registering POST, /volumes/create            
DEBU[2019-07-20T13:36:07.003162988Z] Registering POST, /volumes/prune             
DEBU[2019-07-20T13:36:07.003245095Z] Registering DELETE, /volumes/{name:.*}       
DEBU[2019-07-20T13:36:07.003551431Z] Registering POST, /build                     
DEBU[2019-07-20T13:36:07.003639275Z] Registering POST, /build/prune               
DEBU[2019-07-20T13:36:07.003691312Z] Registering POST, /build/cancel              
DEBU[2019-07-20T13:36:07.003761106Z] Registering POST, /session                   
DEBU[2019-07-20T13:36:07.003826442Z] Registering POST, /swarm/init                
DEBU[2019-07-20T13:36:07.003888584Z] Registering POST, /swarm/join                
DEBU[2019-07-20T13:36:07.003972370Z] Registering POST, /swarm/leave               
DEBU[2019-07-20T13:36:07.004055135Z] Registering GET, /swarm                      
DEBU[2019-07-20T13:36:07.004129069Z] Registering GET, /swarm/unlockkey            
DEBU[2019-07-20T13:36:07.004464751Z] Registering POST, /swarm/update              
DEBU[2019-07-20T13:36:07.004584614Z] Registering POST, /swarm/unlock              
DEBU[2019-07-20T13:36:07.004632401Z] Registering GET, /services                   
DEBU[2019-07-20T13:36:07.004702778Z] Registering GET, /services/{id}              
DEBU[2019-07-20T13:36:07.004787036Z] Registering POST, /services/create           
DEBU[2019-07-20T13:36:07.004849744Z] Registering POST, /services/{id}/update      
DEBU[2019-07-20T13:36:07.004948499Z] Registering DELETE, /services/{id}           
DEBU[2019-07-20T13:36:07.005171949Z] Registering GET, /services/{id}/logs         
DEBU[2019-07-20T13:36:07.005276167Z] Registering GET, /nodes                      
DEBU[2019-07-20T13:36:07.005341259Z] Registering GET, /nodes/{id}                 
DEBU[2019-07-20T13:36:07.005393658Z] Registering DELETE, /nodes/{id}              
DEBU[2019-07-20T13:36:07.005448094Z] Registering POST, /nodes/{id}/update         
DEBU[2019-07-20T13:36:07.005706997Z] Registering GET, /tasks                      
DEBU[2019-07-20T13:36:07.005774383Z] Registering GET, /tasks/{id}                 
DEBU[2019-07-20T13:36:07.005855861Z] Registering GET, /tasks/{id}/logs            
DEBU[2019-07-20T13:36:07.006112896Z] Registering GET, /secrets                    
DEBU[2019-07-20T13:36:07.006160200Z] Registering POST, /secrets/create            
DEBU[2019-07-20T13:36:07.006209551Z] Registering DELETE, /secrets/{id}            
DEBU[2019-07-20T13:36:07.006273696Z] Registering GET, /secrets/{id}               
DEBU[2019-07-20T13:36:07.006328429Z] Registering POST, /secrets/{id}/update       
DEBU[2019-07-20T13:36:07.006578282Z] Registering GET, /configs                    
DEBU[2019-07-20T13:36:07.006631348Z] Registering POST, /configs/create            
DEBU[2019-07-20T13:36:07.006680337Z] Registering DELETE, /configs/{id}            
DEBU[2019-07-20T13:36:07.006735793Z] Registering GET, /configs/{id}               
DEBU[2019-07-20T13:36:07.006792088Z] Registering POST, /configs/{id}/update       
DEBU[2019-07-20T13:36:07.006851888Z] Registering GET, /plugins                    
DEBU[2019-07-20T13:36:07.007085778Z] Registering GET, /plugins/{name:.*}/json     
DEBU[2019-07-20T13:36:07.007215198Z] Registering GET, /plugins/privileges         
DEBU[2019-07-20T13:36:07.007264044Z] Registering DELETE, /plugins/{name:.*}       
DEBU[2019-07-20T13:36:07.007318880Z] Registering POST, /plugins/{name:.*}/enable  
DEBU[2019-07-20T13:36:07.007702452Z] Registering POST, /plugins/{name:.*}/disable 
DEBU[2019-07-20T13:36:07.007763916Z] Registering POST, /plugins/pull              
DEBU[2019-07-20T13:36:07.007819422Z] Registering POST, /plugins/{name:.*}/push    
DEBU[2019-07-20T13:36:07.007876621Z] Registering POST, /plugins/{name:.*}/upgrade 
DEBU[2019-07-20T13:36:07.008203103Z] Registering POST, /plugins/{name:.*}/set     
DEBU[2019-07-20T13:36:07.008275264Z] Registering POST, /plugins/create            
DEBU[2019-07-20T13:36:07.008337969Z] Registering GET, /distribution/{name:.*}/json 
DEBU[2019-07-20T13:36:07.008405308Z] Registering POST, /grpc                      
DEBU[2019-07-20T13:36:07.008452491Z] Registering GET, /networks                   
DEBU[2019-07-20T13:36:07.008505161Z] Registering GET, /networks/                  
DEBU[2019-07-20T13:36:07.008757473Z] Registering GET, /networks/{id:.+}           
DEBU[2019-07-20T13:36:07.008984018Z] Registering POST, /networks/create           
DEBU[2019-07-20T13:36:07.009058678Z] Registering POST, /networks/{id:.*}/connect  
DEBU[2019-07-20T13:36:07.009203598Z] Registering POST, /networks/{id:.*}/disconnect 
DEBU[2019-07-20T13:36:07.009483135Z] Registering POST, /networks/prune            
DEBU[2019-07-20T13:36:07.009803340Z] Registering DELETE, /networks/{id:.*}        
INFO[2019-07-20T13:36:07.010240136Z] API listen on /var/run/docker.sock               

@thaJeztah
Copy link
Member Author

Switching to master, and using Go 1.12.7 on stretch;

make GO_VERSION=1.12.7-stretch binary shell 

....

root@2d0c9e626049:/go/src/github.com/docker/docker# dockerd --debug
INFO[2019-07-20T13:43:58.813155082Z] Starting up                                  
..
INFO[2019-07-20T13:43:59.111450901Z] API listen on /var/run/docker.sock           

And without iptables:

root@2d0c9e626049:/go/src/github.com/docker/docker# dockerd --debug --iptables=false
INFO[2019-07-20T13:45:15.647070052Z] Starting up 
...
INFO[2019-07-20T13:45:28.248168518Z] API listen on /var/run/docker.sock 
root@2d0c9e626049:/go/src/github.com/docker/docker# dockerd --debug
INFO[2019-07-20T13:43:58.813155082Z] Starting up                                  
DEBU[2019-07-20T13:43:58.813766793Z] Listener created for HTTP on unix (/var/run/docker.sock) 
DEBU[2019-07-20T13:43:58.813851025Z] Containerd not running, starting daemon managed containerd 
INFO[2019-07-20T13:43:58.814673482Z] libcontainerd: started new containerd process  pid=279
INFO[2019-07-20T13:43:58.814736270Z] parsed scheme: "unix"                         module=grpc
INFO[2019-07-20T13:43:58.814764906Z] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2019-07-20T13:43:58.814909618Z] ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }  module=grpc
INFO[2019-07-20T13:43:58.814941593Z] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2019-07-20T13:43:58.815001650Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0007fca40, CONNECTING  module=grpc
INFO[2019-07-20T13:43:58.837816886Z] starting containerd                           revision=85f6aa58b8a3170aec9824568f7a31832878b603 version=v1.2.7
DEBU[2019-07-20T13:43:58.837921953Z] changing OOM score to -500                   
INFO[2019-07-20T13:43:58.838263157Z] loading plugin "io.containerd.content.v1.content"...  type=io.containerd.content.v1
INFO[2019-07-20T13:43:58.838396536Z] loading plugin "io.containerd.snapshotter.v1.btrfs"...  type=io.containerd.snapshotter.v1
WARN[2019-07-20T13:43:58.838698801Z] failed to load plugin io.containerd.snapshotter.v1.btrfs  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter"
INFO[2019-07-20T13:43:58.838759827Z] loading plugin "io.containerd.snapshotter.v1.aufs"...  type=io.containerd.snapshotter.v1
WARN[2019-07-20T13:43:58.838960433Z] failed to load plugin io.containerd.snapshotter.v1.aufs  error="modprobe aufs failed: "": exec: "modprobe": executable file not found in $PATH"
INFO[2019-07-20T13:43:58.839003077Z] loading plugin "io.containerd.snapshotter.v1.native"...  type=io.containerd.snapshotter.v1
INFO[2019-07-20T13:43:58.839088178Z] loading plugin "io.containerd.snapshotter.v1.overlayfs"...  type=io.containerd.snapshotter.v1
INFO[2019-07-20T13:43:58.839210043Z] loading plugin "io.containerd.snapshotter.v1.zfs"...  type=io.containerd.snapshotter.v1
WARN[2019-07-20T13:43:58.839471377Z] failed to load plugin io.containerd.snapshotter.v1.zfs  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter"
INFO[2019-07-20T13:43:58.839502623Z] loading plugin "io.containerd.metadata.v1.bolt"...  type=io.containerd.metadata.v1
WARN[2019-07-20T13:43:58.839561510Z] could not use snapshotter btrfs in metadata plugin  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter"
WARN[2019-07-20T13:43:58.839593057Z] could not use snapshotter aufs in metadata plugin  error="modprobe aufs failed: "": exec: "modprobe": executable file not found in $PATH"
WARN[2019-07-20T13:43:58.839605047Z] could not use snapshotter zfs in metadata plugin  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter"
INFO[2019-07-20T13:43:58.844508450Z] loading plugin "io.containerd.differ.v1.walking"...  type=io.containerd.differ.v1
INFO[2019-07-20T13:43:58.844549585Z] loading plugin "io.containerd.gc.v1.scheduler"...  type=io.containerd.gc.v1
INFO[2019-07-20T13:43:58.844616615Z] loading plugin "io.containerd.service.v1.containers-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:43:58.844652546Z] loading plugin "io.containerd.service.v1.content-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:43:58.844663497Z] loading plugin "io.containerd.service.v1.diff-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:43:58.844695620Z] loading plugin "io.containerd.service.v1.images-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:43:58.844734975Z] loading plugin "io.containerd.service.v1.leases-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:43:58.844763019Z] loading plugin "io.containerd.service.v1.namespaces-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:43:58.844839210Z] loading plugin "io.containerd.service.v1.snapshots-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:43:58.844878993Z] loading plugin "io.containerd.runtime.v1.linux"...  type=io.containerd.runtime.v1
INFO[2019-07-20T13:43:58.845104675Z] loading plugin "io.containerd.runtime.v2.task"...  type=io.containerd.runtime.v2
INFO[2019-07-20T13:43:58.845297368Z] loading plugin "io.containerd.monitor.v1.cgroups"...  type=io.containerd.monitor.v1
INFO[2019-07-20T13:43:58.846179269Z] loading plugin "io.containerd.service.v1.tasks-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:43:58.846232103Z] loading plugin "io.containerd.internal.v1.restart"...  type=io.containerd.internal.v1
INFO[2019-07-20T13:43:58.846299139Z] loading plugin "io.containerd.grpc.v1.containers"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.846338184Z] loading plugin "io.containerd.grpc.v1.content"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.846354594Z] loading plugin "io.containerd.grpc.v1.diff"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.846373659Z] loading plugin "io.containerd.grpc.v1.events"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.846388286Z] loading plugin "io.containerd.grpc.v1.healthcheck"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.846399013Z] loading plugin "io.containerd.grpc.v1.images"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.846409649Z] loading plugin "io.containerd.grpc.v1.leases"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.846445325Z] loading plugin "io.containerd.grpc.v1.namespaces"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.846474232Z] loading plugin "io.containerd.internal.v1.opt"...  type=io.containerd.internal.v1
INFO[2019-07-20T13:43:58.847050782Z] loading plugin "io.containerd.grpc.v1.snapshots"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.847106447Z] loading plugin "io.containerd.grpc.v1.tasks"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.847124694Z] loading plugin "io.containerd.grpc.v1.version"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.847136941Z] loading plugin "io.containerd.grpc.v1.introspection"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:43:58.847484499Z] serving...                                    address="/var/run/docker/containerd/containerd-debug.sock"
INFO[2019-07-20T13:43:58.847585582Z] serving...                                    address="/var/run/docker/containerd/containerd.sock"
INFO[2019-07-20T13:43:58.847759462Z] containerd successfully booted in 0.010685s  
INFO[2019-07-20T13:43:58.852456394Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0007fca40, READY  module=grpc
DEBU[2019-07-20T13:43:58.853839622Z] Started daemon managed containerd            
DEBU[2019-07-20T13:43:58.854955784Z] Golang's threads limit set to 14130          
INFO[2019-07-20T13:43:58.855328693Z] parsed scheme: "unix"                         module=grpc
INFO[2019-07-20T13:43:58.855361489Z] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2019-07-20T13:43:58.855384604Z] ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }  module=grpc
INFO[2019-07-20T13:43:58.855391666Z] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2019-07-20T13:43:58.855435032Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0007fcfc0, CONNECTING  module=grpc
INFO[2019-07-20T13:43:58.856116766Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0007fcfc0, READY  module=grpc
INFO[2019-07-20T13:43:58.857085226Z] parsed scheme: "unix"                         module=grpc
INFO[2019-07-20T13:43:58.857127930Z] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2019-07-20T13:43:58.857146617Z] ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }  module=grpc
INFO[2019-07-20T13:43:58.857155179Z] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2019-07-20T13:43:58.857215393Z] pickfirstBalancer: HandleSubConnStateChange: 0xc000881180, CONNECTING  module=grpc
INFO[2019-07-20T13:43:58.857766588Z] pickfirstBalancer: HandleSubConnStateChange: 0xc000881180, READY  module=grpc
DEBU[2019-07-20T13:43:58.858562686Z] processing event stream                       module=libcontainerd namespace=plugins.moby
DEBU[2019-07-20T13:43:58.858612855Z] Using default logging driver json-file       
DEBU[2019-07-20T13:43:58.858661942Z] [graphdriver] priority list: [btrfs zfs overlay2 aufs overlay devicemapper vfs] 
DEBU[2019-07-20T13:43:58.858860957Z] zfs command is not available: exec: "zfs": executable file not found in $PATH  storage-driver=zfs
DEBU[2019-07-20T13:43:58.859261391Z] backingFs=extfs, projectQuotaSupported=false, indexOff=""  storage-driver=overlay2
DEBU[2019-07-20T13:43:58.859327976Z] Initialized graph driver overlay2            
DEBU[2019-07-20T13:43:58.882607855Z] Max Concurrent Downloads: 3                  
DEBU[2019-07-20T13:43:58.882663096Z] Max Concurrent Uploads: 5                    
INFO[2019-07-20T13:43:58.882690260Z] Loading containers: start.                   
DEBU[2019-07-20T13:43:58.882776086Z] Option Experimental: false                   
DEBU[2019-07-20T13:43:58.882789439Z] Option DefaultDriver: bridge                 
DEBU[2019-07-20T13:43:58.882796457Z] Option DefaultNetwork: bridge                
DEBU[2019-07-20T13:43:58.882812981Z] Network Control Plane MTU: 1500              
WARN[2019-07-20T13:43:58.883018693Z] Running modprobe bridge br_netfilter failed with message: , error: exec: "modprobe": executable file not found in $PATH 
WARN[2019-07-20T13:43:58.883061316Z] Running modprobe nf_nat failed with message: ``, error: exec: "modprobe": executable file not found in $PATH 
WARN[2019-07-20T13:43:58.883122116Z] Running modprobe xt_conntrack failed with message: ``, error: exec: "modprobe": executable file not found in $PATH 
DEBU[2019-07-20T13:43:58.883201524Z] Fail to initialize firewalld: Failed to connect to D-Bus system bus: dial unix /var/run/dbus/system_bus_socket: connect: no such file or directory, using raw iptables instead 
DEBU[2019-07-20T13:43:58.887723067Z] processing event stream                       module=libcontainerd namespace=moby
DEBU[2019-07-20T13:43:58.891696107Z] /sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION] 
DEBU[2019-07-20T13:43:58.893408917Z] /sbin/iptables, [--wait -t nat -D PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:43:58.894915918Z] /sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL ! --dst 127.0.0.0/8 -j DOCKER] 
DEBU[2019-07-20T13:43:58.896347195Z] /sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:43:58.897712403Z] /sbin/iptables, [--wait -t nat -D PREROUTING] 
DEBU[2019-07-20T13:43:58.899335061Z] /sbin/iptables, [--wait -t nat -D OUTPUT]    
DEBU[2019-07-20T13:43:58.900613554Z] /sbin/iptables, [--wait -t nat -F DOCKER]    
DEBU[2019-07-20T13:43:58.901655568Z] /sbin/iptables, [--wait -t nat -X DOCKER]    
DEBU[2019-07-20T13:43:58.902847081Z] /sbin/iptables, [--wait -t filter -F DOCKER] 
DEBU[2019-07-20T13:43:58.904184423Z] /sbin/iptables, [--wait -t filter -X DOCKER] 
DEBU[2019-07-20T13:43:58.905287930Z] /sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:43:58.906800651Z] /sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:43:58.907955337Z] /sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:43:58.908926694Z] /sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:43:58.909810382Z] /sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION] 
DEBU[2019-07-20T13:43:58.910705237Z] /sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION] 
DEBU[2019-07-20T13:43:58.911632848Z] /sbin/iptables, [--wait -t nat -n -L DOCKER] 
DEBU[2019-07-20T13:43:58.912607339Z] /sbin/iptables, [--wait -t nat -N DOCKER]    
DEBU[2019-07-20T13:43:58.913526078Z] /sbin/iptables, [--wait -t filter -n -L DOCKER] 
DEBU[2019-07-20T13:43:58.914584405Z] /sbin/iptables, [--wait -t filter -N DOCKER] 
DEBU[2019-07-20T13:43:58.915662422Z] /sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:43:58.916740621Z] /sbin/iptables, [--wait -t filter -N DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:43:58.917760111Z] /sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:43:58.919211027Z] /sbin/iptables, [--wait -t filter -N DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:43:58.920719578Z] /sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -j RETURN] 
DEBU[2019-07-20T13:43:58.922067227Z] /sbin/iptables, [--wait -A DOCKER-ISOLATION-STAGE-1 -j RETURN] 
DEBU[2019-07-20T13:43:58.923511588Z] /sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -j RETURN] 
DEBU[2019-07-20T13:43:58.924744644Z] /sbin/iptables, [--wait -A DOCKER-ISOLATION-STAGE-2 -j RETURN] 
INFO[2019-07-20T13:43:58.938189475Z] Default bridge (docker0) is assigned with an IP address 172.18.0.0/16. Daemon option --bip can be used to set a preferred IP address 
DEBU[2019-07-20T13:43:58.938243103Z] Allocating IPv4 pools for network bridge (be63d4ee81f81f254f3abc1277a9efa4de1c11c4559b31df6941e12819982404) 
DEBU[2019-07-20T13:43:58.938285077Z] RequestPool(LocalDefault, 172.18.0.0/16, , map[], false) 
DEBU[2019-07-20T13:43:58.938471087Z] RequestAddress(LocalDefault/172.18.0.0/16, <nil>, map[RequestAddressType:com.docker.network.gateway]) 
DEBU[2019-07-20T13:43:58.938525848Z] Request address PoolID:172.18.0.0/16 App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65534, Sequence: (0x80000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 Serial:false PrefAddress:<nil>  
DEBU[2019-07-20T13:43:58.938604516Z] Did not find any interface with name docker0: Link not found 
DEBU[2019-07-20T13:43:58.939304438Z] Setting bridge mac address to 02:42:2d:91:14:ef 
DEBU[2019-07-20T13:43:58.939512529Z] Assigning address to bridge interface docker0: 172.18.0.1/16 
DEBU[2019-07-20T13:43:58.939645846Z] /sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.18.0.0/16 ! -o docker0 -j MASQUERADE] 
DEBU[2019-07-20T13:43:58.941386239Z] /sbin/iptables, [--wait -t nat -I POSTROUTING -s 172.18.0.0/16 ! -o docker0 -j MASQUERADE] 
DEBU[2019-07-20T13:43:58.942766238Z] /sbin/iptables, [--wait -t nat -C DOCKER -i docker0 -j RETURN] 
DEBU[2019-07-20T13:43:58.944012691Z] /sbin/iptables, [--wait -t nat -I DOCKER -i docker0 -j RETURN] 
DEBU[2019-07-20T13:43:58.945743369Z] /sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP] 
DEBU[2019-07-20T13:43:58.945960398Z] garbage collected                             d=1.071168ms
DEBU[2019-07-20T13:43:58.947055259Z] /sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:43:58.948387657Z] /sbin/iptables, [--wait -I FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:43:58.949644146Z] /sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:43:58.950788403Z] /sbin/iptables, [--wait -I FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:43:58.952038872Z] /sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:43:58.953457359Z] /sbin/iptables, [--wait -t nat -A PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:43:58.954683459Z] /sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8] 
DEBU[2019-07-20T13:43:58.955885136Z] /sbin/iptables, [--wait -t nat -A OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8] 
DEBU[2019-07-20T13:43:58.957052659Z] /sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:43:58.958238614Z] /sbin/iptables, [--wait -I FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:43:58.959516590Z] /sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:43:58.961532394Z] /sbin/iptables, [--wait -I FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:43:58.962807872Z] /sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:43:58.963950040Z] /sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:43:58.965074571Z] /sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:43:58.966373705Z] /sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:43:58.967695188Z] /sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
DEBU[2019-07-20T13:43:58.969341983Z] /sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
INFO[2019-07-20T13:43:58.976089600Z] Loading containers: done.                    
INFO[2019-07-20T13:43:59.028892563Z] Docker daemon                                 commit=48da116486 graphdriver(s)=overlay2 vers
4B92
ion=dev
INFO[2019-07-20T13:43:59.029123116Z] Daemon has completed initialization          
DEBU[2019-07-20T13:43:59.084955312Z] Registering routers                          
DEBU[2019-07-20T13:43:59.085045425Z] Registering GET, /containers/{name:.*}/checkpoints 
DEBU[2019-07-20T13:43:59.085182985Z] Registering POST, /containers/{name:.*}/checkpoints 
DEBU[2019-07-20T13:43:59.085430532Z] Registering DELETE, /containers/{name}/checkpoints/{checkpoint} 
DEBU[2019-07-20T13:43:59.086029539Z] Registering HEAD, /containers/{name:.*}/archive 
DEBU[2019-07-20T13:43:59.086194827Z] Registering GET, /containers/json            
DEBU[2019-07-20T13:43:59.086293110Z] Registering GET, /containers/{name:.*}/export 
DEBU[2019-07-20T13:43:59.086517891Z] Registering GET, /containers/{name:.*}/changes 
DEBU[2019-07-20T13:43:59.086848116Z] Registering GET, /containers/{name:.*}/json  
DEBU[2019-07-20T13:43:59.086960330Z] Registering GET, /containers/{name:.*}/top   
DEBU[2019-07-20T13:43:59.087200009Z] Registering GET, /containers/{name:.*}/logs  
DEBU[2019-07-20T13:43:59.087324605Z] Registering GET, /containers/{name:.*}/stats 
DEBU[2019-07-20T13:43:59.087533536Z] Registering GET, /containers/{name:.*}/attach/ws 
DEBU[2019-07-20T13:43:59.087686802Z] Registering GET, /exec/{id:.*}/json          
DEBU[2019-07-20T13:43:59.087805610Z] Registering GET, /containers/{name:.*}/archive 
DEBU[2019-07-20T13:43:59.088007334Z] Registering POST, /containers/create         
DEBU[2019-07-20T13:43:59.088071821Z] Registering POST, /containers/{name:.*}/kill 
DEBU[2019-07-20T13:43:59.088242294Z] Registering POST, /containers/{name:.*}/pause 
DEBU[2019-07-20T13:43:59.088411693Z] Registering POST, /containers/{name:.*}/unpause 
DEBU[2019-07-20T13:43:59.088553142Z] Registering POST, /containers/{name:.*}/restart 
DEBU[2019-07-20T13:43:59.089046931Z] Registering POST, /containers/{name:.*}/start 
DEBU[2019-07-20T13:43:59.089224239Z] Registering POST, /containers/{name:.*}/stop 
DEBU[2019-07-20T13:43:59.089358361Z] Registering POST, /containers/{name:.*}/wait 
DEBU[2019-07-20T13:43:59.089635342Z] Registering POST, /containers/{name:.*}/resize 
DEBU[2019-07-20T13:43:59.090258729Z] Registering POST, /containers/{name:.*}/attach 
DEBU[2019-07-20T13:43:59.090666134Z] Registering POST, /containers/{name:.*}/copy 
DEBU[2019-07-20T13:43:59.090988741Z] Registering POST, /containers/{name:.*}/exec 
DEBU[2019-07-20T13:43:59.091329943Z] Registering POST, /exec/{name:.*}/start      
DEBU[2019-07-20T13:43:59.091577554Z] Registering POST, /exec/{name:.*}/resize     
DEBU[2019-07-20T13:43:59.092013504Z] Registering POST, /containers/{name:.*}/rename 
DEBU[2019-07-20T13:43:59.092148140Z] Registering POST, /containers/{name:.*}/update 
DEBU[2019-07-20T13:43:59.092408427Z] Registering POST, /containers/prune          
DEBU[2019-07-20T13:43:59.092635393Z] Registering POST, /commit                    
DEBU[2019-07-20T13:43:59.092746905Z] Registering PUT, /containers/{name:.*}/archive 
DEBU[2019-07-20T13:43:59.093087494Z] Registering DELETE, /containers/{name:.*}    
DEBU[2019-07-20T13:43:59.093218957Z] Registering GET, /images/json                
DEBU[2019-07-20T13:43:59.093289954Z] Registering GET, /images/search              
DEBU[2019-07-20T13:43:59.093432622Z] Registering GET, /images/get                 
DEBU[2019-07-20T13:43:59.093765123Z] Registering GET, /images/{name:.*}/get       
DEBU[2019-07-20T13:43:59.093934266Z] Registering GET, /images/{name:.*}/history   
DEBU[2019-07-20T13:43:59.094210676Z] Registering GET, /images/{name:.*}/json      
DEBU[2019-07-20T13:43:59.094313923Z] Registering POST, /images/load               
DEBU[2019-07-20T13:43:59.094758964Z] Registering POST, /images/create             
DEBU[2019-07-20T13:43:59.094900265Z] Registering POST, /images/{name:.*}/push     
DEBU[2019-07-20T13:43:59.095086930Z] Registering POST, /images/{name:.*}/tag      
DEBU[2019-07-20T13:43:59.095618908Z] Registering POST, /images/prune              
DEBU[2019-07-20T13:43:59.095807546Z] Registering DELETE, /images/{name:.*}        
DEBU[2019-07-20T13:43:59.095972241Z] Registering OPTIONS, /{anyroute:.*}          
DEBU[2019-07-20T13:43:59.096202425Z] Registering GET, /_ping                      
DEBU[2019-07-20T13:43:59.096402867Z] Registering HEAD, /_ping                     
DEBU[2019-07-20T13:43:59.096583610Z] Registering GET, /events                     
DEBU[2019-07-20T13:43:59.096655638Z] Registering GET, /info                       
DEBU[2019-07-20T13:43:59.096847751Z] Registering GET, /version                    
DEBU[2019-07-20T13:43:59.097035459Z] Registering GET, /system/df                  
DEBU[2019-07-20T13:43:59.097195006Z] Registering POST, /auth                      
DEBU[2019-07-20T13:43:59.097657406Z] Registering GET, /volumes                    
DEBU[2019-07-20T13:43:59.097899218Z] Registering GET, /volumes/{name:.*}          
DEBU[2019-07-20T13:43:59.098135303Z] Registering POST, /volumes/create            
DEBU[2019-07-20T13:43:59.098575750Z] Registering POST, /volumes/prune             
DEBU[2019-07-20T13:43:59.098674961Z] Registering DELETE, /volumes/{name:.*}       
DEBU[2019-07-20T13:43:59.098838630Z] Registering POST, /build                     
DEBU[2019-07-20T13:43:59.099031312Z] Registering POST, /build/prune               
DEBU[2019-07-20T13:43:59.099130089Z] Registering POST, /build/cancel              
DEBU[2019-07-20T13:43:59.099554017Z] Registering POST, /session                   
DEBU[2019-07-20T13:43:59.099727892Z] Registering POST, /swarm/init                
DEBU[2019-07-20T13:43:59.100137214Z] Registering POST, /swarm/join                
DEBU[2019-07-20T13:43:59.100293422Z] Registering POST, /swarm/leave               
DEBU[2019-07-20T13:43:59.100407337Z] Registering GET, /swarm                      
DEBU[2019-07-20T13:43:59.100549893Z] Registering GET, /swarm/unlockkey            
DEBU[2019-07-20T13:43:59.100775663Z] Registering POST, /swarm/update              
DEBU[2019-07-20T13:43:59.101137048Z] Registering POST, /swarm/unlock              
DEBU[2019-07-20T13:43:59.101429981Z] Registering GET, /services                   
DEBU[2019-07-20T13:43:59.101794850Z] Registering GET, /services/{id}              
DEBU[2019-07-20T13:43:59.102076175Z] Registering POST, /services/create           
DEBU[2019-07-20T13:43:59.102212795Z] Registering POST, /services/{id}/update      
DEBU[2019-07-20T13:43:59.102512501Z] Registering DELETE, /services/{id}           
DEBU[2019-07-20T13:43:59.102779246Z] Registering GET, /services/{id}/logs         
DEBU[2019-07-20T13:43:59.102991571Z] Registering GET, /nodes                      
DEBU[2019-07-20T13:43:59.103205946Z] Registering GET, /nodes/{id}                 
DEBU[2019-07-20T13:43:59.103374272Z] Registering DELETE, /nodes/{id}              
DEBU[2019-07-20T13:43:59.103657146Z] Registering POST, /nodes/{id}/update         
DEBU[2019-07-20T13:43:59.103891442Z] Registering GET, /tasks                      
DEBU[2019-07-20T13:43:59.104073640Z] Registering GET, /tasks/{id}                 
DEBU[2019-07-20T13:43:59.104706782Z] Registering GET, /tasks/{id}/logs            
DEBU[2019-07-20T13:43:59.104799670Z] Registering GET, /secrets                    
DEBU[2019-07-20T13:43:59.105277477Z] Registering POST, /secrets/create            
DEBU[2019-07-20T13:43:59.105382089Z] Registering DELETE, /secrets/{id}            
DEBU[2019-07-20T13:43:59.105723551Z] Registering GET, /secrets/{id}               
DEBU[2019-07-20T13:43:59.105999415Z] Registering POST, /secrets/{id}/update       
DEBU[2019-07-20T13:43:59.106514862Z] Registering GET, /configs                    
DEBU[2019-07-20T13:43:59.106595170Z] Registering POST, /configs/create            
DEBU[2019-07-20T13:43:59.106746709Z] Registering DELETE, /configs/{id}            
DEBU[2019-07-20T13:43:59.107048114Z] Registering GET, /configs/{id}               
DEBU[2019-07-20T13:43:59.107161440Z] Registering POST, /configs/{id}/update       
DEBU[2019-07-20T13:43:59.107278576Z] Registering GET, /plugins                    
DEBU[2019-07-20T13:43:59.107533526Z] Registering GET, /plugins/{name:.*}/json     
DEBU[2019-07-20T13:43:59.107818567Z] Registering GET, /plugins/privileges         
DEBU[2019-07-20T13:43:59.107923456Z] Registering DELETE, /plugins/{name:.*}       
DEBU[2019-07-20T13:43:59.108085844Z] Registering POST, /plugins/{name:.*}/enable  
DEBU[2019-07-20T13:43:59.108225627Z] Registering POST, /plugins/{name:.*}/disable 
DEBU[2019-07-20T13:43:59.108341157Z] Registering POST, /plugins/pull              
DEBU[2019-07-20T13:43:59.108648089Z] Registering POST, /plugins/{name:.*}/push    
DEBU[2019-07-20T13:43:59.108849376Z] Registering POST, /plugins/{name:.*}/upgrade 
DEBU[2019-07-20T13:43:59.109069201Z] Registering POST, /plugins/{name:.*}/set     
DEBU[2019-07-20T13:43:59.109265051Z] Registering POST, /plugins/create            
DEBU[2019-07-20T13:43:59.109383016Z] Registering GET, /distribution/{name:.*}/json 
DEBU[2019-07-20T13:43:59.109796928Z] Registering POST, /grpc                      
DEBU[2019-07-20T13:43:59.109871886Z] Registering GET, /networks                   
DEBU[2019-07-20T13:43:59.109921659Z] Registering GET, /networks/                  
DEBU[2019-07-20T13:43:59.110013032Z] Registering GET, /networks/{id:.+}           
DEBU[2019-07-20T13:43:59.110133788Z] Registering POST, /networks/create           
DEBU[2019-07-20T13:43:59.110404869Z] Registering POST, /networks/{id:.*}/connect  
DEBU[2019-07-20T13:43:59.110522460Z] Registering POST, /networks/{id:.*}/disconnect 
DEBU[2019-07-20T13:43:59.110651491Z] Registering POST, /networks/prune            
DEBU[2019-07-20T13:43:59.110821311Z] Registering DELETE, /networks/{id:.*}        
INFO[2019-07-20T13:43:59.111450901Z] API listen on /var/run/docker.sock           

@thaJeztah
Copy link
Member Author
thaJeztah commented Jul 20, 2019

This branch again, using Go 1.12.7-buster

make GO_VERSION=1.12.7-buster binary shell

root@49138986ee72:/go/src/github.com/docker/docker# dockerd --debug
INFO[2019-07-20T13:52:09.978749210Z] Starting up  
...
INFO[2019-07-20T13:52:13.204165714Z] API listen on /var/run/docker.sock 

And without iptables

root@49138986ee72:/go/src/github.com/docker/docker# dockerd --debug --iptables=false
INFO[2019-07-20T13:53:36.291893144Z] Starting up                                  
...
INFO[2019-07-20T13:53:36.455966790Z] API listen on /var/run/docker.sock 

So looks to be due to buster (perhaps the iptables version in buster switching to nftables?)

root@49138986ee72:/go/src/github.com/docker/docker# dockerd --debug
INFO[2019-07-20T13:52:09.978749210Z] Starting up                                  
DEBU[2019-07-20T13:52:09.979405467Z] Listener created for HTTP on unix (/var/run/docker.sock) 
DEBU[2019-07-20T13:52:09.979514477Z] Containerd not running, starting daemon managed containerd 
INFO[2019-07-20T13:52:09.980418667Z] libcontainerd: started new containerd process  pid=250
INFO[2019-07-20T13:52:09.980477363Z] parsed scheme: "unix"                         module=grpc
INFO[2019-07-20T13:52:09.980487444Z] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2019-07-20T13:52:09.980525827Z] ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }  module=grpc
INFO[2019-07-20T13:52:09.980557659Z] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2019-07-20T13:52:09.980616844Z] pickfirstBalancer: HandleSubConnStateChange: 0xc00081e4d0, CONNECTING  module=grpc
INFO[2019-07-20T13:52:09.999840454Z] starting containerd                           revision=85f6aa58b8a3170aec9824568f7a31832878b603 version=v1.2.7
DEBU[2019-07-20T13:52:09.999974149Z] changing OOM score to -500                   
INFO[2019-07-20T13:52:10.000238266Z] loading plugin "io.containerd.content.v1.content"...  type=io.containerd.content.v1
INFO[2019-07-20T13:52:10.000355169Z] loading plugin "io.containerd.snapshotter.v1.btrfs"...  type=io.containerd.snapshotter.v1
WARN[2019-07-20T13:52:10.000727780Z] failed to load plugin io.containerd.snapshotter.v1.btrfs  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter"
INFO[2019-07-20T13:52:10.000819602Z] loading plugin "io.containerd.snapshotter.v1.aufs"...  type=io.containerd.snapshotter.v1
WARN[2019-07-20T13:52:10.001231355Z] failed to load plugin io.containerd.snapshotter.v1.aufs  error="modprobe aufs failed: "": exec: "modprobe": executable file not found in $PATH"
INFO[2019-07-20T13:52:10.001334215Z] loading plugin "io.containerd.snapshotter.v1.native"...  type=io.containerd.snapshotter.v1
INFO[2019-07-20T13:52:10.001410681Z] loading plugin "io.containerd.snapshotter.v1.overlayfs"...  type=io.containerd.snapshotter.v1
INFO[2019-07-20T13:52:10.001905735Z] loading plugin "io.containerd.snapshotter.v1.zfs"...  type=io.containerd.snapshotter.v1
WARN[2019-07-20T13:52:10.002268965Z] failed to load plugin io.containerd.snapshotter.v1.zfs  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter"
INFO[2019-07-20T13:52:10.002332313Z] loading plugin "io.containerd.metadata.v1.bolt"...  type=io.containerd.metadata.v1
WARN[2019-07-20T13:52:10.002406059Z] could not use snapshotter btrfs in metadata plugin  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.btrfs must be a btrfs filesystem to be used with the btrfs snapshotter"
WARN[2019-07-20T13:52:10.002434683Z] could not use snapshotter aufs in metadata plugin  error="modprobe aufs failed: "": exec: "modprobe": executable file not found in $PATH"
WARN[2019-07-20T13:52:10.002466193Z] could not use snapshotter zfs in metadata plugin  error="path /var/lib/docker/containerd/daemon/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter"
INFO[2019-07-20T13:52:10.007072601Z] loading plugin "io.containerd.differ.v1.walking"...  type=io.containerd.differ.v1
INFO[2019-07-20T13:52:10.007111274Z] loading plugin "io.containerd.gc.v1.scheduler"...  type=io.containerd.gc.v1
INFO[2019-07-20T13:52:10.007179833Z] loading plugin "io.containerd.service.v1.containers-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:52:10.007214568Z] loading plugin "io.containerd.service.v1.content-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:52:10.007224000Z] loading plugin "io.containerd.service.v1.diff-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:52:10.007232225Z] loading plugin "io.containerd.service.v1.images-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:52:10.007240139Z] loading plugin "io.containerd.service.v1.leases-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:52:10.007248010Z] loading plugin "io.containerd.service.v1.namespaces-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:52:10.007338681Z] loading plugin "io.containerd.service.v1.snapshots-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:52:10.007497765Z] loading plugin "io.containerd.runtime.v1.linux"...  type=io.containerd.runtime.v1
INFO[2019-07-20T13:52:10.007775550Z] loading plugin "io.containerd.runtime.v2.task"...  type=io.containerd.runtime.v2
INFO[2019-07-20T13:52:10.007899939Z] loading plugin "io.containerd.monitor.v1.cgroups"...  type=io.containerd.monitor.v1
INFO[2019-07-20T13:52:10.008381463Z] loading plugin "io.containerd.service.v1.tasks-service"...  type=io.containerd.service.v1
INFO[2019-07-20T13:52:10.008421173Z] loading plugin "io.containerd.internal.v1.restart"...  type=io.containerd.internal.v1
INFO[2019-07-20T13:52:10.008499975Z] loading plugin "io.containerd.grpc.v1.containers"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.008600723Z] loading plugin "io.containerd.grpc.v1.content"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.008681287Z] loading plugin "io.containerd.grpc.v1.diff"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.008862725Z] loading plugin "io.containerd.grpc.v1.events"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.008962709Z] loading plugin "io.containerd.grpc.v1.healthcheck"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.009003384Z] loading plugin "io.containerd.grpc.v1.images"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.009024402Z] loading plugin "io.containerd.grpc.v1.leases"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.009054929Z] loading plugin "io.containerd.grpc.v1.namespaces"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.009064513Z] loading plugin "io.containerd.internal.v1.opt"...  type=io.containerd.internal.v1
INFO[2019-07-20T13:52:10.009869676Z] loading plugin "io.containerd.grpc.v1.snapshots"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.009906522Z] loading plugin "io.containerd.grpc.v1.tasks"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.009937473Z] loading plugin "io.containerd.grpc.v1.version"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.009947156Z] loading plugin "io.containerd.grpc.v1.introspection"...  type=io.containerd.grpc.v1
INFO[2019-07-20T13:52:10.010316905Z] serving...                                    address="/var/run/docker/containerd/containerd-debug.sock"
INFO[2019-07-20T13:52:10.010410130Z] serving...                                    address="/var/run/docker/containerd/containerd.sock"
INFO[2019-07-20T13:52:10.010441052Z] containerd successfully booted in 0.011324s  
INFO[2019-07-20T13:52:10.014554253Z] pickfirstBalancer: HandleSubConnStateChange: 0xc00081e4d0, READY  module=grpc
DEBU[2019-07-20T13:52:10.015774102Z] Started daemon managed containerd            
DEBU[2019-07-20T13:52:10.016958039Z] Golang's threads limit set to 14130          
INFO[2019-07-20T13:52:10.018069798Z] parsed scheme: "unix"                         module=grpc
INFO[2019-07-20T13:52:10.018212017Z] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2019-07-20T13:52:10.018347812Z] ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }  module=grpc
INFO[2019-07-20T13:52:10.018519793Z] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2019-07-20T13:52:10.018823622Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0001f0520, CONNECTING  module=grpc
INFO[2019-07-20T13:52:10.018902034Z] blockingPicker: the picked transport is not ready, loop back to repick  module=grpc
INFO[2019-07-20T13:52:10.020793879Z] pickfirstBalancer: HandleSubConnStateChange: 0xc0001f0520, READY  module=grpc
INFO[2019-07-20T13:52:10.021778631Z] parsed scheme: "unix"                         module=grpc
INFO[2019-07-20T13:52:10.021815973Z] scheme "unix" not registered, fallback to default scheme  module=grpc
INFO[2019-07-20T13:52:10.021833501Z] ccResolverWrapper: sending update to cc: {[{unix:///var/run/docker/containerd/containerd.sock 0  <nil>}] }  module=grpc
INFO[2019-07-20T13:52:10.021839536Z] ClientConn switching balancer to "pick_first"  module=grpc
INFO[2019-07-20T13:52:10.021906695Z] pickfirstBalancer: HandleSubConnStateChange: 0xc00081eaf0, CONNECTING  module=grpc
INFO[2019-07-20T13:52:10.022607639Z] pickfirstBalancer: HandleSubConnStateChange: 0xc00081eaf0, READY  module=grpc
DEBU[2019-07-20T13:52:10.023311189Z] Using default logging driver json-file       
DEBU[2019-07-20T13:52:10.023368339Z] [graphdriver] priority list: [btrfs zfs overlay2 aufs overlay devicemapper vfs] 
DEBU[2019-07-20T13:52:10.023830810Z] processing event stream                       module=libcontainerd namespace=plugins.moby
DEBU[2019-07-20T13:52:10.024312877Z] zfs command is not available: exec: "zfs": executable file not found in $PATH  storage-driver=zfs
DEBU[2019-07-20T13:52:10.025077087Z] backingFs=extfs, projectQuotaSupported=false, indexOff=""  storage-driver=overlay2
DEBU[2019-07-20T13:52:10.025148093Z] Initialized graph driver overlay2            
DEBU[2019-07-20T13:52:10.045355408Z] Max Concurrent Downloads: 3                  
DEBU[2019-07-20T13:52:10.045572319Z] Max Concurrent Uploads: 5                    
INFO[2019-07-20T13:52:10.045732011Z] Loading containers: start.                   
DEBU[2019-07-20T13:52:10.045975154Z] Option Experimental: false                   
DEBU[2019-07-20T13:52:10.046107073Z] Option DefaultDriver: bridge                 
DEBU[2019-07-20T13:52:10.046263662Z] Option DefaultNetwork: bridge                
DEBU[2019-07-20T13:52:10.046361520Z] Network Control Plane MTU: 1500              
WARN[2019-07-20T13:52:10.046731660Z] Running modprobe bridge br_netfilter failed with message: , error: exec: "modprobe": executable file not found in $PATH 
WARN[2019-07-20T13:52:10.046906708Z] Running modprobe nf_nat failed with message: ``, error: exec: "modprobe": executable file not found in $PATH 
WARN[2019-07-20T13:52:10.047062494Z] Running modprobe xt_conntrack failed with message: ``, error: exec: "modprobe": executable file not found in $PATH 
DEBU[2019-07-20T13:52:10.047303078Z] Fail to initialize firewalld: Failed to connect to D-Bus system bus: dial unix /var/run/dbus/system_bus_socket: connect: no such file or directory, using raw iptables instead 
DEBU[2019-07-20T13:52:10.048124236Z] processing event stream                       module=libcontainerd namespace=moby
DEBU[2019-07-20T13:52:10.109609400Z] garbage collected                             d=1.603412ms
DEBU[2019-07-20T13:52:10.284720443Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION] 
DEBU[2019-07-20T13:52:10.287413180Z] /usr/sbin/iptables, [--wait -t nat -D PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:52:10.288952970Z] /usr/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL ! --dst 127.0.0.0/8 -j DOCKER] 
DEBU[2019-07-20T13:52:10.290463343Z] /usr/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:52:10.291809321Z] /usr/sbin/iptables, [--wait -t nat -D PREROUTING] 
DEBU[2019-07-20T13:52:10.292929764Z] /usr/sbin/iptables, [--wait -t nat -D OUTPUT] 
DEBU[2019-07-20T13:52:10.294004207Z] /usr/sbin/iptables, [--wait -t nat -F DOCKER] 
DEBU[2019-07-20T13:52:10.390865694Z] /usr/sbin/iptables, [--wait -t nat -X DOCKER] 
DEBU[2019-07-20T13:52:10.393316532Z] /usr/sbin/iptables, [--wait -t filter -F DOCKER] 
DEBU[2019-07-20T13:52:10.501792703Z] /usr/sbin/iptables, [--wait -t filter -X DOCKER] 
DEBU[2019-07-20T13:52:10.504246752Z] /usr/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:52:10.590594580Z] /usr/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:52:10.592778781Z] /usr/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:52:10.712410569Z] /usr/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:52:10.714681844Z] /usr/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION] 
DEBU[2019-07-20T13:52:10.810837616Z] /usr/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION] 
DEBU[2019-07-20T13:52:10.812961347Z] /usr/sbin/iptables, [--wait -t nat -n -L DOCKER] 
DEBU[2019-07-20T13:52:10.920925093Z] /usr/sbin/iptables, [--wait -t nat -N DOCKER] 
DEBU[2019-07-20T13:52:11.030845040Z] /usr/sbin/iptables, [--wait -t filter -n -L DOCKER] 
DEBU[2019-07-20T13:52:11.120967423Z] /usr/sbin/iptables, [--wait -t filter -N DOCKER] 
DEBU[2019-07-20T13:52:11.210098506Z] /usr/sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:52:11.321267049Z] /usr/sbin/iptables, [--wait -t filter -N DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:52:11.420334246Z] /usr/sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:52:11.521426681Z] /usr/sbin/iptables, [--wait -t filter -N DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:52:11.620130897Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -j RETURN] 
DEBU[2019-07-20T13:52:11.622455961Z] /usr/sbin/iptables, [--wait -A DOCKER-ISOLATION-STAGE-1 -j RETURN] 
DEBU[2019-07-20T13:52:11.730354258Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -j RETURN] 
DEBU[2019-07-20T13:52:11.732466424Z] /usr/sbin/iptables, [--wait -A DOCKER-ISOLATION-STAGE-2 -j RETURN] 
INFO[2019-07-20T13:52:11.822314412Z] Default bridge (docker0) is assigned with an IP address 172.18.0.0/16. Daemon option --bip can be used to set a preferred IP address 
DEBU[2019-07-20T13:52:11.822373388Z] Allocating IPv4 pools for network bridge (9d59137d3cfd295d79d881eba9ebf219695a519054b7259b8cf38553ee2cc661) 
DEBU[2019-07-20T13:52:11.822386851Z] RequestPool(LocalDefault, 172.18.0.0/16, , map[], false) 
DEBU[2019-07-20T13:52:11.822412066Z] RequestAddress(LocalDefault/172.18.0.0/16, <nil>, map[RequestAddressType:com.docker.network.gateway]) 
DEBU[2019-07-20T13:52:11.822451703Z] Request address PoolID:172.18.0.0/16 App: ipam/default/data, ID: LocalDefault/172.18.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65534, Sequence: (0x80000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 Serial:false PrefAddress:<nil>  
DEBU[2019-07-20T13:52:11.822914250Z] Did not find any interface with name docker0: Link not found 
DEBU[2019-07-20T13:52:11.823631767Z] Setting bridge mac address to 02:42:0b:67:7c:01 
DEBU[2019-07-20T13:52:11.823701112Z] Assigning address to bridge interface docker0: 172.18.0.1/16 
DEBU[2019-07-20T13:52:11.823797510Z] /usr/sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.18.0.0/16 ! -o docker0 -j MASQUERADE] 
DEBU[2019-07-20T13:52:11.825612580Z] /usr/sbin/iptables, [--wait -t nat -I POSTROUTING -s 172.18.0.0/16 ! -o docker0 -j MASQUERADE] 
DEBU[2019-07-20T13:52:11.940649314Z] /usr/sbin/iptables, [--wait -t nat -C DOCKER -i docker0 -j RETURN] 
DEBU[2019-07-20T13:52:11.942903068Z] /usr/sbin/iptables, [--wait -t nat -I DOCKER -i docker0 -j RETURN] 
DEBU[2019-07-20T13:52:12.071067152Z] /usr/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP] 
DEBU[2019-07-20T13:52:12.073693095Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:52:12.075642391Z] /usr/sbin/iptables, [--wait -I FORWARD -i docker0 -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:52:12.202138068Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:52:12.205042528Z] /usr/sbin/iptables, [--wait -I FORWARD -i docker0 ! -o docker0 -j ACCEPT] 
DEBU[2019-07-20T13:52:12.292456857Z] /usr/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:52:12.295121779Z] /usr/sbin/iptables, [--wait -t nat -A PREROUTING -m addrtype --dst-type LOCAL -j DOCKER] 
DEBU[2019-07-20T13:52:12.380507932Z] /usr/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8] 
DEBU[2019-07-20T13:52:12.382991028Z] /usr/sbin/iptables, [--wait -t nat -A OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8] 
DEBU[2019-07-20T13:52:12.500406574Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:52:12.502510185Z] /usr/sbin/iptables, [--wait -I FORWARD -o docker0 -j DOCKER] 
DEBU[2019-07-20T13:52:12.580091508Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:52:12.583393903Z] /usr/sbin/iptables, [--wait -I FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] 
DEBU[2019-07-20T13:52:12.700202100Z] /usr/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:52:12.702494185Z] /usr/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION-STAGE-1] 
DEBU[2019-07-20T13:52:12.831939461Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:52:12.833959600Z] /usr/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] 
DEBU[2019-07-20T13:52:12.932188918Z] /usr/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
DEBU[2019-07-20T13:52:12.934230515Z] /usr/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] 
INFO[2019-07-20T13:52:13.056828022Z] Loading containers: done.                    
INFO[2019-07-20T13:52:13.130393519Z] Docker daemon              
4B92
                   commit=4dc163ef31 graphdriver(s)=overlay2 version=dev
INFO[2019-07-20T13:52:13.130578475Z] Daemon has completed initialization          
DEBU[2019-07-20T13:52:13.188877697Z] Registering routers                          
DEBU[2019-07-20T13:52:13.188965785Z] Registering GET, /containers/{name:.*}/checkpoints 
DEBU[2019-07-20T13:52:13.189046538Z] Registering POST, /containers/{name:.*}/checkpoints 
DEBU[2019-07-20T13:52:13.189131158Z] Registering DELETE, /containers/{name}/checkpoints/{checkpoint} 
DEBU[2019-07-20T13:52:13.189246048Z] Registering HEAD, /containers/{name:.*}/archive 
DEBU[2019-07-20T13:52:13.189308494Z] Registering GET, /containers/json            
DEBU[2019-07-20T13:52:13.189384455Z] Registering GET, /containers/{name:.*}/export 
DEBU[2019-07-20T13:52:13.189543270Z] Registering GET, /containers/{name:.*}/changes 
DEBU[2019-07-20T13:52:13.189628383Z] Registering GET, /containers/{name:.*}/json  
DEBU[2019-07-20T13:52:13.189747383Z] Registering GET, /containers/{name:.*}/top   
DEBU[2019-07-20T13:52:13.189831216Z] Registering GET, /containers/{name:.*}/logs  
DEBU[2019-07-20T13:52:13.189960716Z] Registering GET, /containers/{name:.*}/stats 
DEBU[2019-07-20T13:52:13.190083490Z] Registering GET, /containers/{name:.*}/attach/ws 
DEBU[2019-07-20T13:52:13.190319086Z] Registering GET, /exec/{id:.*}/json          
DEBU[2019-07-20T13:52:13.190409075Z] Registering GET, /containers/{name:.*}/archive 
DEBU[2019-07-20T13:52:13.190559022Z] Registering POST, /containers/create         
DEBU[2019-07-20T13:52:13.190623555Z] Registering POST, /containers/{name:.*}/kill 
DEBU[2019-07-20T13:52:13.190695544Z] Registering POST, /containers/{name:.*}/pause 
DEBU[2019-07-20T13:52:13.190774780Z] Registering POST, /containers/{name:.*}/unpause 
DEBU[2019-07-20T13:52:13.190874382Z] Registering POST, /containers/{name:.*}/restart 
DEBU[2019-07-20T13:52:13.190998050Z] Registering POST, /containers/{name:.*}/start 
DEBU[2019-07-20T13:52:13.191073416Z] Registering POST, /containers/{name:.*}/stop 
DEBU[2019-07-20T13:52:13.191192505Z] Registering POST, /containers/{name:.*}/wait 
DEBU[2019-07-20T13:52:13.191282822Z] Registering POST, /containers/{name:.*}/resize 
DEBU[2019-07-20T13:52:13.191350619Z] Registering POST, /containers/{name:.*}/attach 
DEBU[2019-07-20T13:52:13.191594427Z] Registering POST, /containers/{name:.*}/copy 
DEBU[2019-07-20T13:52:13.191698813Z] Registering POST, /containers/{name:.*}/exec 
DEBU[2019-07-20T13:52:13.191834671Z] Registering POST, /exec/{name:.*}/start      
DEBU[2019-07-20T13:52:13.191943986Z] Registering POST, /exec/{name:.*}/resize     
DEBU[2019-07-20T13:52:13.192037450Z] Registering POST, /containers/{name:.*}/rename 
DEBU[2019-07-20T13:52:13.192165584Z] Registering POST, /containers/{name:.*}/update 
DEBU[2019-07-20T13:52:13.192273130Z] Registering POST, /containers/prune          
DEBU[2019-07-20T13:52:13.192375256Z] Registering POST, /commit                    
DEBU[2019-07-20T13:52:13.192452859Z] Registering PUT, /containers/{name:.*}/archive 
DEBU[2019-07-20T13:52:13.192544928Z] Registering DELETE, /containers/{name:.*}    
DEBU[2019-07-20T13:52:13.192677853Z] Registering GET, /images/json                
DEBU[2019-07-20T13:52:13.192793124Z] Registering GET, /images/search              
DEBU[2019-07-20T13:52:13.192834332Z] Registering GET, /images/get                 
DEBU[2019-07-20T13:52:13.192860181Z] Registering GET, /images/{name:.*}/get       
DEBU[2019-07-20T13:52:13.192991451Z] Registering GET, /images/{name:.*}/history   
DEBU[2019-07-20T13:52:13.193082658Z] Registering GET, /images/{name:.*}/json      
DEBU[2019-07-20T13:52:13.193201834Z] Registering POST, /images/load               
DEBU[2019-07-20T13:52:13.193272702Z] Registering POST, /images/create             
DEBU[2019-07-20T13:52:13.193313909Z] Registering POST, /images/{name:.*}/push     
DEBU[2019-07-20T13:52:13.193376994Z] Registering POST, /images/{name:.*}/tag      
DEBU[2019-07-20T13:52:13.193431720Z] Registering POST, /images/prune              
DEBU[2019-07-20T13:52:13.193536341Z] Registering DELETE, /images/{name:.*}        
DEBU[2019-07-20T13:52:13.193656531Z] Registering OPTIONS, /{anyroute:.*}          
DEBU[2019-07-20T13:52:13.193742106Z] Registering GET, /_ping                      
DEBU[2019-07-20T13:52:13.193832868Z] Registering HEAD, /_ping                     
DEBU[2019-07-20T13:52:13.193897539Z] Registering GET, /events                     
DEBU[2019-07-20T13:52:13.194000931Z] Registering GET, /info                       
DEBU[2019-07-20T13:52:13.194081038Z] Registering GET, /version                    
DEBU[2019-07-20T13:52:13.194176986Z] Registering GET, /system/df                  
DEBU[2019-07-20T13:52:13.194278775Z] Registering POST, /auth                      
DEBU[2019-07-20T13:52:13.194395157Z] Registering GET, /volumes                    
DEBU[2019-07-20T13:52:13.194576580Z] Registering GET, /volumes/{name:.*}          
DEBU[2019-07-20T13:52:13.194693046Z] Registering POST, /volumes/create            
DEBU[2019-07-20T13:52:13.194772428Z] Registering POST, /volumes/prune             
DEBU[2019-07-20T13:52:13.194819596Z] Registering DELETE, /volumes/{name:.*}       
DEBU[2019-07-20T13:52:13.194930267Z] Registering POST, /build                     
DEBU[2019-07-20T13:52:13.195011291Z] Registering POST, /build/prune               
DEBU[2019-07-20T13:52:13.195089517Z] Registering POST, /build/cancel              
DEBU[2019-07-20T13:52:13.195129732Z] Registering POST, /session                   
DEBU[2019-07-20T13:52:13.195174332Z] Registering POST, /swarm/init                
DEBU[2019-07-20T13:52:13.195210966Z] Registering POST, /swarm/join                
DEBU[2019-07-20T13:52:13.195299952Z] Registering POST, /swarm/leave               
DEBU[2019-07-20T13:52:13.195356614Z] Registering GET, /swarm                      
DEBU[2019-07-20T13:52:13.195466608Z] Registering GET, /swarm/unlockkey            
DEBU[2019-07-20T13:52:13.195532986Z] Registering POST, /swarm/update              
DEBU[2019-07-20T13:52:13.195596306Z] Registering POST, /swarm/unlock              
DEBU[2019-07-20T13:52:13.195665788Z] Registering GET, /services                   
DEBU[2019-07-20T13:52:13.195749722Z] Registering GET, /services/{id}              
DEBU[2019-07-20T13:52:13.195863104Z] Registering POST, /services/create           
DEBU[2019-07-20T13:52:13.195945480Z] Registering POST, /services/{id}/update      
DEBU[2019-07-20T13:52:13.196062081Z] Registering DELETE, /services/{id}           
DEBU[2019-07-20T13:52:13.196144613Z] Registering GET, /services/{id}/logs         
DEBU[2019-07-20T13:52:13.196283676Z] Registering GET, /nodes                      
DEBU[2019-07-20T13:52:13.196352348Z] Registering GET, /nodes/{id}                 
DEBU[2019-07-20T13:52:13.196411496Z] Registering DELETE, /nodes/{id}              
DEBU[2019-07-20T13:52:13.196549176Z] Registering POST, /nodes/{id}/update         
DEBU[2019-07-20T13:52:13.196672402Z] Registering GET, /tasks                      
DEBU[2019-07-20T13:52:13.196715017Z] Registering GET, /tasks/{id}                 
DEBU[2019-07-20T13:52:13.196832083Z] Registering GET, /tasks/{id}/logs            
DEBU[2019-07-20T13:52:13.196957736Z] Registering GET, /secrets                    
DEBU[2019-07-20T13:52:13.197044819Z] Registering POST, /secrets/create            
DEBU[2019-07-20T13:52:13.197120735Z] Registering DELETE, /secrets/{id}            
DEBU[2019-07-20T13:52:13.197345596Z] Registering GET, /secrets/{id}               
DEBU[2019-07-20T13:52:13.197605670Z] Registering POST, /secrets/{id}/update       
DEBU[2019-07-20T13:52:13.197696826Z] Registering GET, /configs                    
DEBU[2019-07-20T13:52:13.197810052Z] Registering POST, /configs/create            
DEBU[2019-07-20T13:52:13.197863296Z] Registering DELETE, /configs/{id}            
DEBU[2019-07-20T13:52:13.197958411Z] Registering GET, /configs/{id}               
DEBU[2019-07-20T13:52:13.198079990Z] Registering POST, /configs/{id}/update       
DEBU[2019-07-20T13:52:13.198228803Z] Registering GET, /plugins                    
DEBU[2019-07-20T13:52:13.198316213Z] Registering GET, /plugins/{name:.*}/json     
DEBU[2019-07-20T13:52:13.198437497Z] Registering GET, /plugins/privileges         
DEBU[2019-07-20T13:52:13.198592469Z] Registering DELETE, /plugins/{name:.*}       
DEBU[2019-07-20T13:52:13.198679045Z] Registering POST, /plugins/{name:.*}/enable  
DEBU[2019-07-20T13:52:13.198816634Z] Registering POST, /plugins/{name:.*}/disable 
DEBU[2019-07-20T13:52:13.198954057Z] Registering POST, /plugins/pull              
DEBU[2019-07-20T13:52:13.199258961Z] Registering POST, /plugins/{name:.*}/push    
DEBU[2019-07-20T13:52:13.199538469Z] Registering POST, /plugins/{name:.*}/upgrade 
DEBU[2019-07-20T13:52:13.199874100Z] Registering POST, /plugins/{name:.*}/set     
DEBU[2019-07-20T13:52:13.200210809Z] Registering POST, /plugins/create            
DEBU[2019-07-20T13:52:13.200484350Z] Registering GET, /distribution/{name:.*}/json 
DEBU[2019-07-20T13:52:13.200719054Z] Registering POST, /grpc                      
DEBU[2019-07-20T13:52:13.201024715Z] Registering GET, /networks                   
DEBU[2019-07-20T13:52:13.201137724Z] Registering GET, /networks/                  
DEBU[2019-07-20T13:52:13.201272939Z] Registering GET, /networks/{id:.+}           
DEBU[2019-07-20T13:52:13.201604404Z] Registering POST, /networks/create           
DEBU[2019-07-20T13:52:13.201874791Z] Registering POST, /networks/{id:.*}/connect  
DEBU[2019-07-20T13:52:13.202290607Z] Registering POST, /networks/{id:.*}/disconnect 
DEBU[2019-07-20T13:52:13.202964762Z] Registering POST, /networks/prune            
DEBU[2019-07-20T13:52:13.203093562Z] Registering DELETE, /networks/{id:.*}        
INFO[2019-07-20T13:52:13.204165714Z] API listen on /var/run/docker.sock      

@thaJeztah
Copy link
Member Author

Added a bit of debugging for ``, and printing ifconfig as well as content of `/etc/hosts` and `/etc/resolv.conf` before doing the `ping`;

14:17:20 --- FAIL: TestHostnameDnsResolution (1.84s)
14:17:20     run_linux_test.go:127: eth0      Link encap:Ethernet  HWaddr 02:42:AC:14:00:02  
14:17:20                   inet addr:172.20.0.2  Bcast:172.20.255.255  Mask:255.255.0.0
14:17:20                   UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
14:17:20                   RX packets:0 errors:0 dropped:0 overruns:0 frame:0
14:17:20                   TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
14:17:20                   collisions:0 txqueuelen:0 
14:17:20                   RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)
14:17:20         
14:17:20         lo        Link encap:Local Loopback  
14:17:20                   inet addr:127.0.0.1  Mask:255.0.0.0
14:17:20                   UP LOOPBACK RUNNING  MTU:65536  Metric:1
14:17:20                   RX packets:0 errors:0 dropped:0 overruns:0 frame:0
14:17:20                   TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
14:17:20                   collisions:0 txqueuelen:1 
14:17:20                   RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)
14:17:20         
14:17:20         127.0.0.1	localhost
14:17:20         ::1	localhost ip6-localhost ip6-loopback
14:17:20         fe00::0	ip6-localnet
14:17:20         ff00::0	ip6-mcastprefix
14:17:20         ff02::1	ip6-allnodes
14:17:20         ff02::2	ip6-allrouters
14:17:20         172.20.0.2	foobar
14:17:20         search us-west-2.compute.internal
14:17:20         nameserver 127.0.0.11
14:17:20         options ndots:0
14:17:20         
14:17:20     run_linux_test.go:134: assertion failed: 
14:17:20         --- ←
14:17:20         +++ →
14:17:20         @@ -1 +1,2 @@
14:17:20         +ping: bad address 'foobar'
14:17:20          
14:17:20         
14:17:20     run_linux_test.go:135: assertion failed: 0 (int) != 1 (res.ExitCode int)

Nothing that really stands out there

@thaJeztah
Copy link
Member Author

Ok, found the problem (w.r.t. the failing tests); it's indeed because the CI machines run on Ubuntu 16.04, which uses legacy iptables, whereas the Debian buster image uses nftables. Because of this, iptables setup by the daemon inside the test-container won't work; DNS resolution fails (we don't even seem to hit the embedded dns).

Added a hacky few lines to the hack/dind script (which is used as entrypoint) to switch to iptables-legacy. That works (currently) because the CI machines are Ubuntu 16.04, but will break once those machines are updated to anything else (or on master, which also has RHEL machines running)

https://wiki.debian.org/iptables

Starting with Debian Buster, nf_tables is the default backend when using iptables, by means of the iptables-nft layer (i.e, using iptables syntax with the nf_tables kernel subsystem). This also affects ip6tables, arptables and ebtables.

@thaJeztah
Copy link
Member Author

Looks like the performance issue is due to nftables;

Switch to iptables-legacy:

update-alternatives --set iptables /usr/sbin/iptables-legacy   || true
update-alternatives --set ip6tables /usr/sbin/ip6tables-legacy || true
update-alternatives --set arptables /usr/sbin/arptables-legacy || true
update-alternatives --set ebtables /usr/sbin/ebtables-legacy   || true
dockerd
INFO[2019-07-22T15:29:22.489882236Z] Starting up            
INFO[2019-07-22T15:29:22.748612702Z] API listen on /var/run/docker.sock 
time docker network create foo
6b1cf1f980f2956453bb130b57181b9b9425e7084478e0c464281e2594c7e3c2

real	0m0.066s
user	0m0.020s
sys	0m0.000s

Switch to iptables-nft:

update-alternatives --set iptables /usr/sbin/iptables-nft   || true
update-alternatives --set ip6tables /usr/sbin/ip6tables-nft || true
update-alternatives --set arptables /usr/sbin/arptables-nft || true
update-alternatives --set ebtables /usr/sbin/ebtables-nft   || true
INFO[2019-07-22T15:29:56.853611304Z] Starting up                                  
INFO[2019-07-22T15:29:58.697647232Z] API listen on /var/run/docker.sock         
time docker network create bar
4f6808b29aba81f89469934440d6515a12987fcc4a6aecc6787907bb4361dc8f

real	0m0.567s
user	0m0.016s
sys	0m0.028s

@thaJeztah
Copy link
Member Author

switching to iptables-legacy fixes the tests;

15:28:00 === RUN   TestRenameAnonymousContainer
15:28:05 --- PASS: TestRenameAnonymousContainer (4.65s)
15:28:05 === RUN   TestHostnameDnsResolution
15:28:06 --- PASS: TestHostnameDnsResolution (0.82s)

hack/dind Outdated
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't this happen in the Dockerfile instead so we don't accidentally apply this change somewhere less harmless than a container like on a contributor's host machine?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's really a quick hack to see if it did the job
Surprisingly; when I did it as a RUN step, it gave a "permission denied; need to be root"

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh that's really odd -- AFAICT, we're not using USER or anything so it already should be root. 😓

(And doing update-alternatives shouldn't be running iptables or anything that might need additional privileges.)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's what I would expect as well; didn't look closely yet, but I suspect it's calling iptables (perhaps just to check if it's installed?)

@thaJeztah
Copy link
Member Author

Arg; forgot to remove -stretch after rebasing

21:32:00 Step 1/109 : ARG CROSS="false"
21:32:00 Step 2/109 : ARG GO_VERSION=1.13beta1
21:32:00 Step 3/109 : FROM golang:${GO_VERSION}-stretch AS base
21:32:01 manifest for golang:1.13beta1-stretch not found

@tianon
Copy link
Member
tianon commented Jul 22, 2019

Instead of removing it, I'd recommend switching it to be -buster explicitly. 👍

@thaJeztah
Copy link
Member Author

Yes, that's what I actually meant 😅 - updated 🤞

@thaJeztah
Copy link
Member Author

Will have to look into the Windows build failure; the file that it marks missing is on the repository; https://github.com/moby/moby/blob/master/vendor/cloud.google.com/go/compute/metadata/metadata.go

14:49:15 build github.com/docker/docker/cmd/dockerd: cannot load cloud.google.com/go/compute/metadata: open C:\go\src\cloud.google.com\go\compute\metadata: The system cannot find the path specified.
14:49:15 

@kolyshkin
Copy link
Contributor

Nitpick: Commit 03ce8a4 (gofmt 1.13) should come before 988c29e (bump go to 1.13) since doing otherwise is not git bisect friendly

@thaJeztah
Copy link
Member Author

Yes, was actually thinking of separating it from this PR (although it is "accepted" by older versions of Go)

@thaJeztah
Copy link
Member Author

Interesting; this is why validate is failing; https://ci.docker.com/public/job/moby/job/PR-39549/19/execution/node/202/log/?consoleFull

09:08:06  + docker run --rm -t --privileged -v /home/ubuntu/workspace/moby_PR-39549/bundles:/go/src/github.com/docker/docker/bundles -v /home/ubuntu/workspace/moby_PR-39549/.git:/go/src/github.com/docker/docker/.git --name docker-pr19 -e DOCKER_EXPERIMENTAL -e DOCKER_GITCOMMIT=c4e96d80730cf06193a0f182452b3e1748812763 -e DOCKER_GRAPHDRIVER docker:c4e96d80730cf06193a0f182452b3e1748812763 hack/validate/default
09:08:07  Congratulations!  All commits are properly signed with the DCO!
09:12:28  vendor/github.com/moby/buildkit/exporter/containerimage/exptypes/types.go:3:14:warning: could not import github.com/opencontainers/image-spec/specs-go/v1 (go/build: importGo github.com/opencontainers/image-spec/specs-go/v1: exit status 1 (gosimple)
09:12:28  ../../../../pkg/mod/github.com/golang/protobuf@v1.2.0/ptypes/any.go:43:2:warning: could not import github.com/golang/protobuf/ptypes/any (cannot find package "github.com/golang/protobuf/ptypes/any" in any of: (unconvert)
09:12:28  ../../../../pkg/mod/github.com/golang/protobuf@v1.2.0/ptypes/any.go:42:2:warning: could not import github.com/golang/protobuf/proto (cannot find package "github.com/golang/protobuf/proto" in any of: (unconvert)
...
09:12:28  builder/builder-next/adapters/containerimage/pull.go:71:9:warning: cannot use is (variable of type *imageSource) as source.Source value in return statement: wrong type for method Resolve (unconvert)
09:12:28  builder/builder-next/adapters/containerimage/pull.go:205:9:warning: cannot use p (variable of type *puller) as source.SourceInstance value in return statement: wrong type for method Snapshot (unconvert)
09:12:28  builder/builder-next/adapters/containerimage/pull.go:534:13:warning: cannot use p.src.Reference (variable with invalid type) as reference.Spec value in struct literal (unconvert)
09:12:28  builder/builder-next/adapters/localinlinecache/inlinecache.go:30:9:warning: cannot use (func(ctx context.Context, attrs map[string]string) (remotecache.Importer, specs.Descriptor, error) literal) (value of type func(ctx context.Context, attrs map[string]string) (remotecache.Importer, v1.Descriptor, error)) as remotecache.ResolveCacheImporterFunc value in return statement (unconvert)
09:12:28  builder/builder-next/adapters/localinlinecache/inlinecache.go:65:45:warning: cannot use cc (variable of type *v1.CacheChains) as solver.CacheExporterTarget value in argument to li.importInlineCache: wrong type for method Add (unconvert)
09:12:28  builder/builder-next/adapters/localinlinecache/inlinecache.go:56:9:warning: cannot use &(localImporter literal) (value of type *localImporter) as remotecache.Importer value in return statement: wrong type for method Resolve (unconvert)
...
09:12:28  vendor/google.golang.org/api/transport/grpc/go18.go:25:44:warning: cannot use &(ocgrpc.ClientHandler literal) (value of type *ocgrpc.ClientHandler) as stats.Handler value in argument to grpc.WithStatsHandler: wrong type for method HandleConn (unconvert)
09:12:28  vendor/google.golang.org/grpc/credentials/oauth/oauth.go:152:33:warning: cannot use config (variable of type *invalid type) as *jwt.Config value in struct literal (unconvert)
09:12:28  vendor/google.golang.org/grpc/internal/binarylog/method_logger.go:159:26:warning: cannot use ptypes.DurationProto(c.Timeout) (value of type *invalid type) as *duration.Duration value in assignment (unconvert)

Looking at this, it looks like go mod is kicking in

../../../../pkg/mod/github.com/golang/protobuf@v1.2.0/ptypes/any.go:43:2:warning: could not import github.com/golang/protobuf/ptypes/any (cannot find package "github.com/golang/protobuf/ptypes/any" in any of: (unconvert)

@thaJeztah
Copy link
Member Author
thaJeztah commented Sep 11, 2019

ha! looks likeGO111MODULE=off was what's causing fixed the issue. Everything is 💚 now.

Still wondering why it switched to use go mod, but perhaps it's because the hack/Dockerfile/install scripts work in a temp directory 🤔 (although I think they update the GOPATH accordingly)

Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
Signed-off-by: Sebastiaan van Stijn <github@gone.nl>
@thaJeztah thaJeztah changed the title [DO NOT MERGE] Bump go 1.13.0 Bump go 1.13.0 Sep 11, 2019
@thaJeztah
Copy link
Member Author

@kolyshkin @tiborvass @tianon this is all green now; ready for review!

@tiborvass
Copy link
Contributor

@seemethere @zelahi I'm afraid if we merge this, release scripts somewhere will not add the GO111MODULE=off.

Copy link
Member
@tianon tianon left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM 😄

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants
0