Deployment issue -- "remote builder app unavailable"

We are deploying using superfly/flyctl-actions@1.3 and this seems to have just popped up yesterday. We are not using the remote flag, and in fact the build step succeeds, it is the “Deploy Proxy” step that seems to be giving us issues. We have not changed anything on our end.

Log shows this:

==> Building image
Waiting for remote builder fly-builder-broken-feather-756...
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-broken-feather-756`

Are there any outages that we should know about? Deploying to the lax region if that helps.

Thanks

2 Likes

I’m seeing this as well in the ewr region.

Hey there, could y’all try running LOG_LEVEL=debug fly deploy and share the output here, that may give us some more specific information on what’s going on.

I am also experiencing this in lax region
@zee running with debug does not provide much insight

I am just deploying locally with flyctl deploy although I would imagine the same issue would occur on our CI


Waiting for remote builder fly-builder-broken-snowflake-9079... ⢿ DEBUG <-- 200 https://api.fly.io/graphql (477.99ms) {"data":{"validateWireGuardPeers":{"invalidPeerIps":[]}}}
Waiting for remote builder fly-builder-broken-snowflake-9079... ⢿ DEBUG Remote builder unavailable, retrying in 50ms (err: Get "http://[fdaa:0:530b:a7b:28df:0:a811:2]:2375/_ping": context deadline exceeded)
WARN Remote builder did not start in time. Check remote builder logs with `flyctl logs -a fly-builder-broken-snowflake-9079`
DEBUG result image:<nil> error:error connecting to docker: remote builder app unavailable
Error failed to fetch an image or build from source: error connecting to docker: remote builder app unavailable


Getting the same issue in Syd

> flyctl logs -a fly-builder-spring-darkness-1924

Seems like this is the interesting part

2022-05-16T03:07:49Z app[0140b65e] syd [info]time="2022-05-16T03:07:49.561772906Z" 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

Logs (as far back as I can see)

2022-05-16T03:07:45Z app[0140b65e] syd [info]time="2022-05-16T03:07:45.931789468Z" level=debug msg="checking docker activity"
2022-05-16T03:07:45Z app[0140b65e] syd [info]time="2022-05-16T03:07:45.932142831Z" level=debug msg="Calling GET /v1.41/containers/json?filters=%7B%22status%22%3A%7B%22running%22%3Atrue%7D%7D&limit=0"
2022-05-16T03:07:46Z app[0140b65e] syd [info]time="2022-05-16T03:07:46.933348079Z" level=debug msg="checking docker activity"
2022-05-16T03:07:46Z app[0140b65e] syd [info]time="2022-05-16T03:07:46.933694519Z" level=debug msg="Calling GET /v1.41/containers/json?filters=%7B%22status%22%3A%7B%22running%22%3Atrue%7D%7D&limit=0"
2022-05-16T03:07:47Z app[0140b65e] syd [info]time="2022-05-16T03:07:47.934825287Z" level=debug msg="checking docker activity"
2022-05-16T03:07:47Z app[0140b65e] syd [info]time="2022-05-16T03:07:47.935320977Z" level=debug msg="Calling GET /v1.41/containers/json?filters=%7B%22status%22%3A%7B%22running%22%3Atrue%7D%7D&limit=0"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.552360592Z" level=info msg="Deadline reached without docker build"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.552486678Z" level=info msg="shutting down"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.554768659Z" level=info msg="gracefully stopped\n"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.554945331Z" level=info msg="Processing signal 'interrupt'"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.557895736Z" level=debug msg="daemon configured with a 15 seconds minimum shutdown timeout"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.557921194Z" level=debug msg="start clean shutdown of all containers with a 15 seconds timeout..."
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.558051649Z" level=info msg="Waiting for dockerd to exit"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.558192152Z" level=debug msg="found 0 orphan layers"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.558541367Z" level=debug msg="Unix socket /var/run/docker/libnetwork/2b9e7f017fb2.sock doesn't exist. cannot accept client connections"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.558585380Z" level=debug msg="Cleaning up old mountid : start."
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.558659819Z" level=info msg="stopping event stream following graceful shutdown" error="<nil>" module=libcontainerd namespace=moby
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.558742264Z" level=debug msg="Cleaning up old mountid : done."
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.558872549Z" level=debug msg="unmounting daemon root" mountpoint=/data/docker
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.558953591Z" level=debug msg="Clean shutdown succeeded"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.558971484Z" level=info msg="Daemon shutdown complete"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.559090918Z" level=info msg="stopping event stream following graceful shutdown" error="context canceled" module=libcontainerd namespace=plugins.moby
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.559705662Z" level=info msg="stopping healthcheck following graceful shutdown" module=libcontainerd
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.561132408Z" level=debug msg="received signal" signal=terminated
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.561214282Z" level=debug msg="sd notification" error="<nil>" notified=false state="STOPPING=1"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.937135728Z" level=debug msg="checking docker activity"
2022-05-16T03:07:48Z app[0140b65e] syd [info]time="2022-05-16T03:07:48.945008478Z" level=debug msg="Calling GET /v1.41/containers/json?filters=%7B%22status%22%3A%7B%22running%22%3Atrue%7D%7D&limit=0"
2022-05-16T03:07:49Z app[0140b65e] syd [info]time="2022-05-16T03:07:49.561772906Z" 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-05-16T03:07:49Z app[0140b65e] syd [info]time="2022-05-16T03:07:49.565235052Z" level=info msg="dockerd has exited"
1 Like

Yeah, I can confirm this too in the region AMS. Same issue with not being able to connect to the docker daemon. Tried to delete and recreate the builder, but that doesn’t help. Local building seems unaffected.

2 Likes

Same issue in iad, seems to be pretty widespread.

Waiting for remote builder fly-builder-broken-dust-8053... ⣷ DEBUG Remote builder unavailable, retrying in 50ms (err: Get "http://[fdaa:0:5ed3:a7b:775a:0:dc30:2]:2375/_ping": context deadline exceeded)
WARN Remote builder did not start in time. Check remote builder logs with `flyctl logs -a fly-builder-broken-dust-8053`
DEBUG result image:<nil> error:remote builder app unavailable
Error failed to fetch an image or build from source: remote builder app unavailable
1 Like

Hi, @meltingice rlubbers @trent can you try deploying with debug i.e run LOG_LEVEL=debug fly deploy and pasting the output.

And can you all run fly doctor and let me know the response.

sp-api > fly doctor
Testing authentication token... PASSED
Testing flyctl agent... PASSED
Testing local Docker instance... Nope
Pinging WireGuard gateway (give us a sec)... PASSED
sp-api > LOG_LEVEL=debug fly deploy --remote-only
DEBUG Loaded flyctl config from/Users/choc/.fly/config.yml
DEBUG determined hostname: "chocs-MacBook-Pro.local"
DEBUG determined working directory: "/Users/choc/code/sp-api"
DEBUG determined user home directory: "/Users/choc"
DEBUG determined config directory: "/Users/choc/.fly"
DEBUG ensured config directory exists.
DEBUG ensured config directory perms.
DEBUG cache loaded.
DEBUG config initialized.
DEBUG initialized task manager.
DEBUG started querying for new release
DEBUG client initialized.
DEBUG app config loaded from /Users/choc/code/sp-api/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":"sp-api","organizationId":null}}}
}
DEBUG querying for release resulted to v0.0.325
DEBUG <-- 200 https://api.fly.io/graphql (502.07ms) {"data":{"ensureMachineRemoteBuilder":{"machine":{"id":"0140b65e","state":"starting","ips":{"nodes":[{"family":"v6","kind":"privatenet","ip":"fdaa:0:4ab8:a7b:2984:0:cb20:2"},{"family":"v6","kind":"public","ip":"2604:1380:4070:805::cb20:3"},{"family":"v4","kind":"private","ip":"172.19.7.42"}]}},"app":{"name":"fly-builder-spring-darkness-1924","organization":{"id":"MA8702JP9v8awFz5z67ep3b7eRTB0Q","slug":"personal"}}}}}
DEBUG checking ip &{Family:v6 Kind:privatenet IP:fdaa:0:4ab8:a7b:2984:0:cb20:2 MaskSize:0}
Waiting for remote builder fly-builder-spring-darkness-1924... ⣾ DEBUG --> POST https://api.fly.io/graphql {{"query":"query ($appName: String!) { app(name: $appName) { id name hostname deployed status version appUrl platformVersion currentRelease { evaluationId status inProgress version } config { definition } organization { id slug } services { description protocol internalPort ports { port handlers } } ipAddresses { nodes { id address type createdAt } } imageDetails { repository version } machines{ nodes { id name config state region createdAt app { name } ips { nodes { family kind ip maskSize } } host { id } } } postgresAppRole: role { name } } }","variables":{"appName":"sp-api"}}
}
Waiting for remote builder fly-builder-spring-darkness-1924... ⣻ DEBUG <-- 200 https://api.fly.io/graphql (537.02ms) {"data":{"app":{"id":"sp-api","name":"sp-api","hostname":"sp-api.fly.dev","deployed":true,"version":74,"appUrl":"https://188.93.145.243","platformVersion":"nomad","currentRelease":{"evaluationId":null,"status":"succeeded","inProgress":false,"version":74},"config":{"definition":{"kill_timeout":5,"kill_signal":"SIGINT","processes":[],"experimental":{"allowed_public_ports":[],"entrypoint":[],"cmd":[],"exec":[],"auto_rollback":true},"services":[{"processes":["app"],"protocol":"tcp","internal_port":8080,"concurrency":{"soft_limit":100,"hard_limit":1000,"type":"connections"},"ports":[{"port":80,"handlers":["http"],"force_https":true},{"port":443,"handlers":["tls","http"]}],"tcp_checks":[],"http_checks":[{"interval":"10s","timeout":"2s","grace_period":"5s","restart_limit":0,"method":"get","protocol":"http","path":"/","tls_skip_verify":false,"headers":{}}],"script_checks":[]}],"env":{}}},"organization":{"id":"MA8702JP9v8awFz5z67ep3b7eRTB0Q","slug":"personal"},"services":[{"description":"TCP 80/443 ⇢ 8080","protocol":"TCP","internalPort":8080,"ports":[{"port":80,"handlers":["HTTP"]},{"port":443,"handlers":["TLS","HTTP"]}]}],"imageDetails":{"repository":"sp-api","version":null},"postgresAppRole":null,"ipAddresses":{"nodes":[{"id":"2jyLOwPOQ8JYKC7mRaMxbk73xbI16JL1Y","address":"188.93.145.243","type":"v4","createdAt":"2022-04-15T12:53:50Z"},{"id":"QnVDKg5KJQ0A7H1V6Dqm7j1Mm7TBK19JK","address":"2a09:8280:1::3:30bc","type":"v6","createdAt":"2022-04-15T12:53:51Z"}]},"machines":{"nodes":[]},"status":"running"}}}
DEBUG --> POST https://api.fly.io/graphql {{"query":"mutation($input: ValidateWireGuardPeersInput!) { validateWireGuardPeers(input: $input) { invalidPeerIps } }","variables":{"input":{"peerIps":["fdaa:0:4ab8:a7b:d6b:0:a:2"]}}}
}
Waiting for remote builder fly-builder-spring-darkness-1924... ⢿ DEBUG <-- 200 https://api.fly.io/graphql (290.31ms) {"data":{"validateWireGuardPeers":{"invalidPeerIps":[]}}}
Waiting for remote builder fly-builder-spring-darkness-1924... ⣻ DEBUG Remote builder unavailable, retrying in 50ms (err: Get "http://[fdaa:0:4ab8:a7b:2984:0:cb20:2]:2375/_ping": context deadline exceeded)
WARN Remote builder did not start in time. Check remote builder logs with `flyctl logs -a fly-builder-spring-darkness-1924`
DEBUG result image:<nil> error:error connecting to docker: remote builder app unavailable
Error failed to fetch an image or build from source: error connecting to docker: remote builder app unavailable

This happen both in github actions and my local machine.

So here is some (censored) output from the flyctl deploy command:

After a while it times out with this message:

And here is the output from flyctl doctor:

I’m having exactly the same problem, trying to deploy my first elixir application. yyz region.

1 Like

Thank you for reporting this we’ve opened an internal incident. We’re looking into this remote builder issue and will get the status page updated in a second. Please keep an eye out for updates on there:

1 Like

Same from lhr.

Apparently local builds still work so if you have Docker locally you can still do flyctl deploy --local-only. Just not remote builds for now.

in FRA:

$ LOG_LEVEL=debug fly deploy
...
Waiting for remote builder fly-builder-nameless-cherry-8322... ⣻ DEBUG <-- 200 https://api.fly.io/graphql (227.3ms) {"data":{"validateWireGuardPeers":{"invalidPeerIps":[]}}}
Waiting for remote builder fly-builder-nameless-cherry-8322... ⣻
Waiting for remote builder fly-builder-nameless-cherry-8322... ⣻ DEBUG Remote builder unavailable, retrying in 50ms (err: Get "http://[fdaa:0:5f91:a7b:23c3:0:f845:2]:2375/_ping": context deadline exceeded)
WARN Remote builder did not start in time. Check remote builder logs with `flyctl logs -a fly-builder-nameless-cherry-8322`
DEBUG result image:<nil> error:error connecting to docker: remote builder app unavailable
Error failed to fetch an image or build from source: error connecting to docker: remote builder app unavailable

No more progress since that last line. Before re-trying this deploy, I had deleted the build host manually.

$ fly doctor
Testing authentication token... PASSED
Testing flyctl agent... PASSED
Testing local Docker instance... Nope
Pinging WireGuard gateway (give us a sec)... PASSED

While my two applications are actually working OK in FRA, and IP connectivity is fine, I can’t deploy to them using remote builds. I have not tried other locations.

@hb9cwp Seems like it’s a problem regardless of the region, based on the latest update. So yes, apps keep working etc. It’s just new builds (that need the remote builder) can’t be done:

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":"MYAPPNAME","organizationId":null}}}
}
DEBUG <-- 200 https://api.fly.io/graphql (15.53s) {"data":{"ensureMachineRemoteBuilder":null},"errors":[{"message":"Mounts source volume \"vol_\" does not exist","locations":[{"line":1,"column":54}],"path":["ensureMachineRemoteBuilder"],"extensions":{"code":"UNPROCESSABLE"}}]}
DEBUG result image:<nil> error:error connecting to docker: Mounts source volume "vol_" does not exist
Error failed to fetch an image or build from source: error connecting to docker: Mounts source volume "vol_" does not exist

I also have remote builder issues… At first it was timeout in connecting… then i fly destroyed the builder app (which I had done in the past and worked), now I get the above…

I saw the note on the status page that says things are working again but when I try to deploy with a remote build I now get the following error:

Error failed to fetch an image or build from source: error connecting to docker: failed building options: Validation failed: Pubkey has already been taken, Name has already been taken

Any thoughts or suggestions?

Update: retrying the deploy a few minutes later worked, could be things were still coming back up or something when I first tried

Okay, it got further. But Now I get this on deploy. (This is a freshly generated Phoenix app, per your documentation.)

==> Creating release
Release v2 created
Release command detected: this new release will not be available until the command succeeds.

You can detach the terminal anytime without stopping the deployment
==> Release command
Command: /app/bin/migrate
	 Starting instance
	 Configuring virtual machine
	 Pulling container image
	 Unpacking image
	 Preparing kernel init
	 Configuring firecracker
	 Starting virtual machine
	 Starting init (commit: aa54f7d)...
	 Preparing to run: `/app/bin/migrate` as nobody
	 2022/05/16 17:56:03 listening on [fdaa:0:5c43:a7b:88dc:1e7d:40b0:2]:22 (DNS: [fdaa::3]:53)
	 Main child exited normally with code: 0
	 Reaped child process with pid: 566 and signal: SIGUSR1, core dumped? false
	 Starting clean up.
Error Release command failed, deployment aborted

Worked after a rerun.