Skip to content

Instantly share code, notes, and snippets.

@shin-
Created July 26, 2017 23:21
Show Gist options
  • Save shin-/affad1b952bb82fc4b26b0f48829b1cf to your computer and use it in GitHub Desktop.
Save shin-/affad1b952bb82fc4b26b0f48829b1cf to your computer and use it in GitHub Desktop.
time="2017-07-26T16:18:18.018065758-07:00" level=debug msg="Listener created for HTTP on unix (/var/run/docker.sock)"
time="2017-07-26T16:18:18.018634351-07:00" level=info msg="libcontainerd: new containerd process, pid: 11641"
time="2017-07-26T16:18:18.025166468-07:00" level=warning msg="containerd: low RLIMIT_NOFILE changing to max" current=1024 max=1048576
time="2017-07-26T16:18:18.02543859-07:00" level=debug msg="containerd: read past events" count=0
time="2017-07-26T16:18:18.025514637-07:00" level=debug msg="containerd: supervisor running" cpus=4 memory=7678 runtime=docker-runc runtimeArgs=[] stateDir="/var/run/docker/libcontainerd/containerd"
time="2017-07-26T16:18:18.025633505-07:00" level=debug msg="containerd: grpc api on /var/run/docker/libcontainerd/docker-containerd.sock"
time="2017-07-26T16:18:18.519060485-07:00" level=debug msg="libcontainerd: containerd health check returned error: rpc error: code = Unavailable desc = grpc: the connection is unavailable"
time="2017-07-26T16:18:19.019042007-07:00" level=debug msg="libcontainerd: containerd health check returned error: rpc error: code = Unavailable desc = grpc: the connection is unavailable"
time="2017-07-26T16:18:19.020434753-07:00" level=warning msg="failed to rename /var/lib/docker/tmp for background deletion: rename /var/lib/docker/tmp /var/lib/docker/tmp-old: file exists. Deleting synchronously"
time="2017-07-26T16:18:19.020676822-07:00" level=debug msg="Using default logging driver json-file"
time="2017-07-26T16:18:19.020733988-07:00" level=debug msg="Golang's threads limit set to 54630"
time="2017-07-26T16:18:19.033206670-07:00" level=info msg="[graphdriver] using prior storage driver: aufs"
time="2017-07-26T16:18:19.033247787-07:00" level=debug msg="Using graph driver aufs"
time="2017-07-26T16:18:19.054376208-07:00" level=debug msg="Max Concurrent Downloads: 3"
time="2017-07-26T16:18:19.054414143-07:00" level=debug msg="Max Concurrent Uploads: 5"
time="2017-07-26T16:18:19.176348686-07:00" level=error msg="migrate container error: open /var/lib/docker/containers/2502ade222c11e76e0782c549af61f19eed539ed919801729ebfe848661c2465/config.json: no such file or directory"
time="2017-07-26T16:18:19.176382792-07:00" level=error msg="migrate container error: open /var/lib/docker/containers/f61679ad44c2bc079d7acee4a7319a6c6a0d6be5d34c16169c705d2233897e24/config.json: no such file or directory"
time="2017-07-26T16:18:19.176404090-07:00" level=info msg="Graph migration to content-addressability took 0.01 seconds"
time="2017-07-26T16:18:19.176568788-07:00" level=warning msg="Your kernel does not support swap memory limit"
time="2017-07-26T16:18:19.176603406-07:00" level=warning msg="Your kernel does not support cgroup rt period"
time="2017-07-26T16:18:19.176614662-07:00" level=warning msg="Your kernel does not support cgroup rt runtime"
time="2017-07-26T16:18:19.176863478-07:00" level=info msg="Loading containers: start."
time="2017-07-26T16:18:19.177326266-07:00" level=debug msg="Loaded container 09fb1f27f17852e1586b4ddc47340b5377c7c5723e61367dfee5ccb64dabc4a6"
time="2017-07-26T16:18:19.177354507-07:00" level=error msg="Failed to load container 2502ade222c11e76e0782c549af61f19eed539ed919801729ebfe848661c2465: open /var/lib/docker/containers/2502ade222c11e76e0782c549af61f19eed539ed919801729ebfe848661c2465/config.v2.json: no such file or directory"
time="2017-07-26T16:18:19.177571462-07:00" level=debug msg="Loaded container 3baec3cd273fe801e06ff4e94cec8b20fbd1c70e2be3906731619d4a0ca502fc"
time="2017-07-26T16:18:19.177779134-07:00" level=debug msg="Loaded container 4eb86dc5982cfb51651dbe159b4adb8859a3a0ff491546e535704873010af922"
time="2017-07-26T16:18:19.177966778-07:00" level=debug msg="Loaded container 67d7800672213b2484ac459f4ae564bb51e6a2686c7da1339d0c783e0f637e01"
time="2017-07-26T16:18:19.177989931-07:00" level=error msg="Failed to load container f61679ad44c2bc079d7acee4a7319a6c6a0d6be5d34c16169c705d2233897e24: open /var/lib/docker/containers/f61679ad44c2bc079d7acee4a7319a6c6a0d6be5d34c16169c705d2233897e24/config.v2.json: no such file or directory"
time="2017-07-26T16:18:19.228960659-07:00" level=debug msg="Option Experimental: false"
time="2017-07-26T16:18:19.228992696-07:00" level=debug msg="Option DefaultDriver: bridge"
time="2017-07-26T16:18:19.229001844-07:00" level=debug msg="Option DefaultNetwork: bridge"
time="2017-07-26T16:18:19.238409834-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -D PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-07-26T16:18:19.239362946-07:00" 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-07-26T16:18:19.240346326-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-07-26T16:18:19.241335844-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -D PREROUTING]"
time="2017-07-26T16:18:19.242135122-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -D OUTPUT]"
time="2017-07-26T16:18:19.242968936-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -F DOCKER]"
time="2017-07-26T16:18:19.243717464-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -X DOCKER]"
time="2017-07-26T16:18:19.244456120-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -F DOCKER]"
time="2017-07-26T16:18:19.245143593-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -X DOCKER]"
time="2017-07-26T16:18:19.245833979-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION]"
time="2017-07-26T16:18:19.246653886-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION]"
time="2017-07-26T16:18:19.247456165-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -n -L DOCKER]"
time="2017-07-26T16:18:19.248234034-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -N DOCKER]"
time="2017-07-26T16:18:19.248930042-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -n -L DOCKER]"
time="2017-07-26T16:18:19.249602744-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION]"
time="2017-07-26T16:18:19.250276155-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION -j RETURN]"
time="2017-07-26T16:18:19.250985955-07:00" level=debug msg="/sbin/iptables, [--wait -A DOCKER-ISOLATION -j RETURN]"
time="2017-07-26T16:18:19.255774690-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE]"
time="2017-07-26T16:18:19.256578498-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -i docker0 -j RETURN]"
time="2017-07-26T16:18:19.257284736-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -I DOCKER -i docker0 -j RETURN]"
time="2017-07-26T16:18:19.257982924-07:00" level=debug msg="/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP]"
time="2017-07-26T16:18:19.258697335-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.259429020-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.260125411-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-07-26T16:18:19.260884179-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -A PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-07-26T16:18:19.261645551-07:00" 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-07-26T16:18:19.262397655-07:00" 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-07-26T16:18:19.263226582-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-07-26T16:18:19.263992246-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-07-26T16:18:19.264700715-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-07-26T16:18:19.265499420-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-07-26T16:18:19.266265661-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION]"
time="2017-07-26T16:18:19.267000597-07:00" level=debug msg="/sbin/iptables, [--wait -D FORWARD -j DOCKER-ISOLATION]"
time="2017-07-26T16:18:19.267720904-07:00" level=debug msg="/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION]"
time="2017-07-26T16:18:19.268508307-07:00" level=debug msg="Network (fd40737) restored"
time="2017-07-26T16:18:19.277342371-07:00" level=debug msg="Allocating IPv4 pools for network bridge (fd40737a338ba44856fddacf53a21027c99d0174cb9f5a1fefb644cef5f354de)"
time="2017-07-26T16:18:19.277397499-07:00" level=debug msg="RequestPool(LocalDefault, 172.17.0.0/16, , map[], false)"
time="2017-07-26T16:18:19.277466826-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, 172.17.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-07-26T16:18:19.282072708-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE]"
time="2017-07-26T16:18:19.283282188-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -D POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE]"
time="2017-07-26T16:18:19.284229315-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -i docker0 -j RETURN]"
time="2017-07-26T16:18:19.285017755-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -D DOCKER -i docker0 -j RETURN]"
time="2017-07-26T16:18:19.285844173-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.286653187-07:00" level=debug msg="/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.287567595-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.288419040-07:00" level=debug msg="/sbin/iptables, [--wait -D FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.289322375-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-07-26T16:18:19.290140591-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-07-26T16:18:19.291021115-07:00" level=debug msg="/sbin/iptables, [--wait -D FORWARD -o docker0 -j DOCKER]"
time="2017-07-26T16:18:19.291923371-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-07-26T16:18:19.292837164-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-07-26T16:18:19.293704839-07:00" level=debug msg="/sbin/iptables, [--wait -D FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-07-26T16:18:19.296085788-07:00" level=debug msg="releasing IPv4 pools from network bridge (fd40737a338ba44856fddacf53a21027c99d0174cb9f5a1fefb644cef5f354de)"
time="2017-07-26T16:18:19.296108736-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.1)"
time="2017-07-26T16:18:19.296139801-07:00" level=debug msg="ReleasePool(LocalDefault/172.17.0.0/16)"
time="2017-07-26T16:18:19.299398165-07:00" level=debug msg="cleanupServiceBindings for fd40737a338ba44856fddacf53a21027c99d0174cb9f5a1fefb644cef5f354de"
time="2017-07-26T16:18:19.306279437-07:00" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address"
time="2017-07-26T16:18:19.306332679-07:00" level=debug msg="Allocating IPv4 pools for network bridge (37f08436d67b8abcbbb13c8981b43042dc6531d60fc0d6a79c055f385381f43d)"
time="2017-07-26T16:18:19.306350959-07:00" level=debug msg="RequestPool(LocalDefault, 172.17.0.0/16, , map[], false)"
time="2017-07-26T16:18:19.306400282-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, 172.17.0.1, map[RequestAddressType:com.docker.network.gateway])"
time="2017-07-26T16:18:19.306555092-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE]"
time="2017-07-26T16:18:19.307729169-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -I POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE]"
time="2017-07-26T16:18:19.308618359-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -C DOCKER -i docker0 -j RETURN]"
time="2017-07-26T16:18:19.309518324-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -I DOCKER -i docker0 -j RETURN]"
time="2017-07-26T16:18:19.310355224-07:00" level=debug msg="/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP]"
time="2017-07-26T16:18:19.311229852-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.312092615-07:00" level=debug msg="/sbin/iptables, [--wait -I FORWARD -i docker0 -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.312940051-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.313786120-07:00" level=debug msg="/sbin/iptables, [--wait -I FORWARD -i docker0 ! -o docker0 -j ACCEPT]"
time="2017-07-26T16:18:19.314713857-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-07-26T16:18:19.315722289-07:00" level=debug msg="/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]"
time="2017-07-26T16:18:19.316648961-07:00" 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-07-26T16:18:19.317534356-07:00" 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-07-26T16:18:19.318397253-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER]"
time="2017-07-26T16:18:19.319260715-07:00" level=debug msg="/sbin/iptables, [--wait -I FORWARD -o docker0 -j DOCKER]"
time="2017-07-26T16:18:19.320111178-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-07-26T16:18:19.321007673-07:00" level=debug msg="/sbin/iptables, [--wait -I FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT]"
time="2017-07-26T16:18:19.321899413-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION]"
time="2017-07-26T16:18:19.322746595-07:00" level=debug msg="/sbin/iptables, [--wait -D FORWARD -j DOCKER-ISOLATION]"
time="2017-07-26T16:18:19.323609316-07:00" level=debug msg="/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION]"
time="2017-07-26T16:18:19.339626579-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -n -L DOCKER-USER]"
time="2017-07-26T16:18:19.340814695-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C DOCKER-USER -j RETURN]"
time="2017-07-26T16:18:19.341682082-07:00" level=debug msg="/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-USER]"
time="2017-07-26T16:18:19.342580493-07:00" level=debug msg="/sbin/iptables, [--wait -D FORWARD -j DOCKER-USER]"
time="2017-07-26T16:18:19.343463765-07:00" level=debug msg="/sbin/iptables, [--wait -I FORWARD -j DOCKER-USER]"
time="2017-07-26T16:18:19.360982539-07:00" level=info msg="Loading containers: done."
time="2017-07-26T16:18:19.471090362-07:00" level=info msg="Docker daemon" commit=8c4be39 graphdriver(s)=aufs version=17.07.0-ce-rc1
time="2017-07-26T16:18:19.471155041-07:00" level=info msg="Daemon has completed initialization"
time="2017-07-26T16:18:19.471257813-07:00" level=debug msg="Registering routers"
time="2017-07-26T16:18:19.471268532-07:00" level=debug msg="Registering GET, /containers/{name:.*}/checkpoints"
time="2017-07-26T16:18:19.471409750-07:00" level=debug msg="Registering POST, /containers/{name:.*}/checkpoints"
time="2017-07-26T16:18:19.471505243-07:00" level=debug msg="Registering DELETE, /containers/{name}/checkpoints/{checkpoint}"
time="2017-07-26T16:18:19.471640387-07:00" level=debug msg="Registering HEAD, /containers/{name:.*}/archive"
time="2017-07-26T16:18:19.471731816-07:00" level=debug msg="Registering GET, /containers/json"
time="2017-07-26T16:18:19.471789284-07:00" level=debug msg="Registering GET, /containers/{name:.*}/export"
time="2017-07-26T16:18:19.471870899-07:00" level=debug msg="Registering GET, /containers/{name:.*}/changes"
time="2017-07-26T16:18:19.471948919-07:00" level=debug msg="Registering GET, /containers/{name:.*}/json"
time="2017-07-26T16:18:19.472040136-07:00" level=debug msg="Registering GET, /containers/{name:.*}/top"
time="2017-07-26T16:18:19.472130906-07:00" level=debug msg="Registering GET, /containers/{name:.*}/logs"
time="2017-07-26T16:18:19.472199064-07:00" level=debug msg="Registering GET, /containers/{name:.*}/stats"
time="2017-07-26T16:18:19.472258493-07:00" level=debug msg="Registering GET, /containers/{name:.*}/attach/ws"
time="2017-07-26T16:18:19.472331195-07:00" level=debug msg="Registering GET, /exec/{id:.*}/json"
time="2017-07-26T16:18:19.472394197-07:00" level=debug msg="Registering GET, /containers/{name:.*}/archive"
time="2017-07-26T16:18:19.472463253-07:00" level=debug msg="Registering POST, /containers/create"
time="2017-07-26T16:18:19.472516961-07:00" level=debug msg="Registering POST, /containers/{name:.*}/kill"
time="2017-07-26T16:18:19.472582427-07:00" level=debug msg="Registering POST, /containers/{name:.*}/pause"
time="2017-07-26T16:18:19.472666170-07:00" level=debug msg="Registering POST, /containers/{name:.*}/unpause"
time="2017-07-26T16:18:19.472742701-07:00" level=debug msg="Registering POST, /containers/{name:.*}/restart"
time="2017-07-26T16:18:19.472809062-07:00" level=debug msg="Registering POST, /containers/{name:.*}/start"
time="2017-07-26T16:18:19.472876939-07:00" level=debug msg="Registering POST, /containers/{name:.*}/stop"
time="2017-07-26T16:18:19.472941988-07:00" level=debug msg="Registering POST, /containers/{name:.*}/wait"
time="2017-07-26T16:18:19.473005689-07:00" level=debug msg="Registering POST, /containers/{name:.*}/resize"
time="2017-07-26T16:18:19.473073295-07:00" level=debug msg="Registering POST, /containers/{name:.*}/attach"
time="2017-07-26T16:18:19.473138905-07:00" level=debug msg="Registering POST, /containers/{name:.*}/copy"
time="2017-07-26T16:18:19.473199516-07:00" level=debug msg="Registering POST, /containers/{name:.*}/exec"
time="2017-07-26T16:18:19.473266293-07:00" level=debug msg="Registering POST, /exec/{name:.*}/start"
time="2017-07-26T16:18:19.473330038-07:00" level=debug msg="Registering POST, /exec/{name:.*}/resize"
time="2017-07-26T16:18:19.473389965-07:00" level=debug msg="Registering POST, /containers/{name:.*}/rename"
time="2017-07-26T16:18:19.473456575-07:00" level=debug msg="Registering POST, /containers/{name:.*}/update"
time="2017-07-26T16:18:19.473535646-07:00" level=debug msg="Registering POST, /containers/prune"
time="2017-07-26T16:18:19.473580038-07:00" level=debug msg="Registering PUT, /containers/{name:.*}/archive"
time="2017-07-26T16:18:19.473648262-07:00" level=debug msg="Registering DELETE, /containers/{name:.*}"
time="2017-07-26T16:18:19.473714651-07:00" level=debug msg="Registering GET, /images/json"
time="2017-07-26T16:18:19.473757757-07:00" level=debug msg="Registering GET, /images/search"
time="2017-07-26T16:18:19.473804776-07:00" level=debug msg="Registering GET, /images/get"
time="2017-07-26T16:18:19.473844814-07:00" level=debug msg="Registering GET, /images/{name:.*}/get"
time="2017-07-26T16:18:19.473912792-07:00" level=debug msg="Registering GET, /images/{name:.*}/history"
time="2017-07-26T16:18:19.473972979-07:00" level=debug msg="Registering GET, /images/{name:.*}/json"
time="2017-07-26T16:18:19.474030332-07:00" level=debug msg="Registering POST, /commit"
time="2017-07-26T16:18:19.474078292-07:00" level=debug msg="Registering POST, /images/load"
time="2017-07-26T16:18:19.474130578-07:00" level=debug msg="Registering POST, /images/create"
time="2017-07-26T16:18:19.474176493-07:00" level=debug msg="Registering POST, /images/{name:.*}/push"
time="2017-07-26T16:18:19.474237169-07:00" level=debug msg="Registering POST, /images/{name:.*}/tag"
time="2017-07-26T16:18:19.474299305-07:00" level=debug msg="Registering POST, /images/prune"
time="2017-07-26T16:18:19.474346938-07:00" level=debug msg="Registering DELETE, /images/{name:.*}"
time="2017-07-26T16:18:19.474405907-07:00" level=debug msg="Registering OPTIONS, /{anyroute:.*}"
time="2017-07-26T16:18:19.474457497-07:00" level=debug msg="Registering GET, /_ping"
time="2017-07-26T16:18:19.474497474-07:00" level=debug msg="Registering GET, /events"
time="2017-07-26T16:18:19.474542591-07:00" level=debug msg="Registering GET, /info"
time="2017-07-26T16:18:19.474574180-07:00" level=debug msg="Registering GET, /version"
time="2017-07-26T16:18:19.474612900-07:00" level=debug msg="Registering GET, /system/df"
time="2017-07-26T16:18:19.474655839-07:00" level=debug msg="Registering POST, /auth"
time="2017-07-26T16:18:19.474691903-07:00" level=debug msg="Registering GET, /volumes"
time="2017-07-26T16:18:19.474736698-07:00" level=debug msg="Registering GET, /volumes/{name:.*}"
time="2017-07-26T16:18:19.474802883-07:00" level=debug msg="Registering POST, /volumes/create"
time="2017-07-26T16:18:19.474866042-07:00" level=debug msg="Registering POST, /volumes/prune"
time="2017-07-26T16:18:19.474914077-07:00" level=debug msg="Registering DELETE, /volumes/{name:.*}"
time="2017-07-26T16:18:19.474977163-07:00" level=debug msg="Registering POST, /build"
time="2017-07-26T16:18:19.475015501-07:00" level=debug msg="Registering POST, /build/prune"
time="2017-07-26T16:18:19.475060425-07:00" level=debug msg="Registering POST, /session"
time="2017-07-26T16:18:19.475097570-07:00" level=debug msg="Registering POST, /swarm/init"
time="2017-07-26T16:18:19.475133291-07:00" level=debug msg="Registering POST, /swarm/join"
time="2017-07-26T16:18:19.475179396-07:00" level=debug msg="Registering POST, /swarm/leave"
time="2017-07-26T16:18:19.475223893-07:00" level=debug msg="Registering GET, /swarm"
time="2017-07-26T16:18:19.475261782-07:00" level=debug msg="Registering GET, /swarm/unlockkey"
time="2017-07-26T16:18:19.475303319-07:00" level=debug msg="Registering POST, /swarm/update"
time="2017-07-26T16:18:19.475346931-07:00" level=debug msg="Registering POST, /swarm/unlock"
time="2017-07-26T16:18:19.475393161-07:00" level=debug msg="Registering GET, /services"
time="2017-07-26T16:18:19.475435466-07:00" level=debug msg="Registering GET, /services/{id}"
time="2017-07-26T16:18:19.475496136-07:00" level=debug msg="Registering POST, /services/create"
time="2017-07-26T16:18:19.475539128-07:00" level=debug msg="Registering POST, /services/{id}/update"
time="2017-07-26T16:18:19.475605307-07:00" level=debug msg="Registering DELETE, /services/{id}"
time="2017-07-26T16:18:19.475666235-07:00" level=debug msg="Registering GET, /services/{id}/logs"
time="2017-07-26T16:18:19.475729868-07:00" level=debug msg="Registering GET, /nodes"
time="2017-07-26T16:18:19.475767201-07:00" level=debug msg="Registering GET, /nodes/{id}"
time="2017-07-26T16:18:19.475824423-07:00" level=debug msg="Registering DELETE, /nodes/{id}"
time="2017-07-26T16:18:19.475878999-07:00" level=debug msg="Registering POST, /nodes/{id}/update"
time="2017-07-26T16:18:19.475951800-07:00" level=debug msg="Registering GET, /tasks"
time="2017-07-26T16:18:19.475996010-07:00" level=debug msg="Registering GET, /tasks/{id}"
time="2017-07-26T16:18:19.476048262-07:00" level=debug msg="Registering GET, /tasks/{id}/logs"
time="2017-07-26T16:18:19.476110940-07:00" level=debug msg="Registering GET, /secrets"
time="2017-07-26T16:18:19.476155415-07:00" level=debug msg="Registering POST, /secrets/create"
time="2017-07-26T16:18:19.476202761-07:00" level=debug msg="Registering DELETE, /secrets/{id}"
time="2017-07-26T16:18:19.476264267-07:00" level=debug msg="Registering GET, /secrets/{id}"
time="2017-07-26T16:18:19.476324679-07:00" level=debug msg="Registering POST, /secrets/{id}/update"
time="2017-07-26T16:18:19.476390468-07:00" level=debug msg="Registering GET, /configs"
time="2017-07-26T16:18:19.476429082-07:00" level=debug msg="Registering POST, /configs/create"
time="2017-07-26T16:18:19.476474628-07:00" level=debug msg="Registering DELETE, /configs/{id}"
time="2017-07-26T16:18:19.476532164-07:00" level=debug msg="Registering GET, /configs/{id}"
time="2017-07-26T16:18:19.476595862-07:00" level=debug msg="Registering POST, /configs/{id}/update"
time="2017-07-26T16:18:19.476661854-07:00" level=debug msg="Registering GET, /plugins"
time="2017-07-26T16:18:19.476700391-07:00" level=debug msg="Registering GET, /plugins/{name:.*}/json"
time="2017-07-26T16:18:19.476764091-07:00" level=debug msg="Registering GET, /plugins/privileges"
time="2017-07-26T16:18:19.476810824-07:00" level=debug msg="Registering DELETE, /plugins/{name:.*}"
time="2017-07-26T16:18:19.476873511-07:00" level=debug msg="Registering POST, /plugins/{name:.*}/enable"
time="2017-07-26T16:18:19.476933035-07:00" level=debug msg="Registering POST, /plugins/{name:.*}/disable"
time="2017-07-26T16:18:19.476994128-07:00" level=debug msg="Registering POST, /plugins/pull"
time="2017-07-26T16:18:19.477037935-07:00" level=debug msg="Registering POST, /plugins/{name:.*}/push"
time="2017-07-26T16:18:19.477098238-07:00" level=debug msg="Registering POST, /plugins/{name:.*}/upgrade"
time="2017-07-26T16:18:19.477155663-07:00" level=debug msg="Registering POST, /plugins/{name:.*}/set"
time="2017-07-26T16:18:19.477216602-07:00" level=debug msg="Registering POST, /plugins/create"
time="2017-07-26T16:18:19.477259723-07:00" level=debug msg="Registering GET, /distribution/{name:.*}/json"
time="2017-07-26T16:18:19.477329550-07:00" level=debug msg="Registering GET, /networks"
time="2017-07-26T16:18:19.477369282-07:00" level=debug msg="Registering GET, /networks/"
time="2017-07-26T16:18:19.477416989-07:00" level=debug msg="Registering GET, /networks/{id:.+}"
time="2017-07-26T16:18:19.477476148-07:00" level=debug msg="Registering POST, /networks/create"
time="2017-07-26T16:18:19.477517841-07:00" level=debug msg="Registering POST, /networks/{id:.*}/connect"
time="2017-07-26T16:18:19.477585005-07:00" level=debug msg="Registering POST, /networks/{id:.*}/disconnect"
time="2017-07-26T16:18:19.477651688-07:00" level=debug msg="Registering POST, /networks/prune"
time="2017-07-26T16:18:19.477693637-07:00" level=debug msg="Registering DELETE, /networks/{id:.*}"
time="2017-07-26T16:18:19.477972505-07:00" level=info msg="API listen on /var/run/docker.sock"
time="2017-07-26T16:18:38.969071657-07:00" level=debug msg="Calling POST /v1.30/build?q=False&pull=False&t=composetest_web&nocache=False&forcerm=False&rm=True"
time="2017-07-26T16:18:39.048307157-07:00" level=debug msg="Calling GET /v1.30/images/composetest_web/json"
time="2017-07-26T16:18:39.050193259-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:39.051913925-07:00" level=debug msg="Calling DELETE /v1.30/containers/09fb1f27f17852e1586b4ddc47340b5377c7c5723e61367dfee5ccb64dabc4a6?force=True&link=False&v=False"
time="2017-07-26T16:18:39.062290433-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:39.146730991-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:39.149013587-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:39.151455137-07:00" level=debug msg="Calling DELETE /v1.30/images/composetest_web?noprune=False&force=False"
time="2017-07-26T16:18:39.160649833-07:00" level=debug msg="Calling POST /v1.30/build?q=False&pull=False&t=composetest_web&nocache=False&forcerm=False&rm=True"
time="2017-07-26T16:18:39.213878444-07:00" level=debug msg="Calling GET /v1.30/images/composetest_web/json"
time="2017-07-26T16:18:39.215437958-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:39.216756896-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:39.301755959-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:39.303545344-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:39.305119460-07:00" level=debug msg="Calling DELETE /v1.30/images/composetest_web?noprune=False&force=False"
time="2017-07-26T16:18:39.316133829-07:00" level=debug msg="Calling POST /v1.30/build?q=False&pull=False&t=composetest_buildwithargs&nocache=False&forcerm=False&rm=True&buildargs=%7B%22build_version%22%3A+%221%22%7D"
time="2017-07-26T16:18:39.375588506-07:00" level=debug msg="[BUILDER] Cache miss: [/bin/sh -c #(nop) ARG build_version]"
time="2017-07-26T16:18:39.412026787-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/b1d7f170480a87da4d7bd5a42653c43ab460c699fc201b9caa47a05313c92853"
time="2017-07-26T16:18:39.439690971-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/b1d7f170480a87da4d7bd5a42653c43ab460c699fc201b9caa47a05313c92853"
time="2017-07-26T16:18:39.441401300-07:00" level=debug msg="Skipping excluded path: .wh..wh.aufs"
time="2017-07-26T16:18:39.441443438-07:00" level=debug msg="Skipping excluded path: .wh..wh.orph"
time="2017-07-26T16:18:39.441462240-07:00" level=debug msg="Skipping excluded path: .wh..wh.plnk"
time="2017-07-26T16:18:39.479113944-07:00" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to b00d62e42e7bcd680eb466566344d931f3f79832fe3d372860e275d5b98a80f9, size: 0"
time="2017-07-26T16:18:39.516917358-07:00" level=info msg="Layer sha256:5409e59c62907d2d25dc01df7c1f812ca382ff36e82b8c274728c63b3d516c76 cleaned up"
time="2017-07-26T16:18:39.547011589-07:00" level=debug msg="[BUILDER] Command to be executed: [/bin/sh -c echo ${build_version}]"
time="2017-07-26T16:18:39.581410088-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/a02ad1546deb4b139bda4004ae983787761be0a235a99212f89609e6304ea9ba"
time="2017-07-26T16:18:39.611008878-07:00" level=debug msg="attach: stdout: begin"
time="2017-07-26T16:18:39.611027683-07:00" level=debug msg="attach: stderr: begin"
time="2017-07-26T16:18:39.611555346-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/a02ad1546deb4b139bda4004ae983787761be0a235a99212f89609e6304ea9ba"
time="2017-07-26T16:18:39.611871388-07:00" level=debug msg="Assigning addresses for endpoint friendly_mclean's interface on network bridge"
time="2017-07-26T16:18:39.611898575-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:39.620568998-07:00" level=debug msg="Assigning addresses for endpoint friendly_mclean's interface on network bridge"
time="2017-07-26T16:18:39.631767844-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:39.631801271-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:39.640988132-07:00" level=debug msg="Programming external connectivity on endpoint friendly_mclean (2d92fd3bc974f6b647dba1168c8b535ea8b0f5824dc573d1d12d992096fccabd)"
time="2017-07-26T16:18:39.644128073-07:00" level=debug msg="EnableService e8b83eff2056419b577d0257fdda818dce06f0ae2fa319a0de95e88a4edacfef START"
time="2017-07-26T16:18:39.644144753-07:00" level=debug msg="EnableService e8b83eff2056419b577d0257fdda818dce06f0ae2fa319a0de95e88a4edacfef DONE"
time="2017-07-26T16:18:39.752193430-07:00" level=debug msg="sandbox set key processing took 55.486943ms for container e8b83eff2056419b577d0257fdda818dce06f0ae2fa319a0de95e88a4edacfef"
time="2017-07-26T16:18:39.812143619-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"e8b83eff2056419b577d0257fdda818dce06f0ae2fa319a0de95e88a4edacfef\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc421733920)}"
time="2017-07-26T16:18:39.821980551-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"e8b83eff2056419b577d0257fdda818dce06f0ae2fa319a0de95e88a4edacfef\" timestamp:<seconds:1501111119 nanos:811885311 > "
time="2017-07-26T16:18:39.846989079-07:00" level=debug msg="containerd: process exited" id=e8b83eff2056419b577d0257fdda818dce06f0ae2fa319a0de95e88a4edacfef pid=init status=0 systemPid=11889
time="2017-07-26T16:18:39.865302374-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"e8b83eff2056419b577d0257fdda818dce06f0ae2fa319a0de95e88a4edacfef\", Status:0x0, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4212db9f0)}"
time="2017-07-26T16:18:39.865479075-07:00" level=debug msg="attach: stdout: end"
time="2017-07-26T16:18:39.865537284-07:00" level=debug msg="attach: stderr: end"
time="2017-07-26T16:18:39.865684886-07:00" level=debug msg="Revoking external connectivity on endpoint friendly_mclean (2d92fd3bc974f6b647dba1168c8b535ea8b0f5824dc573d1d12d992096fccabd)"
time="2017-07-26T16:18:39.867564438-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:39.967772294-07:00" level=debug msg="Releasing addresses for endpoint friendly_mclean's interface on network bridge"
time="2017-07-26T16:18:39.967798303-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:40.046239423-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/a02ad1546deb4b139bda4004ae983787761be0a235a99212f89609e6304ea9ba"
time="2017-07-26T16:18:40.048205171-07:00" level=debug msg="Skipping excluded path: .wh..wh.aufs"
time="2017-07-26T16:18:40.048247090-07:00" level=debug msg="Skipping excluded path: .wh..wh.orph"
time="2017-07-26T16:18:40.048264814-07:00" level=debug msg="Skipping excluded path: .wh..wh.plnk"
time="2017-07-26T16:18:40.095045271-07:00" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to cca9c93115a5f511082e1fa38e11c9cf598bebf47afd9cd8a8cb30762afc0878, size: 0"
time="2017-07-26T16:18:40.114738993-07:00" level=info msg="Layer sha256:5409e59c62907d2d25dc01df7c1f812ca382ff36e82b8c274728c63b3d516c76 cleaned up"
time="2017-07-26T16:18:40.166460775-07:00" level=debug msg="Calling GET /v1.30/images/composetest_buildwithargs/json"
time="2017-07-26T16:18:40.168012498-07:00" level=debug msg="Calling GET /v1.30/images/composetest_buildwithargs/json"
time="2017-07-26T16:18:40.169366552-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:40.170616348-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:40.255010759-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:40.256777798-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:40.258723491-07:00" level=debug msg="Calling DELETE /v1.30/images/composetest_buildwithargs?noprune=False&force=False"
time="2017-07-26T16:18:40.268035166-07:00" level=debug msg="Calling POST /v1.30/build?q=False&pull=False&t=composetest_buildwithargs&nocache=False&forcerm=False&rm=True&buildargs=%7B%22build_version%22%3A+%222%22%7D"
time="2017-07-26T16:18:40.311601687-07:00" level=debug msg="[BUILDER] Cache miss: [/bin/sh -c #(nop) ARG build_version]"
time="2017-07-26T16:18:40.344321786-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/0b3dcac19dc1c1055cf996ac2e6e02fdf2535e2acb5b13f2f1a862e6cca0cdbf"
time="2017-07-26T16:18:40.378809306-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/0b3dcac19dc1c1055cf996ac2e6e02fdf2535e2acb5b13f2f1a862e6cca0cdbf"
time="2017-07-26T16:18:40.382034440-07:00" level=debug msg="Skipping excluded path: .wh..wh.aufs"
time="2017-07-26T16:18:40.382064809-07:00" level=debug msg="Skipping excluded path: .wh..wh.orph"
time="2017-07-26T16:18:40.382080311-07:00" level=debug msg="Skipping excluded path: .wh..wh.plnk"
time="2017-07-26T16:18:40.427132880-07:00" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to 620ab1845b750ddf1d6823a1398a4a2fe38a62d8d520656c1c6738664e704fcb, size: 0"
time="2017-07-26T16:18:40.459033808-07:00" level=info msg="Layer sha256:5409e59c62907d2d25dc01df7c1f812ca382ff36e82b8c274728c63b3d516c76 cleaned up"
time="2017-07-26T16:18:40.487802230-07:00" level=debug msg="[BUILDER] Command to be executed: [/bin/sh -c echo ${build_version}]"
time="2017-07-26T16:18:40.526893723-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/eba28666b3e17879b63aaa959e96a364cc322e49efbcc60f8f45becdc40c8780"
time="2017-07-26T16:18:40.559175692-07:00" level=debug msg="attach: stdout: begin"
time="2017-07-26T16:18:40.559253059-07:00" level=debug msg="attach: stderr: begin"
time="2017-07-26T16:18:40.560408809-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/eba28666b3e17879b63aaa959e96a364cc322e49efbcc60f8f45becdc40c8780"
time="2017-07-26T16:18:40.560677195-07:00" level=debug msg="Assigning addresses for endpoint romantic_gates's interface on network bridge"
time="2017-07-26T16:18:40.560701312-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:40.563278105-07:00" level=debug msg="Assigning addresses for endpoint romantic_gates's interface on network bridge"
time="2017-07-26T16:18:40.579605806-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:40.579645105-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:40.586847620-07:00" level=debug msg="Programming external connectivity on endpoint romantic_gates (6fd63f3596ff35cf49accc2b8a40adb1efe67759740cb7b563401e488e386b98)"
time="2017-07-26T16:18:40.591690691-07:00" level=debug msg="EnableService 96f90edc63f318bcbdbc43f53bd5392d9d2b0f7cfe3c6364e3dd1d21938be4a9 START"
time="2017-07-26T16:18:40.591713628-07:00" level=debug msg="EnableService 96f90edc63f318bcbdbc43f53bd5392d9d2b0f7cfe3c6364e3dd1d21938be4a9 DONE"
time="2017-07-26T16:18:40.703432037-07:00" level=debug msg="sandbox set key processing took 51.933599ms for container 96f90edc63f318bcbdbc43f53bd5392d9d2b0f7cfe3c6364e3dd1d21938be4a9"
time="2017-07-26T16:18:40.758632700-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"96f90edc63f318bcbdbc43f53bd5392d9d2b0f7cfe3c6364e3dd1d21938be4a9\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4212a6dd0)}"
time="2017-07-26T16:18:40.765766787-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"96f90edc63f318bcbdbc43f53bd5392d9d2b0f7cfe3c6364e3dd1d21938be4a9\" timestamp:<seconds:1501111120 nanos:758492423 > "
time="2017-07-26T16:18:40.8053678-07:00" level=debug msg="containerd: process exited" id=96f90edc63f318bcbdbc43f53bd5392d9d2b0f7cfe3c6364e3dd1d21938be4a9 pid=init status=0 systemPid=12026
time="2017-07-26T16:18:40.809334639-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"96f90edc63f318bcbdbc43f53bd5392d9d2b0f7cfe3c6364e3dd1d21938be4a9\", Status:0x0, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc420a742a0)}"
time="2017-07-26T16:18:40.810289840-07:00" level=debug msg="Revoking external connectivity on endpoint romantic_gates (6fd63f3596ff35cf49accc2b8a40adb1efe67759740cb7b563401e488e386b98)"
time="2017-07-26T16:18:40.813238717-07:00" level=debug msg="attach: stderr: end"
time="2017-07-26T16:18:40.813292189-07:00" level=debug msg="attach: stdout: end"
time="2017-07-26T16:18:40.814302805-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:40.914095984-07:00" level=debug msg="Releasing addresses for endpoint romantic_gates's interface on network bridge"
time="2017-07-26T16:18:40.914127546-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:40.976431478-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/eba28666b3e17879b63aaa959e96a364cc322e49efbcc60f8f45becdc40c8780"
time="2017-07-26T16:18:40.978533986-07:00" level=debug msg="Skipping excluded path: .wh..wh.aufs"
time="2017-07-26T16:18:40.978565762-07:00" level=debug msg="Skipping excluded path: .wh..wh.orph"
time="2017-07-26T16:18:40.978575704-07:00" level=debug msg="Skipping excluded path: .wh..wh.plnk"
time="2017-07-26T16:18:41.027128614-07:00" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to 411c0f6e99fcf7ed4e85aeed2661b1fd537a3493d1eb2b7e924c3b66cc6f743d, size: 0"
time="2017-07-26T16:18:41.055653431-07:00" level=info msg="Layer sha256:5409e59c62907d2d25dc01df7c1f812ca382ff36e82b8c274728c63b3d516c76 cleaned up"
time="2017-07-26T16:18:41.093945956-07:00" level=debug msg="Calling GET /v1.30/images/composetest_buildwithargs/json"
time="2017-07-26T16:18:41.095426424-07:00" level=debug msg="Calling GET /v1.30/images/composetest_buildwithargs/json"
time="2017-07-26T16:18:41.096972160-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:41.098196566-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:41.178673575-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:41.180705870-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:41.182275262-07:00" level=debug msg="Calling DELETE /v1.30/images/composetest_buildwithargs?noprune=False&force=False"
time="2017-07-26T16:18:41.191664061-07:00" level=debug msg="Calling POST /v1.30/build?q=False&pull=False&t=composetest_buildlabels&nocache=False&forcerm=False&rm=True&labels=%7B%22com.docker.compose.test%22%3A+%22true%22%7D"
time="2017-07-26T16:18:41.243590940-07:00" level=debug msg="[BUILDER] Cache miss: [/bin/sh -c #(nop) LABEL com.docker.compose.test=true]"
time="2017-07-26T16:18:41.280708151-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/39aac7ed50a1491b25c4e3b4a34858491ef6578a4379fc1ccf5b5f5a53f6e247"
time="2017-07-26T16:18:41.305076045-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/39aac7ed50a1491b25c4e3b4a34858491ef6578a4379fc1ccf5b5f5a53f6e247"
time="2017-07-26T16:18:41.305490920-07:00" level=debug msg="Skipping excluded path: .wh..wh.aufs"
time="2017-07-26T16:18:41.305525856-07:00" level=debug msg="Skipping excluded path: .wh..wh.orph"
time="2017-07-26T16:18:41.305545929-07:00" level=debug msg="Skipping excluded path: .wh..wh.plnk"
time="2017-07-26T16:18:41.347136132-07:00" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to e80206e0e0e26f064a431aae5a6e58a12058541764811ceca22b55bf767cbf2b, size: 0"
time="2017-07-26T16:18:41.379071114-07:00" level=info msg="Layer sha256:5409e59c62907d2d25dc01df7c1f812ca382ff36e82b8c274728c63b3d516c76 cleaned up"
time="2017-07-26T16:18:41.422808004-07:00" level=debug msg="Calling GET /v1.30/images/composetest_buildlabels/json"
time="2017-07-26T16:18:41.424247069-07:00" level=debug msg="Calling GET /v1.30/images/composetest_buildlabels/json"
time="2017-07-26T16:18:41.425607841-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:41.426855185-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:41.507334502-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:41.509385277-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:41.510952426-07:00" level=debug msg="Calling DELETE /v1.30/images/composetest_buildlabels?noprune=False&force=False"
time="2017-07-26T16:18:41.520339506-07:00" level=debug msg="Calling POST /v1.30/build?q=False&pull=False&cachefrom=%5B%22build1%22%5D&t=composetest_cache_from&nocache=False&forcerm=False&rm=True"
time="2017-07-26T16:18:41.567269410-07:00" level=warning msg="Could not look up build1 for cache resolution, skipping: No such image: build1:latest"
time="2017-07-26T16:18:41.567369100-07:00" level=warning msg="Could not look up build1 for cache resolution, skipping: No such image: build1:latest"
time="2017-07-26T16:18:41.580461941-07:00" level=debug msg="Calling GET /v1.30/images/composetest_cache_from/json"
time="2017-07-26T16:18:41.582061323-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:41.583408025-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:41.663262235-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:41.665102613-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:41.666676351-07:00" level=debug msg="Calling DELETE /v1.30/images/composetest_cache_from?noprune=False&force=False"
time="2017-07-26T16:18:41.675023675-07:00" level=debug msg="Calling POST /v1.30/build?q=False&pull=False&remote=https%3A%2F%2Fgithub.com%2Fdnephin%2Fdocker-build-from-url.git&t=composetest_buildwithurl&nocache=False&forcerm=False&rm=True"
time="2017-07-26T16:18:42.292252795-07:00" level=debug msg="[BUILDER] Cache miss: [/bin/sh -c #(nop) CMD [\"/bin/sh\" \"-c\" \"sh\"]]"
time="2017-07-26T16:18:42.323097905-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/24335f57ace67d0a58519e75f29383ecbddb4cbfd49823646d242d8320a68b28"
time="2017-07-26T16:18:42.360493101-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/24335f57ace67d0a58519e75f29383ecbddb4cbfd49823646d242d8320a68b28"
time="2017-07-26T16:18:42.360907301-07:00" level=debug msg="Skipping excluded path: .wh..wh.aufs"
time="2017-07-26T16:18:42.360940140-07:00" level=debug msg="Skipping excluded path: .wh..wh.orph"
time="2017-07-26T16:18:42.360959602-07:00" level=debug msg="Skipping excluded path: .wh..wh.plnk"
time="2017-07-26T16:18:42.411042188-07:00" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to 98cbb0f47491b90e74a2227f3301ef5efeb65e75dc5177347ec1edbb5e7f411b, size: 0"
time="2017-07-26T16:18:42.441135651-07:00" level=info msg="Layer sha256:f6beec3e0333a1236888a10d37c1e221116fd55bc7564be75d756026e0b0d2f3 cleaned up"
time="2017-07-26T16:18:42.487502669-07:00" level=debug msg="Calling GET /v1.30/images/composetest_buildwithurl/json"
time="2017-07-26T16:18:42.489201676-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:42.490468421-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:42.571153090-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:42.573079320-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:42.574824569-07:00" level=debug msg="Calling DELETE /v1.30/images/composetest_buildwithurl?noprune=False&force=False"
time="2017-07-26T16:18:42.584149242-07:00" level=debug msg="Calling POST /v1.30/build?q=False&pull=False&t=examples%2Fcomposetest%3Alatest&nocache=False&forcerm=False&rm=True"
time="2017-07-26T16:18:42.642626133-07:00" level=debug msg="Calling GET /v1.30/images/examples/composetest:latest/json"
time="2017-07-26T16:18:42.644336271-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:42.645676378-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:42.731803053-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:42.733598997-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:42.735116513-07:00" level=debug msg="Calling DELETE /v1.30/images/examples/composetest:latest?noprune=False&force=False"
time="2017-07-26T16:18:42.740305066-07:00" level=debug msg="Calling GET /v1.30/nodes"
time="2017-07-26T16:18:42.740374795-07:00" level=error msg="Error getting nodes: This node is not a swarm manager. Use \"docker swarm init\" or \"docker swarm join\" to connect this node to swarm and try again."
time="2017-07-26T16:18:42.740394159-07:00" level=error msg="Handler for GET /v1.30/nodes returned error: This node is not a swarm manager. Use \"docker swarm init\" or \"docker swarm join\" to connect this node to swarm and try again."
time="2017-07-26T16:18:42.741991973-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_build_network"
time="2017-07-26T16:18:42.742104385-07:00" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":false,\"AttachStdout\":true,\"Cmd\":[\"top\"],\"HostConfig\":{\"ExtraHosts\":[\"google.local:8.8.8.8\"],\"NetworkMode\":\"default\"},\"Image\":\"busybox\",\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false}"
time="2017-07-26T16:18:42.785286346-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/f4ad1927cf28eff719aa3f54dc94c1db6e85b803163f49a1edd719eba5243caa"
time="2017-07-26T16:18:42.820931646-07:00" level=debug msg="Calling POST /v1.30/containers/fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06/start"
time="2017-07-26T16:18:42.821530583-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/f4ad1927cf28eff719aa3f54dc94c1db6e85b803163f49a1edd719eba5243caa"
time="2017-07-26T16:18:42.821843305-07:00" level=debug msg="Assigning addresses for endpoint composetest_build_network's interface on network bridge"
time="2017-07-26T16:18:42.821869226-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:42.825493515-07:00" level=debug msg="Assigning addresses for endpoint composetest_build_network's interface on network bridge"
time="2017-07-26T16:18:42.833230554-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:42.833266874-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:42.844464865-07:00" level=debug msg="Programming external connectivity on endpoint composetest_build_network (6d6ad8b73d0f5765d0347a0e478c34efb466dbf906ad72ce1dfa7ef56e60bf0c)"
time="2017-07-26T16:18:42.849495273-07:00" level=debug msg="EnableService fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06 START"
time="2017-07-26T16:18:42.849544882-07:00" level=debug msg="EnableService fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06 DONE"
time="2017-07-26T16:18:42.950807623-07:00" level=debug msg="sandbox set key processing took 54.506995ms for container fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06"
time="2017-07-26T16:18:43.003234466-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc420d8bd00)}"
time="2017-07-26T16:18:43.010223253-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06\" timestamp:<seconds:1501111123 nanos:3086807 > "
time="2017-07-26T16:18:43.013386643-07:00" level=debug msg="Calling POST /v1.30/build?q=False&pull=False&t=composetest_buildwithnet&nocache=False&forcerm=False&networkmode=container%3Afc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06&rm=True"
time="2017-07-26T16:18:43.067683576-07:00" level=debug msg="[BUILDER] Cache miss: [/bin/sh -c ping -c1 google.local]"
time="2017-07-26T16:18:43.067721429-07:00" level=debug msg="[BUILDER] Command to be executed: [/bin/sh -c ping -c1 google.local]"
time="2017-07-26T16:18:43.105991947-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/c0f3d1787b8fb7448259c2c9963b874e0dcd520407c73d90425b0fe31c95e95c"
time="2017-07-26T16:18:43.129824825-07:00" level=debug msg="attach: stdout: begin"
time="2017-07-26T16:18:43.129888111-07:00" level=debug msg="attach: stderr: begin"
time="2017-07-26T16:18:43.130615136-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/c0f3d1787b8fb7448259c2c9963b874e0dcd520407c73d90425b0fe31c95e95c"
time="2017-07-26T16:18:43.217218206-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"1c1b7dbf8f20107cf9dacd5712ff5fcf19084ef6c860453893a29f05ee11f8a1\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc420cec220)}"
time="2017-07-26T16:18:43.225966862-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"1c1b7dbf8f20107cf9dacd5712ff5fcf19084ef6c860453893a29f05ee11f8a1\" timestamp:<seconds:1501111123 nanos:217066788 > "
time="2017-07-26T16:18:43.267117475-07:00" level=debug msg="containerd: process exited" id=1c1b7dbf8f20107cf9dacd5712ff5fcf19084ef6c860453893a29f05ee11f8a1 pid=init status=0 systemPid=12292
time="2017-07-26T16:18:43.269943092-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"1c1b7dbf8f20107cf9dacd5712ff5fcf19084ef6c860453893a29f05ee11f8a1\", Status:0x0, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc420939fe0)}"
time="2017-07-26T16:18:43.270114593-07:00" level=debug msg="attach: stdout: end"
time="2017-07-26T16:18:43.271398785-07:00" level=debug msg="attach: stderr: end"
time="2017-07-26T16:18:43.318998723-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/c0f3d1787b8fb7448259c2c9963b874e0dcd520407c73d90425b0fe31c95e95c"
time="2017-07-26T16:18:43.321632061-07:00" level=debug msg="Skipping excluded path: .wh..wh.aufs"
time="2017-07-26T16:18:43.321719141-07:00" level=debug msg="Skipping excluded path: .wh..wh.orph"
time="2017-07-26T16:18:43.321737258-07:00" level=debug msg="Skipping excluded path: .wh..wh.plnk"
time="2017-07-26T16:18:43.363087591-07:00" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to 8dcd45b5b2b7177196bb6aefe6fcf3db58bfe1457b3fcfaeea29ee43fd61ade4, size: 0"
time="2017-07-26T16:18:43.393859092-07:00" level=info msg="Layer sha256:5409e59c62907d2d25dc01df7c1f812ca382ff36e82b8c274728c63b3d516c76 cleaned up"
time="2017-07-26T16:18:43.434941409-07:00" level=debug msg="Calling GET /v1.30/images/composetest_buildwithnet/json"
time="2017-07-26T16:18:43.436647089-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:43.438070795-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:43.521906899-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:43.523634591-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:43.525235797-07:00" level=debug msg="Calling DELETE /v1.30/images/composetest_buildwithnet?noprune=False&force=False"
time="2017-07-26T16:18:43.532312849-07:00" level=debug msg="Calling DELETE /v1.30/containers/fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06?force=True&link=False&v=False"
time="2017-07-26T16:18:43.532363620-07:00" level=debug msg="Sending kill signal 9 to container fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06"
time="2017-07-26T16:18:43.567354435-07:00" level=debug msg="containerd: process exited" id=fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06 pid=init status=137 systemPid=12236
time="2017-07-26T16:18:43.570308833-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"fc398efb4a255168469d6d09f627ac6e82054383f6b487e298ee262ed3bd9a06\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc42167b890)}"
time="2017-07-26T16:18:43.570644335-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_build_network (6d6ad8b73d0f5765d0347a0e478c34efb466dbf906ad72ce1dfa7ef56e60bf0c)"
time="2017-07-26T16:18:43.572593844-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:43.699778385-07:00" level=debug msg="Releasing addresses for endpoint composetest_build_network's interface on network bridge"
time="2017-07-26T16:18:43.699818236-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:43.781477754-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:43.783222520-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dweb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:43.784425004-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:43.811684793-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_web_1"
time="2017-07-26T16:18:43.811852622-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"CapAdd\":[\"SYS_ADMIN\",\"NET_ADMIN\"],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"a02fd5328b6181729f764fce0ba002edf8d2827282a0c1ab88c69b0c1cbf4d0c\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"web\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:43.855379339-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/e5eba17ee22d84cd6c5612ac375166f069d64a026aa98b7fea66b630ccaded2f"
time="2017-07-26T16:18:43.891149379-07:00" level=debug msg="Calling GET /v1.30/containers/37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12/json"
time="2017-07-26T16:18:43.893357816-07:00" level=debug msg="Calling POST /v1.30/containers/37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12/start"
time="2017-07-26T16:18:43.895388834-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/e5eba17ee22d84cd6c5612ac375166f069d64a026aa98b7fea66b630ccaded2f"
time="2017-07-26T16:18:43.895717467-07:00" level=debug msg="Assigning addresses for endpoint composetest_web_1's interface on network bridge"
time="2017-07-26T16:18:43.895740511-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:43.910290910-07:00" level=debug msg="Assigning addresses for endpoint composetest_web_1's interface on network bridge"
time="2017-07-26T16:18:43.924851937-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:43.924874357-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:43.934732258-07:00" level=debug msg="Programming external connectivity on endpoint composetest_web_1 (1bef7ca05b032cea5d4f0a3cba7e29c5e789c1db1122f72429f9b44bc38fddea)"
time="2017-07-26T16:18:43.939809366-07:00" level=debug msg="EnableService 37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12 START"
time="2017-07-26T16:18:43.939841691-07:00" level=debug msg="EnableService 37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12 DONE"
time="2017-07-26T16:18:44.048382617-07:00" level=debug msg="sandbox set key processing took 52.159113ms for container 37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12"
time="2017-07-26T16:18:44.108518431-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc420bb7290)}"
time="2017-07-26T16:18:44.112093847-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12\" timestamp:<seconds:1501111124 nanos:108382069 > "
time="2017-07-26T16:18:44.113577747-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:44.115326581-07:00" level=debug msg="Calling DELETE /v1.30/containers/37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12?force=True&link=False&v=False"
time="2017-07-26T16:18:44.115380990-07:00" level=debug msg="Sending kill signal 9 to container 37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12"
time="2017-07-26T16:18:44.159054174-07:00" level=debug msg="containerd: process exited" id=37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12 pid=init status=137 systemPid=12431
time="2017-07-26T16:18:44.162437064-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"37e7cf4f6a4e53db0e413495b49d5c55162e940f373cbd8a893a84ec58eeae12\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4212dbbe0)}"
time="2017-07-26T16:18:44.162789641-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_web_1 (1bef7ca05b032cea5d4f0a3cba7e29c5e789c1db1122f72429f9b44bc38fddea)"
time="2017-07-26T16:18:44.164855799-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:44.252546286-07:00" level=debug msg="Releasing addresses for endpoint composetest_web_1's interface on network bridge"
time="2017-07-26T16:18:44.252584308-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:44.356360490-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:44.437664737-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:44.439389772-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:44.441662852-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:44.443215918-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dweb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:44.444499257-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:44.446367586-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_web_1"
time="2017-07-26T16:18:44.446483771-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"CapDrop\":[\"SYS_ADMIN\",\"NET_ADMIN\"],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"00a8008fc03d9870d29b8dc7c4aebb3725b56c7e0a39ae1c95b2375829ddf2bc\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"web\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:44.487501586-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/3f53b909d7550541a623f342b4347df30e70ed85c374c9b552fb9c8fb936f9fe"
time="2017-07-26T16:18:44.522139927-07:00" level=debug msg="Calling GET /v1.30/containers/db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7/json"
time="2017-07-26T16:18:44.523710018-07:00" level=debug msg="Calling POST /v1.30/containers/db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7/start"
time="2017-07-26T16:18:44.524467195-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/3f53b909d7550541a623f342b4347df30e70ed85c374c9b552fb9c8fb936f9fe"
time="2017-07-26T16:18:44.524783119-07:00" level=debug msg="Assigning addresses for endpoint composetest_web_1's interface on network bridge"
time="2017-07-26T16:18:44.524801644-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:44.533882119-07:00" level=debug msg="Assigning addresses for endpoint composetest_web_1's interface on network bridge"
time="2017-07-26T16:18:44.541002510-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:44.541033551-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:44.549251672-07:00" level=debug msg="Programming external connectivity on endpoint composetest_web_1 (d4b767ab715b713e2d2c56c2c96b1d07be0b7c686ca74a0d6d0df48cd0111630)"
time="2017-07-26T16:18:44.552445722-07:00" level=debug msg="EnableService db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7 START"
time="2017-07-26T16:18:44.552471158-07:00" level=debug msg="EnableService db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7 DONE"
time="2017-07-26T16:18:44.684891581-07:00" level=debug msg="sandbox set key processing took 68.009867ms for container db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7"
time="2017-07-26T16:18:44.747966108-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4210a2de0)}"
time="2017-07-26T16:18:44.756922807-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7\" timestamp:<seconds:1501111124 nanos:747796945 > "
time="2017-07-26T16:18:44.758322639-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:44.759986052-07:00" level=debug msg="Calling DELETE /v1.30/containers/db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7?force=True&link=False&v=False"
time="2017-07-26T16:18:44.760034801-07:00" level=debug msg="Sending kill signal 9 to container db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7"
time="2017-07-26T16:18:44.795308998-07:00" level=debug msg="containerd: process exited" id=db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7 pid=init status=137 systemPid=12561
time="2017-07-26T16:18:44.798476343-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"db796a3e38d58f0c6b58c7624472be301503524091190b93caada6b5a0ac8cd7\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4209564b0)}"
time="2017-07-26T16:18:44.798859064-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_web_1 (d4b767ab715b713e2d2c56c2c96b1d07be0b7c686ca74a0d6d0df48cd0111630)"
time="2017-07-26T16:18:44.800907900-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:44.906054529-07:00" level=debug msg="Releasing addresses for endpoint composetest_web_1's interface on network bridge"
time="2017-07-26T16:18:44.906082220-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:44.991055047-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:45.067262793-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:45.069371837-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:45.071694912-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:45.073212689-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dfoo%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:45.074370766-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:45.076355611-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_foo_1"
time="2017-07-26T16:18:45.076475421-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"312c296d7eee0896475c5b2e806cf8a832d6d4eeac1ba661c323f44659a63ecc\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"foo\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:45.128438135-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/6d881181edfb91087e40f5e563766e052fa07e41c4593c952ecf6146d87b049b"
time="2017-07-26T16:18:45.160945637-07:00" level=debug msg="Calling GET /v1.30/containers/781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a/json"
time="2017-07-26T16:18:45.162395689-07:00" level=debug msg="Calling POST /v1.30/containers/781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a/start"
time="2017-07-26T16:18:45.162967543-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/6d881181edfb91087e40f5e563766e052fa07e41c4593c952ecf6146d87b049b"
time="2017-07-26T16:18:45.163270950-07:00" level=debug msg="Assigning addresses for endpoint composetest_foo_1's interface on network bridge"
time="2017-07-26T16:18:45.163293061-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:45.182920058-07:00" level=debug msg="Assigning addresses for endpoint composetest_foo_1's interface on network bridge"
time="2017-07-26T16:18:45.192323457-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:45.192365226-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:45.204903926-07:00" level=debug msg="Programming external connectivity on endpoint composetest_foo_1 (7e67bed42fa31810e150f576a53c406dce81ea4390674fb72eeb6a517e7aeab0)"
time="2017-07-26T16:18:45.206436285-07:00" level=debug msg="EnableService 781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a START"
time="2017-07-26T16:18:45.206463927-07:00" level=debug msg="EnableService 781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a DONE"
time="2017-07-26T16:18:45.341890366-07:00" level=debug msg="sandbox set key processing took 65.009017ms for container 781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a"
time="2017-07-26T16:18:45.405778427-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc420baba40)}"
time="2017-07-26T16:18:45.414527940-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a\" timestamp:<seconds:1501111125 nanos:405627584 > "
time="2017-07-26T16:18:45.416097004-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dfoo%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:45.417368466-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dfoo%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:45.418626077-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dbar%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:45.419843047-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:45.421312363-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dbar%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:45.422428966-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:45.424137103-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_bar_1"
time="2017-07-26T16:18:45.424271960-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"312c296d7eee0896475c5b2e806cf8a832d6d4eeac1ba661c323f44659a63ecc\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"bar\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:45.467290382-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/9f4b8862d678b86a1b4e94d12cc640635436c037166c4b386174bf8374520957"
time="2017-07-26T16:18:45.499121315-07:00" level=debug msg="Calling GET /v1.30/containers/fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066/json"
time="2017-07-26T16:18:45.500687041-07:00" level=debug msg="Calling POST /v1.30/containers/fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066/start"
time="2017-07-26T16:18:45.501207310-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/9f4b8862d678b86a1b4e94d12cc640635436c037166c4b386174bf8374520957"
time="2017-07-26T16:18:45.501484156-07:00" level=debug msg="Assigning addresses for endpoint composetest_bar_1's interface on network bridge"
time="2017-07-26T16:18:45.501506561-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:45.507829806-07:00" level=debug msg="Assigning addresses for endpoint composetest_bar_1's interface on network bridge"
time="2017-07-26T16:18:45.516347925-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:45.516383223-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:45.528538444-07:00" level=debug msg="Programming external connectivity on endpoint composetest_bar_1 (8a9dbb89e1aff6b6d692403b8e483a8627c3ad9740591a6fa0fc622c9da2952d)"
time="2017-07-26T16:18:45.533582392-07:00" level=debug msg="EnableService fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066 START"
time="2017-07-26T16:18:45.533603287-07:00" level=debug msg="EnableService fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066 DONE"
time="2017-07-26T16:18:45.650993246-07:00" level=debug msg="sandbox set key processing took 54.896553ms for container fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066"
time="2017-07-26T16:18:45.699974709-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc42167b350)}"
time="2017-07-26T16:18:45.708774274-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066\" timestamp:<seconds:1501111125 nanos:699822838 > "
time="2017-07-26T16:18:45.710232532-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:45.711983910-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dbar%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:45.713189419-07:00" level=debug msg="Calling GET /v1.30/containers/fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066/json"
time="2017-07-26T16:18:45.714436729-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:45.716185919-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_bar_2"
time="2017-07-26T16:18:45.716312580-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"312c296d7eee0896475c5b2e806cf8a832d6d4eeac1ba661c323f44659a63ecc\",\"com.docker.compose.container-number\":\"2\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"bar\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:45.755209254-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/95a6e08443c35121007710bf26e6612da2c2ddaa4a58fa99df10ace0daea0879"
time="2017-07-26T16:18:45.786621065-07:00" level=debug msg="Calling GET /v1.30/containers/f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da/json"
time="2017-07-26T16:18:45.788521373-07:00" level=debug msg="Calling POST /v1.30/containers/f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da/start"
time="2017-07-26T16:18:45.789283157-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/95a6e08443c35121007710bf26e6612da2c2ddaa4a58fa99df10ace0daea0879"
time="2017-07-26T16:18:45.789581546-07:00" level=debug msg="Assigning addresses for endpoint composetest_bar_2's interface on network bridge"
time="2017-07-26T16:18:45.789604474-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:45.796511508-07:00" level=debug msg="Assigning addresses for endpoint composetest_bar_2's interface on network bridge"
time="2017-07-26T16:18:45.807854183-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:45.807972436-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:45.817385396-07:00" level=debug msg="Programming external connectivity on endpoint composetest_bar_2 (ca569862d14f18da57b38758e8e8161ff8c21a1586d77cffd21b9ec4b7c3347e)"
time="2017-07-26T16:18:45.822156250-07:00" level=debug msg="EnableService f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da START"
time="2017-07-26T16:18:45.822174943-07:00" level=debug msg="EnableService f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da DONE"
time="2017-07-26T16:18:45.960901384-07:00" level=debug msg="sandbox set key processing took 83.859656ms for container f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da"
time="2017-07-26T16:18:46.032700071-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc420d7e350)}"
time="2017-07-26T16:18:46.041680659-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da\" timestamp:<seconds:1501111126 nanos:32563164 > "
time="2017-07-26T16:18:46.043260209-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dfoo%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:46.044656763-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dbar%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:46.046001146-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dbar%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:46.047297298-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:46.049077508-07:00" level=debug msg="Calling DELETE /v1.30/containers/f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da?force=True&link=False&v=False"
time="2017-07-26T16:18:46.049138861-07:00" level=debug msg="Sending kill signal 9 to container f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da"
time="2017-07-26T16:18:46.08735461-07:00" level=debug msg="containerd: process exited" id=f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da pid=init status=137 systemPid=12837
time="2017-07-26T16:18:46.090126989-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"f8b49542969f557246213c1cadd585f0c297d5fd138fcaea86e3af475821c9da\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc420d7f9d0)}"
time="2017-07-26T16:18:46.090449001-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_bar_2 (ca569862d14f18da57b38758e8e8161ff8c21a1586d77cffd21b9ec4b7c3347e)"
time="2017-07-26T16:18:46.092414772-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:46.200414674-07:00" level=debug msg="Releasing addresses for endpoint composetest_bar_2's interface on network bridge"
time="2017-07-26T16:18:46.200443844-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.4)"
time="2017-07-26T16:18:46.283759365-07:00" level=debug msg="Calling DELETE /v1.30/containers/fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066?force=True&link=False&v=False"
time="2017-07-26T16:18:46.283828615-07:00" level=debug msg="Sending kill signal 9 to container fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066"
time="2017-07-26T16:18:46.323682862-07:00" level=debug msg="containerd: process exited" id=fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066 pid=init status=137 systemPid=12760
time="2017-07-26T16:18:46.326666504-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"fcb84a5545fc6b92c83034d8340aac301aea0c0402d9506359727a127bd9c066\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc421247460)}"
time="2017-07-26T16:18:46.327044839-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_bar_1 (8a9dbb89e1aff6b6d692403b8e483a8627c3ad9740591a6fa0fc622c9da2952d)"
time="2017-07-26T16:18:46.329003879-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:46.423846603-07:00" level=debug msg="Releasing addresses for endpoint composetest_bar_1's interface on network bridge"
time="2017-07-26T16:18:46.423874880-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.3)"
time="2017-07-26T16:18:46.494707449-07:00" level=debug msg="Calling DELETE /v1.30/containers/781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a?force=True&link=False&v=False"
time="2017-07-26T16:18:46.494770358-07:00" level=debug msg="Sending kill signal 9 to container 781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a"
time="2017-07-26T16:18:46.543031572-07:00" level=debug msg="containerd: process exited" id=781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a pid=init status=137 systemPid=12682
time="2017-07-26T16:18:46.546790362-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"781709fc87d94db15e815074179490a5dd801577bc70563cae869ef8082a6c9a\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4210a2c50)}"
time="2017-07-26T16:18:46.547147623-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_foo_1 (7e67bed42fa31810e150f576a53c406dce81ea4390674fb72eeb6a517e7aeab0)"
time="2017-07-26T16:18:46.549061967-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:46.659868692-07:00" level=debug msg="Releasing addresses for endpoint composetest_foo_1's interface on network bridge"
time="2017-07-26T16:18:46.659906999-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:46.752188928-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:46.837097598-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:46.838774058-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:46.841498768-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:46.844389193-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DTrue%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:46.846213051-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:46.847647866-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_run_1"
time="2017-07-26T16:18:46.847762462-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"True\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:46.889878106-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/062ed0570f2eca26e118cb7a44eb40b8f649dc5199c3f25188d4bbbca758234b"
time="2017-07-26T16:18:46.932272977-07:00" level=debug msg="Calling GET /v1.30/containers/c4b0d0cf5b4b61b68457c8b7028c159372f33e6b4df32b60b3bf9ea1eff09aa3/json"
time="2017-07-26T16:18:46.933888972-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:46.935190595-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DTrue%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:46.936449661-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:46.938007854-07:00" level=debug msg="Calling DELETE /v1.30/containers/c4b0d0cf5b4b61b68457c8b7028c159372f33e6b4df32b60b3bf9ea1eff09aa3?force=True&link=False&v=False"
time="2017-07-26T16:18:46.946197310-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:47.025767265-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:47.027420850-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:47.029795958-07:00" level=debug msg="Calling GET /v1.30/version"
time="2017-07-26T16:18:47.031069082-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:47.032481823-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:47.033618792-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:47.035370515-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:47.035503886-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"CpuCount\":2,\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"d0d54cccae9a468908128d46e10e6ac1d6f414ae64c695339362cc0b559df54b\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:47.077418674-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/0499d2ab23ca3544ebe8fa59e5a33e2e195d315734d6c9a512a245929bae7b1e"
time="2017-07-26T16:18:47.110719563-07:00" level=debug msg="Calling GET /v1.30/containers/32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8/json"
time="2017-07-26T16:18:47.112451189-07:00" level=debug msg="Calling POST /v1.30/containers/32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8/start"
time="2017-07-26T16:18:47.114185632-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/0499d2ab23ca3544ebe8fa59e5a33e2e195d315734d6c9a512a245929bae7b1e"
time="2017-07-26T16:18:47.114497624-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:47.114519147-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:47.125873213-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:47.135214672-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:47.135244674-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:47.146060988-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (76067df8d9503972454905a05036e328bc755fe9de4654e04449d485c0e53be2)"
time="2017-07-26T16:18:47.149300009-07:00" level=debug msg="EnableService 32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8 START"
time="2017-07-26T16:18:47.149371688-07:00" level=debug msg="EnableService 32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8 DONE"
time="2017-07-26T16:18:47.292427755-07:00" level=debug msg="sandbox set key processing took 71.31989ms for container 32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8"
time="2017-07-26T16:18:47.346058227-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4210e2080)}"
time="2017-07-26T16:18:47.352910244-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8\" timestamp:<seconds:1501111127 nanos:345799936 > "
time="2017-07-26T16:18:47.354626690-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:47.356336818-07:00" level=debug msg="Calling DELETE /v1.30/containers/32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8?force=True&link=False&v=False"
time="2017-07-26T16:18:47.356390409-07:00" level=debug msg="Sending kill signal 9 to container 32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8"
time="2017-07-26T16:18:47.404474373-07:00" level=debug msg="containerd: process exited" id=32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8 pid=init status=137 systemPid=13072
time="2017-07-26T16:18:47.407668643-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"32e0813dae8edc8448f7a4cc99810e113ba866dcd0d4ece4d86a6dc40d1862a8\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4208efb40)}"
time="2017-07-26T16:18:47.408020229-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (76067df8d9503972454905a05036e328bc755fe9de4654e04449d485c0e53be2)"
time="2017-07-26T16:18:47.410022078-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:47.515757446-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:47.515787913-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:47.593780965-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:47.674554422-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:47.676216152-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:47.678964129-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:47.680565571-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:47.681698333-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:47.683286810-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:47.683404031-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"CpuQuota\":40000,\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"6703dc8454e2260194e957498626afac6206625de3e28922243eb54e8be43c73\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:47.721517162-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/cb945427cb7fcc0766dd20ab4e50ff2e95b358790d16fdbdd893d5eff3e5c1a1"
time="2017-07-26T16:18:47.754091876-07:00" level=debug msg="Calling GET /v1.30/containers/dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1/json"
time="2017-07-26T16:18:47.755735990-07:00" level=debug msg="Calling POST /v1.30/containers/dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1/start"
time="2017-07-26T16:18:47.757421948-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/cb945427cb7fcc0766dd20ab4e50ff2e95b358790d16fdbdd893d5eff3e5c1a1"
time="2017-07-26T16:18:47.757672976-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:47.757692886-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:47.776661791-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:47.782058947-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:47.782079997-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:47.786995489-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (15e3a36660f055f890aa4c2d15a91cd7e90ea6c77723607dbf06e2ae7523615d)"
time="2017-07-26T16:18:47.788511998-07:00" level=debug msg="EnableService dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1 START"
time="2017-07-26T16:18:47.788532903-07:00" level=debug msg="EnableService dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1 DONE"
time="2017-07-26T16:18:47.912859374-07:00" level=debug msg="sandbox set key processing took 55.889725ms for container dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1"
time="2017-07-26T16:18:47.969875697-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc421326ad0)}"
time="2017-07-26T16:18:47.980705511-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1\" timestamp:<seconds:1501111127 nanos:969744232 > "
time="2017-07-26T16:18:47.982082402-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:47.983797721-07:00" level=debug msg="Calling DELETE /v1.30/containers/dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1?force=True&link=False&v=False"
time="2017-07-26T16:18:47.983854098-07:00" level=debug msg="Sending kill signal 9 to container dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1"
time="2017-07-26T16:18:48.015537015-07:00" level=debug msg="containerd: process exited" id=dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1 pid=init status=137 systemPid=13181
time="2017-07-26T16:18:48.019591960-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"dfce036649b37ab339bdbeb6ebd2c370552bdd99a460b7d88bc8db1f2179e6d1\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4212f3010)}"
time="2017-07-26T16:18:48.019934924-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (15e3a36660f055f890aa4c2d15a91cd7e90ea6c77723607dbf06e2ae7523615d)"
time="2017-07-26T16:18:48.022069135-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:48.146138318-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:48.146165727-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:48.216420153-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:48.299792214-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:48.303093550-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:48.306060188-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:48.307675199-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:48.308868474-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:48.310529223-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:48.310645134-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"CpusetCpus\":\"0\",\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"0d4f94ed96bd96e27575d98f0955f6a5c484d6ecc6969075e66f32e3f00dbf89\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:48.352554836-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/3cbd2bb7446f01fac4841c686fc1b43f3effc827edffbeecfa91635a50920048"
time="2017-07-26T16:18:48.375679800-07:00" level=debug msg="Calling GET /v1.30/containers/ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1/json"
time="2017-07-26T16:18:48.377261248-07:00" level=debug msg="Calling POST /v1.30/containers/ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1/start"
time="2017-07-26T16:18:48.377761456-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/3cbd2bb7446f01fac4841c686fc1b43f3effc827edffbeecfa91635a50920048"
time="2017-07-26T16:18:48.378040270-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:48.378060180-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:48.399865053-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:48.408468853-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:48.408489949-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:48.416827414-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (d78a4357bec9d5aca64e49cff41c8ea6b838effc13d4268b4f9befab3807c4eb)"
time="2017-07-26T16:18:48.418237235-07:00" level=debug msg="EnableService ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1 START"
time="2017-07-26T16:18:48.418251275-07:00" level=debug msg="EnableService ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1 DONE"
time="2017-07-26T16:18:48.522959995-07:00" level=debug msg="sandbox set key processing took 57.082404ms for container ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1"
time="2017-07-26T16:18:48.584918315-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4213d0720)}"
time="2017-07-26T16:18:48.595618230-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1\" timestamp:<seconds:1501111128 nanos:584665076 > "
time="2017-07-26T16:18:48.596968789-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:48.598611419-07:00" level=debug msg="Calling DELETE /v1.30/containers/ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1?force=True&link=False&v=False"
time="2017-07-26T16:18:48.598658780-07:00" level=debug msg="Sending kill signal 9 to container ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1"
time="2017-07-26T16:18:48.640600314-07:00" level=debug msg="containerd: process exited" id=ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1 pid=init status=137 systemPid=13300
time="2017-07-26T16:18:48.643880877-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"ad425006c2ff08a6cb6695ed25fa80b4e2866e086358d75546deec2e225f62e1\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc421246870)}"
time="2017-07-26T16:18:48.644297289-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (d78a4357bec9d5aca64e49cff41c8ea6b838effc13d4268b4f9befab3807c4eb)"
time="2017-07-26T16:18:48.646349563-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:48.751845967-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:48.751874943-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:48.835794768-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:48.918333944-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:48.920063357-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:48.922266464-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:48.923874915-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:48.925399562-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:48.927218321-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:48.927336888-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"CpuShares\":73,\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"71643d66f3784fe537d19efdd63c4078ccbe2558c361f5c378073d710d56695e\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:48.974572599-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/0dbd79db9405d48b151572c8e40ec2bd61e3f26d037f51ee36f589388a586df8"
time="2017-07-26T16:18:49.008937223-07:00" level=debug msg="Calling GET /v1.30/containers/7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4/json"
time="2017-07-26T16:18:49.010639737-07:00" level=debug msg="Calling POST /v1.30/containers/7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4/start"
time="2017-07-26T16:18:49.011196782-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/0dbd79db9405d48b151572c8e40ec2bd61e3f26d037f51ee36f589388a586df8"
time="2017-07-26T16:18:49.011491766-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:49.011515482-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:49.027693003-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:49.035382761-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:49.035419786-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:49.043744843-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (82bf677342c2769375b79e3210399d46c4ac2836b6f5f63355e3f16a3daee3bd)"
time="2017-07-26T16:18:49.048594816-07:00" level=debug msg="EnableService 7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4 START"
time="2017-07-26T16:18:49.048612361-07:00" level=debug msg="EnableService 7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4 DONE"
time="2017-07-26T16:18:49.171379505-07:00" level=debug msg="sandbox set key processing took 64.898279ms for container 7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4"
time="2017-07-26T16:18:49.237465548-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc421290020)}"
time="2017-07-26T16:18:49.246626248-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4\" timestamp:<seconds:1501111129 nanos:237264169 > "
time="2017-07-26T16:18:49.248073460-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:49.249716159-07:00" level=debug msg="Calling DELETE /v1.30/containers/7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4?force=True&link=False&v=False"
time="2017-07-26T16:18:49.249772165-07:00" level=debug msg="Sending kill signal 9 to container 7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4"
time="2017-07-26T16:18:49.287574457-07:00" level=debug msg="containerd: process exited" id=7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4 pid=init status=137 systemPid=13429
time="2017-07-26T16:18:49.290551458-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"7473c7ac94aeffe5e59ecc0a310367ab0e9a54dd0eac7d6f389eaacf8ac305a4\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4212905e0)}"
time="2017-07-26T16:18:49.290940862-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (82bf677342c2769375b79e3210399d46c4ac2836b6f5f63355e3f16a3daee3bd)"
time="2017-07-26T16:18:49.293153557-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:49.390159455-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:49.390196030-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:49.462736814-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:49.543476503-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:49.545351389-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:49.547473080-07:00" level=debug msg="Calling GET /v1.30/version"
time="2017-07-26T16:18:49.548650155-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:49.550022186-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:49.551171612-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:49.552809344-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:49.552928562-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NanoCpus\":1000000000,\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"8cfb02532e33bdd3f3ee117f31a6d3781478fe0cb3b84c4a6c8f28d19cd3ed86\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:49.591719939-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/8594a4b074e26c05be2e001d59e5da4fb595480c7ce6a9a6ac88e9cf007e362b"
time="2017-07-26T16:18:49.620318161-07:00" level=debug msg="Calling GET /v1.30/containers/bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008/json"
time="2017-07-26T16:18:49.621885914-07:00" level=debug msg="Calling POST /v1.30/containers/bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008/start"
time="2017-07-26T16:18:49.623337236-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/8594a4b074e26c05be2e001d59e5da4fb595480c7ce6a9a6ac88e9cf007e362b"
time="2017-07-26T16:18:49.623561752-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:49.623575919-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:49.643073706-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:49.651601836-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:49.651626462-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:49.658333964-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (3eeccc5e8539bb66d1d39a134c788f95d1c7a5e40da34afbc254e5d7e3e8f382)"
time="2017-07-26T16:18:49.661592808-07:00" level=debug msg="EnableService bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008 START"
time="2017-07-26T16:18:49.661623466-07:00" level=debug msg="EnableService bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008 DONE"
time="2017-07-26T16:18:49.780481062-07:00" level=debug msg="sandbox set key processing took 63.2058ms for container bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008"
time="2017-07-26T16:18:49.825883265-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc420984a30)}"
time="2017-07-26T16:18:49.836546863-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008\" timestamp:<seconds:1501111129 nanos:825735901 > "
time="2017-07-26T16:18:49.838022851-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:49.840019158-07:00" level=debug msg="Calling DELETE /v1.30/containers/bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008?force=True&link=False&v=False"
time="2017-07-26T16:18:49.840068857-07:00" level=debug msg="Sending kill signal 9 to container bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008"
time="2017-07-26T16:18:49.887317748-07:00" level=debug msg="containerd: process exited" id=bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008 pid=init status=137 systemPid=13551
time="2017-07-26T16:18:49.891502955-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"bd29544c41889d4bde913c1ac91cf1361ed6a6497cd03173c82df7461719f008\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc420984b40)}"
time="2017-07-26T16:18:49.891888054-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (3eeccc5e8539bb66d1d39a134c788f95d1c7a5e40da34afbc254e5d7e3e8f382)"
time="2017-07-26T16:18:49.894052742-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:50.015969392-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:50.015998137-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:50.080999798-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:50.163475172-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:50.165539177-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:50.168008021-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:50.169530607-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:50.170705711-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:50.172394629-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:50.172509513-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"ExtraHosts\":[\"otherhost:50.31.209.229\",\"somehost:162.242.195.82\"],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"fe44bf69dc8a4be36f8e88f0ef43467f09c61894a6e9db68461adcd3e3eb785b\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:50.229719228-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/92431ab75351097c0fe7226d133f4907b49128da84550a329dad7d0a5aed467d"
time="2017-07-26T16:18:50.260258272-07:00" level=debug msg="Calling GET /v1.30/containers/4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f/json"
time="2017-07-26T16:18:50.261832155-07:00" level=debug msg="Calling POST /v1.30/containers/4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f/start"
time="2017-07-26T16:18:50.262631037-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/92431ab75351097c0fe7226d133f4907b49128da84550a329dad7d0a5aed467d"
time="2017-07-26T16:18:50.263109103-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:50.263161841-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:50.272546604-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:50.292721525-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:50.292760975-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:50.301428409-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (e2ca7e5c589b3ac8f650e8abea72aa14bfc15b430cc2a35abe31a1e07310080d)"
time="2017-07-26T16:18:50.306429597-07:00" level=debug msg="EnableService 4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f START"
time="2017-07-26T16:18:50.306464412-07:00" level=debug msg="EnableService 4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f DONE"
time="2017-07-26T16:18:50.428841982-07:00" level=debug msg="sandbox set key processing took 75.938807ms for container 4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f"
time="2017-07-26T16:18:50.499953258-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc421d31510)}"
time="2017-07-26T16:18:50.508981606-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f\" timestamp:<seconds:1501111130 nanos:499811553 > "
time="2017-07-26T16:18:50.510367448-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:50.512115699-07:00" level=debug msg="Calling DELETE /v1.30/containers/4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f?force=True&link=False&v=False"
time="2017-07-26T16:18:50.512166249-07:00" level=debug msg="Sending kill signal 9 to container 4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f"
time="2017-07-26T16:18:50.543586979-07:00" level=debug msg="containerd: process exited" id=4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f pid=init status=137 systemPid=13689
time="2017-07-26T16:18:50.547426267-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"4d5466d01a86879e6a602bf3d41ced6ce2a07f441fde61970914a488d4905e2f\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4211e7390)}"
time="2017-07-26T16:18:50.547755406-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (e2ca7e5c589b3ac8f650e8abea72aa14bfc15b430cc2a35abe31a1e07310080d)"
time="2017-07-26T16:18:50.549827798-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:50.680443572-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:50.680479654-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:50.767807283-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:50.845210558-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:50.846940734-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:50.849165288-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:50.855680397-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:50.857271164-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:50.858972101-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:50.859104480-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"ExtraHosts\":[\"somehost:162.242.195.82\",\"otherhost:50.31.209.229\"],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"9184a9d41572d4c3592a067f112b406bd52f164253f4528ea26d251bf10c75bd\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:50.897310735-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/21432c37393794094014c17c087a795cc84b839fe4048df80b213a009d7041bd"
time="2017-07-26T16:18:50.933338111-07:00" level=debug msg="Calling GET /v1.30/containers/0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a/json"
time="2017-07-26T16:18:50.935052654-07:00" level=debug msg="Calling POST /v1.30/containers/0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a/start"
time="2017-07-26T16:18:50.936821397-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/21432c37393794094014c17c087a795cc84b839fe4048df80b213a009d7041bd"
time="2017-07-26T16:18:50.937128304-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:50.937152536-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:50.946066805-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:50.957363121-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:50.957387108-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:50.967671078-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (37acd4a2e81743e1001a0a0d8ff9129e672ae151b2f93c797731a3520695d494)"
time="2017-07-26T16:18:50.972609658-07:00" level=debug msg="EnableService 0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a START"
time="2017-07-26T16:18:50.972632238-07:00" level=debug msg="EnableService 0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a DONE"
time="2017-07-26T16:18:51.069668674-07:00" level=debug msg="sandbox set key processing took 45.757753ms for container 0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a"
time="2017-07-26T16:18:51.139966541-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc420a958e0)}"
time="2017-07-26T16:18:51.148869953-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a\" timestamp:<seconds:1501111131 nanos:139808944 > "
time="2017-07-26T16:18:51.150301414-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:51.151933449-07:00" level=debug msg="Calling DELETE /v1.30/containers/0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a?force=True&link=False&v=False"
time="2017-07-26T16:18:51.151983961-07:00" level=debug msg="Sending kill signal 9 to container 0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a"
time="2017-07-26T16:18:51.195365355-07:00" level=debug msg="containerd: process exited" id=0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a pid=init status=137 systemPid=13815
time="2017-07-26T16:18:51.198414921-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"0787de3d684cdf715a96b4105cf01981e4b3f6c6e1b870ab5569c034bd550e2a\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc421c930e0)}"
time="2017-07-26T16:18:51.198769747-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (37acd4a2e81743e1001a0a0d8ff9129e672ae151b2f93c797731a3520695d494)"
time="2017-07-26T16:18:51.200949385-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:51.315919244-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:51.315950471-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:51.397461066-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:51.479484902-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:51.481547072-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:51.484361635-07:00" level=debug msg="Calling GET /v1.30/version"
time="2017-07-26T16:18:51.485905349-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:51.488992683-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:51.490583170-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:51.492512699-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:51.492659127-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Init\":true,\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"a6193fda828bfd949f26383b88a796167aebc05d66b5a98bfc2823db2575dac4\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:51.542520461-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/030188f5c272b5a406daed060d6d75fcd8cba55ccf4094a2480bbadc304e2260"
time="2017-07-26T16:18:51.570206047-07:00" level=debug msg="Calling GET /v1.30/containers/732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134/json"
time="2017-07-26T16:18:51.571869634-07:00" level=debug msg="Calling POST /v1.30/containers/732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134/start"
time="2017-07-26T16:18:51.572385074-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/030188f5c272b5a406daed060d6d75fcd8cba55ccf4094a2480bbadc304e2260"
time="2017-07-26T16:18:51.572668928-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:51.572693612-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:51.580273309-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:51.592109167-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:51.592135992-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:51.600602859-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (12b812b52b766c4c970400f9f848b3657d572b4a8b3e69f15d9125292c98cdc5)"
time="2017-07-26T16:18:51.602058243-07:00" level=debug msg="EnableService 732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134 START"
time="2017-07-26T16:18:51.602072146-07:00" level=debug msg="EnableService 732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134 DONE"
time="2017-07-26T16:18:51.725018799-07:00" level=debug msg="sandbox set key processing took 61.349587ms for container 732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134"
time="2017-07-26T16:18:51.781575355-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc421326b00)}"
time="2017-07-26T16:18:51.792244606-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134\" timestamp:<seconds:1501111131 nanos:781410982 > "
time="2017-07-26T16:18:51.793689701-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:51.795691146-07:00" level=debug msg="Calling DELETE /v1.30/containers/732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134?force=True&link=False&v=False"
time="2017-07-26T16:18:51.795735374-07:00" level=debug msg="Sending kill signal 9 to container 732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134"
time="2017-07-26T16:18:51.835570552-07:00" level=debug msg="containerd: process exited" id=732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134 pid=init status=137 systemPid=13938
time="2017-07-26T16:18:51.838611443-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"732228ddb678ed82ee74b76ec66a04b85f4d4049a14551202efefeff233f1134\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4213db4f0)}"
time="2017-07-26T16:18:51.838973922-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (12b812b52b766c4c970400f9f848b3657d572b4a8b3e69f15d9125292c98cdc5)"
time="2017-07-26T16:18:51.841093745-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:51.951832822-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:51.951860461-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:52.036791586-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:52.118474621-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:52.120098684-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:52.122243222-07:00" level=debug msg="Calling GET /v1.30/version"
time="2017-07-26T16:18:52.123491375-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:52.125001098-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:52.126163115-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:52.128050156-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:52.129249221-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:52.213841020-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:52.215457107-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:52.349645339-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:52.351140433-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:52.352294285-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:52.353892257-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:52.354004118-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"0fbf26d391f8530ffd31bf21748568ceef85f957976e9ca0b5ac037798d334bf\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"MacAddress\":\"02:42:ac:11:65:43\",\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:52.398741411-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/afbf11e4b3861c77a251286af0bdb51e37b9a47143c76af77a76227767364d3d"
time="2017-07-26T16:18:52.426927377-07:00" level=debug msg="Calling GET /v1.30/containers/8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008/json"
time="2017-07-26T16:18:52.428681368-07:00" level=debug msg="Calling POST /v1.30/containers/8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008/start"
time="2017-07-26T16:18:52.430193324-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/afbf11e4b3861c77a251286af0bdb51e37b9a47143c76af77a76227767364d3d"
time="2017-07-26T16:18:52.430521339-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:52.430545551-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:52.433340762-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:52.440158539-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:52.440187444-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:52.456155333-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (063095b3d77039437cfdcc5cdea1bf96b1c17f3d2e8fcb36cd0e18b2fb7f3752)"
time="2017-07-26T16:18:52.459482434-07:00" level=debug msg="EnableService 8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008 START"
time="2017-07-26T16:18:52.459573794-07:00" level=debug msg="EnableService 8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008 DONE"
time="2017-07-26T16:18:52.574821566-07:00" level=debug msg="sandbox set key processing took 57.485864ms for container 8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008"
time="2017-07-26T16:18:52.623695433-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc42122ef80)}"
time="2017-07-26T16:18:52.634489131-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008\" timestamp:<seconds:1501111132 nanos:623574658 > "
time="2017-07-26T16:18:52.635852495-07:00" level=debug msg="Calling GET /v1.30/containers/8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008/json"
time="2017-07-26T16:18:52.637243237-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:52.639020380-07:00" level=debug msg="Calling DELETE /v1.30/containers/8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008?force=True&link=False&v=False"
time="2017-07-26T16:18:52.639073104-07:00" level=debug msg="Sending kill signal 9 to container 8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008"
time="2017-07-26T16:18:52.67581793-07:00" level=debug msg="containerd: process exited" id=8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008 pid=init status=137 systemPid=14062
time="2017-07-26T16:18:52.679662486-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"8887d66de3307a0e9b0ec5ac2319a61feef0340db61231f4e833277457637008\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc421201150)}"
time="2017-07-26T16:18:52.680005979-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (063095b3d77039437cfdcc5cdea1bf96b1c17f3d2e8fcb36cd0e18b2fb7f3752)"
time="2017-07-26T16:18:52.682162192-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:52.791697129-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:52.791723632-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:52.876415257-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:52.956143455-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:52.957858481-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:52.959940979-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:52.961646407-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DTrue%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:52.963353188-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:52.964858255-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_run_1"
time="2017-07-26T16:18:52.964975278-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"True\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:53.010814619-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/6cb9a091802e2dcd1dd303990cbe1afe83b2e87449534fb23d5191883c5b3296"
time="2017-07-26T16:18:53.049815056-07:00" level=debug msg="Calling GET /v1.30/containers/be68a38e4d3aba096a18ecd1d51f5f207c7fca69d56280db473f1b76bb0a0b2d/json"
time="2017-07-26T16:18:53.051301059-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:53.052916927-07:00" level=debug msg="Calling DELETE /v1.30/containers/be68a38e4d3aba096a18ecd1d51f5f207c7fca69d56280db473f1b76bb0a0b2d?force=True&link=False&v=False"
time="2017-07-26T16:18:53.066651967-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:53.147898610-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:53.149599278-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:53.151714523-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:53.152909134-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:53.154445933-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DTrue%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:53.155688156-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:53.156917960-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_run_1"
time="2017-07-26T16:18:53.157018397-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"True\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:53.186603267-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/fa4e65afac9fb08d9a3b42c4c9ebe8213280a21a65122c4ed58b95000af75201"
time="2017-07-26T16:18:53.226571209-07:00" level=debug msg="Calling GET /v1.30/containers/6608504e20abf61ff7e057bae005ab317ad456ed6b5804e1f08a30339a57a4d0/json"
time="2017-07-26T16:18:53.228111123-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:53.229851991-07:00" level=debug msg="Calling DELETE /v1.30/containers/6608504e20abf61ff7e057bae005ab317ad456ed6b5804e1f08a30339a57a4d0?force=True&link=False&v=False"
time="2017-07-26T16:18:53.243917046-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:53.319687818-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:53.321733590-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:53.323963501-07:00" level=debug msg="Calling GET /v1.30/version"
time="2017-07-26T16:18:53.325129388-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:53.326618920-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:53.327758720-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:53.329319831-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:53.329452271-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PidsLimit\":10,\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"39d4319fd1dfa92026beb6202858f4ba330b263087c8b915af0bd11dea5fd3f5\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:53.362611298-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/9cf14961f3b9367bd431ade3802e2f5ca986d9b4925649fb3f71aed22dd68318"
time="2017-07-26T16:18:53.390603921-07:00" level=debug msg="Calling GET /v1.30/containers/1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db/json"
time="2017-07-26T16:18:53.392346211-07:00" level=debug msg="Calling POST /v1.30/containers/1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db/start"
time="2017-07-26T16:18:53.393050961-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/9cf14961f3b9367bd431ade3802e2f5ca986d9b4925649fb3f71aed22dd68318"
time="2017-07-26T16:18:53.393339422-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:53.393364140-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:53.402356551-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:53.414101937-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:53.414135009-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:53.424632446-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (d8545c65dc0add5835d53326f2937b1d9d4dd9d431356dcb2d9ecabf0c251647)"
time="2017-07-26T16:18:53.429744145-07:00" level=debug msg="EnableService 1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db START"
time="2017-07-26T16:18:53.429784212-07:00" level=debug msg="EnableService 1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db DONE"
time="2017-07-26T16:18:53.538675550-07:00" level=debug msg="sandbox set key processing took 55.010076ms for container 1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db"
time="2017-07-26T16:18:53.601374476-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4211e6880)}"
time="2017-07-26T16:18:53.610182338-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db\" timestamp:<seconds:1501111133 nanos:601235647 > "
time="2017-07-26T16:18:53.611666697-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:53.613393428-07:00" level=debug msg="Calling DELETE /v1.30/containers/1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db?force=True&link=False&v=False"
time="2017-07-26T16:18:53.613443964-07:00" level=debug msg="Sending kill signal 9 to container 1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db"
time="2017-07-26T16:18:53.65227351-07:00" level=debug msg="containerd: process exited" id=1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db pid=init status=137 systemPid=14192
time="2017-07-26T16:18:53.655167691-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"1c66d358c440705f24a3191a2687faf51efa8de5895090aec4e769165214b6db\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc421e4c140)}"
time="2017-07-26T16:18:53.655512561-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (d8545c65dc0add5835d53326f2937b1d9d4dd9d431356dcb2d9ecabf0c251647)"
time="2017-07-26T16:18:53.657673190-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:53.746101503-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:53.746131883-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:53.826904886-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:53.908420645-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:53.911598095-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:53.913899535-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:53.915481716-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:53.916630193-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:53.918530059-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:53.918639802-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"ReadonlyRootfs\":true,\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"e5e3b9ce6adc065ece52be7e58e182f32588ee00b523bd6262813d1048acbaa7\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:53.955774942-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/7fec3a3949dc4ceaa834dfa78c89295f3e687ae632a2d4ed8a2eff2e5c137733"
time="2017-07-26T16:18:53.992153858-07:00" level=debug msg="Calling GET /v1.30/containers/f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d/json"
time="2017-07-26T16:18:53.994043248-07:00" level=debug msg="Calling POST /v1.30/containers/f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d/start"
time="2017-07-26T16:18:53.994791890-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/7fec3a3949dc4ceaa834dfa78c89295f3e687ae632a2d4ed8a2eff2e5c137733"
time="2017-07-26T16:18:53.995195382-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:53.995218521-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:54.012367739-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:54.020856085-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:54.020875421-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:54.024215323-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (c58a9b430bc9e0f179dbebcb49b0b0d01e2657b95bc373ae586ff0f55e307833)"
time="2017-07-26T16:18:54.027484352-07:00" level=debug msg="EnableService f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d START"
time="2017-07-26T16:18:54.027572506-07:00" level=debug msg="EnableService f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d DONE"
time="2017-07-26T16:18:54.153516305-07:00" level=debug msg="sandbox set key processing took 65.356201ms for container f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d"
time="2017-07-26T16:18:54.220623008-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc42130f3a0)}"
time="2017-07-26T16:18:54.229641087-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d\" timestamp:<seconds:1501111134 nanos:220316413 > "
time="2017-07-26T16:18:54.231648620-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:54.234374419-07:00" level=debug msg="Calling DELETE /v1.30/containers/f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d?force=True&link=False&v=False"
time="2017-07-26T16:18:54.234459076-07:00" level=debug msg="Sending kill signal 9 to container f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d"
time="2017-07-26T16:18:54.279270692-07:00" level=debug msg="containerd: process exited" id=f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d pid=init status=137 systemPid=14321
time="2017-07-26T16:18:54.282101577-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"f9237ad7d95cdf567ea4fc4be238f92feb7eee094251460a8b575783b7d69f2d\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc421341f50)}"
time="2017-07-26T16:18:54.282455421-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (c58a9b430bc9e0f179dbebcb49b0b0d01e2657b95bc373ae586ff0f55e307833)"
time="2017-07-26T16:18:54.284676463-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:54.426177467-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:54.426203818-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:54.512182553-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:54.594702734-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:54.596329422-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:54.598573044-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:54.600135161-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:54.601309352-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:54.602806280-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:54.602971176-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"SecurityOpt\":[\"label:disable\"],\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"1e59763bf6033cc944b2ae65f283f16e31ad5a83973557b1b8d6c69a0aaa8e16\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:54.604187385-07:00" level=warning msg="Security options with `:` as a separator are deprecated and will be completely unsupported in 17.04, use `=` instead."
time="2017-07-26T16:18:54.648691890-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/6d4248336f6ebc65fee9c84ff3bc0b18d351324fab5ac48dddb07b5fdcf2465d"
time="2017-07-26T16:18:54.682551258-07:00" level=debug msg="Calling GET /v1.30/containers/67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229/json"
time="2017-07-26T16:18:54.684104069-07:00" level=debug msg="Calling POST /v1.30/containers/67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229/start"
time="2017-07-26T16:18:54.684660524-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/6d4248336f6ebc65fee9c84ff3bc0b18d351324fab5ac48dddb07b5fdcf2465d"
time="2017-07-26T16:18:54.684955710-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:54.684978157-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:54.692027258-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:54.695686109-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:54.695718498-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:54.709757279-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (0fb9297d90ae04029768c781160978ae104947cf3dc048916777abea3cdb812d)"
time="2017-07-26T16:18:54.714900059-07:00" level=debug msg="EnableService 67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229 START"
time="2017-07-26T16:18:54.714925786-07:00" level=debug msg="EnableService 67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229 DONE"
time="2017-07-26T16:18:54.720717465-07:00" level=warning msg="Security options with `:` as a separator are deprecated and will be completely unsupported in 17.04, use `=` instead."
time="2017-07-26T16:18:54.831040345-07:00" level=debug msg="sandbox set key processing took 63.325545ms for container 67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229"
time="2017-07-26T16:18:54.880430342-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4208ef090)}"
time="2017-07-26T16:18:54.887631856-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229\" timestamp:<seconds:1501111134 nanos:880288719 > "
time="2017-07-26T16:18:54.889042506-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:54.890753571-07:00" level=debug msg="Calling DELETE /v1.30/containers/67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229?force=True&link=False&v=False"
time="2017-07-26T16:18:54.890804977-07:00" level=debug msg="Sending kill signal 9 to container 67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229"
time="2017-07-26T16:18:54.927066827-07:00" level=debug msg="containerd: process exited" id=67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229 pid=init status=137 systemPid=14449
time="2017-07-26T16:18:54.929995192-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"67ec3f1866fdb4097274ed994678bc10244bc7e6f35f48bbff4c0ae38f320229\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc420916a60)}"
time="2017-07-26T16:18:54.930323501-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (0fb9297d90ae04029768c781160978ae104947cf3dc048916777abea3cdb812d)"
time="2017-07-26T16:18:54.932448504-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:55.027837035-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:55.027863714-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:55.107646251-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:55.184811962-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:55.186501463-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:55.188647939-07:00" level=debug msg="Calling GET /v1.30/version"
time="2017-07-26T16:18:55.189802050-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:55.191414450-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:55.192570988-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:55.194192178-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:55.194314118-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"ShmSize\":67108864,\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"0645cfbed8e3831bba37e8a4b4f641492403ed95a7bd758387c156e3c6ed3b84\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:55.241435094-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/b63ec386996805be9f2c74e558683e3192cdc8e57456f31a33a28168db5bcecc"
time="2017-07-26T16:18:55.272185717-07:00" level=debug msg="Calling GET /v1.30/containers/5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a/json"
time="2017-07-26T16:18:55.273776324-07:00" level=debug msg="Calling POST /v1.30/containers/5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a/start"
time="2017-07-26T16:18:55.275495376-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/b63ec386996805be9f2c74e558683e3192cdc8e57456f31a33a28168db5bcecc"
time="2017-07-26T16:18:55.275748590-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:55.275769782-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:55.294438395-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:55.303730867-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:55.303850130-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:55.312476790-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (fb3860e6954047ea9f51d5084c3bc95100bffc6db8b99aa50bbd0b61b2317867)"
time="2017-07-26T16:18:55.314032243-07:00" level=debug msg="EnableService 5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a START"
time="2017-07-26T16:18:55.314054069-07:00" level=debug msg="EnableService 5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a DONE"
time="2017-07-26T16:18:55.425140449-07:00" level=debug msg="sandbox set key processing took 65.01633ms for container 5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a"
time="2017-07-26T16:18:55.477312071-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc42109ae90)}"
time="2017-07-26T16:18:55.480854272-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a\" timestamp:<seconds:1501111135 nanos:477070520 > "
time="2017-07-26T16:18:55.482274846-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:55.483986353-07:00" level=debug msg="Calling DELETE /v1.30/containers/5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a?force=True&link=False&v=False"
time="2017-07-26T16:18:55.484038418-07:00" level=debug msg="Sending kill signal 9 to container 5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a"
time="2017-07-26T16:18:55.527571404-07:00" level=debug msg="containerd: process exited" id=5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a pid=init status=137 systemPid=14571
time="2017-07-26T16:18:55.530428667-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"5040ded082f3805c4541f2814c90cda62de9f5d74f9a772f413c152a1ed7457a\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc421e359b0)}"
time="2017-07-26T16:18:55.530771419-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (fb3860e6954047ea9f51d5084c3bc95100bffc6db8b99aa50bbd0b61b2317867)"
time="2017-07-26T16:18:55.532961526-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:55.639827923-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:55.639856855-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:55.729116855-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:55.815071603-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:55.816677091-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:55.818891213-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:55.820349361-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:55.821817652-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:55.823795636-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:55.823909144-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[\"/tmp/host-path:/container-path:rw\"],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"cfb75a58ed7ad947e617d06555b2fd479289150d9301275de0551bc41dc6a0f4\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{\"/container-path\":{}}}"
time="2017-07-26T16:18:55.874829079-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/3ba50eb93d5bacebcdd41f87dde0b1b572c438c98dddcab148530bcaf7850754"
time="2017-07-26T16:18:55.906975719-07:00" level=debug msg="Calling GET /v1.30/containers/0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a/json"
time="2017-07-26T16:18:55.908571275-07:00" level=debug msg="Calling POST /v1.30/containers/0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a/start"
time="2017-07-26T16:18:55.909140010-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/3ba50eb93d5bacebcdd41f87dde0b1b572c438c98dddcab148530bcaf7850754"
time="2017-07-26T16:18:55.909448133-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:55.909476089-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:55.919239038-07:00" level=debug msg="Assigning addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:55.930852221-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:55.930876340-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:55.939160961-07:00" level=debug msg="Programming external connectivity on endpoint composetest_db_1 (02bdb5f5bdb1bec119350f7a42ca1d1dcfcf08560e0b29775b583aaedfc98cf0)"
time="2017-07-26T16:18:55.942310124-07:00" level=debug msg="EnableService 0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a START"
time="2017-07-26T16:18:55.942330390-07:00" level=debug msg="EnableService 0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a DONE"
time="2017-07-26T16:18:56.059387159-07:00" level=debug msg="sandbox set key processing took 66.766509ms for container 0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a"
time="2017-07-26T16:18:56.108677607-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4213b5c60)}"
time="2017-07-26T16:18:56.117540409-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a\" timestamp:<seconds:1501111136 nanos:108534775 > "
time="2017-07-26T16:18:56.118953592-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:56.120657168-07:00" level=debug msg="Calling DELETE /v1.30/containers/0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a?force=True&link=False&v=False"
time="2017-07-26T16:18:56.120728563-07:00" level=debug msg="Sending kill signal 9 to container 0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a"
time="2017-07-26T16:18:56.159821184-07:00" level=debug msg="containerd: process exited" id=0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a pid=init status=137 systemPid=14705
time="2017-07-26T16:18:56.162862926-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"0fa5696c9fa919ebc2b62dc21d6ec2ebcc941e8023cd8a5db54e74d964a36b8a\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4213632e0)}"
time="2017-07-26T16:18:56.163220905-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_db_1 (02bdb5f5bdb1bec119350f7a42ca1d1dcfcf08560e0b29775b583aaedfc98cf0)"
time="2017-07-26T16:18:56.165490301-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:56.262059373-07:00" level=debug msg="Releasing addresses for endpoint composetest_db_1's interface on network bridge"
time="2017-07-26T16:18:56.262089183-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:56.354723987-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:56.435205220-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:56.436985217-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:56.439194469-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:56.440770527-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:56.441931125-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:56.443557355-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:56.443703813-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"StorageOpt\":{\"size\":\"1G\"},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"9bde3092f75fdeabaf857dcd3b999acf1ab3161a38d221d8795b23b87d501d40\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:56.444918817-07:00" level=error msg="Handler for POST /v1.30/containers/create returned error: --storage-opt is not supported for aufs"
time="2017-07-26T16:18:56.446169933-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:56.447503033-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:56.525930155-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:56.527877202-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:56.579344136-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:56.580878308-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:56.581998508-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:56.583510572-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:56.583638498-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"fe6e1e68ba6e4127ede12380e143d7bf8f2f242aa02b7e99169359cecaa1dc74\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{\"/var/db\":{}}}"
time="2017-07-26T16:18:56.585709074-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:56.586871233-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:56.676485992-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:56.678180676-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:56.751162320-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:56.752697230-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:56.753906556-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:56.755576266-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_db_1"
time="2017-07-26T16:18:56.755688981-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumeDriver\":\"foodriver\",\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"b246bf26b7a1fd586e2891f47667febba09dbe8c6933d5ad0ff5eea2b0b61de6\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"db\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:56.757582124-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:56.758689058-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:56.834671392-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:56.836356610-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:56.885673828-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:56.887505511-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddata%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:56.888728719-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:56.890482164-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_data_1"
time="2017-07-26T16:18:56.890606262-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"312c296d7eee0896475c5b2e806cf8a832d6d4eeac1ba661c323f44659a63ecc\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"data\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:56.923822341-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/a65864197d21d152e6c9f66d06d4d9de143cacee4033a80547dbb78e68c01a68"
time="2017-07-26T16:18:56.958553460-07:00" level=debug msg="Calling GET /v1.30/containers/ce9fc6983d1d5197f8f411d6022c77a7d09b309c02648342a6baa9aaaade3429/json"
time="2017-07-26T16:18:56.960164211-07:00" level=debug msg="Calling POST /v1.30/containers/create"
time="2017-07-26T16:18:56.960273146-07:00" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":false,\"AttachStdout\":true,\"Cmd\":[\"top\"],\"HostConfig\":{},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.project\":\"composetest\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false}"
time="2017-07-26T16:18:57.003198353-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/db623d177ed89482624bd3b234553e2c223f55ef876bae7ecd65f98f510c8391"
time="2017-07-26T16:18:57.030641490-07:00" level=debug msg="Calling GET /v1.30/containers/660d9f1bfb9bd87ee3f19da2fce4c85d4ea13bb9ae54c35f6d68290f73d3321e/json"
time="2017-07-26T16:18:57.032139166-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:57.033850094-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dhost%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:57.035118938-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:57.036684245-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Ddata%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:57.038266923-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_host_1"
time="2017-07-26T16:18:57.038400547-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[\"ce9fc6983d1d5197f8f411d6022c77a7d09b309c02648342a6baa9aaaade3429:rw\",\"660d9f1bfb9bd87ee3f19da2fce4c85d4ea13bb9ae54c35f6d68290f73d3321e:rw\"]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"ce76c19a22c294e2265ead0bbc286dfb19365e859073c9f74e5e529fe3c53755\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"host\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:57.084808601-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/6ee89be2cf39716912a8719c701b29c374add228b6a7e234b289f5b503288374"
time="2017-07-26T16:18:57.118967088-07:00" level=debug msg="Calling GET /v1.30/containers/3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be/json"
time="2017-07-26T16:18:57.120741240-07:00" level=debug msg="Calling POST /v1.30/containers/3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be/start"
time="2017-07-26T16:18:57.121451375-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/6ee89be2cf39716912a8719c701b29c374add228b6a7e234b289f5b503288374"
time="2017-07-26T16:18:57.121740140-07:00" level=debug msg="Assigning addresses for endpoint composetest_host_1's interface on network bridge"
time="2017-07-26T16:18:57.121761519-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:57.139060733-07:00" level=debug msg="Assigning addresses for endpoint composetest_host_1's interface on network bridge"
time="2017-07-26T16:18:57.148576970-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:57.148608143-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:57.158784182-07:00" level=debug msg="Programming external connectivity on endpoint composetest_host_1 (215bc1d5ed3fdc5d717996662f5454a0b6ff4ec6a533b84565966a222bfb4a2d)"
time="2017-07-26T16:18:57.163732435-07:00" level=debug msg="EnableService 3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be START"
time="2017-07-26T16:18:57.163760728-07:00" level=debug msg="EnableService 3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be DONE"
time="2017-07-26T16:18:57.292972692-07:00" level=debug msg="sandbox set key processing took 77.284904ms for container 3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be"
time="2017-07-26T16:18:57.343299443-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc42122f330)}"
time="2017-07-26T16:18:57.352490282-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be\" timestamp:<seconds:1501111137 nanos:343161626 > "
time="2017-07-26T16:18:57.354099761-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:57.355957975-07:00" level=debug msg="Calling DELETE /v1.30/containers/3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be?force=True&link=False&v=False"
time="2017-07-26T16:18:57.356013238-07:00" level=debug msg="Sending kill signal 9 to container 3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be"
time="2017-07-26T16:18:57.39553098-07:00" level=debug msg="containerd: process exited" id=3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be pid=init status=137 systemPid=14821
time="2017-07-26T16:18:57.398500795-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"3683a8e4aa6a963357de85d7588e98759ab5329611eaea96e57a12300d15d2be\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc42122f860)}"
time="2017-07-26T16:18:57.398830321-07:00" level=debug msg="Revoking external connectivity on endpoint composetest_host_1 (215bc1d5ed3fdc5d717996662f5454a0b6ff4ec6a533b84565966a222bfb4a2d)"
time="2017-07-26T16:18:57.401135668-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:57.502115186-07:00" level=debug msg="Releasing addresses for endpoint composetest_host_1's interface on network bridge"
time="2017-07-26T16:18:57.502143064-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:57.594861798-07:00" level=debug msg="Calling DELETE /v1.30/containers/660d9f1bfb9bd87ee3f19da2fce4c85d4ea13bb9ae54c35f6d68290f73d3321e?force=True&link=False&v=False"
time="2017-07-26T16:18:57.611504679-07:00" level=debug msg="Calling DELETE /v1.30/containers/ce9fc6983d1d5197f8f411d6022c77a7d09b309c02648342a6baa9aaaade3429?force=True&link=False&v=False"
time="2017-07-26T16:18:57.621191340-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:57.701838386-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:57.703684716-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:57.726307997-07:00" level=debug msg="Calling POST /v1.30/images/create?tag=latest&fromImage=busybox"
time="2017-07-26T16:18:57.726456213-07:00" level=debug msg="Trying to pull busybox from https://registry-1.docker.io v2"
time="2017-07-26T16:18:58.876225892-07:00" level=debug msg="Pulling ref from V2 registry: busybox:latest"
time="2017-07-26T16:18:58.878365999-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:58.880172923-07:00" level=debug msg="Calling GET /v1.30/images/sha256:efe10/json"
time="2017-07-26T16:18:58.881752365-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dfoo%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:58.882976501-07:00" level=debug msg="Calling GET /v1.30/images/sha256:efe10/json"
time="2017-07-26T16:18:58.884795599-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_foo_1"
time="2017-07-26T16:18:58.884919334-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"sha256:efe10\",\"Labels\":{\"com.docker.compose.config-hash\":\"8f6c723ff0ddf87302b3fa7527b1fa78cdfd425d44b77c1ad9960f5eba884ecb\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"foo\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:58.938068089-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/d147f32f99216fa50a7ca902ee7559faa37ddd54f18a7f1e9e1456bff4183914"
time="2017-07-26T16:18:58.968582967-07:00" level=debug msg="Calling GET /v1.30/containers/f43bd7d5e9291488464aebe4656fc07ce949f5ade375dccf2b38f3814f8ded77/json"
time="2017-07-26T16:18:58.970237546-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:58.973476938-07:00" level=debug msg="Calling DELETE /v1.30/containers/f43bd7d5e9291488464aebe4656fc07ce949f5ade375dccf2b38f3814f8ded77?force=True&link=False&v=False"
time="2017-07-26T16:18:58.986384197-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:59.063774966-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:59.065668077-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:59.068507306-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:59.070379680-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dweb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:59.071743857-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:59.073536726-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=my-web-container"
time="2017-07-26T16:18:59.073685367-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"c237bc042d8824bdbc4055bbaa583d571be382249d0cbf7d1bb35357e77d7849\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"web\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:59.109084204-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/004ab1905705ba360ecf96732c543b8dfe2d7041c8bbb21c19e10617179e4c18"
time="2017-07-26T16:18:59.152457246-07:00" level=debug msg="Calling GET /v1.30/containers/d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976/json"
time="2017-07-26T16:18:59.154168672-07:00" level=debug msg="Calling POST /v1.30/containers/d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976/start"
time="2017-07-26T16:18:59.155525061-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/004ab1905705ba360ecf96732c543b8dfe2d7041c8bbb21c19e10617179e4c18"
time="2017-07-26T16:18:59.155767061-07:00" level=debug msg="Assigning addresses for endpoint my-web-container's interface on network bridge"
time="2017-07-26T16:18:59.155784854-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:59.162466397-07:00" level=debug msg="Assigning addresses for endpoint my-web-container's interface on network bridge"
time="2017-07-26T16:18:59.174124679-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:59.174156342-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:59.182781513-07:00" level=debug msg="Programming external connectivity on endpoint my-web-container (3ec337d140165649f8a1ab42d472590bafc99614fd9bd5bd49af6faf4e325bea)"
time="2017-07-26T16:18:59.184202436-07:00" level=debug msg="EnableService d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976 START"
time="2017-07-26T16:18:59.184223362-07:00" level=debug msg="EnableService d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976 DONE"
time="2017-07-26T16:18:59.276664287-07:00" level=debug msg="sandbox set key processing took 48.960863ms for container d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976"
time="2017-07-26T16:18:59.363374951-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4210fcca0)}"
time="2017-07-26T16:18:59.370381768-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976\" timestamp:<seconds:1501111139 nanos:363221210 > "
time="2017-07-26T16:18:59.371914147-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:59.373591104-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dweb%22%2C+%22com.docker.compose.oneoff%3DTrue%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:59.375034399-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=0&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dweb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:59.376208648-07:00" level=debug msg="Calling GET /v1.30/containers/d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976/json"
time="2017-07-26T16:18:59.377899782-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_web_run_1"
time="2017-07-26T16:18:59.378014314-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Links\":[\"my-web-container:my-web-container\",\"my-web-container:web\"],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"True\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"web\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:59.425119876-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/286fd9a6aa6f84720893503af0352ab34960ec0936a5a0677ea62890bddd9253"
time="2017-07-26T16:18:59.450965181-07:00" level=debug msg="Calling GET /v1.30/containers/9873b266357e26840dfd02d79fef728e9f242441361b987251d9fdce399ae7f5/json"
time="2017-07-26T16:18:59.452512895-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:59.454323164-07:00" level=debug msg="Calling DELETE /v1.30/containers/9873b266357e26840dfd02d79fef728e9f242441361b987251d9fdce399ae7f5?force=True&link=False&v=False"
time="2017-07-26T16:18:59.462013211-07:00" level=debug msg="Calling DELETE /v1.30/containers/d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976?force=True&link=False&v=False"
time="2017-07-26T16:18:59.462071565-07:00" level=debug msg="Sending kill signal 9 to container d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976"
time="2017-07-26T16:18:59.491366588-07:00" level=debug msg="containerd: process exited" id=d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976 pid=init status=137 systemPid=14943
time="2017-07-26T16:18:59.494797673-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"d5ff55e7d62727992ce5ec136f54b3d51fab6d9e37509ac96fd6175072c65976\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc421ad8150)}"
time="2017-07-26T16:18:59.495196927-07:00" level=debug msg="Revoking external connectivity on endpoint my-web-container (3ec337d140165649f8a1ab42d472590bafc99614fd9bd5bd49af6faf4e325bea)"
time="2017-07-26T16:18:59.497636492-07:00" level=debug msg="DeleteConntrackEntries purged ipv4:0, ipv6:0"
time="2017-07-26T16:18:59.598047330-07:00" level=debug msg="Releasing addresses for endpoint my-web-container's interface on network bridge"
time="2017-07-26T16:18:59.598075271-07:00" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.2)"
time="2017-07-26T16:18:59.695096495-07:00" level=debug msg="Calling GET /v1.30/images/json?only_ids=0&all=0&filters=%7B%22label%22%3A+%5B%22com.docker.compose.test_image%22%5D%7D"
time="2017-07-26T16:18:59.775849555-07:00" level=debug msg="Calling GET /v1.30/volumes"
time="2017-07-26T16:18:59.777434385-07:00" level=debug msg="Calling GET /v1.30/networks?filters=%7B%7D"
time="2017-07-26T16:18:59.779767050-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:59.781548337-07:00" level=debug msg="Calling GET /v1.30/containers/json?all=1&limit=-1&filters=%7B%22label%22%3A+%5B%22com.docker.compose.project%3Dcomposetest%22%2C+%22com.docker.compose.service%3Dweb%22%2C+%22com.docker.compose.oneoff%3DFalse%22%5D%7D&trunc_cmd=0&size=0"
time="2017-07-26T16:18:59.782714393-07:00" level=debug msg="Calling GET /v1.30/images/busybox:latest/json"
time="2017-07-26T16:18:59.784625181-07:00" level=debug msg="Calling POST /v1.30/containers/create?name=composetest_web_1"
time="2017-07-26T16:18:59.784742505-07:00" level=debug msg="form data: {\"AttachStderr\":false,\"AttachStdin\":false,\"AttachStdout\":false,\"Cmd\":[\"top\"],\"Env\":[],\"HostConfig\":{\"Binds\":[],\"Devices\":[{\"CgroupPermissions\":\"rwm\",\"PathInContainer\":\"/dev/mapped-random\",\"PathOnHost\":\"/dev/random\"}],\"Links\":[],\"LogConfig\":{\"Config\":{},\"Type\":\"\"},\"NetworkMode\":\"default\",\"PortBindings\":{},\"VolumesFrom\":[]},\"Image\":\"busybox:latest\",\"Labels\":{\"com.docker.compose.config-hash\":\"44d6d542b18fae14a4de94e897b52b5433f1e04c7a7cd7160e0d1441bf76ac7f\",\"com.docker.compose.container-number\":\"1\",\"com.docker.compose.oneoff\":\"False\",\"com.docker.compose.project\":\"composetest\",\"com.docker.compose.service\":\"web\",\"com.docker.compose.version\":\"1.15.0\"},\"NetworkDisabled\":false,\"OpenStdin\":false,\"StdinOnce\":false,\"Tty\":false,\"Volumes\":{}}"
time="2017-07-26T16:18:59.831332339-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/5d179109e6944057a0cff7be08239e869a62109e7a1dd0b4bcf559d68e641ea6"
time="2017-07-26T16:18:59.878259341-07:00" level=debug msg="Calling GET /v1.30/containers/f0b3dcbad74796679d3e0fd6968734031b9a6320c15ae2febc7e5dc69de9f759/json"
time="2017-07-26T16:18:59.879927406-07:00" level=debug msg="Calling POST /v1.30/containers/f0b3dcbad74796679d3e0fd6968734031b9a6320c15ae2febc7e5dc69de9f759/start"
time="2017-07-26T16:18:59.881735566-07:00" level=debug msg="container mounted via layerStore: /var/lib/docker/aufs/mnt/5d179109e6944057a0cff7be08239e869a62109e7a1dd0b4bcf559d68e641ea6"
time="2017-07-26T16:18:59.882008952-07:00" level=debug msg="Assigning addresses for endpoint composetest_web_1's interface on network bridge"
time="2017-07-26T16:18:59.882026798-07:00" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])"
time="2017-07-26T16:18:59.887352669-07:00" level=debug msg="Assigning addresses for endpoint composetest_web_1's interface on network bridge"
time="2017-07-26T16:18:59.897671550-07:00" level=info msg="No non-localhost DNS nameservers are left in resolv.conf. Using default external servers: [nameserver 8.8.8.8 nameserver 8.8.4.4]"
time="2017-07-26T16:18:59.897695281-07:00" level=info msg="IPv6 enabled; Adding default IPv6 external servers: [nameserver 2001:4860:4860::8888 nameserver 2001:4860:4860::8844]"
time="2017-07-26T16:18:59.904921773-07:00" level=debug msg="Programming external connectivity on endpoint composetest_web_1 (815a384ba09f07eb386dddad542d234dd6ac2385f5e69ee69d79a583950b90e1)"
time="2017-07-26T16:18:59.908203630-07:00" level=debug msg="EnableService f0b3dcbad74796679d3e0fd6968734031b9a6320c15ae2febc7e5dc69de9f759 START"
time="2017-07-26T16:18:59.908234394-07:00" level=debug msg="EnableService f0b3dcbad74796679d3e0fd6968734031b9a6320c15ae2febc7e5dc69de9f759 DONE"
time="2017-07-26T16:19:00.039073839-07:00" level=debug msg="sandbox set key processing took 70.010368ms for container f0b3dcbad74796679d3e0fd6968734031b9a6320c15ae2febc7e5dc69de9f759"
time="2017-07-26T16:19:00.106351861-07:00" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"f0b3dcbad74796679d3e0fd6968734031b9a6320c15ae2febc7e5dc69de9f759\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4213978a0)}"
time="2017-07-26T16:19:00.111773505-07:00" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"f0b3dcbad74796679d3e0fd6968734031b9a6320c15ae2febc7e5dc69de9f759\" timestamp:<seconds:1501111140 nanos:106201311 > "
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment