vapor/vapor

Vapor migrations do not finish running on fly.io

nicolassrod opened this issue · 8 comments

nicolassrod commented

Describe the bug

Im trying to launch an update to production but the migration, never finishes running and ends up throwing a timeout error.

// MARK: Postgres
    var postgresConfiguration = try SQLPostgresConfiguration(url: databaseURL)
    postgresConfiguration.coreConfiguration.tls = .disable
    app.databases.use(.postgres(configuration: postgresConfiguration), as: .psql)

fly.io monitor log
2023-12-27T00:53:50.784 app[56833794c7e258] lax [info] [ DEBUG ] SELECT "_fluent_migrations"."id" AS "_fluent_migrations_id", "_fluent_migrations"."name" AS "_fluent_migrations_name", "_fluent_migrations"."batch" AS "_fluent_migrations_batch", "_fluent_migrations"."created_at" AS "_fluent_migrations_created_at", "_fluent_migrations"."updated_at" AS "_fluent_migrations_updated_at" FROM "_fluent_migrations" [[]] [database-id: psql] (PostgresKit/PostgresDatabase+SQL.swift:44)
2023-12-27T00:53:50.785 app[56833794c7e258] lax [info] The following migration(s) will be prepared:
2023-12-27T00:53:50.785 app[56833794c7e258] lax [info] + App.M0CreateUserRole on default
2023-12-27T00:53:50.785 app[56833794c7e258] lax [info] + App.M1CreateUser on default
2023-12-27T00:53:50.786 app[56833794c7e258] lax [info] + App.M2CreateTrack on default
2023-12-27T00:53:50.786 app[56833794c7e258] lax [info] + App.M3CreateChart on default
2023-12-27T00:53:50.786 app[56833794c7e258] lax [info] + App.M4CreateChartTrack on default
2023-12-27T00:53:50.786 app[56833794c7e258] lax [info] + App.M5CrateTrackMetadataError on default
2023-12-27T00:53:50.787 app[56833794c7e258] lax [info] + App.M6CreateDevice on default
2023-12-27T00:53:50.787 app[56833794c7e258] lax [info] + App.M3CreateChart.Seed on default
2023-12-27T00:53:50.787 app[56833794c7e258] lax [info] Would you like to continue?
2023-12-27T00:53:50.787 app[56833794c7e258] lax [info] y/n> yes
2023-12-27T00:53:50.788 app[56833794c7e258] lax [info] [ DEBUG ] query read _fluent_migrations limits=[count(1)] [database-id: psql] (FluentKit/QueryBuilder.swift:293)
2023-12-27T00:53:50.788 app[56833794c7e258] lax [info] [ DEBUG ] SELECT "_fluent_migrations"."id" AS "_fluent_migrations_id", "_fluent_migrations"."name" AS "_fluent_migrations_name", "_fluent_migrations"."batch" AS "_fluent_migrations_batch", "_fluent_migrations"."created_at" AS "_fluent_migrations_created_at", "_fluent_migrations"."updated_at" AS "_fluent_migrations_updated_at" FROM "_fluent_migrations" ORDER BY "_fluent_migrations"."batch" DESC LIMIT 1 [[]] [database-id: psql] (PostgresKit/PostgresDatabase+SQL.swift:44)
2023-12-27T00:53:50.789 app[56833794c7e258] lax [info] [ DEBUG ] query read _fluent_migrations [database-id: psql] (FluentKit/QueryBuilder.swift:293)
2023-12-27T00:53:50.789 app[56833794c7e258] lax [info] [ DEBUG ] SELECT "_fluent_migrations"."id" AS "_fluent_migrations_id", "_fluent_migrations"."name" AS "_fluent_migrations_name", "_fluent_migrations"."batch" AS "_fluent_migrations_batch", "_fluent_migrations"."created_at" AS "_fluent_migrations_created_at", "_fluent_migrations"."updated_at" AS "_fluent_migrations_updated_at" FROM "_fluent_migrations" [[]] [database-id: psql] (PostgresKit/PostgresDatabase+SQL.swift:44)
2023-12-27T00:53:50.790 app[56833794c7e258] lax [info] [ INFO ] [Migrator] Starting prepare [database-id: psql, migration: App.M0CreateUserRole] (FluentKit/Migrator.swift:205)

fly deploy command log
-------
 ✖ Failed: error waiting for release_command machine 56833794c7e258 to finish running: timeout reached waiting for machine's state to change
-------
Error: release command failed - aborting deployment. error waiting for release_command machine 56833794c7e258 to finish running: timeout reached waiting for machine's state to change
Your machine never reached the state "%s".

fly.toml
[processes]
  app = "serve --env production --hostname 0.0.0.0 --port 8080"
  scheduled_queues = "queues --scheduled"

[deploy]
  processes = ["app"]
  release_command = "migrate --yes"

To Reproduce

