Source of deployment failing due to unhealthy allocations?

user114 · March 2, 2022, 8:18pm

After successfully deploying my rust service last week I went back to make a minor change and found that the same build command no longer works. I’m almost certain this is unrelated to the change I made.

I’m having trouble finding the issue from the deployment error and service logs and any help would be appreciated. Here is the output from fly-deploy --remote-only which I must use because I’m on an M1 Mac:

❯ fly deploy --remote-only
==> Verifying app config
--> Verified app config
==> Building image
Remote builder fly-builder-dry-moon-914 ready
==> Creating build context
--> Creating build context done
==> Building image with Docker
--> docker host: 20.10.12 linux x86_64
[+] Building 149.4s (0/1)                                                                                                                                                       
[+] Building 0.2s (20/20) FINISHED                                                                                                                                              
 => CACHED [internal] load remote build context                                                                                                                            0.0s
 => CACHED copy /context /                                                                                                                                                 0.0s
 => [internal] load metadata for docker.io/library/debian:buster-slim                                                                                                      0.2s
 => [internal] load metadata for docker.io/library/rust:latest                                                                                                             0.2s
 => [stage-1  1/11] FROM docker.io/library/debian:buster-slim@sha256:e61cffb42ef0dbb31832d4543d6998ab9125210d0136bc0aed65cc753cee9125                                      0.0s
 => [rust-env 1/4] FROM docker.io/library/rust:latest@sha256:12993d6e83049487cabb7afe0864535140f6e8b0322a45532a0a337fac870355                                              0.0s
 => CACHED [stage-1  2/11] RUN apt-get update  && apt-get install -y --no-install-recommends ca-certificates  && apt-get install -y libssl-dev                             0.0s
 => CACHED [stage-1  3/11] RUN update-ca-certificates                                                                                                                      0.0s
 => CACHED [stage-1  4/11] RUN apt-get install -y curl                                                                                                                     0.0s
 => CACHED [stage-1  5/11] RUN curl -sL https://deb.nodesource.com/setup_16.x -o nodesource_setup.sh                                                                       0.0s
 => CACHED [stage-1  6/11] RUN bash nodesource_setup.sh                                                                                                                    0.0s
 => CACHED [stage-1  7/11] RUN apt-get install -y nodejs                                                                                                                   0.0s
 => CACHED [stage-1  8/11] RUN npm i -g ipfs-car                                                                                                                           0.0s
 => CACHED [stage-1  9/11] RUN npm i -g carbites-cli                                                                                                                       0.0s
 => CACHED [stage-1 10/11] RUN rm -rf /var/lib/apt/lists/*                                                                                                                 0.0s
 => CACHED [rust-env 2/4] WORKDIR /app                                                                                                                                     0.0s
 => CACHED [rust-env 3/4] COPY server/. /app                                                                                                                               0.0s
 => CACHED [rust-env 4/4] RUN cargo build --release                                                                                                                        0.0s
 => CACHED [stage-1 11/11] COPY --from=rust-env /app/target/release/server /                                                                                               0.0s
 => exporting to image                                                                                                                                                     0.0s
 => => exporting layers                                                                                                                                                    0.0s
 => => writing image sha256:76dd7cd146c56f8f47775a0a3e11be1eb28a80115ff1f4c786199397d08d33b8                                                                               0.0s
 => => naming to registry.fly.io/precrypt:deployment-1646251954                                                                                                            0.0s
--> Building image done
==> Pushing image to fly
The push refers to repository [registry.fly.io/precrypt]
9275d2ffb72a: Layer already exists 
020f79bc4637: Layer already exists 
f704113d1b48: Layer already exists 
dcf7fa592184: Layer already exists 
52468c85255f: Layer already exists 
31d35832c7b9: Layer already exists 
d1bd041492af: Layer already exists 
5adf1992e17c: Layer already exists 
c6aec2b2f35c: Layer already exists 
b7da7346c91d: Layer already exists 
e5baccb54724: Layer already exists 
deployment-1646251954: digest: sha256:623ab22cbc72f09483409a26a0db8c88819a79c1bcee821ff3e40bc7ef9c2678 size: 2634
--> Pushing image done
image: registry.fly.io/precrypt:deployment-1646251954
image size: 307 MB
==> Creating release
--> release v53 created

--> You can detach the terminal anytime without stopping the deployment
==> Monitoring deployment

 1 desired, 1 placed, 0 healthy, 1 unhealthy [restarts: 2] [health checks: 1 total]
Failed Instances

Failure #1

Instance
ID              PROCESS VERSION REGION  DESIRED STATUS  HEALTH CHECKS   RESTARTS        CREATED 
d948ffba                53      ord     run     pending 1 total         2               24s ago

Recent Events
TIMESTAMP               TYPE            MESSAGE                         
2022-03-02T20:15:08Z    Received        Task received by client        
2022-03-02T20:15:08Z    Task Setup      Building Task Directory        
2022-03-02T20:15:11Z    Started         Task started by client         
2022-03-02T20:15:13Z    Terminated      Exit Code: 1                   
2022-03-02T20:15:13Z    Restarting      Task restarting in 1.08533806s 
2022-03-02T20:15:20Z    Started         Task started by client         
2022-03-02T20:15:22Z    Terminated      Exit Code: 1                   
2022-03-02T20:15:22Z    Restarting      Task restarting in 1.112323122s

2022-03-02T20:15:18Z   [info]Starting instance
2022-03-02T20:15:18Z   [info]Configuring virtual machine
2022-03-02T20:15:18Z   [info]Pulling container image
2022-03-02T20:15:19Z   [info]Unpacking image
2022-03-02T20:15:19Z   [info]Preparing kernel init
2022-03-02T20:15:19Z   [info]Setting up volume 'precrypt_data'
2022-03-02T20:15:20Z   [info]Configuring firecracker
2022-03-02T20:15:20Z   [info]Starting virtual machine
2022-03-02T20:15:20Z   [info]Starting init (commit: 0c50bff)...
2022-03-02T20:15:20Z   [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T20:15:20Z   [info]Preparing to run: `/server` as root
2022-03-02T20:15:20Z   [info]2022/03/02 20:15:20 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T20:15:21Z   [info]Main child exited normally with code: 1
2022-03-02T20:15:21Z   [info]Starting clean up.
2022-03-02T20:15:21Z   [info]Umounting /dev/vdc from /data
2022-03-02T20:15:27Z   [info]Starting instance
2022-03-02T20:15:27Z   [info]Configuring virtual machine
2022-03-02T20:15:27Z   [info]Pulling container image
2022-03-02T20:15:28Z   [info]Unpacking image
2022-03-02T20:15:28Z   [info]Preparing kernel init
2022-03-02T20:15:28Z   [info]Setting up volume 'precrypt_data'
2022-03-02T20:15:29Z   [info]Configuring firecracker
2022-03-02T20:15:29Z   [info]Starting virtual machine
2022-03-02T20:15:29Z   [info]Starting init (commit: 0c50bff)...
2022-03-02T20:15:29Z   [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T20:15:29Z   [info]Preparing to run: `/server` as root
2022-03-02T20:15:29Z   [info]2022/03/02 20:15:29 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T20:15:30Z   [info]Main child exited normally with code: 1
2022-03-02T20:15:30Z   [info]Starting clean up.
2022-03-02T20:15:30Z   [info]Umounting /dev/vdc from /data
--> v53 failed - Failed due to unhealthy allocations - not rolling back to stable job version 53 as current job has same specification and deploying as v54 

--> Troubleshooting guide at https://fly.io/docs/getting-started/troubleshooting/
Error abort

I have also tried running with --no-cache and re creating my volume and deployment instance. The error is obviously this line:
--> v53 failed - Failed due to unhealthy allocations - not rolling back to stable job version 53 as current job has same specification and deploying as v54
But where can I go to see what caused the unhealthy allocation? Here is a sample of my fly logs:

2022-03-02T20:07:47Z runner[c1f597fe] ord [info]Setting up volume 'precrypt_data'
2022-03-02T20:07:48Z runner[c1f597fe] ord [info]Configuring firecracker
2022-03-02T20:07:48Z runner[c1f597fe] ord [info]Starting virtual machine
2022-03-02T20:07:49Z app[c1f597fe] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T20:07:49Z app[c1f597fe] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T20:07:49Z app[c1f597fe] ord [info]Preparing to run: `/server` as root
2022-03-02T20:07:49Z app[c1f597fe] ord [info]2022/03/02 20:07:49 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T20:07:50Z app[c1f597fe] ord [info]Main child exited normally with code: 1
2022-03-02T20:07:50Z app[c1f597fe] ord [info]Starting clean up.
2022-03-02T20:07:50Z app[c1f597fe] ord [info]Umounting /dev/vdc from /data
2022-03-02T20:08:06Z runner[9a35b8a9] ord [info]Starting instance
2022-03-02T20:08:06Z runner[9a35b8a9] ord [info]Configuring virtual machine
2022-03-02T20:08:06Z runner[9a35b8a9] ord [info]Pulling container image
2022-03-02T20:08:07Z runner[9a35b8a9] ord [info]Unpacking image
2022-03-02T20:08:07Z runner[9a35b8a9] ord [info]Preparing kernel init
2022-03-02T20:08:07Z runner[9a35b8a9] ord [info]Setting up volume 'precrypt_data'
2022-03-02T20:08:08Z runner[9a35b8a9] ord [info]Configuring firecracker
2022-03-02T20:08:08Z runner[9a35b8a9] ord [info]Starting virtual machine
2022-03-02T20:08:08Z app[9a35b8a9] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T20:08:08Z app[9a35b8a9] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T20:08:08Z app[9a35b8a9] ord [info]Preparing to run: `/server` as root
2022-03-02T20:08:08Z app[9a35b8a9] ord [info]2022/03/02 20:08:08 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T20:08:09Z app[9a35b8a9] ord [info]Main child exited normally with code: 1
2022-03-02T20:08:09Z app[9a35b8a9] ord [info]Starting clean up.
2022-03-02T20:08:09Z app[9a35b8a9] ord [info]Umounting /dev/vdc from /data
2022-03-02T20:08:16Z runner[9a35b8a9] ord [info]Starting instance
2022-03-02T20:08:16Z runner[9a35b8a9] ord [info]Configuring virtual machine
2022-03-02T20:08:16Z runner[9a35b8a9] ord [info]Pulling container image
2022-03-02T20:08:16Z runner[9a35b8a9] ord [info]Unpacking image
2022-03-02T20:08:16Z runner[9a35b8a9] ord [info]Preparing kernel init
2022-03-02T20:08:16Z runner[9a35b8a9] ord [info]Setting up volume 'precrypt_data'
2022-03-02T20:08:17Z runner[9a35b8a9] ord [info]Configuring firecracker
2022-03-02T20:08:17Z runner[9a35b8a9] ord [info]Starting virtual machine
2022-03-02T20:08:18Z app[9a35b8a9] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T20:08:18Z app[9a35b8a9] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T20:08:18Z app[9a35b8a9] ord [info]Preparing to run: `/server` as root
2022-03-02T20:08:18Z app[9a35b8a9] ord [info]2022/03/02 20:08:18 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T20:08:19Z app[9a35b8a9] ord [info]Main child exited normally with code: 1
2022-03-02T20:08:19Z app[9a35b8a9] ord [info]Starting clean up.
2022-03-02T20:08:19Z app[9a35b8a9] ord [info]Umounting /dev/vdc from /data
2022-03-02T20:08:25Z runner[9a35b8a9] ord [info]Starting instance
2022-03-02T20:08:25Z runner[9a35b8a9] ord [info]Configuring virtual machine
2022-03-02T20:08:25Z runner[9a35b8a9] ord [info]Pulling container image
2022-03-02T20:08:25Z runner[9a35b8a9] ord [info]Unpacking image
2022-03-02T20:08:25Z runner[9a35b8a9] ord [info]Preparing kernel init
2022-03-02T20:08:25Z runner[9a35b8a9] ord [info]Setting up volume 'precrypt_data'
2022-03-02T20:08:27Z runner[9a35b8a9] ord [info]Configuring firecracker
2022-03-02T20:08:27Z runner[9a35b8a9] ord [info]Starting virtual machine
2022-03-02T20:08:27Z app[9a35b8a9] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T20:08:27Z app[9a35b8a9] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T20:08:27Z app[9a35b8a9] ord [info]Preparing to run: `/server` as root
2022-03-02T20:08:27Z app[9a35b8a9] ord [info]2022/03/02 20:08:27 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T20:08:28Z app[9a35b8a9] ord [info]Main child exited normally with code: 1
2022-03-02T20:08:28Z app[9a35b8a9] ord [info]Starting clean up.
2022-03-02T20:08:28Z app[9a35b8a9] ord [info]Umounting /dev/vdc from /data
2022-03-02T20:15:09Z runner[d948ffba] ord [info]Starting instance
2022-03-02T20:15:09Z runner[d948ffba] ord [info]Configuring virtual machine
2022-03-02T20:15:09Z runner[d948ffba] ord [info]Pulling container image
2022-03-02T20:15:09Z runner[d948ffba] ord [info]Unpacking image
2022-03-02T20:15:09Z runner[d948ffba] ord [info]Preparing kernel init
2022-03-02T20:15:09Z runner[d948ffba] ord [info]Setting up volume 'precrypt_data'
2022-03-02T20:15:11Z runner[d948ffba] ord [info]Configuring firecracker
2022-03-02T20:15:11Z runner[d948ffba] ord [info]Starting virtual machine
2022-03-02T20:15:11Z app[d948ffba] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T20:15:11Z app[d948ffba] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T20:15:11Z app[d948ffba] ord [info]Preparing to run: `/server` as root
2022-03-02T20:15:11Z app[d948ffba] ord [info]2022/03/02 20:15:11 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T20:15:12Z app[d948ffba] ord [info]Main child exited normally with code: 1
2022-03-02T20:15:12Z app[d948ffba] ord [info]Starting clean up.
2022-03-02T20:15:12Z app[d948ffba] ord [info]Umounting /dev/vdc from /data
2022-03-02T20:15:18Z runner[d948ffba] ord [info]Starting instance
2022-03-02T20:15:18Z runner[d948ffba] ord [info]Configuring virtual machine
2022-03-02T20:15:18Z runner[d948ffba] ord [info]Pulling container image
2022-03-02T20:15:19Z runner[d948ffba] ord [info]Unpacking image
2022-03-02T20:15:19Z runner[d948ffba] ord [info]Preparing kernel init
2022-03-02T20:15:19Z runner[d948ffba] ord [info]Setting up volume 'precrypt_data'
2022-03-02T20:15:20Z runner[d948ffba] ord [info]Configuring firecracker
2022-03-02T20:15:20Z runner[d948ffba] ord [info]Starting virtual machine
2022-03-02T20:15:20Z app[d948ffba] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T20:15:20Z app[d948ffba] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T20:15:20Z app[d948ffba] ord [info]Preparing to run: `/server` as root
2022-03-02T20:15:20Z app[d948ffba] ord [info]2022/03/02 20:15:20 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T20:15:21Z app[d948ffba] ord [info]Main child exited normally with code: 1
2022-03-02T20:15:21Z app[d948ffba] ord [info]Starting clean up.
2022-03-02T20:15:21Z app[d948ffba] ord [info]Umounting /dev/vdc from /data
2022-03-02T20:15:27Z runner[d948ffba] ord [info]Starting instance
2022-03-02T20:15:27Z runner[d948ffba] ord [info]Configuring virtual machine
2022-03-02T20:15:27Z runner[d948ffba] ord [info]Pulling container image
2022-03-02T20:15:28Z runner[d948ffba] ord [info]Unpacking image
2022-03-02T20:15:28Z runner[d948ffba] ord [info]Preparing kernel init
2022-03-02T20:15:28Z runner[d948ffba] ord [info]Setting up volume 'precrypt_data'
2022-03-02T20:15:29Z runner[d948ffba] ord [info]Configuring firecracker
2022-03-02T20:15:29Z runner[d948ffba] ord [info]Starting virtual machine
2022-03-02T20:15:29Z app[d948ffba] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T20:15:29Z app[d948ffba] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T20:15:29Z app[d948ffba] ord [info]Preparing to run: `/server` as root
2022-03-02T20:15:29Z app[d948ffba] ord [info]2022/03/02 20:15:29 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T20:15:30Z app[d948ffba] ord [info]Main child exited normally with code: 1
2022-03-02T20:15:30Z app[d948ffba] ord [info]Starting clean up.
2022-03-02T20:15:30Z app[d948ffba] ord [info]Umounting /dev/vdc from /data

Thank you any help in advance!

rahmatjunaid · March 2, 2022, 9:31pm

Unhealthy allocations errors means the app could boot okay but couldn’t connect to our healthchecks.

We have a guide to troubleshooting this: https://fly.io/docs/getting-started/troubleshooting/

Normally this happens when an app is listening on 127.0.0.1 , or an app is listening on a different port than internal_port in the config.

What does your fly.toml look like?

user114 · March 2, 2022, 9:45pm

Here is my fly.toml:

# fly.toml file generated for precrypt on 2022-02-07T15:24:35-05:00

app = "precrypt"

kill_signal = "SIGINT"
kill_timeout = 5
processes = []

[mounts]
source="precrypt_data"
destination="/data"

[env]
DATA="/data"

[experimental]
  allowed_public_ports = []
  auto_rollback = true

[[services]]
  http_checks = []
  internal_port = 8000
  processes = ["app"]
  protocol = "tcp"
  script_checks = []

  [services.concurrency]
    hard_limit = 25
    soft_limit = 20
    type = "connections"

  [[services.ports]]
    handlers = ["http"]
    port = 80

  [[services.ports]]
    handlers = ["tls", "http"]
    port = 443

  [[services.tcp_checks]]
    grace_period = "1s"
    interval = "15s"
    restart_limit = 0
    timeout = "2s"

And my Dockerfile:

FROM rust:latest as rust-env
WORKDIR /app
COPY server/. /app
RUN cargo build --release

FROM debian:buster-slim
# Install things required for SSL
RUN apt-get update \
 && apt-get install -y --no-install-recommends ca-certificates \
 && apt-get install -y libssl-dev
RUN update-ca-certificates
# Install node CLI dependencies
RUN apt-get install -y curl
RUN curl -sL https://deb.nodesource.com/setup_16.x -o nodesource_setup.sh
RUN bash nodesource_setup.sh
RUN apt-get install -y nodejs
RUN npm i -g ipfs-car
RUN npm i -g carbites-cli
# Cleanup and run
RUN rm -rf /var/lib/apt/lists/*
COPY --from=rust-env /app/target/release/server /
CMD ["/server"]

The project is actually open source so you can checkout the repo: GitHub - rebase-foundation/precrypt: Open source implementation of a service and client libraries for adding proxy(less) re-encryption to your decentralized project.

I have also tried resetting my repository to the commit that worked last week and that fails now as well. Is there anything with fly.io’s health check that has changed since then?

rahmatjunaid · March 2, 2022, 9:56pm

It looks like you have to set PORT=8080 under the [env] section of your fly.toml

What happens when you do that?

user114 · March 2, 2022, 10:20pm

It was 8000 because that was my server was using, but I changed them both to 8080 just for a sanity check and nothing changed. I feel like I should be seeing an error here:

2022-03-02T22:17:49Z   [info]Preparing to run: `/server` as root
2022-03-02T22:17:49Z   [info]2022/03/02 22:17:49 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T22:17:50Z   [info]Main child exited normally with code: 1

What can I try to get more information?

rahmatjunaid · March 2, 2022, 10:30pm

Yes of course I meant 8000

Unhealthy allocations can also happen when a process crashes after it boots too

Can you run fly status --all this should show the failing vms and then fly logs -i <id> of one of the failing vms which should give you a little more information

user114 · March 2, 2022, 10:49pm

Here is the output of the logs for the most recent instance:

2022-03-02T22:17:36Z runner[dbc20447] ord [info]Starting instance
2022-03-02T22:17:36Z runner[dbc20447] ord [info]Configuring virtual machine
2022-03-02T22:17:36Z runner[dbc20447] ord [info]Pulling container image
2022-03-02T22:17:37Z runner[dbc20447] ord [info]Unpacking image
2022-03-02T22:17:37Z runner[dbc20447] ord [info]Preparing kernel init
2022-03-02T22:17:38Z runner[dbc20447] ord [info]Setting up volume 'precrypt_data'
2022-03-02T22:17:39Z runner[dbc20447] ord [info]Configuring firecracker
2022-03-02T22:17:39Z runner[dbc20447] ord [info]Starting virtual machine
2022-03-02T22:17:39Z app[dbc20447] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T22:17:39Z app[dbc20447] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T22:17:39Z app[dbc20447] ord [info]Preparing to run: `/server` as root
2022-03-02T22:17:39Z app[dbc20447] ord [info]2022/03/02 22:17:39 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T22:17:40Z app[dbc20447] ord [info]Main child exited normally with code: 1
2022-03-02T22:17:40Z app[dbc20447] ord [info]Starting clean up.
2022-03-02T22:17:40Z app[dbc20447] ord [info]Umounting /dev/vdc from /data
2022-03-02T22:17:46Z runner[dbc20447] ord [info]Starting instance
2022-03-02T22:17:46Z runner[dbc20447] ord [info]Configuring virtual machine
2022-03-02T22:17:46Z runner[dbc20447] ord [info]Pulling container image
2022-03-02T22:17:47Z runner[dbc20447] ord [info]Unpacking image
2022-03-02T22:17:47Z runner[dbc20447] ord [info]Preparing kernel init
2022-03-02T22:17:47Z runner[dbc20447] ord [info]Setting up volume 'precrypt_data'
2022-03-02T22:17:48Z runner[dbc20447] ord [info]Configuring firecracker
2022-03-02T22:17:48Z runner[dbc20447] ord [info]Starting virtual machine
2022-03-02T22:17:48Z app[dbc20447] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T22:17:48Z app[dbc20447] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T22:17:49Z app[dbc20447] ord [info]Preparing to run: `/server` as root
2022-03-02T22:17:49Z app[dbc20447] ord [info]2022/03/02 22:17:49 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T22:17:50Z app[dbc20447] ord [info]Main child exited normally with code: 1
2022-03-02T22:17:50Z app[dbc20447] ord [info]Starting clean up.
2022-03-02T22:17:50Z app[dbc20447] ord [info]Umounting /dev/vdc from /data
2022-03-02T22:17:56Z runner[dbc20447] ord [info]Starting instance
2022-03-02T22:17:56Z runner[dbc20447] ord [info]Configuring virtual machine
2022-03-02T22:17:56Z runner[dbc20447] ord [info]Pulling container image
2022-03-02T22:17:56Z runner[dbc20447] ord [info]Unpacking image
2022-03-02T22:17:56Z runner[dbc20447] ord [info]Preparing kernel init
2022-03-02T22:17:56Z runner[dbc20447] ord [info]Setting up volume 'precrypt_data'
2022-03-02T22:17:57Z runner[dbc20447] ord [info]Configuring firecracker
2022-03-02T22:17:57Z runner[dbc20447] ord [info]Starting virtual machine
2022-03-02T22:17:58Z app[dbc20447] ord [info]Starting init (commit: 0c50bff)...
2022-03-02T22:17:58Z app[dbc20447] ord [info]Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-03-02T22:17:58Z app[dbc20447] ord [info]Preparing to run: `/server` as root
2022-03-02T22:17:58Z app[dbc20447] ord [info]2022/03/02 22:17:58 listening on [fdaa:0:424c:a7b:20db:0:a0d8:2]:22 (DNS: [fdaa::3]:53)
2022-03-02T22:17:59Z app[dbc20447] ord [info]Main child exited normally with code: 1
2022-03-02T22:17:59Z app[dbc20447] ord [info]Starting clean up.
2022-03-02T22:17:59Z app[dbc20447] ord [info]Umounting /dev/vdc from /data

Really struggling to see an error message.

rahmatjunaid · March 2, 2022, 11:09pm

You mentioned in the first message that it was working before you made some changes what was the change that you made?

I just want to get a full picture

user114 · March 2, 2022, 11:22pm

It was really minor, just adding a header to one of the responses. I also tried going back to a commit that was the last one that worked and I saw the same error and logs.

kurt · March 2, 2022, 11:25pm

What kind of app is this? The process is exiting with an error:

Main child exited normally with code: 1

Is there some kind of external service it connects to at boot? If you can enable debug logging it may tell you more about why it’s exiting.

OCH · April 15, 2022, 8:54pm

How do you enable debug logging?

greg · April 15, 2022, 9:51pm

I think you can set it like …

LOG_LEVEL=debug fly deploy --verbose
LOG_LEVEL=debug fly deploy --remote-only --verbose

OCH · April 16, 2022, 12:00am

Thank you @greg ! For a moment I thought debug logging was something to change the fly.io logs, but your answer clarified that it is only for the deployment command

Topic		Replies	Views
Deployments using remote builder failing Build debugging	2	787	October 14, 2022
Remote deploys no longer working for me Build debugging	5	1107	July 28, 2022
Deployment issues Build debugging	8	873	December 20, 2022
Remote builder seems not be working now Build debugging docs	1	325	September 1, 2022
failed deployment Questions / Help	0	452	October 22, 2022

Source of deployment failing due to unhealthy allocations?

Related topics