Skip to content

Instantly share code, notes, and snippets.

@tonistiigi
Created August 22, 2016 21:37
Show Gist options
  • Save tonistiigi/f3e7496e1b8523174d0729080705ea38 to your computer and use it in GitHub Desktop.
Save tonistiigi/f3e7496e1b8523174d0729080705ea38 to your computer and use it in GitHub Desktop.
diff --git a/integration-cli/docker_cli_swarm_test.go b/integration-cli/docker_cli_swarm_test.go
index c1401ac..3850853 100644
--- a/integration-cli/docker_cli_swarm_test.go
+++ b/integration-cli/docker_cli_swarm_test.go
@@ -51,7 +51,6 @@ func (s *DockerSwarmSuite) TestSwarmInit(c *check.C) {
c.Assert(spec.Dispatcher.HeartbeatPeriod, checker.Equals, uint64(11*time.Second))
c.Assert(d.Leave(true), checker.IsNil)
- time.Sleep(500 * time.Millisecond) // https://github.com/docker/swarmkit/issues/1421
out, err = d.Cmd("swarm", "init")
c.Assert(err, checker.IsNil, check.Commentf("out: %v", out))
diff --git a/vendor/src/github.com/docker/swarmkit/agent/node.go b/vendor/src/github.com/docker/swarmkit/agent/node.go
index 116436b..7d3a704 100644
--- a/vendor/src/github.com/docker/swarmkit/agent/node.go
+++ b/vendor/src/github.com/docker/swarmkit/agent/node.go
@@ -585,6 +585,7 @@ func (n *Node) runManager(ctx context.Context, securityConfig *ca.SecurityConfig
return ctx.Err()
}
remoteAddr, _ := n.remotes.Select(n.nodeID)
+ logrus.Infof("manager.New %v", ctx)
m, err := manager.New(&manager.Config{
ForceNewCluster: n.config.ForceNewCluster,
ProtoAddr: map[string]string{
@@ -604,8 +605,9 @@ func (n *Node) runManager(ctx context.Context, securityConfig *ca.SecurityConfig
}
done := make(chan struct{})
go func() {
- m.Run(context.Background()) // todo: store error
+ err := m.Run(context.Background()) // todo: store error
close(done)
+ logrus.Errorf("m.Run=%v", err)
}()
n.Lock()
time="2016-08-22T21:35:02.051715780Z" level=debug msg="docker group found. gid: 999"
time="2016-08-22T21:35:02.051754631Z" level=debug msg="Listener created for HTTP on unix (/tmp/docker-integration/d34826118.sock)"
time="2016-08-22T21:35:02.052057535Z" level=debug msg="libcontainerd: containerd connection state change: CONNECTING"
time="2016-08-22T21:35:02.052712419Z" level=debug msg="libcontainerd: containerd connection state change: READY"
time="2016-08-22T21:35:02.053182425Z" level=debug msg="Using default logging driver json-file"
time="2016-08-22T21:35:02.053211295Z" level=debug msg="Golang's threads limit set to 14220"
time="2016-08-22T21:35:02.053263544Z" level=debug msg="[graphdriver] trying provided driver: overlay"
time="2016-08-22T21:35:02.056465297Z" level=debug msg="Using graph driver overlay"
time="2016-08-22T21:35:02.056577124Z" level=debug msg="Max Concurrent Downloads: 3"
time="2016-08-22T21:35:02.056589142Z" level=debug msg="Max Concurrent Uploads: 5"
time="2016-08-22T21:35:02.098393678Z" level=info msg="Graph migration to content-addressability took 0.00 seconds"
time="2016-08-22T21:35:02.098677260Z" level=warning msg="Your kernel does not support swap memory limit."
time="2016-08-22T21:35:02.098706007Z" level=warning msg="Your kernel does not support kernel memory limit."
time="2016-08-22T21:35:02.098793258Z" level=warning msg="mountpoint for pids not found"
time="2016-08-22T21:35:02.099246704Z" level=debug msg="Option DefaultDriver: bridge"
time="2016-08-22T21:35:02.099260666Z" level=debug msg="Option DefaultNetwork: bridge"
time="2016-08-22T21:35:02.208295511Z" level=warning msg="Could not load necessary modules for IPSEC rules: Running modprobe xfrm_user failed with message: `modprobe: ERROR: ../libkmod/libkmod.c:557 kmod_search_moddep() could not open moddep file '/lib/modules/4.3.0-0.bpo.1-amd64/modules.dep.bin'`, error: exit status 1"
time="2016-08-22T21:35:02.208572011Z" level=info msg="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"
time="2016-08-22T21:35:02.208622975Z" level=debug msg="Allocating IPv4 pools for network bridge (29192db06bb0ab8e975b6e335aac8faef2de0b716c5533ea05eaf03e54ed19d9)"
time="2016-08-22T21:35:02.208643804Z" level=debug msg="RequestPool(LocalDefault, 172.18.0.0/16, , map[], false)"
time="2016-08-22T21:35:02.208685550Z" level=debug msg="RequestAddress(LocalDefault/172.18.0.0/16, 172.18.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2016-08-22T21:35:02.254040322Z" level=info msg="Daemon has completed initialization"
time="2016-08-22T21:35:02.254072429Z" level=info msg="Docker daemon" commit=unsupported graphdriver=overlay version=1.13.0-dev
time="2016-08-22T21:35:02.254172867Z" level=debug msg="Registering routers"
time="2016-08-22T21:35:02.254186001Z" level=debug msg="Registering HEAD, /containers/{name:.*}/archive"
time="2016-08-22T21:35:02.254326429Z" level=debug msg="Registering GET, /containers/json"
time="2016-08-22T21:35:02.254394279Z" level=debug msg="Registering GET, /containers/{name:.*}/export"
time="2016-08-22T21:35:02.254486565Z" level=debug msg="Registering GET, /containers/{name:.*}/changes"
time="2016-08-22T21:35:02.254569600Z" level=debug msg="Registering GET, /containers/{name:.*}/json"
time="2016-08-22T21:35:02.254677039Z" level=debug msg="Registering GET, /containers/{name:.*}/top"
time="2016-08-22T21:35:02.254764848Z" level=debug msg="Registering GET, /containers/{name:.*}/logs"
time="2016-08-22T21:35:02.254853029Z" level=debug msg="Registering GET, /containers/{name:.*}/stats"
time="2016-08-22T21:35:02.254928582Z" level=debug msg="Registering GET, /containers/{name:.*}/attach/ws"
time="2016-08-22T21:35:02.255011015Z" level=debug msg="Registering GET, /exec/{id:.*}/json"
time="2016-08-22T21:35:02.255093271Z" level=debug msg="Registering GET, /containers/{name:.*}/archive"
time="2016-08-22T21:35:02.255180134Z" level=debug msg="Registering POST, /containers/create"
time="2016-08-22T21:35:02.255237520Z" level=debug msg="Registering POST, /containers/{name:.*}/kill"
time="2016-08-22T21:35:02.255330499Z" level=debug msg="Registering POST, /containers/{name:.*}/pause"
time="2016-08-22T21:35:02.255409282Z" level=debug msg="Registering POST, /containers/{name:.*}/unpause"
time="2016-08-22T21:35:02.255490848Z" level=debug msg="Registering POST, /containers/{name:.*}/restart"
time="2016-08-22T21:35:02.255673683Z" level=debug msg="Registering POST, /containers/{name:.*}/start"
time="2016-08-22T21:35:02.255769111Z" level=debug msg="Registering POST, /containers/{name:.*}/stop"
time="2016-08-22T21:35:02.255844777Z" level=debug msg="Registering POST, /containers/{name:.*}/wait"
time="2016-08-22T21:35:02.255939514Z" level=debug msg="Registering POST, /containers/{name:.*}/resize"
time="2016-08-22T21:35:02.256014990Z" level=debug msg="Registering POST, /containers/{name:.*}/attach"
time="2016-08-22T21:35:02.256095877Z" level=debug msg="Registering POST, /containers/{name:.*}/copy"
time="2016-08-22T21:35:02.256252820Z" level=debug msg="Registering POST, /containers/{name:.*}/exec"
time="2016-08-22T21:35:02.256340452Z" level=debug msg="Registering POST, /exec/{name:.*}/start"
time="2016-08-22T21:35:02.256409442Z" level=debug msg="Registering POST, /exec/{name:.*}/resize"
time="2016-08-22T21:35:02.256486928Z" level=debug msg="Registering POST, /containers/{name:.*}/rename"
time="2016-08-22T21:35:02.256564972Z" level=debug msg="Registering POST, /containers/{name:.*}/update"
time="2016-08-22T21:35:02.256681929Z" level=debug msg="Registering PUT, /containers/{name:.*}/archive"
time="2016-08-22T21:35:02.256786053Z" level=debug msg="Registering DELETE, /containers/{name:.*}"
time="2016-08-22T21:35:02.256882211Z" level=debug msg="Registering GET, /images/json"
time="2016-08-22T21:35:02.256936280Z" level=debug msg="Registering GET, /images/search"
time="2016-08-22T21:35:02.256999750Z" level=debug msg="Registering GET, /images/get"
time="2016-08-22T21:35:02.257067969Z" level=debug msg="Registering GET, /images/{name:.*}/get"
time="2016-08-22T21:35:02.257159824Z" level=debug msg="Registering GET, /images/{name:.*}/history"
time="2016-08-22T21:35:02.257253868Z" level=debug msg="Registering GET, /images/{name:.*}/json"
time="2016-08-22T21:35:02.257336563Z" level=debug msg="Registering POST, /commit"
time="2016-08-22T21:35:02.257388325Z" level=debug msg="Registering POST, /images/load"
time="2016-08-22T21:35:02.257454340Z" level=debug msg="Registering POST, /images/create"
time="2016-08-22T21:35:02.257510533Z" level=debug msg="Registering POST, /images/{name:.*}/push"
time="2016-08-22T21:35:02.257590977Z" level=debug msg="Registering POST, /images/{name:.*}/tag"
time="2016-08-22T21:35:02.257703985Z" level=debug msg="Registering DELETE, /images/{name:.*}"
time="2016-08-22T21:35:02.257832642Z" level=debug msg="Registering OPTIONS, /{anyroute:.*}"
time="2016-08-22T21:35:02.257888201Z" level=debug msg="Registering GET, /_ping"
time="2016-08-22T21:35:02.257938445Z" level=debug msg="Registering GET, /events"
time="2016-08-22T21:35:02.257975000Z" level=debug msg="Registering GET, /info"
time="2016-08-22T21:35:02.258013822Z" level=debug msg="Registering GET, /version"
time="2016-08-22T21:35:02.258054326Z" level=debug msg="Registering POST, /auth"
time="2016-08-22T21:35:02.258099841Z" level=debug msg="Registering GET, /volumes"
time="2016-08-22T21:35:02.258170085Z" level=debug msg="Registering GET, /volumes/{name:.*}"
time="2016-08-22T21:35:02.258246013Z" level=debug msg="Registering POST, /volumes/create"
time="2016-08-22T21:35:02.258308710Z" level=debug msg="Registering DELETE, /volumes/{name:.*}"
time="2016-08-22T21:35:02.258379680Z" level=debug msg="Registering POST, /build"
time="2016-08-22T21:35:02.258415792Z" level=debug msg="Registering POST, /swarm/init"
time="2016-08-22T21:35:02.258461945Z" level=debug msg="Registering POST, /swarm/join"
time="2016-08-22T21:35:02.258504804Z" level=debug msg="Registering POST, /swarm/leave"
time="2016-08-22T21:35:02.258554835Z" level=debug msg="Registering GET, /swarm"
time="2016-08-22T21:35:02.258589699Z" level=debug msg="Registering POST, /swarm/update"
time="2016-08-22T21:35:02.258636085Z" level=debug msg="Registering GET, /services"
time="2016-08-22T21:35:02.258683230Z" level=debug msg="Registering GET, /services/{id:.*}"
time="2016-08-22T21:35:02.258758231Z" level=debug msg="Registering POST, /services/create"
time="2016-08-22T21:35:02.258805272Z" level=debug msg="Registering POST, /services/{id:.*}/update"
time="2016-08-22T21:35:02.258943209Z" level=debug msg="Registering DELETE, /services/{id:.*}"
time="2016-08-22T21:35:02.259020128Z" level=debug msg="Registering GET, /nodes"
time="2016-08-22T21:35:02.262407011Z" level=debug msg="Registering GET, /nodes/{id:.*}"
time="2016-08-22T21:35:02.262593529Z" level=debug msg="Registering DELETE, /nodes/{id:.*}"
time="2016-08-22T21:35:02.262735549Z" level=debug msg="Registering POST, /nodes/{id:.*}/update"
time="2016-08-22T21:35:02.262867408Z" level=debug msg="Registering GET, /tasks"
time="2016-08-22T21:35:02.262950106Z" level=debug msg="Registering GET, /tasks/{id:.*}"
time="2016-08-22T21:35:02.263068257Z" level=debug msg="Registering GET, /networks"
time="2016-08-22T21:35:02.263169906Z" level=debug msg="Registering GET, /networks/{id:.*}"
time="2016-08-22T21:35:02.263307525Z" level=debug msg="Registering POST, /networks/create"
time="2016-08-22T21:35:02.263413132Z" level=debug msg="Registering POST, /networks/{id:.*}/connect"
time="2016-08-22T21:35:02.263558356Z" level=debug msg="Registering POST, /networks/{id:.*}/disconnect"
time="2016-08-22T21:35:02.263703655Z" level=debug msg="Registering DELETE, /networks/{id:.*}"
time="2016-08-22T21:35:02.266333402Z" level=info msg="API listen on /tmp/docker-integration/d34826118.sock"
time="2016-08-22T21:35:02.538303319Z" level=debug msg="Calling GET /_ping"
time="2016-08-22T21:35:02.539407739Z" level=debug msg="Calling GET /info"
time="2016-08-22T21:35:02.589722507Z" level=debug msg="Calling POST /v1.25/images/load?quiet=1"
time="2016-08-22T21:35:02.657282558Z" level=debug msg="Start untar layer"
time="2016-08-22T21:35:02.760975492Z" level=debug msg="Untar time: 0.10366551800000001s"
time="2016-08-22T21:35:02.761059574Z" level=debug msg="Failed to unmount a19973ab5e84a3e63b439a7b7b89807db116326729d229188e1c5ad4c87c3a29 overlay: no such file or directory"
time="2016-08-22T21:35:02.761099663Z" level=debug msg="Applied tar sha256:8ac8bfaff55af948c796026ee867448c5b5b5d9dd3549f4006d9759b25d4a893 to a19973ab5e84a3e63b439a7b7b89807db116326729d229188e1c5ad4c87c3a29, size: 1092588"
time="2016-08-22T21:35:02.799324572Z" level=debug msg="Calling POST /v1.25/swarm/init"
time="2016-08-22T21:35:02.799412975Z" level=debug msg="form data: {\"AdvertiseAddr\":\"\",\"ForceNewCluster\":false,\"ListenAddr\":\"0.0.0.0:2377\",\"Spec\":{\"CAConfig\":{\"NodeCertExpiry\":1.08e+14},\"Dispatcher\":{\"HeartbeatPeriod\":1.1e+10},\"Orchestration\":{\"TaskHistoryRetentionLimit\":5},\"Raft\":{},\"TaskDefaults\":{}}}"
time="2016-08-22T21:35:02.878808831Z" level=debug msg="successfully loaded the Root CA: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-root-ca.crt"
time="2016-08-22T21:35:02.879620164Z" level=debug msg="successfully loaded the Root CA: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-root-ca.crt"
time="2016-08-22T21:35:02.879637473Z" level=debug msg="loaded local CA certificate: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-root-ca.crt."
time="2016-08-22T21:35:02.880089749Z" level=debug msg="loaded local TLS credentials: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-node.crt."
time="2016-08-22T21:35:02.880410491Z" level=debug msg="Requesting certificate for NodeID: 59mtz3tngme8b8xnc8fcx85mz"
time="2016-08-22T21:35:02.895365780Z" level=debug msg="successfully loaded the Root CA: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-root-ca.crt"
time="2016-08-22T21:35:02.896392688Z" level=info msg="manager.New context.Background.WithCancel.WithValue(log.loggerKey{}, &logrus.Entry{Logger:(*logrus.Logger)(0xc820012480), Data:logrus.Fields{\"module\":\"node\"}, Time:time.Time{sec:0, nsec:0, loc:(*time.Location)(nil)}, Level:0x0, Message:\"\"}).WithValue(log.moduleKey{}, \"node\")"
time="2016-08-22T21:35:02.897009759Z" level=info msg="Listening for local connections" addr="/var/lib/docker/tests/d34826118/root/swarm/control.sock" proto=unix
time="2016-08-22T21:35:02.897283890Z" level=info msg="Listening for connections" addr="[::]:2377" proto=tcp
time="2016-08-22T21:35:02.911330586Z" level=debug msg="(*Agent).run" module="node/agent"
time="2016-08-22T21:35:02.911702117Z" level=debug msg="(*session).start" module="node/agent"
time="2016-08-22T21:35:02.911698194Z" level=info msg="21d086ec79a0a29 became follower at term 0"
time="2016-08-22T21:35:02.921032258Z" level=info msg="newRaft 21d086ec79a0a29 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"
time="2016-08-22T21:35:02.921059118Z" level=info msg="21d086ec79a0a29 became follower at term 1"
time="2016-08-22T21:35:02.921134776Z" level=warning msg="21d086ec79a0a29 cannot campaign at term 1 since there are still 1 pending configuration changes to apply"
time="2016-08-22T21:35:02.929445334Z" level=info msg="21d086ec79a0a29 is starting a new election at term 1"
time="2016-08-22T21:35:02.936915397Z" level=info msg="21d086ec79a0a29 became candidate at term 2"
time="2016-08-22T21:35:02.936969877Z" level=info msg="21d086ec79a0a29 received vote from 21d086ec79a0a29 at term 2"
time="2016-08-22T21:35:02.937167590Z" level=info msg="21d086ec79a0a29 became leader at term 2"
time="2016-08-22T21:35:02.937253177Z" level=info msg="raft.node: 21d086ec79a0a29 elected leader 21d086ec79a0a29 at term 2"
time="2016-08-22T21:35:02.947535275Z" level=debug msg="RequestPool(GlobalDefault, 10.255.0.0/16, , map[], false)"
time="2016-08-22T21:35:02.947583134Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, <nil>, map[])"
time="2016-08-22T21:35:02.949606804Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, <nil>, map[])"
time="2016-08-22T21:35:02.951458063Z" level=debug msg="Root CA updated successfully" cluster.id=29fdohe2ms3poaomaq1enoyir method="(*Server).updateCluster" module=ca
time="2016-08-22T21:35:02.959244132Z" level=debug msg="Root CA updated successfully" cluster.id=29fdohe2ms3poaomaq1enoyir method="(*Server).updateCluster" module=ca
time="2016-08-22T21:35:03.051450262Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=59mtz3tngme8b8xnc8fcx85mz
time="2016-08-22T21:35:03.054258896Z" level=debug msg="(*session).listen" module="node/agent" session.id=4uc6neciix8dhvkmvo9jj74yp
time="2016-08-22T21:35:03.054498012Z" level=debug msg="(*session).heartbeat" module="node/agent" session.id=4uc6neciix8dhvkmvo9jj74yp
time="2016-08-22T21:35:03.054493160Z" level=debug msg="(*session).watch" module="node/agent" session.id=4uc6neciix8dhvkmvo9jj74yp
time="2016-08-22T21:35:03.061677776Z" level=debug method="(*Dispatcher).Tasks" node.id=59mtz3tngme8b8xnc8fcx85mz node.session=4uc6neciix8dhvkmvo9jj74yp
time="2016-08-22T21:35:03.083902458Z" level=info msg="Initializing Libnetwork Agent Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr ="
time="2016-08-22T21:35:03.083989037Z" level=debug msg="(*worker).Assign" len(tasks)=0 module="node/agent"
time="2016-08-22T21:35:03.094224392Z" level=debug msg="agent: registered" module="node/agent"
time="2016-08-22T21:35:03.094325800Z" level=info msg="Initializing Libnetwork Agent Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr ="
time="2016-08-22T21:35:03.094441029Z" level=debug msg="Encryption key 1: 79ba0"
time="2016-08-22T21:35:03.094452286Z" level=debug msg="Encryption key 2: b4584"
time="2016-08-22T21:35:03.094459802Z" level=debug msg="Encryption key 3: 3e934"
time="2016-08-22T21:35:03.094894335Z" level=debug msg="Initial encryption keys: [(key: 5023d, tag: 0x9d67) (key: 58b74, tag: 0x9d66) (key: beed9, tag: 0x9d68)]"
time="2016-08-22T21:35:03.095024447Z" level=debug msg="Allocating IPv4 pools for network ingress (cbj1w3vytzfonrag9qazk35f3)"
time="2016-08-22T21:35:03.095069578Z" level=debug msg="RequestPool(LocalDefault, 10.255.0.0/16, , map[], false)"
time="2016-08-22T21:35:03.095107209Z" level=debug msg="RequestAddress(LocalDefault/10.255.0.0/16, 10.255.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2016-08-22T21:35:03.095131627Z" level=debug msg="overlay: Received vxlan IDs: 256"
time="2016-08-22T21:35:03.098922424Z" level=warning msg="Running modprobe nf_nat failed with message: `modprobe: ERROR: ../libkmod/libkmod.c:557 kmod_search_moddep() could not open moddep file '/lib/modules/4.3.0-0.bpo.1-amd64/modules.dep.bin'`, error: exit status 1"
time="2016-08-22T21:35:03.108979192Z" level=debug msg="Root CA updated successfully" cluster.id=29fdohe2ms3poaomaq1enoyir method="(*Server).updateCluster" module=ca
time="2016-08-22T21:35:03.110100733Z" level=debug msg="Calling GET /v1.25/swarm"
time="2016-08-22T21:35:03.111496114Z" level=debug msg="Calling GET /v1.25/nodes/59mtz3tngme8b8xnc8fcx85mz"
time="2016-08-22T21:35:03.111632839Z" level=warning msg="Running modprobe xt_conntrack failed with message: `modprobe: ERROR: ../libkmod/libkmod.c:557 kmod_search_moddep() could not open moddep file '/lib/modules/4.3.0-0.bpo.1-amd64/modules.dep.bin'`, error: exit status 1"
time="2016-08-22T21:35:03.111700616Z" level=debug msg="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"
time="2016-08-22T21:35:03.114774619Z" level=debug msg="/sbin/iptables, [--wait --version]"
time="2016-08-22T21:35:03.116798618Z" level=debug msg="Calling GET /swarm"
time="2016-08-22T21:35:03.117868166Z" level=debug msg="/sbin/iptables, [--wait -t mangle -C OUTPUT -p udp --dport 4789 -m u32 --u32 0>>22&0x3C@12&0xFFFFFF00=65536 -j MARK --set-mark 13681891]"
time="2016-08-22T21:35:03.117914640Z" level=debug msg="Calling POST /swarm/leave?force=1"
time="2016-08-22T21:35:03.118636899Z" level=debug msg="form data: null"
time="2016-08-22T21:35:03.118858419Z" level=debug msg="(*Agent).run exited" module="node/agent"
time="2016-08-22T21:35:03.118882177Z" level=info msg="Stopping manager"
time="2016-08-22T21:35:03.119079033Z" level=info msg="Initializing Libnetwork Agent Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr ="
time="2016-08-22T21:35:03.119947065Z" level=info msg="Manager shut down"
time="2016-08-22T21:35:03.120061308Z" level=error msg="m.Run=<nil>"
time="2016-08-22T21:35:03.120342067Z" level=debug msg="726fabba6f90: joined network cbj1w3vytzfonrag9qazk35f3"
time="2016-08-22T21:35:03.120364272Z" level=debug msg="726fabba6f90: Initiating bulk sync with nodes [726fabba6f90]"
time="2016-08-22T21:35:03.130871501Z" level=debug msg="Calling POST /v1.25/swarm/init"
time="2016-08-22T21:35:03.130951711Z" level=debug msg="form data: {\"AdvertiseAddr\":\"\",\"ForceNewCluster\":false,\"ListenAddr\":\"0.0.0.0:2377\",\"Spec\":{\"CAConfig\":{\"NodeCertExpiry\":7.776e+15},\"Dispatcher\":{\"HeartbeatPeriod\":5e+09},\"Orchestration\":{\"TaskHistoryRetentionLimit\":5},\"Raft\":{},\"TaskDefaults\":{}}}"
time="2016-08-22T21:35:03.165359761Z" level=debug msg="Assigning addresses for endpoint ingress-endpoint's interface on network ingress"
time="2016-08-22T21:35:03.165396583Z" level=debug msg="RequestAddress(LocalDefault/10.255.0.0/16, 10.255.0.2, map[])"
time="2016-08-22T21:35:03.194496383Z" level=debug msg="successfully loaded the Root CA: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-root-ca.crt"
time="2016-08-22T21:35:03.195554977Z" level=debug msg="successfully loaded the Root CA: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-root-ca.crt"
time="2016-08-22T21:35:03.195579853Z" level=debug msg="loaded local CA certificate: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-root-ca.crt."
time="2016-08-22T21:35:03.196051532Z" level=debug msg="loaded local TLS credentials: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-node.crt."
time="2016-08-22T21:35:03.196587876Z" level=debug msg="Requesting certificate for NodeID: cudl25oqy1iivrqp2rdlyiemd"
time="2016-08-22T21:35:03.201560233Z" level=debug msg="Assigning addresses for endpoint ingress-endpoint's interface on network ingress"
time="2016-08-22T21:35:03.210839901Z" level=debug msg="successfully loaded the Root CA: /var/lib/docker/tests/d34826118/root/swarm/certificates/swarm-root-ca.crt"
time="2016-08-22T21:35:03.211666545Z" level=info msg="manager.New context.Background.WithCancel.WithValue(log.loggerKey{}, &logrus.Entry{Logger:(*logrus.Logger)(0xc820012480), Data:logrus.Fields{\"module\":\"node\"}, Time:time.Time{sec:0, nsec:0, loc:(*time.Location)(nil)}, Level:0x0, Message:\"\"}).WithValue(log.moduleKey{}, \"node\")"
time="2016-08-22T21:35:03.215593043Z" level=info msg="Listening for connections" addr="[::]:2377" proto=tcp
time="2016-08-22T21:35:03.217430631Z" level=info msg="Listening for local connections" addr="/var/lib/docker/tests/d34826118/root/swarm/control.sock" proto=unix
time="2016-08-22T21:35:03.219401173Z" level=info msg="Initializing Libnetwork Agent Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr ="
time="2016-08-22T21:35:03.231811495Z" level=error msg="m.Run=can't initialize raft node: create WAL error: fileutil: file already locked"
time="2016-08-22T21:35:03.245558115Z" level=debug msg="(*Agent).run" module="node/agent"
time="2016-08-22T21:35:03.245955928Z" level=debug msg="(*session).start" module="node/agent"
time="2016-08-22T21:35:03.301646341Z" level=debug msg="checkEncryption(cbj1w3v, <nil>, 256, true)"
time="2016-08-22T21:35:03Z" level=warning msg="Running modprobe nf_nat failed with message: `modprobe: ERROR: ../libkmod/libkmod.c:557 kmod_search_moddep() could not open moddep file '/lib/modules/4.3.0-0.bpo.1-amd64/modules.dep.bin'`, error: exit status 1"
time="2016-08-22T21:35:03Z" level=warning msg="Running modprobe xt_conntrack failed with message: `modprobe: ERROR: ../libkmod/libkmod.c:557 kmod_search_moddep() could not open moddep file '/lib/modules/4.3.0-0.bpo.1-amd64/modules.dep.bin'`, error: exit status 1"
time="2016-08-22T21:35:03.366912054Z" level=debug msg="Allocating IPv4 pools for network docker_gwbridge (8ffc8eed54f79ccb4d09e2d04e0d9bbf5544818cc197007bab8896a593b96e5e)"
time="2016-08-22T21:35:03.366950231Z" level=debug msg="RequestPool(LocalDefault, , , map[], false)"
time="2016-08-22T21:35:03.367111817Z" level=debug msg="RequestPool(LocalDefault, , , map[], false)"
time="2016-08-22T21:35:03.367197302Z" level=debug msg="RequestPool(LocalDefault, , , map[], false)"
time="2016-08-22T21:35:03.367290490Z" level=debug msg="ReleasePool(LocalDefault/172.19.0.0/16)"
time="2016-08-22T21:35:03.367306903Z" level=debug msg="ReleasePool(LocalDefault/172.17.0.0/16)"
time="2016-08-22T21:35:03.367325958Z" level=debug msg="RequestAddress(LocalDefault/172.20.0.0/16, <nil>, map[RequestAddressType:com.docker.network.gateway])"
time="2016-08-22T21:35:03.368087855Z" level=debug msg="Assigning address to bridge interface docker_gwbridge: 172.20.0.1/16"
time="2016-08-22T21:35:03.437098585Z" level=debug msg="Assigning addresses for endpoint gateway_ingress-sbox's interface on network docker_gwbridge"
time="2016-08-22T21:35:03.437134767Z" level=debug msg="RequestAddress(LocalDefault/172.20.0.0/16, <nil>, map[])"
time="2016-08-22T21:35:03.439040951Z" level=debug msg="Assigning addresses for endpoint gateway_ingress-sbox's interface on network docker_gwbridge"
time="2016-08-22T21:35:03.467344142Z" level=debug msg="Programming external connectivity on endpoint gateway_ingress-sbox (441cb2ccbf13faea2e82508bdcfc886a6cbb2c734fef5d19b94a846ad7442544)"
time="2016-08-22T21:35:05.631219927Z" level=error msg="agent: session failed" error="rpc error: code = 2 desc = grpc: the client connection is closing" module="node/agent"
time="2016-08-22T21:35:05.631316532Z" level=debug msg="agent: rebuild session" module="node/agent"
time="2016-08-22T21:35:05.639350572Z" level=debug msg="(*session).start" module="node/agent"
time="2016-08-22T21:35:08.151369135Z" level=error msg="agent: session failed" error="rpc error: code = 2 desc = grpc: the client connection is closing" module="node/agent"
time="2016-08-22T21:35:08.151443038Z" level=debug msg="agent: rebuild session" module="node/agent"
time="2016-08-22T21:35:08.226078196Z" level=debug msg="(*session).start" module="node/agent"
time="2016-08-22T21:35:10.681366680Z" level=error msg="agent: session failed" error="rpc error: code = 2 desc = grpc: the client connection is closing" module="node/agent"
time="2016-08-22T21:35:10.681427269Z" level=debug msg="agent: rebuild session" module="node/agent"
time="2016-08-22T21:35:11.118567559Z" level=debug msg="(*session).start" module="node/agent"
time="2016-08-22T21:35:13.435445167Z" level=error msg="agent: session failed" error="rpc error: code = 2 desc = grpc: the client connection is closing" module="node/agent"
time="2016-08-22T21:35:13.435502799Z" level=debug msg="agent: rebuild session" module="node/agent"
time="2016-08-22T21:35:13.585260113Z" level=debug msg="(*session).start" module="node/agent"
time="2016-08-22T21:35:14.213047289Z" level=error msg="error reestabilishing connection to leader" error="raft: no elected cluster leader"
time="2016-08-22T21:35:16.350104296Z" level=error msg="agent: session failed" error="rpc error: code = 2 desc = grpc: the client connection is closing" module="node/agent"
time="2016-08-22T21:35:16.350156731Z" level=debug msg="agent: rebuild session" module="node/agent"
time="2016-08-22T21:35:19.140456315Z" level=debug msg="(*session).start" module="node/agent"
time="2016-08-22T21:35:19.141892452Z" level=error msg="agent: session failed" error="rpc error: code = 2 desc = grpc: the client connection is closing" module="node/agent"
time="2016-08-22T21:35:19.141928578Z" level=debug msg="agent: rebuild session" module="node/agent"
time="2016-08-22T21:35:20.654654686Z" level=debug msg="(*session).start" module="node/agent"
time="2016-08-22T21:35:21.957442491Z" level=error msg="agent: session failed" error="rpc error: code = 2 desc = grpc: the client connection is closing" module="node/agent"
time="2016-08-22T21:35:21.957551169Z" level=debug msg="agent: rebuild session" module="node/agent"
time="2016-08-22T21:35:24.214856897Z" level=error msg="error reestabilishing connection to leader" error="raft: no elected cluster leader"
time="2016-08-22T21:35:24.456164494Z" level=info msg="Processing signal 'interrupt'"
time="2016-08-22T21:35:29.355243938Z" level=debug msg="(*session).start" module="node/agent"
time="2016-08-22T21:35:29.356698834Z" level=error msg="agent: session failed" error="rpc error: code = 2 desc = grpc: the client connection is closing" module="node/agent"
time="2016-08-22T21:35:29.356733703Z" level=debug msg="agent: rebuild session" module="node/agent"
time="2016-08-22T21:35:29.459029539Z" level=debug msg="(*Agent).run exited" module="node/agent"
time="2016-08-22T21:35:29.459329782Z" level=debug msg="starting clean shutdown of all containers..."
time="2016-08-22T21:35:29.460062293Z" level=debug msg="Unix socket /run/docker/libnetwork/8df7739936db2a9e1dee568ce7d5aec716794fe2efcd5420258bbd782c55b244.sock doesn't exist. cannot accept client connections"
time="2016-08-22T21:35:29.480476855Z" level=debug msg="Cleaning up old mountid : start."
time="2016-08-22T21:35:29.481046046Z" level=debug msg="Cleaning up old mountid : done."
time="2016-08-22T21:35:29.481097911Z" level=debug msg="Clean shutdown succeeded"
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment