[521] [INFO] Shutting down: Master

1

I get the following error in my deploy, without any follow or before errors shown in the low. Can someone advice on how to debug?

What’s funny is that the app was working yesterday, I have no clue what changed - I did develop it a bit, but cannot find a source of error and rolling back to yesterday’s build that worked doesn’t help.

Thanks!

Full log (couple of prints for debug):

2022-11-13T16:48:47Z runner[2742ee02] waw [info]Starting instance
2022-11-13T16:48:47Z runner[2742ee02] waw [info]Configuring virtual machine
2022-11-13T16:48:47Z runner[2742ee02] waw [info]Pulling container image
2022-11-13T16:48:51Z runner[2742ee02] waw [info]Unpacking image
2022-11-13T16:48:54Z runner[2742ee02] waw [info]Preparing kernel init
2022-11-13T16:48:55Z runner[2742ee02] waw [info]Configuring firecracker
2022-11-13T16:48:55Z runner[2742ee02] waw [info]Starting virtual machine
2022-11-13T16:48:55Z app[2742ee02] waw [info]Starting init (commit: 81d5330)...
2022-11-13T16:48:55Z app[2742ee02] waw [info]Preparing to run: `/cnb/process/web` as 1000
2022-11-13T16:48:55Z app[2742ee02] waw [info]2022/11/13 16:48:55 listening on [fdaa:0:cec4:a7b:84:2742:ee02:2]:22 (DNS: [fdaa::3]:53)
2022-11-13T16:48:56Z app[2742ee02] waw [info][2022-11-13 16:48:56 +0000] [520] [INFO] Starting gunicorn 20.1.0
2022-11-13T16:48:56Z app[2742ee02] waw [info][2022-11-13 16:48:56 +0000] [520] [INFO] Listening at: http://0.0.0.0:8080 (520)
2022-11-13T16:48:56Z app[2742ee02] waw [info][2022-11-13 16:48:56 +0000] [520] [INFO] Using worker: sync
2022-11-13T16:48:56Z app[2742ee02] waw [info][2022-11-13 16:48:56 +0000] [538] [INFO] Booting worker with pid: 538
2022-11-13T16:49:26Z runner[ef1b7b3e] waw [info]Shutting down virtual machine
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]Sending signal SIGINT to main child process w/ PID 521
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info][2022-11-13 16:49:26 +0000] [521] [INFO] Handling signal: int
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info][2022-11-13 16:49:26 +0000] [539] [INFO] Worker exiting (pid: 539)
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]Running __init__.py
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]run.py - trying to load configurations: Production
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]Loaded configuration
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]__init__.py - create_app()
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]apps
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]__init__.py - register_extensions()
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]__init__.py - register_extensions() - success
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]__init__.py - register_blueprints()
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]__init__.py - register_blueprints() - success
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]__init__.py - configure_database()
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]__init__.py - configure_database() - success
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]__init__.py - create_app() - success
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]Created app & migrated
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]Minified
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]Scheduler?
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]Scheduler finished
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]Name: run
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]After printing, before if
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info][2022-11-13 16:49:26 +0000] [521] [INFO] Shutting down: Master
2022-11-13T16:49:26Z app[ef1b7b3e] waw [info]Starting clean up.
2

That looks like it was shut down externally, possibly due to health check failures.

You can run fly vm status ef1b7b3e to see the event log. It should tell you if it was killed because it failed health checks.

3 
Instance
  ID            = ef1b7b3e
  Process       = app
  Version       = 1
  Region        = waw
  Desired       = stop
  Status        = complete
  Health Checks = 1 total, 1 passing
  Restarts      = 0
  Created       = 20m8s ago

Events
TIMESTAMP               TYPE            MESSAGE
2022-11-13T16:43:29Z    Received        Task received by client
2022-11-13T16:43:29Z    Task Setup      Building Task Directory
2022-11-13T16:43:38Z    Started         Task started by client
2022-11-13T16:49:11Z    Killing         Sent interrupt. Waiting 5s before force killing
2022-11-13T16:49:28Z    Terminated      Exit Code: 0
2022-11-13T16:49:28Z    Killed          Task successfully killed

Checks
ID                                      SERVICE         STATE   OUTPUT
3df2415693844068640885b45074b954        tcp-8080        passing TCP connect 172.19.2.226:8080: Success

Instance
  ID            = b30f58e1
  Process       = app
  Version       = 3
  Region        = waw
  Desired       = stop
  Status        = complete
  Health Checks = 1 total, 1 passing
  Restarts      = 0
  Created       = 6m22s ago

Events
TIMESTAMP               TYPE            MESSAGE
2022-11-13T16:55:24Z    Received        Task received by client
2022-11-13T16:55:24Z    Task Setup      Building Task Directory
2022-11-13T16:55:36Z    Started         Task started by client
2022-11-13T16:59:17Z    Killing         Sent interrupt. Waiting 5s before force killing
2022-11-13T16:59:34Z    Terminated      Exit Code: 0
2022-11-13T16:59:34Z    Killed          Task successfully killed

Checks
ID                                      SERVICE         STATE   OUTPUT
3df2415693844068640885b45074b954        tcp-8080        passing TCP connect 172.19.2.226:8080: Success

Recent Logs
  2022-11-13T16:59:32Z   [info]Running __init__.py
  2022-11-13T16:59:32Z   [info]Name: run
  2022-11-13T16:59:32Z   [info]run.py - trying to load configurations: Production
  2022-11-13T16:59:32Z   [info]Production
  2022-11-13T16:59:32Z   [info]<class 'apps.config.ProductionConfig'>
  2022-11-13T16:59:32Z   [info]Loaded configuration
  2022-11-13T16:59:32Z   [info]__init__.py - create_app()
  2022-11-13T16:59:32Z   [info]apps
  2022-11-13T16:59:32Z   [info]__init__.py - register_extensions()
  2022-11-13T16:59:32Z   [info]__init__.py - register_extensions() - success
  2022-11-13T16:59:32Z   [info]__init__.py - register_blueprints()
  2022-11-13T16:59:32Z   [info]__init__.py - register_blueprints() - success
  2022-11-13T16:59:32Z   [info]__init__.py - configure_database()
  2022-11-13T16:59:32Z   [info]__init__.py - configure_database() - success
  2022-11-13T16:59:32Z   [info]__init__.py - create_app() - success
  2022-11-13T16:59:32Z   [info]Created app & migrated
  2022-11-13T16:59:32Z   [info]Minified
  2022-11-13T16:59:32Z   [info]Scheduler?
  2022-11-13T16:59:32Z   [info]Scheduler finished
  2022-11-13T16:59:32Z   [info]Name: run
  2022-11-13T16:59:32Z   [info]After printing, before if
  2022-11-13T16:59:32Z   [info][2022-11-13 16:59:32 +0000] [521] [INFO] Shutting down: Master
  2022-11-13T16:59:33Z   [info]Starting clean up.

Not sure what to do with that further - don’t see anything suggesting that something went bad with health checks and what exactly. Can you suggest next steps to help me debug? :smiley:

4

As far as I can tell, everything that was shut down was due to a deploy. fly releases list should show you all the deploy activity.

That shutting down: Master error is coming from the app itself. But those VMs you posted exited when they were replaced by a newer version.

5

Ok, let me try to deploy the current version and let’s have a look at this one. Couple info:

  1. The app is running perfectly on local (when I run it with flask run) - the only diff is that it uses proxied postgres into localhost on local, vs the normal address on deployed (worked fine yesterday).

  2. Procfile:
    web: gunicorn run:app

The app structure is run.py + apps/* with various parts of the app, all on flask & sqlalchemy

  1. I’ve deployed v7 (basically the same as previous, no changes tbh):
    v7 true release succeeded Deploy image ruryop@gmail.com 33s ago

ht-pl-youth personal running nomad 1m17s ago

  1. After this deploy, I don’t see anything in logs at all and fly open does not open the app :confused:
6

Current VM:
flyctl.exe vm status 9db94565

Nothing is working :confused:

7

I’ve just deployed it as a new app (with new name), and suddenly it works, without any changes.
Basically:

  1. removed ht-pl-youth and builder apps
  2. removed fly.toml/Procfile from my folder
    2a. restarted PC (why not xD)
  3. fly launched as ht-pl-youth-2
  4. changed Procfile to “run:app” from initial
  5. deployed
  6. App suddenly works

Could you look into it, feels like a bug on your end…

I’ve spent like 4h on trying to debug this… xD