@fideloper-fly our deploys still aren’t working. Here’s the output of the fly deploy
output after enabling LOG_LEVEL=debug
. Killing it might solve it one time but I’ll leave it running for now. I hope it will help you debug the problem.
Run LOG_LEVEL=debug flyctl deploy -c fly/staging/fly.toml --remote-only
DEBUG determined hostname: "fv-az348-953"
DEBUG determined working directory: "/home/runner/work/marketphase/marketphase"
DEBUG determined user home directory: "/home/runner"
DEBUG determined config directory: "/home/runner/.fly"
DEBUG ensured config directory exists.
DEBUG ensured config directory perms.
DEBUG cache loaded.
DEBUG config initialized.
DEBUG initialized task manager.
DEBUG skipped querying for new release
DEBUG client initialized.
DEBUG --> POST https://api.fly.io/graphql
{
"query": "query ($appName: String!) { appbasic:app(name: $appName) { id name platformVersion organization { id slug } } }",
"variables": {
"appName": "staxcloud-staging"
}
}
DEBUG {}
DEBUG <-- 200 https://api.fly.io/graphql (60.8ms)
{
"data": {
"appbasic": {
"id": "staxcloud-staging",
"name": "staxcloud-staging",
"platformVersion": "nomad",
"organization": {
"id": "X14ZNqpmoA4vDI0Y0D3VeJP3VqfNmM",
"slug": "staxxer-848"
}
}
}
}
DEBUG app config loaded from fly/staging/fly.toml
==> Verifying app config
--> Verified app config
==> Building image
DEBUG trying remote docker daemon
DEBUG Trying 'Buildpacks' strategy
DEBUG no buildpack builder configured, skipping
DEBUG result image:<nil> error:<nil>
DEBUG Trying 'Dockerfile' strategy
DEBUG --> POST https://api.fly.io/graphql
{
"query": "mutation($input: EnsureMachineRemoteBuilderInput!) { ensureMachineRemoteBuilder(input: $input) { machine { id state ips { nodes { family kind ip } } }, app { name organization { id slug } } } }",
"variables": {
"input": {
"appName": "staxcloud-staging",
"organizationId": null
}
}
}
DEBUG {}
DEBUG <-- 200 https://api.fly.io/graphql (149.5ms)
{
"data": {
"ensureMachineRemoteBuilder": {
"machine": {
"id": "e784376f447583",
"state": "started",
"ips": {
"nodes": [
{
"family": "v6",
"kind": "public",
"ip": "2604:1380:4601:d603:0:7b64:6cd5:1"
},
{
"family": "v4",
"kind": "private",
"ip": "172.19.20.162"
},
{
"family": "v6",
"kind": "privatenet",
"ip": "fdaa:0:8efd:a7b:23c5:7b64:6cd5:2"
}
]
}
},
"app": {
"name": "fly-builder-morning-thunder-7621",
"organization": {
"id": "X14ZNqpmoA4vDI0Y0D3VeJP3VqfNmM",
"slug": "staxxer-848"
}
}
}
}
}
Waiting for remote builder fly-builder-morning-thunder-7621...
DEBUG --> POST https://api.fly.io/graphql
{
"query": "query ($appName: String!) { appbasic:app(name: $appName) { id name platformVersion organization { id slug } } }",
"variables": {
"appName": "staxcloud-staging"
}
}
DEBUG {}
DEBUG checking ip &{Family:v6 Kind:public IP:2604:1380:4601:d603:0:7b64:6cd5:1 MaskSize:0}
DEBUG checking ip &{Family:v4 Kind:private IP:172.19.20.162 MaskSize:0}
DEBUG checking ip &{Family:v6 Kind:privatenet IP:fdaa:0:8efd:a7b:23c5:7b64:6cd5:2 MaskSize:0}
DEBUG <-- 200 https://api.fly.io/graphql (48.92ms)
{
"data": {
"appbasic": {
"id": "staxcloud-staging",
"name": "staxcloud-staging",
"platformVersion": "nomad",
"organization": {
"id": "X14ZNqpmoA4vDI0Y0D3VeJP3VqfNmM",
"slug": "staxxer-848"
}
}
}
}
DEBUG --> POST https://api.fly.io/graphql
{
"query": "mutation($input: ValidateWireGuardPeersInput!) { validateWireGuardPeers(input: $input) { invalidPeerIps } }",
"variables": {
"input": {
"peerIps": []
}
}
}
DEBUG {}
DEBUG <-- 200 https://api.fly.io/graphql (180.14ms)
{
"data": {
"validateWireGuardPeers": {
"invalidPeerIps": []
}
}
}
DEBUG started agent process (pid: 1683, log: /home/runner/.fly/agent-logs/1685186385.log)
DEBUG Remote builder unavailable, retrying in 50ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 53.081885ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 68.622393ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 76.482854ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 90.823897ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 68.149607ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 73.346476ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 138.511691ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 142.580191ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 152.640711ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 163.01728ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 58.217897ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 57.030597ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 116.860038ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 62.791272ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
DEBUG Remote builder unavailable, retrying in 200ms (err: Get "http://[fdaa:0:8efd:a7b:23c5:7b64:6cd5:2]:2375/_ping": context deadline exceeded)
Error failed to fetch an image or build from source: error connecting to docker: remote builder app unavailable
WARN Remote builder did not start in time. Check remote builder logs with `flyctl logs -a fly-builder-morning-thunder-7621`
DEBUG result image:<nil> error:error connecting to docker: remote builder app unavailable
The builder logs:
2022-09-30T13:24:54Z app[e784376f447583] ams [info]time="2022-09-30T13:24:54.447168536Z" level=debug msg="checking docker activity"
2022-09-30T13:24:54Z app[e784376f447583] ams [info]time="2022-09-30T13:24:54.447580408Z" level=debug msg="Calling GET /v1.41/containers/json?filters=%7B%22status%22%3A%7B%22running%22%3Atrue%7D%7D&limit=0"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.329143196Z" level=info msg="Deadline reached without docker build"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.329215101Z" level=info msg="shutting down"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.330492045Z" level=info msg="gracefully stopped\n"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.330536499Z" level=info msg="disk space used: 15.19%"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.330559682Z" level=info msg="Waiting for dockerd to exit"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.330762583Z" level=info msg="Processing signal 'interrupt'"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.330974951Z" level=debug msg="daemon configured with a 15 seconds minimum shutdown timeout"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.330988246Z" level=debug msg="start clean shutdown of all containers with a 15 seconds timeout..."
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.331232334Z" level=debug msg="found 0 orphan layers"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.331620201Z" level=debug msg="Unix socket /var/run/docker/libnetwork/b0919202342e.sock doesn't exist. cannot accept client connections"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.331679021Z" level=debug msg="Cleaning up old mountid : start."
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.331815617Z" level=debug msg="Cleaning up old mountid : done."
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.331892311Z" level=debug msg="unmounting daemon root" mountpoint=/data/docker
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.331974686Z" level=info msg="stopping event stream following graceful shutdown" error="<nil>" module=libcontainerd namespace=moby
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.332106773Z" level=debug msg="Clean shutdown succeeded"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.332128664Z" level=info msg="Daemon shutdown complete"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.332164622Z" level=info msg="stopping healthcheck following graceful shutdown" module=libcontainerd
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.332175973Z" level=info msg="stopping event stream following graceful shutdown" error="context canceled" module=libcontainerd namespace=plugins.moby
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.332423117Z" level=debug msg="received signal" signal=terminated
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.332570182Z" level=debug msg="sd notification" error="<nil>" notified=false state="STOPPING=1"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.449892700Z" level=debug msg="checking docker activity"
2022-09-30T13:24:55Z app[e784376f447583] ams [info]time="2022-09-30T13:24:55.450221767Z" level=debug msg="Calling GET /v1.41/containers/json?filters=%7B%22status%22%3A%7B%22running%22%3Atrue%7D%7D&limit=0"
2022-09-30T13:24:56Z app[e784376f447583] ams [info]time="2022-09-30T13:24:56.333529141Z" level=warning msg="grpc: addrConn.createTransport failed to connect to {unix:///var/run/docker/containerd/containerd.sock <nil> 0 <nil>}. Err :connection error: desc = \"transport: Error while dialing dial unix:///var/run/docker/containerd/containerd.sock: timeout\". Reconnecting..." module=grpc
2022-09-30T13:24:56Z app[e784376f447583] ams [info]time="2022-09-30T13:24:56.337467185Z" level=info msg="dockerd has exited"
2022-09-30T13:25:00Z runner[e784376f447583] ams [info]machine exited with exit code 0, not restarting