I tried to launch from a clean project but the migrations don't work either, I deleted everything and did everything from scratch but still the first migration never finishes running

import Fluent

struct M0CreateUserRole: AsyncMigration {
    func prepare(on database: Database) async throws {
        _ = try await database.enum("users_roles")
            .case("user")
            .case("moderator")
            .case("admin")
            .create()
    }
    
    func revert(on database: Database) async throws {
        try await database.enum("users_roles").delete()
    }
}

Environment

I am update to the latest update of vapor template e9155a08a5661bd09ba633c21aa1777e38e0bd0d

  • Vapor Framework version: 4.89.3
  • Vapor Toolbox version: 18.7.4
  • OS version: Sonoma 14.2.1
0xTim commented

Is this reproducible or a network hiccup etc? Can you turn on trace debugging as well

easonchan42 commented

I've encountered a similar issue with my setup.

I start 2 fresh DigitalOcean servers with Ubuntu 22.04, clean vapor new HelloWorld project with mysql or postgresql.

swift run App migrate —log trace

It always stuck on this line and never finishes the migration.
[ INFO ] [Migrator] Starting prepare [database-id: psql, migration: App.CreateTodo] (FluentKit/Migrator.swift:205)

But if you change AsyncMigration to Migration, it will go through the migration without any problems.

Change

// Always stuck on [Migrator] Starting prepare
struct CreateTodo: AsyncMigration {
    func prepare(on database: Database) async throws {
        // Make a change to the database.
    }

to

// Now it works!
struct CreateTodo: Migration {
    func prepare(on database: Database) -> EventLoopFuture<Void> {
        // Make a change to the database.
    }

Environment

Vapor Toolbox version 18.6.0
Vapor Framework version 4.91.1
Swift version 5.9.2 (swift-5.9.2-RELEASE)
OS version: Sonoma 14.2.1

The last few lines of server output

[ codes.vapor.application ] [ TRACE ] Run action [database-id: psql, psql_connection_action: wait, psql_connection_id: 1] (PostgresNIO/PostgresChannelHandler.swift:321)
[ codes.vapor.application ] [ TRACE ] Backend message received [database-id: psql, psql_connection_id: 1, psql_message: .commandComplete("SELECT 0")] (PostgresNIO/PostgresChannelHandler.swift:125)
[ codes.vapor.application ] [ TRACE ] Run action [database-id: psql, psql_connection_action: forwardStreamComplete([], commandTag: "SELECT 0"), psql_connection_id: 1] (PostgresNIO/PostgresChannelHandler.swift:321)
[ codes.vapor.application ] [ TRACE ] Releasing pool connection on SelectableEventLoop { selector = Selector { descriptor = 3 }, thread = NIOThread(name = NIO-SGLTN-0-#0) }, 1 connnections available. [database-id: psql] (AsyncKit/EventLoopConnectionPool.swift:278)
[ codes.vapor.application ] [ INFO ] [Migrator] Starting prepare [database-id: psql, migration: App.CreateTodo] (FluentKit/Migrator.swift:205)
[ codes.vapor.application ] [ TRACE ] Backend message received [database-id: psql, psql_connection_id: 1, psql_message: .readyForQuery(.idle)] (PostgresNIO/PostgresChannelHandler.swift:125)
[ codes.vapor.application ] [ TRACE ] Run action [database-id: psql, psql_connection_action: fireEventReadyForQuery, psql_connection_id: 1] (PostgresNIO/PostgresChannelHandler.swift:321)
[ codes.vapor.application ] [ TRACE ] Run action [database-id: psql, psql_connection_action: wait, psql_connection_id: 1] (PostgresNIO/PostgresChannelHandler.swift:321)
[ codes.vapor.application ] [ TRACE ] Channel read event received [database-id: psql, psql_connection_id: 1] (PostgresNIO/PostgresChannelHandler.swift:194)
[ codes.vapor.application ] [ TRACE ] Run action [database-id: psql, psql_connection_action: read, psql_connection_id: 1] (PostgresNIO/PostgresChannelHandler.swift:321)
  • 👍1
0xTim commented

Have you migrated your entrypoint.swift to the new version? That appears to have fixed it in one instance on Discord

laiso commented

I was able to perform the migration using the method mentioned in this comment #3122 (comment) in my tests https://github.com/vapor/template-fluent-sqlite as well. It operates with fly.io and SQLite. The entry point is described the same as the latest.

easonchan42 commented

I am using the latest entrypoint.swift from the template.

Also the migration runs fine on macOS but needs changing from AsyncMigration to Migration to work on Ubuntu Server.

0xTim commented

Can you try updating to the latest Fluent release - that should fix the issue

easonchan42 commented

Can you try updating to the latest Fluent release - that should fix the issue

This does indeed fix the migration issue, thank you.

0xTim commented

Closing this then, feel free to say if it's still an issue