Skip to content

Instantly share code, notes, and snippets.

@aaronlehmann
Created April 17, 2017 22:28
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save aaronlehmann/c46e85d7626431e9c4dfe857f77f9df8 to your computer and use it in GitHub Desktop.
Save aaronlehmann/c46e85d7626431e9c4dfe857f77f9df8 to your computer and use it in GitHub Desktop.
time="2017-04-17T14:16:06.886265000Z" level=debug msg="Listener created for HTTP on unix (/tmp/docker-integration/d167bfd8fc6d9.sock)"
time="2017-04-17T14:16:06.889233000Z" level=debug msg="Using default logging driver json-file"
time="2017-04-17T14:16:06.889371000Z" level=debug msg="Golang's threads limit set to 57960"
time="2017-04-17T14:16:06.889960000Z" level=debug msg="[graphdriver] trying provided driver: vfs"
time="2017-04-17T14:16:06.890107000Z" level=debug msg="Using graph driver vfs"
time="2017-04-17T14:16:06.890293000Z" level=debug msg="Max Concurrent Downloads: 3"
time="2017-04-17T14:16:06.890308000Z" level=debug msg="Max Concurrent Uploads: 5"
time="2017-04-17T14:16:06.903142000Z" level=info msg="Graph migration to content-addressability took 0.00 seconds"
time="2017-04-17T14:16:06.903388000Z" level=warning msg="Your kernel does not support swap memory limit"
time="2017-04-17T14:16:06.903447000Z" level=warning msg="Your kernel does not support cgroup rt period"
time="2017-04-17T14:16:06.903464000Z" level=warning msg="Your kernel does not support cgroup rt runtime"
time="2017-04-17T14:16:06.903914000Z" level=info msg="Loading containers: start."
time="2017-04-17T14:16:06.903977000Z" level=debug msg="Option Experimental: false"
time="2017-04-17T14:16:06.903990000Z" level=debug msg="Option DefaultDriver: bridge"
time="2017-04-17T14:16:06.904009000Z" level=debug msg="Option DefaultNetwork: bridge"
time="2017-04-17T14:16:06.949100000Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.19.0.0/16. Daemon option --bip can be used to set a preferred IP address"
time="2017-04-17T14:16:06.949230000Z" level=debug msg="Allocating IPv4 pools for network bridge (6110eb9893fa184896a1a4e12935c9beac0c30108cfcd3a31fff76de95c15383)"
time="2017-04-17T14:16:06.949261000Z" level=debug msg="RequestPool(LocalDefault, 172.19.0.0/16, , map[], false)"
time="2017-04-17T14:16:06.949345000Z" level=debug msg="RequestAddress(LocalDefault/172.19.0.0/16, 172.19.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:06.958413000Z" level=info msg="Loading containers: done."
time="2017-04-17T14:16:06.972746000Z" level=info msg="Daemon has completed initialization"
time="2017-04-17T14:16:06.972790000Z" level=info msg="Docker daemon" commit=a100c08 graphdriver=vfs version=17.06.0-dev
time="2017-04-17T14:16:06.972871000Z" level=debug msg="Registering routers"
time="2017-04-17T14:16:06.972885000Z" level=debug msg="Registering GET, /containers/{name:.*}/checkpoints"
time="2017-04-17T14:16:06.973108000Z" level=debug msg="Registering POST, /containers/{name:.*}/checkpoints"
time="2017-04-17T14:16:06.973255000Z" level=debug msg="Registering DELETE, /containers/{name}/checkpoints/{checkpoint}"
time="2017-04-17T14:16:06.973448000Z" level=debug msg="Registering HEAD, /containers/{name:.*}/archive"
time="2017-04-17T14:16:06.976469000Z" level=debug msg="Registering GET, /containers/json"
time="2017-04-17T14:16:06.977019000Z" level=debug msg="Registering GET, /containers/{name:.*}/export"
time="2017-04-17T14:16:06.978572000Z" level=debug msg="Registering GET, /containers/{name:.*}/changes"
time="2017-04-17T14:16:06.990218000Z" level=debug msg="Registering GET, /containers/{name:.*}/json"
time="2017-04-17T14:16:06.990667000Z" level=debug msg="Registering GET, /containers/{name:.*}/top"
time="2017-04-17T14:16:06.991038000Z" level=debug msg="Registering GET, /containers/{name:.*}/logs"
time="2017-04-17T14:16:06.991461000Z" level=debug msg="Registering GET, /containers/{name:.*}/stats"
time="2017-04-17T14:16:06.993048000Z" level=debug msg="Registering GET, /containers/{name:.*}/attach/ws"
time="2017-04-17T14:16:06.993464000Z" level=debug msg="Registering GET, /exec/{id:.*}/json"
time="2017-04-17T14:16:06.994290000Z" level=debug msg="Registering GET, /containers/{name:.*}/archive"
time="2017-04-17T14:16:06.994457000Z" level=debug msg="Registering POST, /containers/create"
time="2017-04-17T14:16:06.994550000Z" level=debug msg="Registering POST, /containers/{name:.*}/kill"
time="2017-04-17T14:16:06.994685000Z" level=debug msg="Registering POST, /containers/{name:.*}/pause"
time="2017-04-17T14:16:06.994817000Z" level=debug msg="Registering POST, /containers/{name:.*}/unpause"
time="2017-04-17T14:16:06.994949000Z" level=debug msg="Registering POST, /containers/{name:.*}/restart"
time="2017-04-17T14:16:06.995093000Z" level=debug msg="Registering POST, /containers/{name:.*}/start"
time="2017-04-17T14:16:06.995255000Z" level=debug msg="Registering POST, /containers/{name:.*}/stop"
time="2017-04-17T14:16:06.995367000Z" level=debug msg="Registering POST, /containers/{name:.*}/wait"
time="2017-04-17T14:16:06.995487000Z" level=debug msg="Registering POST, /containers/{name:.*}/resize"
time="2017-04-17T14:16:06.995614000Z" level=debug msg="Registering POST, /containers/{name:.*}/attach"
time="2017-04-17T14:16:06.995734000Z" level=debug msg="Registering POST, /containers/{name:.*}/copy"
time="2017-04-17T14:16:06.995863000Z" level=debug msg="Registering POST, /containers/{name:.*}/exec"
time="2017-04-17T14:16:06.995978000Z" level=debug msg="Registering POST, /exec/{name:.*}/start"
time="2017-04-17T14:16:06.996099000Z" level=debug msg="Registering POST, /exec/{name:.*}/resize"
time="2017-04-17T14:16:06.996212000Z" level=debug msg="Registering POST, /containers/{name:.*}/rename"
time="2017-04-17T14:16:06.996324000Z" level=debug msg="Registering POST, /containers/{name:.*}/update"
time="2017-04-17T14:16:06.996458000Z" level=debug msg="Registering POST, /containers/prune"
time="2017-04-17T14:16:06.996552000Z" level=debug msg="Registering PUT, /containers/{name:.*}/archive"
time="2017-04-17T14:16:06.996671000Z" level=debug msg="Registering DELETE, /containers/{name:.*}"
time="2017-04-17T14:16:06.996792000Z" level=debug msg="Registering GET, /images/json"
time="2017-04-17T14:16:06.996870000Z" level=debug msg="Registering GET, /images/search"
time="2017-04-17T14:16:06.996949000Z" level=debug msg="Registering GET, /images/get"
time="2017-04-17T14:16:06.997022000Z" level=debug msg="Registering GET, /images/{name:.*}/get"
time="2017-04-17T14:16:06.997134000Z" level=debug msg="Registering GET, /images/{name:.*}/history"
time="2017-04-17T14:16:06.997247000Z" level=debug msg="Registering GET, /images/{name:.*}/json"
time="2017-04-17T14:16:06.997356000Z" level=debug msg="Registering POST, /commit"
time="2017-04-17T14:16:06.997424000Z" level=debug msg="Registering POST, /images/load"
time="2017-04-17T14:16:06.997509000Z" level=debug msg="Registering POST, /images/create"
time="2017-04-17T14:16:06.997586000Z" level=debug msg="Registering POST, /images/{name:.*}/push"
time="2017-04-17T14:16:06.997703000Z" level=debug msg="Registering POST, /images/{name:.*}/tag"
time="2017-04-17T14:16:06.997807000Z" level=debug msg="Registering POST, /images/prune"
time="2017-04-17T14:16:06.997892000Z" level=debug msg="Registering DELETE, /images/{name:.*}"
time="2017-04-17T14:16:06.998004000Z" level=debug msg="Registering OPTIONS, /{anyroute:.*}"
time="2017-04-17T14:16:06.998102000Z" level=debug msg="Registering GET, /_ping"
time="2017-04-17T14:16:06.998162000Z" level=debug msg="Registering GET, /events"
time="2017-04-17T14:16:06.998236000Z" level=debug msg="Registering GET, /info"
time="2017-04-17T14:16:06.998298000Z" level=debug msg="Registering GET, /version"
time="2017-04-17T14:16:06.998363000Z" level=debug msg="Registering GET, /system/df"
time="2017-04-17T14:16:06.998440000Z" level=debug msg="Registering POST, /auth"
time="2017-04-17T14:16:06.998503000Z" level=debug msg="Registering GET, /volumes"
time="2017-04-17T14:16:06.998573000Z" level=debug msg="Registering GET, /volumes/{name:.*}"
time="2017-04-17T14:16:06.998687000Z" level=debug msg="Registering POST, /volumes/create"
time="2017-04-17T14:16:06.998769000Z" level=debug msg="Registering POST, /volumes/prune"
time="2017-04-17T14:16:06.998857000Z" level=debug msg="Registering DELETE, /volumes/{name:.*}"
time="2017-04-17T14:16:06.998979000Z" level=debug msg="Registering POST, /build"
time="2017-04-17T14:16:06.999042000Z" level=debug msg="Registering POST, /swarm/init"
time="2017-04-17T14:16:06.999123000Z" level=debug msg="Registering POST, /swarm/join"
time="2017-04-17T14:16:06.999208000Z" level=debug msg="Registering POST, /swarm/leave"
time="2017-04-17T14:16:06.999280000Z" level=debug msg="Registering GET, /swarm"
time="2017-04-17T14:16:06.999341000Z" level=debug msg="Registering GET, /swarm/unlockkey"
time="2017-04-17T14:16:06.999429000Z" level=debug msg="Registering POST, /swarm/update"
time="2017-04-17T14:16:06.999512000Z" level=debug msg="Registering POST, /swarm/unlock"
time="2017-04-17T14:16:06.999591000Z" level=debug msg="Registering GET, /services"
time="2017-04-17T14:16:06.999659000Z" level=debug msg="Registering GET, /services/{id}"
time="2017-04-17T14:16:06.999774000Z" level=debug msg="Registering POST, /services/create"
time="2017-04-17T14:16:06.999855000Z" level=debug msg="Registering POST, /services/{id}/update"
time="2017-04-17T14:16:06.999979000Z" level=debug msg="Registering DELETE, /services/{id}"
time="2017-04-17T14:16:07.000085000Z" level=debug msg="Registering GET, /services/{id}/logs"
time="2017-04-17T14:16:07.000210000Z" level=debug msg="Registering GET, /nodes"
time="2017-04-17T14:16:07.000276000Z" level=debug msg="Registering GET, /nodes/{id}"
time="2017-04-17T14:16:07.000381000Z" level=debug msg="Registering DELETE, /nodes/{id}"
time="2017-04-17T14:16:07.000489000Z" level=debug msg="Registering POST, /nodes/{id}/update"
time="2017-04-17T14:16:07.000605000Z" level=debug msg="Registering GET, /tasks"
time="2017-04-17T14:16:07.000676000Z" level=debug msg="Registering GET, /tasks/{id}"
time="2017-04-17T14:16:07.000773000Z" level=debug msg="Registering GET, /tasks/{id}/logs"
time="2017-04-17T14:16:07.000885000Z" level=debug msg="Registering GET, /secrets"
time="2017-04-17T14:16:07.000959000Z" level=debug msg="Registering POST, /secrets/create"
time="2017-04-17T14:16:07.001043000Z" level=debug msg="Registering DELETE, /secrets/{id}"
time="2017-04-17T14:16:07.001149000Z" level=debug msg="Registering GET, /secrets/{id}"
time="2017-04-17T14:16:07.001263000Z" level=debug msg="Registering POST, /secrets/{id}/update"
time="2017-04-17T14:16:07.001379000Z" level=debug msg="Registering GET, /plugins"
time="2017-04-17T14:16:07.001454000Z" level=debug msg="Registering GET, /plugins/{name:.*}/json"
time="2017-04-17T14:16:07.001558000Z" level=debug msg="Registering GET, /plugins/privileges"
time="2017-04-17T14:16:07.001654000Z" level=debug msg="Registering DELETE, /plugins/{name:.*}"
time="2017-04-17T14:16:07.001763000Z" level=debug msg="Registering POST, /plugins/{name:.*}/enable"
time="2017-04-17T14:16:07.001881000Z" level=debug msg="Registering POST, /plugins/{name:.*}/disable"
time="2017-04-17T14:16:07.001983000Z" level=debug msg="Registering POST, /plugins/pull"
time="2017-04-17T14:16:07.002060000Z" level=debug msg="Registering POST, /plugins/{name:.*}/push"
time="2017-04-17T14:16:07.002170000Z" level=debug msg="Registering POST, /plugins/{name:.*}/upgrade"
time="2017-04-17T14:16:07.002281000Z" level=debug msg="Registering POST, /plugins/{name:.*}/set"
time="2017-04-17T14:16:07.002395000Z" level=debug msg="Registering POST, /plugins/create"
time="2017-04-17T14:16:07.002473000Z" level=debug msg="Registering GET, /networks"
time="2017-04-17T14:16:07.002539000Z" level=debug msg="Registering GET, /networks/"
time="2017-04-17T14:16:07.002618000Z" level=debug msg="Registering GET, /networks/{id:.+}"
time="2017-04-17T14:16:07.002724000Z" level=debug msg="Registering POST, /networks/create"
time="2017-04-17T14:16:07.002814000Z" level=debug msg="Registering POST, /networks/{id:.*}/connect"
time="2017-04-17T14:16:07.002921000Z" level=debug msg="Registering POST, /networks/{id:.*}/disconnect"
time="2017-04-17T14:16:07.003040000Z" level=debug msg="Registering POST, /networks/prune"
time="2017-04-17T14:16:07.003119000Z" level=debug msg="Registering DELETE, /networks/{id:.*}"
time="2017-04-17T14:16:07.003691000Z" level=info msg="API listen on /tmp/docker-integration/d167bfd8fc6d9.sock"
time="2017-04-17T14:16:07.364592000Z" level=debug msg="Calling GET /_ping"
time="2017-04-17T14:16:07.369584000Z" level=debug msg="Calling GET /info"
time="2017-04-17T14:16:07.622708000Z" level=debug msg="Calling GET /_ping"
time="2017-04-17T14:16:07.623947000Z" level=debug msg="Calling POST /v1.30/images/load?quiet=1"
time="2017-04-17T14:16:07.697290000Z" level=debug msg="Start untar layer"
time="2017-04-17T14:16:07.916214000Z" level=debug msg="Untar time: 0.218919s"
time="2017-04-17T14:16:07.916299000Z" level=debug msg="Applied tar sha256:6719b42e03539a9ab2e99140109b53a88dd1dd8d85d5da6f1fcccad543024c9e to 59c718d385307547b29a81423e0550c9d679b737e51cf07e89d1ed57806bbb34, size: 4386624"
time="2017-04-17T14:16:07.932381000Z" level=debug msg="Calling POST /swarm/join"
time="2017-04-17T14:16:07.932482000Z" level=debug msg="form data: {\"AdvertiseAddr\":\"\",\"Availability\":\"\",\"JoinToken\":\"*****\",\"ListenAddr\":\"0.0.0.0:2479\",\"RemoteAddrs\":[\"0.0.0.0:2477\"]}"
time="2017-04-17T14:16:07.981232000Z" level=debug msg="retrieved remote CA certificate: /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/d167bfd8fc6d9/root/swarm/certificates/swarm-root-ca.crt" module=node
time="2017-04-17T14:16:07.981272000Z" level=debug msg="downloaded CA certificate" module=node
time="2017-04-17T14:16:07.981308000Z" level=debug msg="no node credentials found in: /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/d167bfd8fc6d9/root/swarm/certificates/swarm-node.crt" error="open /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/d167bfd8fc6d9/root/swarm/certificates/swarm-node.key: no such file or directory" module=node
time="2017-04-17T14:16:08.177297000Z" level=debug msg="new node credentials generated: /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/d167bfd8fc6d9/root/swarm/certificates/swarm-node.crt" module="node/tls" node.id=tsfg8t1nmbz50cpzkzmomzmid node.role=swarm-manager
time="2017-04-17T14:16:08.180077000Z" level=debug msg="(*Agent).run" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.184887000Z" level=debug msg="next certificate renewal scheduled for 1563h36m51.815139s from now" module="node/tls" node.id=tsfg8t1nmbz50cpzkzmomzmid node.role=swarm-manager time=2017-06-21 17:53:00 +0000 UTC
time="2017-04-17T14:16:08.191677000Z" level=debug msg="(*session).start" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.191770000Z" level=info msg="Listening for connections" addr="[::]:2479" module=node node.id=tsfg8t1nmbz50cpzkzmomzmid proto=tcp
time="2017-04-17T14:16:08.191929000Z" level=info msg="Listening for local connections" addr="/tmp/docker-execroot/d167bfd8fc6d9/swarm/control.sock" module=node node.id=tsfg8t1nmbz50cpzkzmomzmid proto=unix
time="2017-04-17T14:16:08.326725000Z" level=info msg="26315b37c1589836 became follower at term 0" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.326813000Z" level=info msg="newRaft 26315b37c1589836 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.326832000Z" level=info msg="26315b37c1589836 became follower at term 1" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.327025000Z" level=debug msg="transport: add peer 7fc2bf7e4a2bd73 with address 127.0.0.1:2477"
time="2017-04-17T14:16:08.331583000Z" level=debug msg="transport: add peer 2e55d6c0fc7e7b91 with address 127.0.0.1:2478"
time="2017-04-17T14:16:08.337750000Z" level=debug method="(*session).logSubscriptions" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=f6y8ib7za9yrweybdxvsw5p2j
time="2017-04-17T14:16:08.362650000Z" level=debug msg="(*session).heartbeat" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=f6y8ib7za9yrweybdxvsw5p2j
time="2017-04-17T14:16:08.362867000Z" level=debug method="(*session).watch" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=f6y8ib7za9yrweybdxvsw5p2j
time="2017-04-17T14:16:08.369122000Z" level=debug msg="(*session).listen" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=f6y8ib7za9yrweybdxvsw5p2j
time="2017-04-17T14:16:08.369608000Z" level=debug msg="received encryption keys before cluster config"
time="2017-04-17T14:16:08.369652000Z" level=debug msg="agent: registered" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.372138000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.372173000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.372198000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.404982000Z" level=info msg="26315b37c1589836 [term: 1] received a MsgApp message with higher term from 7fc2bf7e4a2bd73 [term: 2]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.405021000Z" level=info msg="26315b37c1589836 became follower at term 2" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.405043000Z" level=debug msg="26315b37c1589836 [logterm: 0, index: 21] rejected msgApp [logterm: 2, index: 21] from 7fc2bf7e4a2bd73" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.405062000Z" level=info msg="raft.node: 26315b37c1589836 elected leader 7fc2bf7e4a2bd73 at term 2" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.448044000Z" level=debug msg="Updating security config due to change in cluster Root CA" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=node node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.472395000Z" level=debug msg="Root CA updated successfully" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=node node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.472428000Z" level=debug msg="Updating security config due to change in cluster Root CA or cluster spec" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=node node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.743215000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr =127.0.0.1"
time="2017-04-17T14:16:08.743422000Z" level=info msg="Gossip cluster hostname f725cf4eef9e-49fac4f797bc"
time="2017-04-17T14:16:08.743490000Z" level=debug msg="Encryption key 1: 555df"
time="2017-04-17T14:16:08.743503000Z" level=debug msg="Encryption key 2: 3f5d4"
time="2017-04-17T14:16:08.743515000Z" level=debug msg="Encryption key 3: 391d1"
time="2017-04-17T14:16:08.743594000Z" level=error msg="Error in agentInit : failed to create memberlist: Failed to start TCP listener. Err: listen tcp 0.0.0.0:7946: bind: address already in use"
time="2017-04-17T14:16:08.743620000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr =127.0.0.1"
time="2017-04-17T14:16:08.743650000Z" level=info msg="Gossip cluster hostname f725cf4eef9e-947779a83090"
time="2017-04-17T14:16:08.743685000Z" level=debug msg="Encryption key 1: 555df"
time="2017-04-17T14:16:08.743697000Z" level=debug msg="Encryption key 2: 3f5d4"
time="2017-04-17T14:16:08.743708000Z" level=debug msg="Encryption key 3: 391d1"
time="2017-04-17T14:16:08.743767000Z" level=error msg="Error in agentInit : failed to create memberlist: Failed to start TCP listener. Err: listen tcp 0.0.0.0:7946: bind: address already in use"
time="2017-04-17T14:16:08.744761000Z" level=debug msg="Calling GET /info"
time="2017-04-17T14:16:08.773967000Z" level=error msg="agent: session failed" error="rpc error: code = 1 desc = context canceled" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.774132000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.797838000Z" level=debug msg="(*session).start" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.799886000Z" level=error msg="agent: session failed" error="rpc error: code = 14 desc = grpc: the connection is unavailable" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.799992000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.847772000Z" level=debug msg="(*session).start" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.849884000Z" level=error msg="agent: session failed" error="rpc error: code = 14 desc = grpc: the connection is unavailable" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.849995000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:09.131430000Z" level=debug msg="(*session).start" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:09.132794000Z" level=error msg="agent: session failed" error="rpc error: code = 14 desc = grpc: the connection is unavailable" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:09.132854000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:09.205799000Z" level=debug msg="(*session).start" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:09.207427000Z" level=error msg="agent: session failed" error="rpc error: code = 14 desc = grpc: the connection is unavailable" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:09.207490000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.302462000Z" level=info msg="26315b37c1589836 [term: 2] received a MsgVote message with higher term from 2e55d6c0fc7e7b91 [term: 3]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.302501000Z" level=info msg="26315b37c1589836 became follower at term 3" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.302531000Z" level=info msg="26315b37c1589836 [logterm: 2, index: 22, vote: 0] cast MsgVote for 2e55d6c0fc7e7b91 [logterm: 2, index: 22] at term 3" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.302551000Z" level=info msg="raft.node: 26315b37c1589836 lost leader 7fc2bf7e4a2bd73 at term 3" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.304074000Z" level=info msg="raft.node: 26315b37c1589836 elected leader 2e55d6c0fc7e7b91 at term 3" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.771023000Z" level=debug msg="(*session).start" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.822634000Z" level=debug method="(*session).logSubscriptions" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=81ut9eko9ukn696tt472a1nep
time="2017-04-17T14:16:11.822704000Z" level=debug msg="(*session).heartbeat" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=81ut9eko9ukn696tt472a1nep
time="2017-04-17T14:16:11.822727000Z" level=debug method="(*session).watch" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=81ut9eko9ukn696tt472a1nep
time="2017-04-17T14:16:11.822749000Z" level=debug msg="(*session).listen" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=81ut9eko9ukn696tt472a1nep
time="2017-04-17T14:16:11.823139000Z" level=debug msg="agent: registered" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.824130000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.824152000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.824172000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:19.120547000Z" level=debug msg="Calling GET /nodes/tsfg8t1nmbz50cpzkzmomzmid"
time="2017-04-17T14:16:22.418654000Z" level=debug msg="member which sent vote request failed health check" error="failed to check health: rpc error: code = 14 desc = grpc: the connection is unavailable" from=7fc2bf7e4a2bd73 method="(*Node).ProcessRaftMessage" raft_id=26315b37c1589836
time="2017-04-17T14:16:25.416235000Z" level=debug msg="member which sent vote request failed health check" error="failed to check health: rpc error: code = 14 desc = grpc: the connection is unavailable" from=7fc2bf7e4a2bd73 method="(*Node).ProcessRaftMessage" raft_id=26315b37c1589836
time="2017-04-17T14:16:30.418652000Z" level=info msg="26315b37c1589836 [term: 3] received a MsgVote message with higher term from 7fc2bf7e4a2bd73 [term: 5]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:30.418705000Z" level=info msg="26315b37c1589836 became follower at term 5" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:30.418728000Z" level=info msg="26315b37c1589836 [logterm: 3, index: 29, vote: 0] rejected MsgVote from 7fc2bf7e4a2bd73 [logterm: 2, index: 22] at term 5" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:30.418748000Z" level=info msg="raft.node: 26315b37c1589836 lost leader 2e55d6c0fc7e7b91 at term 5" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:30.423451000Z" level=error msg="agent: session failed" error="rpc error: code = 1 desc = context canceled" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:30.423481000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:30.462729000Z" level=debug msg="(*session).start" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.186625000Z" level=info msg="26315b37c1589836 is starting a new election at term 5" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.186842000Z" level=info msg="26315b37c1589836 became candidate at term 6" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.186893000Z" level=info msg="26315b37c1589836 received MsgVoteResp from 26315b37c1589836 at term 6" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.186918000Z" level=info msg="26315b37c1589836 [logterm: 3, index: 29] sent MsgVote request to 7fc2bf7e4a2bd73 at term 6" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.186942000Z" level=info msg="26315b37c1589836 [logterm: 3, index: 29] sent MsgVote request to 2e55d6c0fc7e7b91 at term 6" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.190792000Z" level=info msg="26315b37c1589836 received MsgVoteResp from 7fc2bf7e4a2bd73 at term 6" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.190852000Z" level=info msg="26315b37c1589836 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.190888000Z" level=info msg="26315b37c1589836 became leader at term 6" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.190910000Z" level=info msg="raft.node: 26315b37c1589836 elected leader 26315b37c1589836 at term 6" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.193626000Z" level=debug msg="26315b37c1589836 received msgApp rejection(lastindex: 22) from 7fc2bf7e4a2bd73 for index 29" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.193666000Z" level=debug msg="26315b37c1589836 decreased progress of 7fc2bf7e4a2bd73 to [next = 23, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.197786000Z" level=debug msg="RequestPool(GlobalDefault, 10.255.0.0/16, , map[], false)"
time="2017-04-17T14:16:33.197873000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, 10.255.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:33.197906000Z" level=debug msg="overlay network option: 4096"
time="2017-04-17T14:16:33.204818000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, 10.255.0.3, map[])"
time="2017-04-17T14:16:33.204877000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, 10.255.0.2, map[])"
time="2017-04-17T14:16:33.204906000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, 10.255.0.4, map[])"
time="2017-04-17T14:16:33.503520000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.503651000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.503719000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.516473000Z" level=debug method="(*session).logSubscriptions" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=vkc6ft1xagb081w6x8yp8k4ea
time="2017-04-17T14:16:33.516920000Z" level=debug msg="node registered" method="(*LogBroker).ListenSubscriptions" node=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.516959000Z" level=debug method="(*session).watch" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=vkc6ft1xagb081w6x8yp8k4ea
time="2017-04-17T14:16:33.516982000Z" level=debug msg="agent: registered" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.517019000Z" level=debug msg="(*session).listen" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=vkc6ft1xagb081w6x8yp8k4ea
time="2017-04-17T14:16:33.517096000Z" level=debug msg="(*session).heartbeat" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid session.id=vkc6ft1xagb081w6x8yp8k4ea
time="2017-04-17T14:16:33.517189000Z" level=debug method="(*Dispatcher).Assignments" node.id=tsfg8t1nmbz50cpzkzmomzmid node.session=vkc6ft1xagb081w6x8yp8k4ea
time="2017-04-17T14:16:33.517338000Z" level=debug msg="node registered" method="(*LogBroker).ListenSubscriptions" node=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.517384000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.517407000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.517428000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:33.517439000Z" level=debug method="(*Dispatcher).Assignments" node.id=5fy73cplhm7k9pi2olk3lxckq node.session=ij82bw65etnxuu5ada669x3au
time="2017-04-17T14:16:33.519205000Z" level=debug msg="node registered" method="(*LogBroker).ListenSubscriptions" node=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.520162000Z" level=debug method="(*Dispatcher).Assignments" node.id=nd0egxko61vvi4262sbc6fx0z node.session=qz029pgki4a4bvgv8crf8r1x4
time="2017-04-17T14:16:33.653655000Z" level=debug msg="Calling GET /nodes/tsfg8t1nmbz50cpzkzmomzmid"
time="2017-04-17T14:16:34.187275000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:34.187359000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:35.186798000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:35.186908000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:36.187813000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:36.187972000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:37.187357000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:37.187493000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:38.186808000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:38.186917000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:39.186769000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:39.186843000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:40.186952000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:40.187020000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:41.186914000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:41.187006000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:42.186886000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:42.186987000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:43.186997000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:43.187081000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:44.186799000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:44.186895000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:44.186945000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=2e55d6c0fc7e7b91
time="2017-04-17T14:16:44.186970000Z" level=debug msg="26315b37c1589836 failed to send message to 2e55d6c0fc7e7b91 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:45.187004000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:45.187097000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:45.187271000Z" level=debug msg="26315b37c1589836 failed to send message to 2e55d6c0fc7e7b91 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:45.187327000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=2e55d6c0fc7e7b91
time="2017-04-17T14:16:46.186799000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:46.186890000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:46.186938000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=2e55d6c0fc7e7b91
time="2017-04-17T14:16:46.186962000Z" level=debug msg="26315b37c1589836 failed to send message to 2e55d6c0fc7e7b91 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:47.187279000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:47.187448000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:47.187534000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=2e55d6c0fc7e7b91
time="2017-04-17T14:16:47.187579000Z" level=debug msg="26315b37c1589836 failed to send message to 2e55d6c0fc7e7b91 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:48.186894000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=2e55d6c0fc7e7b91
time="2017-04-17T14:16:48.186966000Z" level=debug msg="26315b37c1589836 failed to send message to 2e55d6c0fc7e7b91 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:48.187034000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:48.187085000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:48.235964000Z" level=debug msg="heartbeat expiration"
time="2017-04-17T14:16:48.252566000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:48.253479000Z" level=debug msg="failed to send message MsgApp" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=2e55d6c0fc7e7b91
time="2017-04-17T14:16:48.253517000Z" level=debug msg="26315b37c1589836 failed to send message to 2e55d6c0fc7e7b91 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:48.253560000Z" level=debug msg="failed to send message MsgApp" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:48.253584000Z" level=debug msg="26315b37c1589836 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 35, match = 34, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.020507000Z" level=info msg="Processing signal 'interrupt'"
time="2017-04-17T14:16:49.022507000Z" level=error msg="Leaving cluster with 0 managers left out of 3. Raft quorum will be lost."
time="2017-04-17T14:16:49.022566000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.022588000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.022616000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.024091000Z" level=info msg="Stopping manager" module=node node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.024283000Z" level=error msg="agent: session failed" error="rpc error: code = 1 desc = context canceled" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.024320000Z" level=debug msg="(*Agent).run exited" module="node/agent" node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.024352000Z" level=error msg="dispatcher batch failed" error="context canceled" method="(*Dispatcher).processUpdates" module=dispatcher node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.024314000Z" level=info msg="shutting down certificate renewal routine" module="node/tls" node.id=tsfg8t1nmbz50cpzkzmomzmid node.role=swarm-manager
time="2017-04-17T14:16:49.024505000Z" level=error msg="LogBroker exited with an error" error="context canceled" module=node node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.024847000Z" level=debug msg="stop transport"
time="2017-04-17T14:16:49.024902000Z" level=info msg="Manager shut down" module=node node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:49.025016000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr =127.0.0.1"
time="2017-04-17T14:16:49.024999000Z" level=error msg="cluster exited with error: manager stopped: context canceled"
time="2017-04-17T14:16:49.025092000Z" level=info msg="Gossip cluster hostname f725cf4eef9e-8c46d8b5477c"
time="2017-04-17T14:16:49.025172000Z" level=debug msg="Encryption key 1: 555df"
time="2017-04-17T14:16:49.025155000Z" level=debug msg="start clean shutdown of all containers with a 15 seconds timeout..."
time="2017-04-17T14:16:49.025188000Z" level=debug msg="Encryption key 2: 3f5d4"
time="2017-04-17T14:16:49.025207000Z" level=debug msg="Encryption key 3: 391d1"
time="2017-04-17T14:16:49.025216000Z" level=debug msg="start clean shutdown of cluster resources..."
time="2017-04-17T14:16:49.025807000Z" level=debug msg="Initial encryption keys: [(key: 47e16, tag: 0xaf6d) (key: 02ab5, tag: 0xaf6c) (key: 85873, tag: 0xaf6e)]"
time="2017-04-17T14:16:49.026099000Z" level=debug msg="Initial encryption keys: [(key: 47e16, tag: 0xaf6d) (key: 02ab5, tag: 0xaf6c) (key: 85873, tag: 0xaf6e)]"
time="2017-04-17T14:16:49.026310000Z" level=debug msg="memberlist: Initiating push/pull sync with: 127.0.0.1:7946"
time="2017-04-17T14:16:49.026580000Z" level=debug msg="memberlist: TCP connection from=127.0.0.1:35628"
time="2017-04-17T14:16:54.025751000Z" level=warning msg="timeout while waiting for ingress network removal"
time="2017-04-17T14:16:54.026101000Z" level=debug msg="Cleaning up old mountid : start."
time="2017-04-17T14:16:54.026752000Z" level=debug msg="Cleaning up old mountid : done."
time="2017-04-17T14:16:54.026657000Z" level=debug msg="Unix socket /run/docker/libnetwork/964a2110e3b2293850e87da47097f213c3536e823b557a8e616d20d1a774d43a.sock doesn't exist. cannot accept client connections"
time="2017-04-17T14:16:54.026779000Z" level=debug msg="Clean shutdown succeeded"
time="2017-04-17T14:16:03.723476000Z" level=debug msg="Listener created for HTTP on unix (/tmp/docker-integration/d91b9df46789c.sock)"
time="2017-04-17T14:16:03.724790000Z" level=debug msg="Using default logging driver json-file"
time="2017-04-17T14:16:03.724823000Z" level=debug msg="Golang's threads limit set to 57960"
time="2017-04-17T14:16:03.725366000Z" level=debug msg="[graphdriver] trying provided driver: vfs"
time="2017-04-17T14:16:03.725511000Z" level=debug msg="Using graph driver vfs"
time="2017-04-17T14:16:03.725714000Z" level=debug msg="Max Concurrent Downloads: 3"
time="2017-04-17T14:16:03.725728000Z" level=debug msg="Max Concurrent Uploads: 5"
time="2017-04-17T14:16:03.733919000Z" level=info msg="Graph migration to content-addressability took 0.00 seconds"
time="2017-04-17T14:16:03.734142000Z" level=warning msg="Your kernel does not support swap memory limit"
time="2017-04-17T14:16:03.734205000Z" level=warning msg="Your kernel does not support cgroup rt period"
time="2017-04-17T14:16:03.734222000Z" level=warning msg="Your kernel does not support cgroup rt runtime"
time="2017-04-17T14:16:03.734693000Z" level=info msg="Loading containers: start."
time="2017-04-17T14:16:03.734770000Z" level=debug msg="Option Experimental: false"
time="2017-04-17T14:16:03.734783000Z" level=debug msg="Option DefaultDriver: bridge"
time="2017-04-17T14:16:03.734795000Z" level=debug msg="Option DefaultNetwork: bridge"
time="2017-04-17T14:16:03.781459000Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.19.0.0/16. Daemon option --bip can be used to set a preferred IP address"
time="2017-04-17T14:16:03.781546000Z" level=debug msg="Allocating IPv4 pools for network bridge (dc32fd1004a70ad767fe43e0082b128d666d3f6625650afb96e0c0e634ae7d9c)"
time="2017-04-17T14:16:03.781567000Z" level=debug msg="RequestPool(LocalDefault, 172.19.0.0/16, , map[], false)"
time="2017-04-17T14:16:03.781632000Z" level=debug msg="RequestAddress(LocalDefault/172.19.0.0/16, 172.19.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:03.787969000Z" level=info msg="Loading containers: done."
time="2017-04-17T14:16:03.798660000Z" level=info msg="Daemon has completed initialization"
time="2017-04-17T14:16:03.798770000Z" level=info msg="Docker daemon" commit=a100c08 graphdriver=vfs version=17.06.0-dev
time="2017-04-17T14:16:03.798957000Z" level=debug msg="Registering routers"
time="2017-04-17T14:16:03.798987000Z" level=debug msg="Registering GET, /containers/{name:.*}/checkpoints"
time="2017-04-17T14:16:03.799445000Z" level=debug msg="Registering POST, /containers/{name:.*}/checkpoints"
time="2017-04-17T14:16:03.799672000Z" level=debug msg="Registering DELETE, /containers/{name}/checkpoints/{checkpoint}"
time="2017-04-17T14:16:03.800994000Z" level=debug msg="Registering HEAD, /containers/{name:.*}/archive"
time="2017-04-17T14:16:03.801187000Z" level=debug msg="Registering GET, /containers/json"
time="2017-04-17T14:16:03.801273000Z" level=debug msg="Registering GET, /containers/{name:.*}/export"
time="2017-04-17T14:16:03.801414000Z" level=debug msg="Registering GET, /containers/{name:.*}/changes"
time="2017-04-17T14:16:03.801547000Z" level=debug msg="Registering GET, /containers/{name:.*}/json"
time="2017-04-17T14:16:03.801662000Z" level=debug msg="Registering GET, /containers/{name:.*}/top"
time="2017-04-17T14:16:03.801784000Z" level=debug msg="Registering GET, /containers/{name:.*}/logs"
time="2017-04-17T14:16:03.801906000Z" level=debug msg="Registering GET, /containers/{name:.*}/stats"
time="2017-04-17T14:16:03.802029000Z" level=debug msg="Registering GET, /containers/{name:.*}/attach/ws"
time="2017-04-17T14:16:03.802173000Z" level=debug msg="Registering GET, /exec/{id:.*}/json"
time="2017-04-17T14:16:03.802297000Z" level=debug msg="Registering GET, /containers/{name:.*}/archive"
time="2017-04-17T14:16:03.802417000Z" level=debug msg="Registering POST, /containers/create"
time="2017-04-17T14:16:03.802519000Z" level=debug msg="Registering POST, /containers/{name:.*}/kill"
time="2017-04-17T14:16:03.802627000Z" level=debug msg="Registering POST, /containers/{name:.*}/pause"
time="2017-04-17T14:16:03.802745000Z" level=debug msg="Registering POST, /containers/{name:.*}/unpause"
time="2017-04-17T14:16:03.802872000Z" level=debug msg="Registering POST, /containers/{name:.*}/restart"
time="2017-04-17T14:16:03.802984000Z" level=debug msg="Registering POST, /containers/{name:.*}/start"
time="2017-04-17T14:16:03.808331000Z" level=debug msg="Registering POST, /containers/{name:.*}/stop"
time="2017-04-17T14:16:03.808650000Z" level=debug msg="Registering POST, /containers/{name:.*}/wait"
time="2017-04-17T14:16:03.808925000Z" level=debug msg="Registering POST, /containers/{name:.*}/resize"
time="2017-04-17T14:16:03.809238000Z" level=debug msg="Registering POST, /containers/{name:.*}/attach"
time="2017-04-17T14:16:03.809539000Z" level=debug msg="Registering POST, /containers/{name:.*}/copy"
time="2017-04-17T14:16:03.809832000Z" level=debug msg="Registering POST, /containers/{name:.*}/exec"
time="2017-04-17T14:16:03.810151000Z" level=debug msg="Registering POST, /exec/{name:.*}/start"
time="2017-04-17T14:16:03.813480000Z" level=debug msg="Registering POST, /exec/{name:.*}/resize"
time="2017-04-17T14:16:03.813775000Z" level=debug msg="Registering POST, /containers/{name:.*}/rename"
time="2017-04-17T14:16:03.814096000Z" level=debug msg="Registering POST, /containers/{name:.*}/update"
time="2017-04-17T14:16:03.814393000Z" level=debug msg="Registering POST, /containers/prune"
time="2017-04-17T14:16:03.814627000Z" level=debug msg="Registering PUT, /containers/{name:.*}/archive"
time="2017-04-17T14:16:03.814932000Z" level=debug msg="Registering DELETE, /containers/{name:.*}"
time="2017-04-17T14:16:03.815552000Z" level=debug msg="Registering GET, /images/json"
time="2017-04-17T14:16:03.815670000Z" level=debug msg="Registering GET, /images/search"
time="2017-04-17T14:16:03.815756000Z" level=debug msg="Registering GET, /images/get"
time="2017-04-17T14:16:03.815834000Z" level=debug msg="Registering GET, /images/{name:.*}/get"
time="2017-04-17T14:16:03.815955000Z" level=debug msg="Registering GET, /images/{name:.*}/history"
time="2017-04-17T14:16:03.816074000Z" level=debug msg="Registering GET, /images/{name:.*}/json"
time="2017-04-17T14:16:03.816210000Z" level=debug msg="Registering POST, /commit"
time="2017-04-17T14:16:03.816282000Z" level=debug msg="Registering POST, /images/load"
time="2017-04-17T14:16:03.816387000Z" level=debug msg="Registering POST, /images/create"
time="2017-04-17T14:16:03.816492000Z" level=debug msg="Registering POST, /images/{name:.*}/push"
time="2017-04-17T14:16:03.816611000Z" level=debug msg="Registering POST, /images/{name:.*}/tag"
time="2017-04-17T14:16:03.816724000Z" level=debug msg="Registering POST, /images/prune"
time="2017-04-17T14:16:03.816805000Z" level=debug msg="Registering DELETE, /images/{name:.*}"
time="2017-04-17T14:16:03.816922000Z" level=debug msg="Registering OPTIONS, /{anyroute:.*}"
time="2017-04-17T14:16:03.817023000Z" level=debug msg="Registering GET, /_ping"
time="2017-04-17T14:16:03.817090000Z" level=debug msg="Registering GET, /events"
time="2017-04-17T14:16:03.817197000Z" level=debug msg="Registering GET, /info"
time="2017-04-17T14:16:03.817264000Z" level=debug msg="Registering GET, /version"
time="2017-04-17T14:16:03.817360000Z" level=debug msg="Registering GET, /system/df"
time="2017-04-17T14:16:03.817465000Z" level=debug msg="Registering POST, /auth"
time="2017-04-17T14:16:03.817532000Z" level=debug msg="Registering GET, /volumes"
time="2017-04-17T14:16:03.817609000Z" level=debug msg="Registering GET, /volumes/{name:.*}"
time="2017-04-17T14:16:03.817721000Z" level=debug msg="Registering POST, /volumes/create"
time="2017-04-17T14:16:03.817810000Z" level=debug msg="Registering POST, /volumes/prune"
time="2017-04-17T14:16:03.817916000Z" level=debug msg="Registering DELETE, /volumes/{name:.*}"
time="2017-04-17T14:16:03.818038000Z" level=debug msg="Registering POST, /build"
time="2017-04-17T14:16:03.818104000Z" level=debug msg="Registering POST, /swarm/init"
time="2017-04-17T14:16:03.818183000Z" level=debug msg="Registering POST, /swarm/join"
time="2017-04-17T14:16:03.818259000Z" level=debug msg="Registering POST, /swarm/leave"
time="2017-04-17T14:16:03.818336000Z" level=debug msg="Registering GET, /swarm"
time="2017-04-17T14:16:03.818467000Z" level=debug msg="Registering GET, /swarm/unlockkey"
time="2017-04-17T14:16:03.818554000Z" level=debug msg="Registering POST, /swarm/update"
time="2017-04-17T14:16:03.818638000Z" level=debug msg="Registering POST, /swarm/unlock"
time="2017-04-17T14:16:03.818716000Z" level=debug msg="Registering GET, /services"
time="2017-04-17T14:16:03.818863000Z" level=debug msg="Registering GET, /services/{id}"
time="2017-04-17T14:16:03.819059000Z" level=debug msg="Registering POST, /services/create"
time="2017-04-17T14:16:03.819142000Z" level=debug msg="Registering POST, /services/{id}/update"
time="2017-04-17T14:16:03.819297000Z" level=debug msg="Registering DELETE, /services/{id}"
time="2017-04-17T14:16:03.819559000Z" level=debug msg="Registering GET, /services/{id}/logs"
time="2017-04-17T14:16:03.819685000Z" level=debug msg="Registering GET, /nodes"
time="2017-04-17T14:16:03.819790000Z" level=debug msg="Registering GET, /nodes/{id}"
time="2017-04-17T14:16:03.819897000Z" level=debug msg="Registering DELETE, /nodes/{id}"
time="2017-04-17T14:16:03.820004000Z" level=debug msg="Registering POST, /nodes/{id}/update"
time="2017-04-17T14:16:03.820231000Z" level=debug msg="Registering GET, /tasks"
time="2017-04-17T14:16:03.820298000Z" level=debug msg="Registering GET, /tasks/{id}"
time="2017-04-17T14:16:03.820452000Z" level=debug msg="Registering GET, /tasks/{id}/logs"
time="2017-04-17T14:16:03.820608000Z" level=debug msg="Registering GET, /secrets"
time="2017-04-17T14:16:03.820772000Z" level=debug msg="Registering POST, /secrets/create"
time="2017-04-17T14:16:03.820872000Z" level=debug msg="Registering DELETE, /secrets/{id}"
time="2017-04-17T14:16:03.821024000Z" level=debug msg="Registering GET, /secrets/{id}"
time="2017-04-17T14:16:03.821140000Z" level=debug msg="Registering POST, /secrets/{id}/update"
time="2017-04-17T14:16:03.821262000Z" level=debug msg="Registering GET, /plugins"
time="2017-04-17T14:16:03.821329000Z" level=debug msg="Registering GET, /plugins/{name:.*}/json"
time="2017-04-17T14:16:03.821470000Z" level=debug msg="Registering GET, /plugins/privileges"
time="2017-04-17T14:16:03.821557000Z" level=debug msg="Registering DELETE, /plugins/{name:.*}"
time="2017-04-17T14:16:03.821685000Z" level=debug msg="Registering POST, /plugins/{name:.*}/enable"
time="2017-04-17T14:16:03.821813000Z" level=debug msg="Registering POST, /plugins/{name:.*}/disable"
time="2017-04-17T14:16:03.821928000Z" level=debug msg="Registering POST, /plugins/pull"
time="2017-04-17T14:16:03.822006000Z" level=debug msg="Registering POST, /plugins/{name:.*}/push"
time="2017-04-17T14:16:03.822116000Z" level=debug msg="Registering POST, /plugins/{name:.*}/upgrade"
time="2017-04-17T14:16:03.822238000Z" level=debug msg="Registering POST, /plugins/{name:.*}/set"
time="2017-04-17T14:16:03.822347000Z" level=debug msg="Registering POST, /plugins/create"
time="2017-04-17T14:16:03.822454000Z" level=debug msg="Registering GET, /networks"
time="2017-04-17T14:16:03.822529000Z" level=debug msg="Registering GET, /networks/"
time="2017-04-17T14:16:03.822606000Z" level=debug msg="Registering GET, /networks/{id:.+}"
time="2017-04-17T14:16:03.822712000Z" level=debug msg="Registering POST, /networks/create"
time="2017-04-17T14:16:03.822792000Z" level=debug msg="Registering POST, /networks/{id:.*}/connect"
time="2017-04-17T14:16:03.822906000Z" level=debug msg="Registering POST, /networks/{id:.*}/disconnect"
time="2017-04-17T14:16:03.823029000Z" level=debug msg="Registering POST, /networks/prune"
time="2017-04-17T14:16:03.823111000Z" level=debug msg="Registering DELETE, /networks/{id:.*}"
time="2017-04-17T14:16:03.828177000Z" level=info msg="API listen on /tmp/docker-integration/d91b9df46789c.sock"
time="2017-04-17T14:16:04.201620000Z" level=debug msg="Calling GET /_ping"
time="2017-04-17T14:16:04.202626000Z" level=debug msg="Calling GET /info"
time="2017-04-17T14:16:04.439183000Z" level=debug msg="Calling GET /_ping"
time="2017-04-17T14:16:04.439917000Z" level=debug msg="Calling POST /v1.30/images/load?quiet=1"
time="2017-04-17T14:16:04.521470000Z" level=debug msg="Start untar layer"
time="2017-04-17T14:16:04.736209000Z" level=debug msg="Untar time: 0.21472200000000002s"
time="2017-04-17T14:16:04.736325000Z" level=debug msg="Applied tar sha256:6719b42e03539a9ab2e99140109b53a88dd1dd8d85d5da6f1fcccad543024c9e to 942648b3413cf46e18a2ec0c4cd5a2a8d8fcc89ee08729a2e0851829b4030c1d, size: 4386624"
time="2017-04-17T14:16:04.749822000Z" level=debug msg="Calling POST /swarm/init"
time="2017-04-17T14:16:04.749984000Z" level=debug msg="form data: {\"AdvertiseAddr\":\"\",\"AutoLockManagers\":false,\"Availability\":\"\",\"ForceNewCluster\":false,\"ListenAddr\":\"0.0.0.0:2477\",\"Spec\":{\"CAConfig\":{},\"Dispatcher\":{},\"EncryptionConfig\":{\"AutoLockManagers\":false},\"Labels\":null,\"Orchestration\":{},\"Raft\":{\"ElectionTick\":0,\"HeartbeatTick\":0},\"TaskDefaults\":{}}}"
time="2017-04-17T14:16:04.787567000Z" level=debug msg="generated CA key and certificate" module=node
time="2017-04-17T14:16:04.787621000Z" level=debug msg="no node credentials found in: /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/d91b9df46789c/root/swarm/certificates/swarm-node.crt" error="open /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/d91b9df46789c/root/swarm/certificates/swarm-node.key: no such file or directory" module=node
time="2017-04-17T14:16:04.806814000Z" level=debug msg="issued new TLS certificate" module="node/tls" node.id=nd0egxko61vvi4262sbc6fx0z node.role=swarm-manager
time="2017-04-17T14:16:04.807072000Z" level=debug msg="new node credentials generated: /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/d91b9df46789c/root/swarm/certificates/swarm-node.crt" module="node/tls" node.id=nd0egxko61vvi4262sbc6fx0z node.role=swarm-manager
time="2017-04-17T14:16:04.811363000Z" level=debug msg="next certificate renewal scheduled for 1181h47m55.188649s from now" module="node/tls" node.id=nd0egxko61vvi4262sbc6fx0z node.role=swarm-manager time=2017-06-05 20:04:00.000001 +0000 UTC
time="2017-04-17T14:16:04.816954000Z" level=info msg="Listening for local connections" addr="/tmp/docker-execroot/d91b9df46789c/swarm/control.sock" module=node node.id=nd0egxko61vvi4262sbc6fx0z proto=unix
time="2017-04-17T14:16:04.818761000Z" level=info msg="7fc2bf7e4a2bd73 became follower at term 0" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.818792000Z" level=info msg="newRaft 7fc2bf7e4a2bd73 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.818808000Z" level=info msg="7fc2bf7e4a2bd73 became follower at term 1" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.819353000Z" level=info msg="7fc2bf7e4a2bd73 is starting a new election at term 1" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.819400000Z" level=info msg="7fc2bf7e4a2bd73 became candidate at term 2" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.819429000Z" level=info msg="7fc2bf7e4a2bd73 received MsgVoteResp from 7fc2bf7e4a2bd73 at term 2" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.819462000Z" level=info msg="7fc2bf7e4a2bd73 became leader at term 2" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.819478000Z" level=info msg="raft.node: 7fc2bf7e4a2bd73 elected leader 7fc2bf7e4a2bd73 at term 2" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.819961000Z" level=info msg="Creating default ingress network" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.820919000Z" level=debug msg="RequestPool(GlobalDefault, 10.255.0.0/16, , map[], false)"
time="2017-04-17T14:16:04.820970000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, <nil>, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:04.822197000Z" level=info msg="Listening for connections" addr="[::]:2477" module=node node.id=nd0egxko61vvi4262sbc6fx0z proto=tcp
time="2017-04-17T14:16:04.829047000Z" level=debug msg="Updating security config due to change in cluster Root CA" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=ca node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.845729000Z" level=debug msg="(*Agent).run" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.863874000Z" level=debug msg="Root CA updated successfully" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=ca node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.863978000Z" level=debug msg="Updating security config due to change in cluster Root CA or cluster spec" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=ca node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.866219000Z" level=debug msg="(*session).start" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.866867000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, <nil>, map[])"
time="2017-04-17T14:16:04.929227000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.935792000Z" level=debug method="(*session).logSubscriptions" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=56d2l21rv7pu018d8e103ffid
time="2017-04-17T14:16:04.936670000Z" level=debug method="(*session).watch" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=56d2l21rv7pu018d8e103ffid
time="2017-04-17T14:16:04.936764000Z" level=debug msg="(*session).listen" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=56d2l21rv7pu018d8e103ffid
time="2017-04-17T14:16:04.936835000Z" level=debug msg="(*session).heartbeat" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=56d2l21rv7pu018d8e103ffid
time="2017-04-17T14:16:04.937450000Z" level=debug msg="node registered" method="(*LogBroker).ListenSubscriptions" node=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.937645000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr ="
time="2017-04-17T14:16:04.937663000Z" level=debug method="(*Dispatcher).Assignments" node.id=nd0egxko61vvi4262sbc6fx0z node.session=56d2l21rv7pu018d8e103ffid
time="2017-04-17T14:16:04.937691000Z" level=debug msg="agent: registered" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.937760000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr ="
time="2017-04-17T14:16:04.937846000Z" level=info msg="Gossip cluster hostname f725cf4eef9e-4345c1f1693b"
time="2017-04-17T14:16:04.937893000Z" level=debug msg="Encryption key 1: 555df"
time="2017-04-17T14:16:04.937905000Z" level=debug msg="Encryption key 2: 3f5d4"
time="2017-04-17T14:16:04.937917000Z" level=debug msg="Encryption key 3: 391d1"
time="2017-04-17T14:16:04.938540000Z" level=debug msg="Initial encryption keys: [(key: 47e16, tag: 0xaf6d) (key: 02ab5, tag: 0xaf6c) (key: 85873, tag: 0xaf6e)]"
time="2017-04-17T14:16:04.938897000Z" level=debug msg="Initial encryption keys: [(key: 47e16, tag: 0xaf6d) (key: 02ab5, tag: 0xaf6c) (key: 85873, tag: 0xaf6e)]"
time="2017-04-17T14:16:04.939082000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.939105000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.939130000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:04.939431000Z" level=debug msg="Allocating IPv4 pools for network ingress (3o8pzln4jg0wsil8dx6ny3cgm)"
time="2017-04-17T14:16:04.939462000Z" level=debug msg="RequestPool(LocalDefault, 10.255.0.0/16, , map[], false)"
time="2017-04-17T14:16:04.939508000Z" level=debug msg="RequestAddress(LocalDefault/10.255.0.0/16, 10.255.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:04.939543000Z" level=debug msg="overlay: Received vxlan IDs: 4096"
time="2017-04-17T14:16:04.941739000Z" 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.4.0-66-generic/modules.dep.bin'`, error: exit status 1"
time="2017-04-17T14:16:04.943495000Z" 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.4.0-66-generic/modules.dep.bin'`, error: exit status 1"
time="2017-04-17T14:16:04.943647000Z" 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="2017-04-17T14:16:04.953239000Z" level=debug msg="Calling GET /info"
time="2017-04-17T14:16:04.965860000Z" level=debug msg="/sbin/iptables, [--wait -t mangle -C OUTPUT -p udp --dport 4789 -m u32 --u32 0>>22&0x3C@12&0xFFFFFF00=1048576 -j MARK --set-mark 13681891]"
time="2017-04-17T14:16:04.970414000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C INPUT -m policy --dir in --pol ipsec -p udp --dport 4789 -m u32 --u32 0>>22&0x3C@12&0xFFFFFF00=1048576 -j ACCEPT]"
time="2017-04-17T14:16:04.975174000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C INPUT -p udp --dport 4789 -m u32 --u32 0>>22&0x3C@12&0xFFFFFF00=1048576 -j DROP]"
time="2017-04-17T14:16:04.978432000Z" level=debug msg="f725cf4eef9e-4345c1f1693b: joined network 3o8pzln4jg0wsil8dx6ny3cgm"
time="2017-04-17T14:16:04.978462000Z" level=debug msg="f725cf4eef9e-4345c1f1693b: Initiating bulk sync with nodes [f725cf4eef9e-4345c1f1693b]"
time="2017-04-17T14:16:04.978622000Z" level=debug msg="/sbin/iptables, [--wait -t filter -L DOCKER-INGRESS]"
time="2017-04-17T14:16:05.060365000Z" level=debug msg="Assigning addresses for endpoint ingress-endpoint's interface on network ingress"
time="2017-04-17T14:16:05.060415000Z" level=debug msg="RequestAddress(LocalDefault/10.255.0.0/16, 10.255.0.2, map[])"
time="2017-04-17T14:16:05.067958000Z" level=debug msg="Assigning addresses for endpoint ingress-endpoint's interface on network ingress"
time="2017-04-17T14:16:05.256755000Z" level=debug msg="checkEncryption(3o8pzln, <nil>, 4096, true)"
time="2017-04-17T14:16:05Z" 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.4.0-66-generic/modules.dep.bin'`, error: exit status 1"
time="2017-04-17T14:16:05Z" 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.4.0-66-generic/modules.dep.bin'`, error: exit status 1"
time="2017-04-17T14:16:05.377025000Z" level=debug msg="Allocating IPv4 pools for network docker_gwbridge (e599a8aeb82082766877681322949fc9ef55325730459854aa344d44aa8c2887)"
time="2017-04-17T14:16:05.377069000Z" level=debug msg="RequestPool(LocalDefault, , , map[], false)"
time="2017-04-17T14:16:05.377330000Z" level=debug msg="RequestPool(LocalDefault, , , map[], false)"
time="2017-04-17T14:16:05.377454000Z" level=debug msg="RequestPool(LocalDefault, , , map[], false)"
time="2017-04-17T14:16:05.377633000Z" level=debug msg="RequestPool(LocalDefault, , , map[], false)"
time="2017-04-17T14:16:05.377750000Z" level=debug msg="RequestPool(LocalDefault, , , map[], false)"
time="2017-04-17T14:16:05.377869000Z" level=debug msg="ReleasePool(LocalDefault/172.21.0.0/16)"
time="2017-04-17T14:16:05.377895000Z" level=debug msg="ReleasePool(LocalDefault/172.20.0.0/16)"
time="2017-04-17T14:16:05.377911000Z" level=debug msg="ReleasePool(LocalDefault/172.18.0.0/16)"
time="2017-04-17T14:16:05.377926000Z" level=debug msg="ReleasePool(LocalDefault/172.17.0.0/16)"
time="2017-04-17T14:16:05.377948000Z" level=debug msg="RequestAddress(LocalDefault/172.22.0.0/16, <nil>, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:05.381851000Z" level=debug msg="Assigning address to bridge interface docker_gwbridge: 172.22.0.1/16"
time="2017-04-17T14:16:05.392315000Z" level=debug msg="/sbin/iptables, [--wait -t filter -L DOCKER-INGRESS]"
time="2017-04-17T14:16:05.394417000Z" level=debug msg="Assigning addresses for endpoint gateway_ingress-sbox's interface on network docker_gwbridge"
time="2017-04-17T14:16:05.394440000Z" level=debug msg="RequestAddress(LocalDefault/172.22.0.0/16, <nil>, map[])"
time="2017-04-17T14:16:05.397171000Z" level=debug msg="Assigning addresses for endpoint gateway_ingress-sbox's interface on network docker_gwbridge"
time="2017-04-17T14:16:05.445387000Z" level=debug msg="Programming external connectivity on endpoint gateway_ingress-sbox (8fff9d623cacdbbf74b92ea2f78d940496fbba2a0c3e8267831d71a7c839160c)"
time="2017-04-17T14:16:06.058458000Z" level=debug msg="Calling GET /swarm"
time="2017-04-17T14:16:06.181636000Z" level=debug msg="new certificate entry added" method=IssueNodeCertificate node.id=5fy73cplhm7k9pi2olk3lxckq node.role=MANAGER
time="2017-04-17T14:16:06.181950000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, <nil>, map[])"
time="2017-04-17T14:16:06.184317000Z" level=debug msg="started watching for certificate updates" method=NodeCertificateStatus node.id=5fy73cplhm7k9pi2olk3lxckq status={PENDING }
time="2017-04-17T14:16:06.193632000Z" level=debug msg="certificate issued" method="(*Server).signNodeCert" module=ca node.id=5fy73cplhm7k9pi2olk3lxckq node.role=MANAGER
time="2017-04-17T14:16:06.206147000Z" level=debug msg="certificate issued" method="(*Server).signNodeCert" module=ca node.id=5fy73cplhm7k9pi2olk3lxckq node.role=MANAGER
time="2017-04-17T14:16:06.362529000Z" level=debug method="(*Node).Join" node.id=5fy73cplhm7k9pi2olk3lxckq raft_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:06.425831000Z" level=debug msg="transport: add peer 2e55d6c0fc7e7b91 with address 127.0.0.1:2478"
time="2017-04-17T14:16:06.426376000Z" level=debug msg="node joined" method="(*Node).Join" node.id=5fy73cplhm7k9pi2olk3lxckq raft_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:06.443297000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.506953000Z" level=debug msg="7fc2bf7e4a2bd73 received msgApp rejection(lastindex: 0) from 2e55d6c0fc7e7b91 for index 15" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:06.507001000Z" level=debug msg="7fc2bf7e4a2bd73 decreased progress of 2e55d6c0fc7e7b91 to [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:06.521284000Z" level=debug msg="node registered" method="(*LogBroker).ListenSubscriptions" node=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.521628000Z" level=debug method="(*Dispatcher).Assignments" node.id=5fy73cplhm7k9pi2olk3lxckq node.session=ezkh18qebozhpgjypkvj21r6p
time="2017-04-17T14:16:07.930576000Z" level=debug msg="Calling GET /swarm"
time="2017-04-17T14:16:08.055243000Z" level=debug msg="new certificate entry added" method=IssueNodeCertificate node.id=tsfg8t1nmbz50cpzkzmomzmid node.role=MANAGER
time="2017-04-17T14:16:08.055405000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, <nil>, map[])"
time="2017-04-17T14:16:08.059406000Z" level=debug msg="started watching for certificate updates" method=NodeCertificateStatus node.id=tsfg8t1nmbz50cpzkzmomzmid status={PENDING }
time="2017-04-17T14:16:08.090370000Z" level=debug msg="certificate issued" method="(*Server).signNodeCert" module=ca node.id=tsfg8t1nmbz50cpzkzmomzmid node.role=MANAGER
time="2017-04-17T14:16:08.110049000Z" level=debug msg="certificate issued" method="(*Server).signNodeCert" module=ca node.id=tsfg8t1nmbz50cpzkzmomzmid node.role=MANAGER
time="2017-04-17T14:16:08.250785000Z" level=debug method="(*Node).Join" node.id=tsfg8t1nmbz50cpzkzmomzmid raft_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:08.315306000Z" level=debug msg="transport: add peer 26315b37c1589836 with address 127.0.0.1:2479"
time="2017-04-17T14:16:08.315874000Z" level=debug msg="node joined" method="(*Node).Join" node.id=tsfg8t1nmbz50cpzkzmomzmid raft_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:08.324541000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.338154000Z" level=debug msg="node registered" method="(*LogBroker).ListenSubscriptions" node=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:08.370042000Z" level=debug method="(*Dispatcher).Assignments" node.id=tsfg8t1nmbz50cpzkzmomzmid node.session=f6y8ib7za9yrweybdxvsw5p2j
time="2017-04-17T14:16:08.438321000Z" level=debug msg="7fc2bf7e4a2bd73 received msgApp rejection(lastindex: 0) from 26315b37c1589836 for index 21" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:08.438394000Z" level=debug msg="7fc2bf7e4a2bd73 decreased progress of 26315b37c1589836 to [next = 1, match = 0, state = ProgressStateProbe, waiting = false, pendingSnapshot = 0]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:08.767084000Z" level=debug msg="Calling GET /nodes/nd0egxko61vvi4262sbc6fx0z"
time="2017-04-17T14:16:08.768676000Z" level=debug msg="Calling GET /nodes/5fy73cplhm7k9pi2olk3lxckq"
time="2017-04-17T14:16:08.769905000Z" level=debug msg="Calling GET /nodes/tsfg8t1nmbz50cpzkzmomzmid"
time="2017-04-17T14:16:08.770918000Z" level=info msg="Processing signal 'interrupt'"
time="2017-04-17T14:16:08.772123000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:08.772150000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:08.772170000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:08.773432000Z" level=info msg="Stopping manager" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:08.773507000Z" level=info msg="shutting down certificate renewal routine" module="node/tls" node.id=nd0egxko61vvi4262sbc6fx0z node.role=swarm-manager
time="2017-04-17T14:16:08.773540000Z" level=debug msg="(*Agent).run exited" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:08.774704000Z" level=error msg="failed to remove node" error="rpc error: code = 10 desc = dispatcher is stopped" method="(*Dispatcher).Session" node.id=5fy73cplhm7k9pi2olk3lxckq node.session=ezkh18qebozhpgjypkvj21r6p
time="2017-04-17T14:16:08.774829000Z" level=error msg="LogBroker exited with an error" error="context canceled" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:08.775771000Z" level=debug msg="stop transport"
time="2017-04-17T14:16:08.776050000Z" level=info msg="Manager shut down" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:08.776145000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr =127.0.0.1"
time="2017-04-17T14:16:08.776332000Z" level=debug msg="memberlist: Initiating push/pull sync with: 127.0.0.1:7946"
time="2017-04-17T14:16:08.776421000Z" level=debug msg="memberlist: TCP connection from=127.0.0.1:35568"
time="2017-04-17T14:16:08.776706000Z" level=error msg="cluster exited with error: manager stopped: context canceled"
time="2017-04-17T14:16:08.776832000Z" level=debug msg="start clean shutdown of all containers with a 15 seconds timeout..."
time="2017-04-17T14:16:08.776921000Z" level=debug msg="start clean shutdown of cluster resources..."
time="2017-04-17T14:16:13.777403000Z" level=error msg="Error in joining gossip cluster : failed to send node join: timed out broadcasting node event(join will be retried in background)"
time="2017-04-17T14:16:18.777906000Z" level=error msg="failed to send node leave: timed out broadcasting node event"
time="2017-04-17T14:16:18.944071000Z" level=debug msg="checkEncryption(3o8pzln, <nil>, 0, true)"
time="2017-04-17T14:16:18.976598000Z" level=debug msg="Revoking external connectivity on endpoint gateway_ingress-sbox (8fff9d623cacdbbf74b92ea2f78d940496fbba2a0c3e8267831d71a7c839160c)"
time="2017-04-17T14:16:18.980767000Z" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-04-17T14:16:19.068993000Z" level=debug msg="Releasing addresses for endpoint gateway_ingress-sbox's interface on network docker_gwbridge"
time="2017-04-17T14:16:19.069053000Z" level=debug msg="ReleaseAddress(LocalDefault/172.22.0.0/16, 172.22.0.2)"
time="2017-04-17T14:16:19.086378000Z" level=debug msg="Releasing addresses for endpoint ingress-endpoint's interface on network ingress"
time="2017-04-17T14:16:19.086467000Z" level=debug msg="ReleaseAddress(LocalDefault/10.255.0.0/16, 10.255.0.2)"
time="2017-04-17T14:16:19.109891000Z" level=debug msg="releasing IPv4 pools from network ingress (3o8pzln4jg0wsil8dx6ny3cgm)"
time="2017-04-17T14:16:19.109924000Z" level=debug msg="ReleaseAddress(LocalDefault/10.255.0.0/16, 10.255.0.1)"
time="2017-04-17T14:16:19.109948000Z" level=debug msg="ReleasePool(LocalDefault/10.255.0.0/16)"
time="2017-04-17T14:16:19.111384000Z" level=debug msg="Unix socket /run/docker/libnetwork/3c09af56d5281b1a87750cdf3d765b1ceeb163910d1e7b3af1b7704556b38ddc.sock doesn't exist. cannot accept client connections"
time="2017-04-17T14:16:19.110291000Z" level=debug msg="Cleaning up old mountid : start."
time="2017-04-17T14:16:19.112098000Z" level=debug msg="Cleaning up old mountid : done."
time="2017-04-17T14:16:19.112130000Z" level=debug msg="Clean shutdown succeeded"
time="2017-04-17T14:16:19.151544000Z" level=debug msg="Listener created for HTTP on unix (/tmp/docker-integration/d91b9df46789c.sock)"
time="2017-04-17T14:16:19.152416000Z" level=warning msg="failed to rename /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/d91b9df46789c/root/tmp for background deletion: %!s(<nil>). Deleting synchronously"
time="2017-04-17T14:16:19.152759000Z" level=debug msg="Using default logging driver json-file"
time="2017-04-17T14:16:19.152790000Z" level=debug msg="Golang's threads limit set to 57960"
time="2017-04-17T14:16:19.153028000Z" level=debug msg="[graphdriver] trying provided driver: vfs"
time="2017-04-17T14:16:19.153069000Z" level=debug msg="Using graph driver vfs"
time="2017-04-17T14:16:19.153331000Z" level=debug msg="Max Concurrent Downloads: 3"
time="2017-04-17T14:16:19.153345000Z" level=debug msg="Max Concurrent Uploads: 5"
time="2017-04-17T14:16:19.157531000Z" level=info msg="Graph migration to content-addressability took 0.00 seconds"
time="2017-04-17T14:16:19.157741000Z" level=warning msg="Your kernel does not support swap memory limit"
time="2017-04-17T14:16:19.157801000Z" level=warning msg="Your kernel does not support cgroup rt period"
time="2017-04-17T14:16:19.157818000Z" level=warning msg="Your kernel does not support cgroup rt runtime"
time="2017-04-17T14:16:19.158246000Z" level=info msg="Loading containers: start."
time="2017-04-17T14:16:19.158308000Z" level=debug msg="Option Experimental: false"
time="2017-04-17T14:16:19.158321000Z" level=debug msg="Option DefaultDriver: bridge"
time="2017-04-17T14:16:19.158332000Z" level=debug msg="Option DefaultNetwork: bridge"
time="2017-04-17T14:16:19.160215000Z" level=warning msg="Running modprobe bridge br_netfilter failed with message: modprobe: ERROR: ../libkmod/libkmod.c:557 kmod_search_moddep() could not open moddep file '/lib/modules/4.4.0-66-generic/modules.dep.bin'\nmodprobe: ERROR: ../libkmod/libkmod.c:557 kmod_search_moddep() could not open moddep file '/lib/modules/4.4.0-66-generic/modules.dep.bin'\n, error: exit status 1"
time="2017-04-17T14:16:19.161505000Z" 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.4.0-66-generic/modules.dep.bin'`, error: exit status 1"
time="2017-04-17T14:16:19.162591000Z" 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.4.0-66-generic/modules.dep.bin'`, error: exit status 1"
time="2017-04-17T14:16:19.162682000Z" 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="2017-04-17T14:16:19.165528000Z" level=debug msg="/sbin/iptables, [--wait -t nat -D PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-04-17T14:16:19.167184000Z" level=debug msg="/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL ! --dst 127.0.0.0/8 -j DOCKER]"
time="2017-04-17T14:16:19.168788000Z" level=debug msg="/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-04-17T14:16:19.170592000Z" level=debug msg="/sbin/iptables, [--wait -t nat -D PREROUTING]"
time="2017-04-17T14:16:19.171892000Z" level=debug msg="/sbin/iptables, [--wait -t nat -D OUTPUT]"
time="2017-04-17T14:16:19.173102000Z" level=debug msg="/sbin/iptables, [--wait -t nat -F DOCKER]"
time="2017-04-17T14:16:19.174208000Z" level=debug msg="/sbin/iptables, [--wait -t nat -X DOCKER]"
time="2017-04-17T14:16:19.175427000Z" level=debug msg="/sbin/iptables, [--wait -t filter -F DOCKER]"
time="2017-04-17T14:16:19.176454000Z" level=debug msg="/sbin/iptables, [--wait -t filter -X DOCKER]"
time="2017-04-17T14:16:19.177461000Z" level=debug msg="/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.178558000Z" level=debug msg="/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.179582000Z" level=debug msg="/sbin/iptables, [--wait -t nat -n -L DOCKER]"
time="2017-04-17T14:16:19.181625000Z" level=debug msg="/sbin/iptables, [--wait -t nat -N DOCKER]"
time="2017-04-17T14:16:19.183008000Z" level=debug msg="/sbin/iptables, [--wait -t filter -n -L DOCKER]"
time="2017-04-17T14:16:19.184435000Z" level=debug msg="/sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.185690000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION -j RETURN]"
time="2017-04-17T14:16:19.187451000Z" level=debug msg="/sbin/iptables, [--wait -I DOCKER-ISOLATION -j RETURN]"
time="2017-04-17T14:16:19.198755000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP]"
time="2017-04-17T14:16:19.200308000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.202139000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.203424000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-04-17T14:16:19.205168000Z" level=debug msg="/sbin/iptables, [--wait -t nat -A PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-04-17T14:16:19.206691000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8]"
time="2017-04-17T14:16:19.208301000Z" level=debug msg="/sbin/iptables, [--wait -t nat -A OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8]"
time="2017-04-17T14:16:19.209616000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-04-17T14:16:19.210804000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-04-17T14:16:19.212048000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-04-17T14:16:19.213702000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-04-17T14:16:19.215077000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.216382000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -j DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.217762000Z" level=debug msg="/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.219230000Z" level=debug msg="Network (dc32fd1) restored"
time="2017-04-17T14:16:19.223149000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.22.0.0/16 ! -o docker_gwbridge -j MASQUERADE]"
time="2017-04-17T14:16:19.224862000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -i docker_gwbridge -j RETURN]"
time="2017-04-17T14:16:19.226153000Z" level=debug msg="/sbin/iptables, [--wait -t nat -I DOCKER -i docker_gwbridge -j RETURN]"
time="2017-04-17T14:16:19.227404000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -i docker_gwbridge -o docker_gwbridge -j ACCEPT]"
time="2017-04-17T14:16:19.228741000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker_gwbridge -o docker_gwbridge -j DROP]"
time="2017-04-17T14:16:19.229943000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker_gwbridge ! -o docker_gwbridge -j ACCEPT]"
time="2017-04-17T14:16:19.231169000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-04-17T14:16:19.232512000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-04-17T14:16:19.233868000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8]"
time="2017-04-17T14:16:19.235318000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8]"
time="2017-04-17T14:16:19.237171000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker_gwbridge -j DOCKER]"
time="2017-04-17T14:16:19.238551000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker_gwbridge -j DOCKER]"
time="2017-04-17T14:16:19.239941000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker_gwbridge -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-04-17T14:16:19.241428000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker_gwbridge -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-04-17T14:16:19.242874000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.244270000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -j DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.245576000Z" level=debug msg="/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.247021000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION -i docker_gwbridge -o docker0 -j DROP]"
time="2017-04-17T14:16:19.248518000Z" level=debug msg="/sbin/iptables, [--wait -I DOCKER-ISOLATION -i docker_gwbridge -o docker0 -j DROP]"
time="2017-04-17T14:16:19.249885000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION -i docker0 -o docker_gwbridge -j DROP]"
time="2017-04-17T14:16:19.252224000Z" level=debug msg="/sbin/iptables, [--wait -I DOCKER-ISOLATION -i docker0 -o docker_gwbridge -j DROP]"
time="2017-04-17T14:16:19.253943000Z" level=warning msg="running inside docker container, ignoring missing kernel params: open /proc/sys/net/bridge/bridge-nf-call-iptables: no such file or directory"
time="2017-04-17T14:16:19.254157000Z" level=debug msg="Network (e599a8a) restored"
time="2017-04-17T14:16:19.276697000Z" level=debug msg="Allocating IPv4 pools for network bridge (dc32fd1004a70ad767fe43e0082b128d666d3f6625650afb96e0c0e634ae7d9c)"
time="2017-04-17T14:16:19.276758000Z" level=debug msg="RequestPool(LocalDefault, 172.19.0.0/16, , map[], false)"
time="2017-04-17T14:16:19.276809000Z" level=debug msg="RequestAddress(LocalDefault/172.19.0.0/16, 172.19.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:19.276895000Z" level=debug msg="Allocating IPv4 pools for network docker_gwbridge (e599a8aeb82082766877681322949fc9ef55325730459854aa344d44aa8c2887)"
time="2017-04-17T14:16:19.276913000Z" level=debug msg="RequestPool(LocalDefault, 172.22.0.0/16, , map[], false)"
time="2017-04-17T14:16:19.276941000Z" level=debug msg="RequestAddress(LocalDefault/172.22.0.0/16, 172.22.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:19.292100000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.294578000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.297179000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.298828000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.300251000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-04-17T14:16:19.301868000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-04-17T14:16:19.303369000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -o docker0 -j DOCKER]"
time="2017-04-17T14:16:19.305965000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-04-17T14:16:19.307423000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-04-17T14:16:19.309840000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-04-17T14:16:19.311478000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION -i docker0 -o docker_gwbridge -j DROP]"
time="2017-04-17T14:16:19.312873000Z" level=debug msg="/sbin/iptables, [--wait -D DOCKER-ISOLATION -i docker0 -o docker_gwbridge -j DROP]"
time="2017-04-17T14:16:19.315163000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION -i docker_gwbridge -o docker0 -j DROP]"
time="2017-04-17T14:16:19.316881000Z" level=debug msg="/sbin/iptables, [--wait -D DOCKER-ISOLATION -i docker_gwbridge -o docker0 -j DROP]"
time="2017-04-17T14:16:19.325146000Z" level=debug msg="releasing IPv4 pools from network bridge (dc32fd1004a70ad767fe43e0082b128d666d3f6625650afb96e0c0e634ae7d9c)"
time="2017-04-17T14:16:19.325187000Z" level=debug msg="ReleaseAddress(LocalDefault/172.19.0.0/16, 172.19.0.1)"
time="2017-04-17T14:16:19.325274000Z" level=debug msg="ReleasePool(LocalDefault/172.19.0.0/16)"
time="2017-04-17T14:16:19.332859000Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.19.0.0/16. Daemon option --bip can be used to set a preferred IP address"
time="2017-04-17T14:16:19.332938000Z" level=debug msg="Allocating IPv4 pools for network bridge (676d8a26ed5e05e659b9ea5ae862cc87d69d6836680d49d8b44d99d0e968a764)"
time="2017-04-17T14:16:19.332961000Z" level=debug msg="RequestPool(LocalDefault, 172.19.0.0/16, , map[], false)"
time="2017-04-17T14:16:19.333000000Z" level=debug msg="RequestAddress(LocalDefault/172.19.0.0/16, 172.19.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:19.333472000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.19.0.0/16 ! -o docker0 -j MASQUERADE]"
time="2017-04-17T14:16:19.335429000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -i docker0 -j RETURN]"
time="2017-04-17T14:16:19.337086000Z" level=debug msg="/sbin/iptables, [--wait -t nat -I DOCKER -i docker0 -j RETURN]"
time="2017-04-17T14:16:19.338792000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP]"
time="2017-04-17T14:16:19.340417000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.341805000Z" level=debug msg="/sbin/iptables, [--wait -I FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.344091000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.345608000Z" level=debug msg="/sbin/iptables, [--wait -I FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-04-17T14:16:19.347167000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-04-17T14:16:19.348776000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-04-17T14:16:19.351991000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8]"
time="2017-04-17T14:16:19.353329000Z" level=debug msg="/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8]"
time="2017-04-17T14:16:19.355548000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-04-17T14:16:19.361164000Z" level=debug msg="/sbin/iptables, [--wait -I FORWARD -o docker0 -j DOCKER]"
time="2017-04-17T14:16:19.362588000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-04-17T14:16:19.363943000Z" level=debug msg="/sbin/iptables, [--wait -I FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-04-17T14:16:19.365788000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.367018000Z" level=debug msg="/sbin/iptables, [--wait -D FORWARD -j DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.368180000Z" level=debug msg="/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION]"
time="2017-04-17T14:16:19.369322000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION -i docker0 -o docker_gwbridge -j DROP]"
time="2017-04-17T14:16:19.370375000Z" level=debug msg="/sbin/iptables, [--wait -I DOCKER-ISOLATION -i docker0 -o docker_gwbridge -j DROP]"
time="2017-04-17T14:16:19.371498000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION -i docker_gwbridge -o docker0 -j DROP]"
time="2017-04-17T14:16:19.372692000Z" level=debug msg="/sbin/iptables, [--wait -I DOCKER-ISOLATION -i docker_gwbridge -o docker0 -j DROP]"
time="2017-04-17T14:16:19.378327000Z" level=info msg="Loading containers: done."
time="2017-04-17T14:16:19.410922000Z" level=debug msg="loaded node credentials" module="node/tls" node.id=nd0egxko61vvi4262sbc6fx0z node.role=swarm-manager
time="2017-04-17T14:16:19.411378000Z" level=debug msg="(*Agent).run" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.413867000Z" level=debug msg="next certificate renewal scheduled for 1104h36m40.586177s from now" module="node/tls" node.id=nd0egxko61vvi4262sbc6fx0z node.role=swarm-manager time=2017-06-02 14:53:00.000001 +0000 UTC
time="2017-04-17T14:16:19.419693000Z" level=info msg="Listening for connections" addr="[::]:2477" module=node node.id=nd0egxko61vvi4262sbc6fx0z proto=tcp
time="2017-04-17T14:16:19.419885000Z" level=info msg="Listening for local connections" addr="/tmp/docker-execroot/d91b9df46789c/swarm/control.sock" module=node node.id=nd0egxko61vvi4262sbc6fx0z proto=unix
time="2017-04-17T14:16:19.431568000Z" level=debug msg="(*session).start" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.438883000Z" level=warning msg="ignoring request to join cluster, because raft state already exists" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.438976000Z" level=info msg="7fc2bf7e4a2bd73 became follower at term 2" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.439484000Z" level=info msg="newRaft 7fc2bf7e4a2bd73 [peers: [], term: 2, commit: 22, applied: 0, lastindex: 22, lastterm: 2]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.445401000Z" level=debug msg="transport: add peer 2e55d6c0fc7e7b91 with address 127.0.0.1:2478"
time="2017-04-17T14:16:19.446066000Z" level=debug msg="transport: add peer 26315b37c1589836 with address 127.0.0.1:2479"
time="2017-04-17T14:16:19.552707000Z" level=debug msg="(*session).heartbeat" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=dn4pr76g1cjn6lp7ykfdn694x
time="2017-04-17T14:16:19.552724000Z" level=debug method="(*session).watch" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=dn4pr76g1cjn6lp7ykfdn694x
time="2017-04-17T14:16:19.553243000Z" level=debug msg="(*session).listen" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=dn4pr76g1cjn6lp7ykfdn694x
time="2017-04-17T14:16:19.554025000Z" level=debug method="(*session).logSubscriptions" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=dn4pr76g1cjn6lp7ykfdn694x
time="2017-04-17T14:16:19.555088000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr =127.0.0.1"
time="2017-04-17T14:16:19.555114000Z" level=debug msg="agent: registered" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.555135000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.555159000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.555182000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.555227000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr =127.0.0.1"
time="2017-04-17T14:16:19.555336000Z" level=info msg="Daemon has completed initialization"
time="2017-04-17T14:16:19.555363000Z" level=info msg="Docker daemon" commit=a100c08 graphdriver=vfs version=17.06.0-dev
time="2017-04-17T14:16:19.555460000Z" level=debug msg="Registering routers"
time="2017-04-17T14:16:19.555473000Z" level=debug msg="Registering GET, /containers/{name:.*}/checkpoints"
time="2017-04-17T14:16:19.555669000Z" level=debug msg="Registering POST, /containers/{name:.*}/checkpoints"
time="2017-04-17T14:16:19.555832000Z" level=debug msg="Registering DELETE, /containers/{name}/checkpoints/{checkpoint}"
time="2017-04-17T14:16:19.556055000Z" level=debug msg="Registering HEAD, /containers/{name:.*}/archive"
time="2017-04-17T14:16:19.556197000Z" level=debug msg="Registering GET, /containers/json"
time="2017-04-17T14:16:19.556280000Z" level=debug msg="Registering GET, /containers/{name:.*}/export"
time="2017-04-17T14:16:19.556420000Z" level=debug msg="Registering GET, /containers/{name:.*}/changes"
time="2017-04-17T14:16:19.556543000Z" level=debug msg="Registering GET, /containers/{name:.*}/json"
time="2017-04-17T14:16:19.556654000Z" level=debug msg="Registering GET, /containers/{name:.*}/top"
time="2017-04-17T14:16:19.556778000Z" level=debug msg="Registering GET, /containers/{name:.*}/logs"
time="2017-04-17T14:16:19.556921000Z" level=debug msg="Registering GET, /containers/{name:.*}/stats"
time="2017-04-17T14:16:19.557056000Z" level=debug msg="Registering GET, /containers/{name:.*}/attach/ws"
time="2017-04-17T14:16:19.557184000Z" level=debug msg="Registering GET, /exec/{id:.*}/json"
time="2017-04-17T14:16:19.557288000Z" level=debug msg="Registering GET, /containers/{name:.*}/archive"
time="2017-04-17T14:16:19.557415000Z" level=debug msg="Registering POST, /containers/create"
time="2017-04-17T14:16:19.557502000Z" level=debug msg="Registering POST, /containers/{name:.*}/kill"
time="2017-04-17T14:16:19.557612000Z" level=debug msg="Registering POST, /containers/{name:.*}/pause"
time="2017-04-17T14:16:19.557735000Z" level=debug msg="Registering POST, /containers/{name:.*}/unpause"
time="2017-04-17T14:16:19.557846000Z" level=debug msg="Registering POST, /containers/{name:.*}/restart"
time="2017-04-17T14:16:19.557966000Z" level=debug msg="Registering POST, /containers/{name:.*}/start"
time="2017-04-17T14:16:19.555338000Z" level=info msg="Gossip cluster hostname f725cf4eef9e-60f32d02595c"
time="2017-04-17T14:16:19.558121000Z" level=debug msg="Encryption key 1: 555df"
time="2017-04-17T14:16:19.558134000Z" level=debug msg="Encryption key 2: 3f5d4"
time="2017-04-17T14:16:19.558145000Z" level=debug msg="Encryption key 3: 391d1"
time="2017-04-17T14:16:19.558178000Z" level=debug msg="Registering POST, /containers/{name:.*}/stop"
time="2017-04-17T14:16:19.558347000Z" level=debug msg="Registering POST, /containers/{name:.*}/wait"
time="2017-04-17T14:16:19.558557000Z" level=debug msg="Registering POST, /containers/{name:.*}/resize"
time="2017-04-17T14:16:19.558667000Z" level=debug msg="Initial encryption keys: [(key: 47e16, tag: 0xaf6d) (key: 02ab5, tag: 0xaf6c) (key: 85873, tag: 0xaf6e)]"
time="2017-04-17T14:16:19.558704000Z" level=debug msg="Registering POST, /containers/{name:.*}/attach"
time="2017-04-17T14:16:19.558847000Z" level=debug msg="Registering POST, /containers/{name:.*}/copy"
time="2017-04-17T14:16:19.558974000Z" level=debug msg="Initial encryption keys: [(key: 47e16, tag: 0xaf6d) (key: 02ab5, tag: 0xaf6c) (key: 85873, tag: 0xaf6e)]"
time="2017-04-17T14:16:19.559005000Z" level=debug msg="Registering POST, /containers/{name:.*}/exec"
time="2017-04-17T14:16:19.559124000Z" level=debug msg="Registering POST, /exec/{name:.*}/start"
time="2017-04-17T14:16:19.559142000Z" level=debug msg="memberlist: TCP connection from=127.0.0.1:35592"
time="2017-04-17T14:16:19.559226000Z" level=debug msg="memberlist: Initiating push/pull sync with: 127.0.0.1:7946"
time="2017-04-17T14:16:19.559254000Z" level=debug msg="Registering POST, /exec/{name:.*}/resize"
time="2017-04-17T14:16:19.572710000Z" level=debug msg="Registering POST, /containers/{name:.*}/rename"
time="2017-04-17T14:16:19.573035000Z" level=debug msg="Registering POST, /containers/{name:.*}/update"
time="2017-04-17T14:16:19.573354000Z" level=debug msg="Registering POST, /containers/prune"
time="2017-04-17T14:16:19.573606000Z" level=debug msg="Registering PUT, /containers/{name:.*}/archive"
time="2017-04-17T14:16:19.573914000Z" level=debug msg="Registering DELETE, /containers/{name:.*}"
time="2017-04-17T14:16:19.574220000Z" level=debug msg="Registering GET, /images/json"
time="2017-04-17T14:16:19.574412000Z" level=debug msg="Registering GET, /images/search"
time="2017-04-17T14:16:19.574622000Z" level=debug msg="Registering GET, /images/get"
time="2017-04-17T14:16:19.574807000Z" level=debug msg="Registering GET, /images/{name:.*}/get"
time="2017-04-17T14:16:19.575110000Z" level=debug msg="Registering GET, /images/{name:.*}/history"
time="2017-04-17T14:16:19.575415000Z" level=debug msg="Registering GET, /images/{name:.*}/json"
time="2017-04-17T14:16:19.575695000Z" level=debug msg="Registering POST, /commit"
time="2017-04-17T14:16:19.575861000Z" level=debug msg="Registering POST, /images/load"
time="2017-04-17T14:16:19.576071000Z" level=debug msg="Registering POST, /images/create"
time="2017-04-17T14:16:19.576293000Z" level=debug msg="Registering POST, /images/{name:.*}/push"
time="2017-04-17T14:16:19.576584000Z" level=debug msg="Registering POST, /images/{name:.*}/tag"
time="2017-04-17T14:16:19.576873000Z" level=debug msg="Registering POST, /images/prune"
time="2017-04-17T14:16:19.577076000Z" level=debug msg="Registering DELETE, /images/{name:.*}"
time="2017-04-17T14:16:19.577363000Z" level=debug msg="Registering OPTIONS, /{anyroute:.*}"
time="2017-04-17T14:16:19.577579000Z" level=debug msg="Registering GET, /_ping"
time="2017-04-17T14:16:19.577732000Z" level=debug msg="Registering GET, /events"
time="2017-04-17T14:16:19.577976000Z" level=debug msg="Registering GET, /info"
time="2017-04-17T14:16:19.578121000Z" level=debug msg="Registering GET, /version"
time="2017-04-17T14:16:19.578290000Z" level=debug msg="Registering GET, /system/df"
time="2017-04-17T14:16:19.578496000Z" level=debug msg="Registering POST, /auth"
time="2017-04-17T14:16:19.578643000Z" level=debug msg="Registering GET, /volumes"
time="2017-04-17T14:16:19.578830000Z" level=debug msg="Registering GET, /volumes/{name:.*}"
time="2017-04-17T14:16:19.579134000Z" level=debug msg="Registering POST, /volumes/create"
time="2017-04-17T14:16:19.579355000Z" level=debug msg="Registering POST, /volumes/prune"
time="2017-04-17T14:16:19.579558000Z" level=debug msg="Registering DELETE, /volumes/{name:.*}"
time="2017-04-17T14:16:19.579851000Z" level=debug msg="Registering POST, /build"
time="2017-04-17T14:16:19.580012000Z" level=debug msg="Registering POST, /swarm/init"
time="2017-04-17T14:16:19.580221000Z" level=debug msg="Registering POST, /swarm/join"
time="2017-04-17T14:16:19.580432000Z" level=debug msg="Registering POST, /swarm/leave"
time="2017-04-17T14:16:19.580622000Z" level=debug msg="Registering GET, /swarm"
time="2017-04-17T14:16:19.580770000Z" level=debug msg="Registering GET, /swarm/unlockkey"
time="2017-04-17T14:16:19.581032000Z" level=debug msg="Registering POST, /swarm/update"
time="2017-04-17T14:16:19.581679000Z" level=debug msg="Registering POST, /swarm/unlock"
time="2017-04-17T14:16:19.581776000Z" level=debug msg="Registering GET, /services"
time="2017-04-17T14:16:19.581865000Z" level=debug msg="Registering GET, /services/{id}"
time="2017-04-17T14:16:19.581980000Z" level=debug msg="Registering POST, /services/create"
time="2017-04-17T14:16:19.582074000Z" level=debug msg="Registering POST, /services/{id}/update"
time="2017-04-17T14:16:19.582208000Z" level=debug msg="Registering DELETE, /services/{id}"
time="2017-04-17T14:16:19.582337000Z" level=debug msg="Registering GET, /services/{id}/logs"
time="2017-04-17T14:16:19.582467000Z" level=debug msg="Registering GET, /nodes"
time="2017-04-17T14:16:19.582536000Z" level=debug msg="Registering GET, /nodes/{id}"
time="2017-04-17T14:16:19.582646000Z" level=debug msg="Registering DELETE, /nodes/{id}"
time="2017-04-17T14:16:19.582756000Z" level=debug msg="Registering POST, /nodes/{id}/update"
time="2017-04-17T14:16:19.582877000Z" level=debug msg="Registering GET, /tasks"
time="2017-04-17T14:16:19.582941000Z" level=debug msg="Registering GET, /tasks/{id}"
time="2017-04-17T14:16:19.583046000Z" level=debug msg="Registering GET, /tasks/{id}/logs"
time="2017-04-17T14:16:19.583162000Z" level=debug msg="Registering GET, /secrets"
time="2017-04-17T14:16:19.583245000Z" level=debug msg="Registering POST, /secrets/create"
time="2017-04-17T14:16:19.583330000Z" level=debug msg="Registering DELETE, /secrets/{id}"
time="2017-04-17T14:16:19.583443000Z" level=debug msg="Registering GET, /secrets/{id}"
time="2017-04-17T14:16:19.583552000Z" level=debug msg="Registering POST, /secrets/{id}/update"
time="2017-04-17T14:16:19.583679000Z" level=debug msg="Registering GET, /plugins"
time="2017-04-17T14:16:19.583752000Z" level=debug msg="Registering GET, /plugins/{name:.*}/json"
time="2017-04-17T14:16:19.583871000Z" level=debug msg="Registering GET, /plugins/privileges"
time="2017-04-17T14:16:19.583959000Z" level=debug msg="Registering DELETE, /plugins/{name:.*}"
time="2017-04-17T14:16:19.584089000Z" level=debug msg="Registering POST, /plugins/{name:.*}/enable"
time="2017-04-17T14:16:19.584205000Z" level=debug msg="Registering POST, /plugins/{name:.*}/disable"
time="2017-04-17T14:16:19.584320000Z" level=debug msg="Registering POST, /plugins/pull"
time="2017-04-17T14:16:19.584400000Z" level=debug msg="Registering POST, /plugins/{name:.*}/push"
time="2017-04-17T14:16:19.584516000Z" level=debug msg="Registering POST, /plugins/{name:.*}/upgrade"
time="2017-04-17T14:16:19.584630000Z" level=debug msg="Registering POST, /plugins/{name:.*}/set"
time="2017-04-17T14:16:19.584767000Z" level=debug msg="Registering POST, /plugins/create"
time="2017-04-17T14:16:19.584853000Z" level=debug msg="Registering GET, /networks"
time="2017-04-17T14:16:19.584930000Z" level=debug msg="Registering GET, /networks/"
time="2017-04-17T14:16:19.585107000Z" level=debug msg="Registering GET, /networks/{id:.+}"
time="2017-04-17T14:16:19.585223000Z" level=debug msg="Registering POST, /networks/create"
time="2017-04-17T14:16:19.585308000Z" level=debug msg="Registering POST, /networks/{id:.*}/connect"
time="2017-04-17T14:16:19.585418000Z" level=debug msg="Registering POST, /networks/{id:.*}/disconnect"
time="2017-04-17T14:16:19.585541000Z" level=debug msg="Registering POST, /networks/prune"
time="2017-04-17T14:16:19.585631000Z" level=debug msg="Registering DELETE, /networks/{id:.*}"
time="2017-04-17T14:16:19.586142000Z" level=info msg="API listen on /tmp/docker-integration/d91b9df46789c.sock"
time="2017-04-17T14:16:19.630385000Z" level=debug msg="Calling GET /_ping"
time="2017-04-17T14:16:19.631070000Z" level=debug msg="Calling GET /info"
time="2017-04-17T14:16:22.414278000Z" level=info msg="7fc2bf7e4a2bd73 is starting a new election at term 2" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:22.414367000Z" level=info msg="7fc2bf7e4a2bd73 became candidate at term 3" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:22.414407000Z" level=info msg="7fc2bf7e4a2bd73 received MsgVoteResp from 7fc2bf7e4a2bd73 at term 3" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:22.414432000Z" level=info msg="7fc2bf7e4a2bd73 [logterm: 2, index: 22] sent MsgVote request to 2e55d6c0fc7e7b91 at term 3" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:22.414469000Z" level=info msg="7fc2bf7e4a2bd73 [logterm: 2, index: 22] sent MsgVote request to 26315b37c1589836 at term 3" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:24.580671000Z" level=error msg="Error in joining gossip cluster : failed to send node join: timed out broadcasting node event(join will be retried in background)"
time="2017-04-17T14:16:24.581774000Z" level=debug msg="Allocating IPv4 pools for network ingress (3o8pzln4jg0wsil8dx6ny3cgm)"
time="2017-04-17T14:16:24.581797000Z" level=debug msg="RequestPool(LocalDefault, 10.255.0.0/16, , map[], false)"
time="2017-04-17T14:16:24.581848000Z" level=debug msg="RequestAddress(LocalDefault/10.255.0.0/16, 10.255.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:24.581894000Z" level=debug msg="overlay: Received vxlan IDs: 4096"
time="2017-04-17T14:16:24.581934000Z" level=debug msg="/sbin/iptables, [--wait -t mangle -C OUTPUT -p udp --dport 4789 -m u32 --u32 0>>22&0x3C@12&0xFFFFFF00=1048576 -j MARK --set-mark 13681891]"
time="2017-04-17T14:16:24.585300000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C INPUT -m policy --dir in --pol ipsec -p udp --dport 4789 -m u32 --u32 0>>22&0x3C@12&0xFFFFFF00=1048576 -j ACCEPT]"
time="2017-04-17T14:16:24.587571000Z" level=debug msg="/sbin/iptables, [--wait -t filter -C INPUT -p udp --dport 4789 -m u32 --u32 0>>22&0x3C@12&0xFFFFFF00=1048576 -j DROP]"
time="2017-04-17T14:16:24.590170000Z" level=debug msg="f725cf4eef9e-60f32d02595c: joined network 3o8pzln4jg0wsil8dx6ny3cgm"
time="2017-04-17T14:16:24.590191000Z" level=debug msg="f725cf4eef9e-60f32d02595c: Initiating bulk sync with nodes [f725cf4eef9e-60f32d02595c]"
time="2017-04-17T14:16:24.590361000Z" level=debug msg="/sbin/iptables, [--wait -t filter -L DOCKER-INGRESS]"
time="2017-04-17T14:16:24.647852000Z" level=debug msg="Assigning addresses for endpoint ingress-endpoint's interface on network ingress"
time="2017-04-17T14:16:24.647906000Z" level=debug msg="RequestAddress(LocalDefault/10.255.0.0/16, 10.255.0.2, map[])"
time="2017-04-17T14:16:24.649824000Z" level=debug msg="Assigning addresses for endpoint ingress-endpoint's interface on network ingress"
time="2017-04-17T14:16:24.832584000Z" level=debug msg="checkEncryption(3o8pzln, <nil>, 4096, true)"
time="2017-04-17T14:16:24Z" 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.4.0-66-generic/modules.dep.bin'`, error: exit status 1"
time="2017-04-17T14:16:24Z" 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.4.0-66-generic/modules.dep.bin'`, error: exit status 1"
time="2017-04-17T14:16:24.940729000Z" level=debug msg="Assigning addresses for endpoint gateway_ingress-sbox's interface on network docker_gwbridge"
time="2017-04-17T14:16:24.940778000Z" level=debug msg="RequestAddress(LocalDefault/172.22.0.0/16, <nil>, map[])"
time="2017-04-17T14:16:24.950380000Z" level=debug msg="Assigning addresses for endpoint gateway_ingress-sbox's interface on network docker_gwbridge"
time="2017-04-17T14:16:24.987741000Z" level=debug msg="Programming external connectivity on endpoint gateway_ingress-sbox (a08cd7e998a9bb60a7764c083e2795aa42d251862754b5ef87779130d89cd67a)"
time="2017-04-17T14:16:25.414349000Z" level=info msg="7fc2bf7e4a2bd73 is starting a new election at term 3" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:25.414433000Z" level=info msg="7fc2bf7e4a2bd73 became candidate at term 4" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:25.414456000Z" level=info msg="7fc2bf7e4a2bd73 received MsgVoteResp from 7fc2bf7e4a2bd73 at term 4" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:25.414480000Z" level=info msg="7fc2bf7e4a2bd73 [logterm: 2, index: 22] sent MsgVote request to 26315b37c1589836 at term 4" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:25.414505000Z" level=info msg="7fc2bf7e4a2bd73 [logterm: 2, index: 22] sent MsgVote request to 2e55d6c0fc7e7b91 at term 4" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:26.285452000Z" level=info msg="7fc2bf7e4a2bd73 [term: 4] ignored a MsgHeartbeat message with lower term from 2e55d6c0fc7e7b91 [term: 3]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:27.284658000Z" level=info msg="7fc2bf7e4a2bd73 [term: 4] ignored a MsgHeartbeat message with lower term from 2e55d6c0fc7e7b91 [term: 3]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:28.284460000Z" level=info msg="7fc2bf7e4a2bd73 [term: 4] ignored a MsgHeartbeat message with lower term from 2e55d6c0fc7e7b91 [term: 3]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:29.284200000Z" level=info msg="7fc2bf7e4a2bd73 [term: 4] ignored a MsgHeartbeat message with lower term from 2e55d6c0fc7e7b91 [term: 3]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.284130000Z" level=info msg="7fc2bf7e4a2bd73 [term: 4] ignored a MsgHeartbeat message with lower term from 2e55d6c0fc7e7b91 [term: 3]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.416261000Z" level=info msg="7fc2bf7e4a2bd73 is starting a new election at term 4" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.416359000Z" level=info msg="7fc2bf7e4a2bd73 became candidate at term 5" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.416394000Z" level=info msg="7fc2bf7e4a2bd73 received MsgVoteResp from 7fc2bf7e4a2bd73 at term 5" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.416419000Z" level=info msg="7fc2bf7e4a2bd73 [logterm: 2, index: 22] sent MsgVote request to 2e55d6c0fc7e7b91 at term 5" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.416450000Z" level=info msg="7fc2bf7e4a2bd73 [logterm: 2, index: 22] sent MsgVote request to 26315b37c1589836 at term 5" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.419802000Z" level=info msg="7fc2bf7e4a2bd73 received MsgVoteResp rejection from 26315b37c1589836 at term 5" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.419859000Z" level=info msg="7fc2bf7e4a2bd73 [quorum:2] has received 1 MsgVoteResp votes and 1 vote rejections" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.422056000Z" level=error msg="agent: session failed" error="rpc error: code = 1 desc = context canceled" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.422144000Z" level=info msg="7fc2bf7e4a2bd73 received MsgVoteResp rejection from 2e55d6c0fc7e7b91 at term 5" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.422175000Z" level=info msg="7fc2bf7e4a2bd73 [quorum:2] has received 1 MsgVoteResp votes and 2 vote rejections" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.422197000Z" level=info msg="7fc2bf7e4a2bd73 became follower at term 5" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.422155000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:30.438554000Z" level=debug msg="(*session).start" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.189714000Z" level=info msg="7fc2bf7e4a2bd73 [term: 5] received a MsgVote message with higher term from 26315b37c1589836 [term: 6]" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.189803000Z" level=info msg="7fc2bf7e4a2bd73 became follower at term 6" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.189839000Z" level=info msg="7fc2bf7e4a2bd73 [logterm: 2, index: 22, vote: 0] cast MsgVote for 26315b37c1589836 [logterm: 3, index: 29] at term 6" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.193280000Z" level=debug msg="7fc2bf7e4a2bd73 [logterm: 0, index: 29] rejected msgApp [logterm: 3, index: 29] from 26315b37c1589836" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.193314000Z" level=info msg="raft.node: 7fc2bf7e4a2bd73 elected leader 26315b37c1589836 at term 6" module=raft node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.239860000Z" level=debug msg="Updating security config due to change in cluster Root CA" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.263128000Z" level=debug msg="Root CA updated successfully" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.263152000Z" level=debug msg="Updating security config due to change in cluster Root CA or cluster spec" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.518635000Z" level=debug method="(*session).logSubscriptions" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=qz029pgki4a4bvgv8crf8r1x4
time="2017-04-17T14:16:33.518777000Z" level=debug msg="(*session).listen" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=qz029pgki4a4bvgv8crf8r1x4
time="2017-04-17T14:16:33.519167000Z" level=debug msg="agent: registered" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.519397000Z" level=debug method="(*session).watch" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=qz029pgki4a4bvgv8crf8r1x4
time="2017-04-17T14:16:33.519595000Z" level=debug msg="(*session).heartbeat" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z session.id=qz029pgki4a4bvgv8crf8r1x4
time="2017-04-17T14:16:33.520758000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.520814000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.520845000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.647767000Z" level=debug msg="Calling GET /nodes/nd0egxko61vvi4262sbc6fx0z"
time="2017-04-17T14:16:33.659786000Z" level=info msg="Processing signal 'interrupt'"
time="2017-04-17T14:16:33.662938000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.662988000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.663021000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.669567000Z" level=info msg="Stopping manager" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.670021000Z" level=error msg="agent: session failed" error="rpc error: code = 1 desc = context canceled" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.670085000Z" level=debug msg="(*Agent).run exited" module="node/agent" node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.670284000Z" level=info msg="shutting down certificate renewal routine" module="node/tls" node.id=nd0egxko61vvi4262sbc6fx0z node.role=swarm-manager
time="2017-04-17T14:16:33.672048000Z" level=debug msg="stop transport"
time="2017-04-17T14:16:33.672371000Z" level=info msg="Manager shut down" module=node node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:33.672620000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr =127.0.0.1"
time="2017-04-17T14:16:33.673082000Z" level=debug msg="memberlist: TCP connection from=127.0.0.1:35604"
time="2017-04-17T14:16:33.673225000Z" level=debug msg="memberlist: Initiating push/pull sync with: 127.0.0.1:7946"
time="2017-04-17T14:16:33.673350000Z" level=error msg="cluster exited with error: manager stopped: context canceled"
time="2017-04-17T14:16:33.673505000Z" level=debug msg="start clean shutdown of all containers with a 15 seconds timeout..."
time="2017-04-17T14:16:33.674183000Z" level=debug msg="start clean shutdown of cluster resources..."
time="2017-04-17T14:16:38.675467000Z" level=error msg="Error in joining gossip cluster : failed to send node join: timed out broadcasting node event(join will be retried in background)"
time="2017-04-17T14:16:43.675906000Z" level=error msg="failed to send node leave: timed out broadcasting node event"
time="2017-04-17T14:16:43.828054000Z" level=debug msg="checkEncryption(3o8pzln, <nil>, 0, true)"
time="2017-04-17T14:16:43.856410000Z" level=debug msg="Revoking external connectivity on endpoint gateway_ingress-sbox (a08cd7e998a9bb60a7764c083e2795aa42d251862754b5ef87779130d89cd67a)"
time="2017-04-17T14:16:43.859764000Z" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-04-17T14:16:43.953914000Z" level=debug msg="Releasing addresses for endpoint gateway_ingress-sbox's interface on network docker_gwbridge"
time="2017-04-17T14:16:43.953980000Z" level=debug msg="ReleaseAddress(LocalDefault/172.22.0.0/16, 172.22.0.2)"
time="2017-04-17T14:16:43.983511000Z" level=debug msg="Releasing addresses for endpoint ingress-endpoint's interface on network ingress"
time="2017-04-17T14:16:43.983602000Z" level=debug msg="ReleaseAddress(LocalDefault/10.255.0.0/16, 10.255.0.2)"
time="2017-04-17T14:16:44.006674000Z" level=debug msg="releasing IPv4 pools from network ingress (3o8pzln4jg0wsil8dx6ny3cgm)"
time="2017-04-17T14:16:44.006697000Z" level=debug msg="ReleaseAddress(LocalDefault/10.255.0.0/16, 10.255.0.1)"
time="2017-04-17T14:16:44.006723000Z" level=debug msg="ReleasePool(LocalDefault/10.255.0.0/16)"
time="2017-04-17T14:16:44.007082000Z" level=debug msg="Cleaning up old mountid : start."
time="2017-04-17T14:16:44.007178000Z" level=debug msg="Unix socket /run/docker/libnetwork/8c661df9ec6588ae2ca81307a4a7310e6488eef9263bf6154c257598177277d4.sock doesn't exist. cannot accept client connections"
time="2017-04-17T14:16:44.007808000Z" level=debug msg="Cleaning up old mountid : done."
time="2017-04-17T14:16:44.007847000Z" level=debug msg="Clean shutdown succeeded"
time="2017-04-17T14:16:05.030003000Z" level=debug msg="Listener created for HTTP on unix (/tmp/docker-integration/dd94ddc5d72d2.sock)"
time="2017-04-17T14:16:05.031511000Z" level=debug msg="Using default logging driver json-file"
time="2017-04-17T14:16:05.031589000Z" level=debug msg="Golang's threads limit set to 57960"
time="2017-04-17T14:16:05.032441000Z" level=debug msg="[graphdriver] trying provided driver: vfs"
time="2017-04-17T14:16:05.032768000Z" level=debug msg="Using graph driver vfs"
time="2017-04-17T14:16:05.033032000Z" level=debug msg="Max Concurrent Downloads: 3"
time="2017-04-17T14:16:05.033096000Z" level=debug msg="Max Concurrent Uploads: 5"
time="2017-04-17T14:16:05.060252000Z" level=info msg="Graph migration to content-addressability took 0.00 seconds"
time="2017-04-17T14:16:05.060545000Z" level=warning msg="Your kernel does not support swap memory limit"
time="2017-04-17T14:16:05.060599000Z" level=warning msg="Your kernel does not support cgroup rt period"
time="2017-04-17T14:16:05.060617000Z" level=warning msg="Your kernel does not support cgroup rt runtime"
time="2017-04-17T14:16:05.061223000Z" level=info msg="Loading containers: start."
time="2017-04-17T14:16:05.061324000Z" level=debug msg="Option Experimental: false"
time="2017-04-17T14:16:05.061338000Z" level=debug msg="Option DefaultDriver: bridge"
time="2017-04-17T14:16:05.061350000Z" level=debug msg="Option DefaultNetwork: bridge"
time="2017-04-17T14:16:05.163260000Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.19.0.0/16. Daemon option --bip can be used to set a preferred IP address"
time="2017-04-17T14:16:05.163357000Z" level=debug msg="Allocating IPv4 pools for network bridge (673b66a519543eda167e78ea8c19cf24ad4916c5a2214936c155598a83088b7a)"
time="2017-04-17T14:16:05.163380000Z" level=debug msg="RequestPool(LocalDefault, 172.19.0.0/16, , map[], false)"
time="2017-04-17T14:16:05.163481000Z" level=debug msg="RequestAddress(LocalDefault/172.19.0.0/16, 172.19.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:05.168033000Z" level=info msg="Loading containers: done."
time="2017-04-17T14:16:05.180147000Z" level=info msg="Daemon has completed initialization"
time="2017-04-17T14:16:05.180174000Z" level=info msg="Docker daemon" commit=a100c08 graphdriver=vfs version=17.06.0-dev
time="2017-04-17T14:16:05.180277000Z" level=debug msg="Registering routers"
time="2017-04-17T14:16:05.180291000Z" level=debug msg="Registering GET, /containers/{name:.*}/checkpoints"
time="2017-04-17T14:16:05.184018000Z" level=debug msg="Registering POST, /containers/{name:.*}/checkpoints"
time="2017-04-17T14:16:05.184643000Z" level=debug msg="Registering DELETE, /containers/{name}/checkpoints/{checkpoint}"
time="2017-04-17T14:16:05.185508000Z" level=debug msg="Registering HEAD, /containers/{name:.*}/archive"
time="2017-04-17T14:16:05.186194000Z" level=debug msg="Registering GET, /containers/json"
time="2017-04-17T14:16:05.186419000Z" level=debug msg="Registering GET, /containers/{name:.*}/export"
time="2017-04-17T14:16:05.186742000Z" level=debug msg="Registering GET, /containers/{name:.*}/changes"
time="2017-04-17T14:16:05.187144000Z" level=debug msg="Registering GET, /containers/{name:.*}/json"
time="2017-04-17T14:16:05.187509000Z" level=debug msg="Registering GET, /containers/{name:.*}/top"
time="2017-04-17T14:16:05.187820000Z" level=debug msg="Registering GET, /containers/{name:.*}/logs"
time="2017-04-17T14:16:05.188113000Z" level=debug msg="Registering GET, /containers/{name:.*}/stats"
time="2017-04-17T14:16:05.188621000Z" level=debug msg="Registering GET, /containers/{name:.*}/attach/ws"
time="2017-04-17T14:16:05.189874000Z" level=debug msg="Registering GET, /exec/{id:.*}/json"
time="2017-04-17T14:16:05.190870000Z" level=debug msg="Registering GET, /containers/{name:.*}/archive"
time="2017-04-17T14:16:05.192298000Z" level=debug msg="Registering POST, /containers/create"
time="2017-04-17T14:16:05.193248000Z" level=debug msg="Registering POST, /containers/{name:.*}/kill"
time="2017-04-17T14:16:05.194378000Z" level=debug msg="Registering POST, /containers/{name:.*}/pause"
time="2017-04-17T14:16:05.195401000Z" level=debug msg="Registering POST, /containers/{name:.*}/unpause"
time="2017-04-17T14:16:05.196805000Z" level=debug msg="Registering POST, /containers/{name:.*}/restart"
time="2017-04-17T14:16:05.197851000Z" level=debug msg="Registering POST, /containers/{name:.*}/start"
time="2017-04-17T14:16:05.198487000Z" level=debug msg="Registering POST, /containers/{name:.*}/stop"
time="2017-04-17T14:16:05.198762000Z" level=debug msg="Registering POST, /containers/{name:.*}/wait"
time="2017-04-17T14:16:05.199051000Z" level=debug msg="Registering POST, /containers/{name:.*}/resize"
time="2017-04-17T14:16:05.199359000Z" level=debug msg="Registering POST, /containers/{name:.*}/attach"
time="2017-04-17T14:16:05.199671000Z" level=debug msg="Registering POST, /containers/{name:.*}/copy"
time="2017-04-17T14:16:05.200645000Z" level=debug msg="Registering POST, /containers/{name:.*}/exec"
time="2017-04-17T14:16:05.200799000Z" level=debug msg="Registering POST, /exec/{name:.*}/start"
time="2017-04-17T14:16:05.200909000Z" level=debug msg="Registering POST, /exec/{name:.*}/resize"
time="2017-04-17T14:16:05.201035000Z" level=debug msg="Registering POST, /containers/{name:.*}/rename"
time="2017-04-17T14:16:05.201173000Z" level=debug msg="Registering POST, /containers/{name:.*}/update"
time="2017-04-17T14:16:05.201323000Z" level=debug msg="Registering POST, /containers/prune"
time="2017-04-17T14:16:05.201421000Z" level=debug msg="Registering PUT, /containers/{name:.*}/archive"
time="2017-04-17T14:16:05.201537000Z" level=debug msg="Registering DELETE, /containers/{name:.*}"
time="2017-04-17T14:16:05.201660000Z" level=debug msg="Registering GET, /images/json"
time="2017-04-17T14:16:05.201736000Z" level=debug msg="Registering GET, /images/search"
time="2017-04-17T14:16:05.201823000Z" level=debug msg="Registering GET, /images/get"
time="2017-04-17T14:16:05.201896000Z" level=debug msg="Registering GET, /images/{name:.*}/get"
time="2017-04-17T14:16:05.202008000Z" level=debug msg="Registering GET, /images/{name:.*}/history"
time="2017-04-17T14:16:05.202120000Z" level=debug msg="Registering GET, /images/{name:.*}/json"
time="2017-04-17T14:16:05.202227000Z" level=debug msg="Registering POST, /commit"
time="2017-04-17T14:16:05.202301000Z" level=debug msg="Registering POST, /images/load"
time="2017-04-17T14:16:05.202386000Z" level=debug msg="Registering POST, /images/create"
time="2017-04-17T14:16:05.202463000Z" level=debug msg="Registering POST, /images/{name:.*}/push"
time="2017-04-17T14:16:05.202570000Z" level=debug msg="Registering POST, /images/{name:.*}/tag"
time="2017-04-17T14:16:05.202675000Z" level=debug msg="Registering POST, /images/prune"
time="2017-04-17T14:16:05.202759000Z" level=debug msg="Registering DELETE, /images/{name:.*}"
time="2017-04-17T14:16:05.202866000Z" level=debug msg="Registering OPTIONS, /{anyroute:.*}"
time="2017-04-17T14:16:05.202970000Z" level=debug msg="Registering GET, /_ping"
time="2017-04-17T14:16:05.203037000Z" level=debug msg="Registering GET, /events"
time="2017-04-17T14:16:05.203107000Z" level=debug msg="Registering GET, /info"
time="2017-04-17T14:16:05.203222000Z" level=debug msg="Registering GET, /version"
time="2017-04-17T14:16:05.203309000Z" level=debug msg="Registering GET, /system/df"
time="2017-04-17T14:16:05.203384000Z" level=debug msg="Registering POST, /auth"
time="2017-04-17T14:16:05.203448000Z" level=debug msg="Registering GET, /volumes"
time="2017-04-17T14:16:05.203516000Z" level=debug msg="Registering GET, /volumes/{name:.*}"
time="2017-04-17T14:16:05.203639000Z" level=debug msg="Registering POST, /volumes/create"
time="2017-04-17T14:16:05.203738000Z" level=debug msg="Registering POST, /volumes/prune"
time="2017-04-17T14:16:05.203819000Z" level=debug msg="Registering DELETE, /volumes/{name:.*}"
time="2017-04-17T14:16:05.203953000Z" level=debug msg="Registering POST, /build"
time="2017-04-17T14:16:05.204025000Z" level=debug msg="Registering POST, /swarm/init"
time="2017-04-17T14:16:05.204113000Z" level=debug msg="Registering POST, /swarm/join"
time="2017-04-17T14:16:05.204187000Z" level=debug msg="Registering POST, /swarm/leave"
time="2017-04-17T14:16:05.204259000Z" level=debug msg="Registering GET, /swarm"
time="2017-04-17T14:16:05.204333000Z" level=debug msg="Registering GET, /swarm/unlockkey"
time="2017-04-17T14:16:05.204467000Z" level=debug msg="Registering POST, /swarm/update"
time="2017-04-17T14:16:05.204558000Z" level=debug msg="Registering POST, /swarm/unlock"
time="2017-04-17T14:16:05.204634000Z" level=debug msg="Registering GET, /services"
time="2017-04-17T14:16:05.204699000Z" level=debug msg="Registering GET, /services/{id}"
time="2017-04-17T14:16:05.204809000Z" level=debug msg="Registering POST, /services/create"
time="2017-04-17T14:16:05.204904000Z" level=debug msg="Registering POST, /services/{id}/update"
time="2017-04-17T14:16:05.205030000Z" level=debug msg="Registering DELETE, /services/{id}"
time="2017-04-17T14:16:05.205138000Z" level=debug msg="Registering GET, /services/{id}/logs"
time="2017-04-17T14:16:05.205254000Z" level=debug msg="Registering GET, /nodes"
time="2017-04-17T14:16:05.205322000Z" level=debug msg="Registering GET, /nodes/{id}"
time="2017-04-17T14:16:05.205428000Z" level=debug msg="Registering DELETE, /nodes/{id}"
time="2017-04-17T14:16:05.205531000Z" level=debug msg="Registering POST, /nodes/{id}/update"
time="2017-04-17T14:16:05.205642000Z" level=debug msg="Registering GET, /tasks"
time="2017-04-17T14:16:05.205707000Z" level=debug msg="Registering GET, /tasks/{id}"
time="2017-04-17T14:16:05.205809000Z" level=debug msg="Registering GET, /tasks/{id}/logs"
time="2017-04-17T14:16:05.205918000Z" level=debug msg="Registering GET, /secrets"
time="2017-04-17T14:16:05.205990000Z" level=debug msg="Registering POST, /secrets/create"
time="2017-04-17T14:16:05.206079000Z" level=debug msg="Registering DELETE, /secrets/{id}"
time="2017-04-17T14:16:05.206196000Z" level=debug msg="Registering GET, /secrets/{id}"
time="2017-04-17T14:16:05.206311000Z" level=debug msg="Registering POST, /secrets/{id}/update"
time="2017-04-17T14:16:05.206423000Z" level=debug msg="Registering GET, /plugins"
time="2017-04-17T14:16:05.206495000Z" level=debug msg="Registering GET, /plugins/{name:.*}/json"
time="2017-04-17T14:16:05.206606000Z" level=debug msg="Registering GET, /plugins/privileges"
time="2017-04-17T14:16:05.206698000Z" level=debug msg="Registering DELETE, /plugins/{name:.*}"
time="2017-04-17T14:16:05.206805000Z" level=debug msg="Registering POST, /plugins/{name:.*}/enable"
time="2017-04-17T14:16:05.206920000Z" level=debug msg="Registering POST, /plugins/{name:.*}/disable"
time="2017-04-17T14:16:05.207028000Z" level=debug msg="Registering POST, /plugins/pull"
time="2017-04-17T14:16:05.207108000Z" level=debug msg="Registering POST, /plugins/{name:.*}/push"
time="2017-04-17T14:16:05.207288000Z" level=debug msg="Registering POST, /plugins/{name:.*}/upgrade"
time="2017-04-17T14:16:05.207426000Z" level=debug msg="Registering POST, /plugins/{name:.*}/set"
time="2017-04-17T14:16:05.207538000Z" level=debug msg="Registering POST, /plugins/create"
time="2017-04-17T14:16:05.207616000Z" level=debug msg="Registering GET, /networks"
time="2017-04-17T14:16:05.207684000Z" level=debug msg="Registering GET, /networks/"
time="2017-04-17T14:16:05.207761000Z" level=debug msg="Registering GET, /networks/{id:.+}"
time="2017-04-17T14:16:05.207874000Z" level=debug msg="Registering POST, /networks/create"
time="2017-04-17T14:16:05.207954000Z" level=debug msg="Registering POST, /networks/{id:.*}/connect"
time="2017-04-17T14:16:05.208082000Z" level=debug msg="Registering POST, /networks/{id:.*}/disconnect"
time="2017-04-17T14:16:05.208210000Z" level=debug msg="Registering POST, /networks/prune"
time="2017-04-17T14:16:05.208287000Z" level=debug msg="Registering DELETE, /networks/{id:.*}"
time="2017-04-17T14:16:05.208947000Z" level=info msg="API listen on /tmp/docker-integration/dd94ddc5d72d2.sock"
time="2017-04-17T14:16:05.493869000Z" level=debug msg="Calling GET /_ping"
time="2017-04-17T14:16:05.494605000Z" level=debug msg="Calling GET /info"
time="2017-04-17T14:16:05.752085000Z" level=debug msg="Calling GET /_ping"
time="2017-04-17T14:16:05.755649000Z" level=debug msg="Calling POST /v1.30/images/load?quiet=1"
time="2017-04-17T14:16:05.821228000Z" level=debug msg="Start untar layer"
time="2017-04-17T14:16:06.040226000Z" level=debug msg="Untar time: 0.218983s"
time="2017-04-17T14:16:06.040354000Z" level=debug msg="Applied tar sha256:6719b42e03539a9ab2e99140109b53a88dd1dd8d85d5da6f1fcccad543024c9e to dc547fdb7a1deaf04678490a645c635d1886e0bc981188a67703384e896d0303, size: 4386624"
time="2017-04-17T14:16:06.062107000Z" level=debug msg="Calling POST /swarm/join"
time="2017-04-17T14:16:06.062259000Z" level=debug msg="form data: {\"AdvertiseAddr\":\"\",\"Availability\":\"\",\"JoinToken\":\"*****\",\"ListenAddr\":\"0.0.0.0:2478\",\"RemoteAddrs\":[\"0.0.0.0:2477\"]}"
time="2017-04-17T14:16:06.122452000Z" level=debug msg="retrieved remote CA certificate: /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/dd94ddc5d72d2/root/swarm/certificates/swarm-root-ca.crt" module=node
time="2017-04-17T14:16:06.122542000Z" level=debug msg="downloaded CA certificate" module=node
time="2017-04-17T14:16:06.122614000Z" level=debug msg="no node credentials found in: /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/dd94ddc5d72d2/root/swarm/certificates/swarm-node.crt" error="open /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/dd94ddc5d72d2/root/swarm/certificates/swarm-node.key: no such file or directory" module=node
time="2017-04-17T14:16:06.273835000Z" level=debug msg="new node credentials generated: /go/src/github.com/docker/docker/bundles/17.06.0-dev/test-integration-cli/dd94ddc5d72d2/root/swarm/certificates/swarm-node.crt" module="node/tls" node.id=5fy73cplhm7k9pi2olk3lxckq node.role=swarm-manager
time="2017-04-17T14:16:06.278262000Z" level=debug msg="(*Agent).run" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.279669000Z" level=debug msg="next certificate renewal scheduled for 1095h44m53.720344s from now" module="node/tls" node.id=5fy73cplhm7k9pi2olk3lxckq node.role=swarm-manager time=2017-06-02 06:01:00 +0000 UTC
time="2017-04-17T14:16:06.288015000Z" level=info msg="Listening for connections" addr="[::]:2478" module=node node.id=5fy73cplhm7k9pi2olk3lxckq proto=tcp
time="2017-04-17T14:16:06.288119000Z" level=info msg="Listening for local connections" addr="/tmp/docker-execroot/dd94ddc5d72d2/swarm/control.sock" module=node node.id=5fy73cplhm7k9pi2olk3lxckq proto=unix
time="2017-04-17T14:16:06.304974000Z" level=debug msg="(*session).start" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.429493000Z" level=info msg="2e55d6c0fc7e7b91 became follower at term 0" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.429545000Z" level=info msg="newRaft 2e55d6c0fc7e7b91 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.429564000Z" level=info msg="2e55d6c0fc7e7b91 became follower at term 1" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.429668000Z" level=debug msg="transport: add peer 7fc2bf7e4a2bd73 with address 127.0.0.1:2477"
time="2017-04-17T14:16:06.505976000Z" level=info msg="2e55d6c0fc7e7b91 [term: 1] received a MsgApp message with higher term from 7fc2bf7e4a2bd73 [term: 2]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.506054000Z" level=info msg="2e55d6c0fc7e7b91 became follower at term 2" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.506078000Z" level=debug msg="2e55d6c0fc7e7b91 [logterm: 0, index: 15] rejected msgApp [logterm: 2, index: 15] from 7fc2bf7e4a2bd73" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.506101000Z" level=info msg="raft.node: 2e55d6c0fc7e7b91 elected leader 7fc2bf7e4a2bd73 at term 2" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.520614000Z" level=debug method="(*session).logSubscriptions" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=ezkh18qebozhpgjypkvj21r6p
time="2017-04-17T14:16:06.520700000Z" level=debug msg="(*session).heartbeat" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=ezkh18qebozhpgjypkvj21r6p
time="2017-04-17T14:16:06.520937000Z" level=debug method="(*session).watch" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=ezkh18qebozhpgjypkvj21r6p
time="2017-04-17T14:16:06.521044000Z" level=debug msg="(*session).listen" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=ezkh18qebozhpgjypkvj21r6p
time="2017-04-17T14:16:06.529924000Z" level=debug msg="Updating security config due to change in cluster Root CA" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=node node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.554686000Z" level=debug msg="received encryption keys before cluster config"
time="2017-04-17T14:16:06.554726000Z" level=debug msg="agent: registered" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.554757000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.554784000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.554871000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.563005000Z" level=debug msg="Root CA updated successfully" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=node node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.563037000Z" level=debug msg="Updating security config due to change in cluster Root CA or cluster spec" cluster.id=9vtjsn0tio6zdgps2x3ulrslo method="(*Server).UpdateRootCA" module=node node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:06.834838000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr =127.0.0.1"
time="2017-04-17T14:16:06.835238000Z" level=info msg="Gossip cluster hostname f725cf4eef9e-391eb3152dd6"
time="2017-04-17T14:16:06.835345000Z" level=debug msg="Encryption key 1: 555df"
time="2017-04-17T14:16:06.835371000Z" level=debug msg="Encryption key 2: 3f5d4"
time="2017-04-17T14:16:06.835393000Z" level=debug msg="Encryption key 3: 391d1"
time="2017-04-17T14:16:06.835650000Z" level=error msg="Error in agentInit : failed to create memberlist: Failed to start TCP listener. Err: listen tcp 0.0.0.0:7946: bind: address already in use"
time="2017-04-17T14:16:06.835707000Z" level=info msg="Initializing Libnetwork Agent Listen-Addr=0.0.0.0 Local-addr=127.0.0.1 Adv-addr=127.0.0.1 Remote-addr =127.0.0.1"
time="2017-04-17T14:16:06.835798000Z" level=info msg="Gossip cluster hostname f725cf4eef9e-361e7efbba05"
time="2017-04-17T14:16:06.835883000Z" level=debug msg="Encryption key 1: 555df"
time="2017-04-17T14:16:06.835909000Z" level=debug msg="Encryption key 2: 3f5d4"
time="2017-04-17T14:16:06.835932000Z" level=debug msg="Encryption key 3: 391d1"
time="2017-04-17T14:16:06.835989000Z" level=error msg="Error in agentInit : failed to create memberlist: Failed to start TCP listener. Err: listen tcp 0.0.0.0:7946: bind: address already in use"
time="2017-04-17T14:16:06.836713000Z" level=debug msg="Calling GET /info"
time="2017-04-17T14:16:08.315829000Z" level=debug msg="transport: add peer 26315b37c1589836 with address 127.0.0.1:2479"
time="2017-04-17T14:16:08.774649000Z" level=error msg="agent: session failed" error="rpc error: code = 1 desc = context canceled" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:08.774700000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:08.776313000Z" level=debug msg="(*session).start" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:08.777639000Z" level=error msg="agent: session failed" error="rpc error: code = 14 desc = grpc: the connection is unavailable" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:08.777668000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:09.037337000Z" level=debug msg="(*session).start" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:09.038249000Z" level=error msg="agent: session failed" error="rpc error: code = 14 desc = grpc: the connection is unavailable" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:09.038289000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:09.360240000Z" level=debug msg="(*session).start" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:09.361873000Z" level=error msg="agent: session failed" error="rpc error: code = 14 desc = grpc: the connection is unavailable" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:09.361980000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:09.850864000Z" level=debug msg="(*session).start" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:09.852013000Z" level=error msg="agent: session failed" error="rpc error: code = 14 desc = grpc: the connection is unavailable" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:09.852106000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:10.979792000Z" level=debug msg="(*session).start" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:10.980896000Z" level=error msg="agent: session failed" error="rpc error: code = 14 desc = grpc: the connection is unavailable" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:10.980942000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.283422000Z" level=info msg="2e55d6c0fc7e7b91 is starting a new election at term 2" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.283525000Z" level=info msg="2e55d6c0fc7e7b91 became candidate at term 3" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.283565000Z" level=info msg="2e55d6c0fc7e7b91 received MsgVoteResp from 2e55d6c0fc7e7b91 at term 3" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.283600000Z" level=info msg="2e55d6c0fc7e7b91 [logterm: 2, index: 22] sent MsgVote request to 7fc2bf7e4a2bd73 at term 3" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.283624000Z" level=info msg="2e55d6c0fc7e7b91 [logterm: 2, index: 22] sent MsgVote request to 26315b37c1589836 at term 3" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.283645000Z" level=info msg="raft.node: 2e55d6c0fc7e7b91 lost leader 7fc2bf7e4a2bd73 at term 3" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.301079000Z" level=debug msg="failed to send message MsgVote" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:11.303341000Z" level=info msg="2e55d6c0fc7e7b91 received MsgVoteResp from 26315b37c1589836 at term 3" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.303363000Z" level=info msg="2e55d6c0fc7e7b91 [quorum:2] has received 2 MsgVoteResp votes and 0 vote rejections" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.303391000Z" level=info msg="2e55d6c0fc7e7b91 became leader at term 3" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.303411000Z" level=info msg="raft.node: 2e55d6c0fc7e7b91 elected leader 2e55d6c0fc7e7b91 at term 3" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.303800000Z" level=debug msg="failed to send message MsgApp" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:11.303859000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:11.305286000Z" level=debug msg="RequestPool(GlobalDefault, 10.255.0.0/16, , map[], false)"
time="2017-04-17T14:16:11.305342000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, 10.255.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-04-17T14:16:11.305383000Z" level=debug msg="overlay network option: 4096"
time="2017-04-17T14:16:11.307353000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, 10.255.0.3, map[])"
time="2017-04-17T14:16:11.307390000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, 10.255.0.2, map[])"
time="2017-04-17T14:16:11.307418000Z" level=debug msg="RequestAddress(GlobalDefault/10.255.0.0/16, 10.255.0.4, map[])"
time="2017-04-17T14:16:11.816864000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:11.823652000Z" level=debug method="(*Dispatcher).Assignments" node.id=tsfg8t1nmbz50cpzkzmomzmid node.session=81ut9eko9ukn696tt472a1nep
time="2017-04-17T14:16:11.823971000Z" level=debug msg="node registered" method="(*LogBroker).ListenSubscriptions" node=tsfg8t1nmbz50cpzkzmomzmid
time="2017-04-17T14:16:12.283763000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:12.283865000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:13.284032000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:13.284087000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:14.113781000Z" level=debug msg="(*session).start" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:14.126761000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:14.133663000Z" level=debug method="(*session).logSubscriptions" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=wugu039p5su6ao9nobbbcyflc
time="2017-04-17T14:16:14.134040000Z" level=debug msg="node registered" method="(*LogBroker).ListenSubscriptions" node=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:14.134132000Z" level=debug method="(*session).watch" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=wugu039p5su6ao9nobbbcyflc
time="2017-04-17T14:16:14.134329000Z" level=debug msg="(*session).heartbeat" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=wugu039p5su6ao9nobbbcyflc
time="2017-04-17T14:16:14.134354000Z" level=debug msg="(*session).listen" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=wugu039p5su6ao9nobbbcyflc
time="2017-04-17T14:16:14.134499000Z" level=debug method="(*Dispatcher).Assignments" node.id=5fy73cplhm7k9pi2olk3lxckq node.session=wugu039p5su6ao9nobbbcyflc
time="2017-04-17T14:16:14.134814000Z" level=debug msg="agent: registered" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:14.134861000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:14.134887000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:14.134915000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:14.283722000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:14.283807000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:15.283690000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:15.283777000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:16.283820000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:16.283885000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:17.283966000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:17.284213000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:18.284501000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:18.284648000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:19.117880000Z" level=debug msg="Calling GET /nodes/5fy73cplhm7k9pi2olk3lxckq"
time="2017-04-17T14:16:19.283556000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:19.283637000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:19.549021000Z" level=debug msg="node status updated" method="(*Dispatcher).processUpdates" module=dispatcher node.id=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:19.553138000Z" level=debug method="(*Dispatcher).Assignments" node.id=nd0egxko61vvi4262sbc6fx0z node.session=dn4pr76g1cjn6lp7ykfdn694x
time="2017-04-17T14:16:19.554663000Z" level=debug msg="node registered" method="(*LogBroker).ListenSubscriptions" node=nd0egxko61vvi4262sbc6fx0z
time="2017-04-17T14:16:20.283557000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:20.283666000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:21.283637000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:21.283740000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:22.283539000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:22.283617000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:22.418001000Z" level=debug msg="member which sent vote request failed health check" error="failed to check health: rpc error: code = 14 desc = grpc: the connection is unavailable" from=7fc2bf7e4a2bd73 method="(*Node).ProcessRaftMessage" raft_id=2e55d6c0fc7e7b91
time="2017-04-17T14:16:23.283582000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:23.283685000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:24.283708000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:24.283818000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:25.283953000Z" level=debug msg="failed to send message MsgHeartbeat" error="rpc error: code = 14 desc = grpc: the connection is unavailable" peer_id=7fc2bf7e4a2bd73
time="2017-04-17T14:16:25.284070000Z" level=debug msg="2e55d6c0fc7e7b91 failed to send message to 7fc2bf7e4a2bd73 because it is unreachable [next = 23, match = 0, state = ProgressStateProbe, waiting = true, pendingSnapshot = 0]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:25.416286000Z" level=debug msg="member which sent vote request failed health check" error="failed to check health: rpc error: code = 14 desc = grpc: the connection is unavailable" from=7fc2bf7e4a2bd73 method="(*Node).ProcessRaftMessage" raft_id=2e55d6c0fc7e7b91
time="2017-04-17T14:16:30.418668000Z" level=info msg="2e55d6c0fc7e7b91 [term: 3] received a MsgVote message with higher term from 7fc2bf7e4a2bd73 [term: 5]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:30.418851000Z" level=info msg="2e55d6c0fc7e7b91 became follower at term 5" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:30.418996000Z" level=info msg="2e55d6c0fc7e7b91 [logterm: 3, index: 29, vote: 0] rejected MsgVote from 7fc2bf7e4a2bd73 [logterm: 2, index: 22] at term 5" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:30.419032000Z" level=info msg="raft.node: 2e55d6c0fc7e7b91 lost leader 2e55d6c0fc7e7b91 at term 5" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:30.422237000Z" level=error msg="failed to remove node" error="rpc error: code = 10 desc = dispatcher is stopped" method="(*Dispatcher).Session" node.id=tsfg8t1nmbz50cpzkzmomzmid node.session=81ut9eko9ukn696tt472a1nep
time="2017-04-17T14:16:30.422297000Z" level=error msg="failed to remove node" error="rpc error: code = 10 desc = dispatcher is stopped" method="(*Dispatcher).Session" node.id=5fy73cplhm7k9pi2olk3lxckq node.session=wugu039p5su6ao9nobbbcyflc
time="2017-04-17T14:16:30.422669000Z" level=error msg="LogBroker exited with an error" error="context canceled" module=node node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:30.422797000Z" level=error msg="session end" error="write tcp 127.0.0.1:2478->127.0.0.1:51074: write: broken pipe" method="(*Dispatcher).Session" node.id=nd0egxko61vvi4262sbc6fx0z node.session=dn4pr76g1cjn6lp7ykfdn694x
time="2017-04-17T14:16:30.422841000Z" level=error msg="failed to remove node" error="rpc error: code = 10 desc = dispatcher is stopped" method="(*Dispatcher).Session" node.id=nd0egxko61vvi4262sbc6fx0z node.session=dn4pr76g1cjn6lp7ykfdn694x
time="2017-04-17T14:16:30.423953000Z" level=error msg="agent: session failed" error="rpc error: code = 13 desc = transport is closing" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:30.423987000Z" level=debug msg="agent: rebuild session" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:30.493453000Z" level=debug msg="(*session).start" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.191390000Z" level=info msg="2e55d6c0fc7e7b91 [term: 5] received a MsgVote message with higher term from 26315b37c1589836 [term: 6]" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.191672000Z" level=info msg="2e55d6c0fc7e7b91 became follower at term 6" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.191743000Z" level=info msg="2e55d6c0fc7e7b91 [logterm: 3, index: 29, vote: 0] cast MsgVote for 26315b37c1589836 [logterm: 3, index: 29] at term 6" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.195872000Z" level=info msg="raft.node: 2e55d6c0fc7e7b91 elected leader 26315b37c1589836 at term 6" module=raft node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.516247000Z" level=debug method="(*session).logSubscriptions" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=ij82bw65etnxuu5ada669x3au
time="2017-04-17T14:16:33.516540000Z" level=debug method="(*session).watch" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=ij82bw65etnxuu5ada669x3au
time="2017-04-17T14:16:33.516659000Z" level=debug msg="agent: registered" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.516702000Z" level=debug msg="(*session).listen" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=ij82bw65etnxuu5ada669x3au
time="2017-04-17T14:16:33.516248000Z" level=debug msg="(*session).heartbeat" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq session.id=ij82bw65etnxuu5ada669x3au
time="2017-04-17T14:16:33.518067000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.518101000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.518122000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:33.650642000Z" level=debug msg="Calling GET /nodes/5fy73cplhm7k9pi2olk3lxckq"
time="2017-04-17T14:16:44.010806000Z" level=info msg="Processing signal 'interrupt'"
time="2017-04-17T14:16:44.013429000Z" level=error msg="Leaving cluster with 1 managers left out of 3. Raft quorum will be lost."
time="2017-04-17T14:16:44.013474000Z" level=debug msg="(*worker).Assign" len(assignments)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:44.013504000Z" level=debug msg="(*worker).reconcileSecrets" len(removedSecrets)=0 len(updatedSecrets)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:44.013527000Z" level=debug msg="(*worker).reconcileTaskState" len(removedTasks)=0 len(updatedTasks)=0 module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:44.014854000Z" level=info msg="shutting down certificate renewal routine" module="node/tls" node.id=5fy73cplhm7k9pi2olk3lxckq node.role=swarm-manager
time="2017-04-17T14:16:44.014881000Z" level=debug msg="(*Agent).run exited" module="node/agent" node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:44.014896000Z" level=info msg="Stopping manager" module=node node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:44.015486000Z" level=debug msg="stop transport"
time="2017-04-17T14:16:44.015671000Z" level=info msg="Manager shut down" module=node node.id=5fy73cplhm7k9pi2olk3lxckq
time="2017-04-17T14:16:44.015780000Z" level=error msg="cluster exited with error: manager stopped: context canceled"
time="2017-04-17T14:16:44.015871000Z" level=debug msg="start clean shutdown of all containers with a 15 seconds timeout..."
time="2017-04-17T14:16:44.015934000Z" level=debug msg="start clean shutdown of cluster resources..."
time="2017-04-17T14:16:49.016647000Z" level=warning msg="timeout while waiting for ingress network removal"
time="2017-04-17T14:16:49.016970000Z" level=debug msg="Cleaning up old mountid : start."
time="2017-04-17T14:16:49.017148000Z" level=debug msg="Unix socket /run/docker/libnetwork/58626b68138fe864a80c89421bc57578fe29a42c6fd39f2269f72b9e2048db91.sock doesn't exist. cannot accept client connections"
time="2017-04-17T14:16:49.017857000Z" level=debug msg="Cleaning up old mountid : done."
time="2017-04-17T14:16:49.017928000Z" level=debug msg="Clean shutdown succeeded"
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment