GoodJob tells me to upgrade but migrations fail

[katelovescode]

When I run my server, good_job tells me to upgrade:

10:27:14 PM api.1 |  [47502] 2022-03-23 22:27:14.484 WARN  | DEPRECATION WARNING: GoodJob has pending database migrations. To create the migration files, run:
10:27:14 PM api.1 |      rails generate good_job:update
10:27:14 PM api.1 |  To apply the migration files, run:
10:27:14 PM api.1 |      rails db:migrate
10:27:14 PM api.1 |   (called from migrated? at /Users/katedonaldson/.rbenv/versions/3.0.2/lib/ruby/gems/3.0.0/gems/good_job-2.11.2/lib/good_job/process.rb:33)

But when I try to follow the instructions I get a failure:

➜ bundle exec rails generate good_job:update
Running via Spring preloader in process 51105
        skip  db/migrate/20220324032728_create_good_jobs.rb
      create  db/migrate/20220324032728_add_cron_at_to_good_jobs.rb
      create  db/migrate/20220324032729_add_cron_key_cron_at_index_to_good_jobs.rb
      create  db/migrate/20220324032730_create_good_job_processes.rb
      create  db/migrate/20220324032731_index_good_job_jobs_on_finished_at.rb

➜ bundle exec rails db:migrate
[51234] 2022-03-23 22:27:35.772 INFO  | [SKYLIGHT] [5.3.1] Skylight agent enabled
[51234] 2022-03-23 22:27:36.275 DEBUG |    (0.2ms)  SELECT pg_try_advisory_lock(186062436696592260)
[51234] 2022-03-23 22:27:36.289 DEBUG |    (1.6ms)  SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
[51234] 2022-03-23 22:27:36.291 INFO  | Migrating to AddCronAtToGoodJobs (20220324032728)
== 20220324032728 AddCronAtToGoodJobs: migrating ==============================
[51234] 2022-03-23 22:27:36.294 DEBUG |   TRANSACTION (0.2ms)  BEGIN
-- add_column(:good_jobs, :cron_at, :timestamp)
[51234] 2022-03-23 22:27:36.317 DEBUG |    (18.4ms)  ALTER TABLE "good_jobs" ADD "cron_at" timestamp
   -> 0.0196s
== 20220324032728 AddCronAtToGoodJobs: migrated (0.0241s) =====================

[51234] 2022-03-23 22:27:36.321 DEBUG |   ActiveRecord::SchemaMigration Create (0.9ms)  INSERT INTO "schema_migrations" ("version") VALUES ($1) RETURNING "version"  [["version", "20220324032728"]]
[51234] 2022-03-23 22:27:36.323 DEBUG |   TRANSACTION (0.4ms)  COMMIT
[51234] 2022-03-23 22:27:36.323 INFO  | Migrating to AddCronKeyCronAtIndexToGoodJobs (20220324032729)
== 20220324032729 AddCronKeyCronAtIndexToGoodJobs: migrating ==================
-- add_index(:good_jobs, [:cron_key, :cron_at], {:algorithm=>:concurrently, :name=>:index_good_jobs_on_cron_key_and_cron_at, :unique=>true})
[51234] 2022-03-23 22:27:36.360 DEBUG |    (29.7ms)  CREATE UNIQUE INDEX CONCURRENTLY "index_good_jobs_on_cron_key_and_cron_at" ON "good_jobs" ("cron_key", "cron_at")
   -> 0.0347s
== 20220324032729 AddCronKeyCronAtIndexToGoodJobs: migrated (0.0409s) =========

[51234] 2022-03-23 22:27:36.366 DEBUG |   TRANSACTION (0.1ms)  BEGIN
[51234] 2022-03-23 22:27:36.372 DEBUG |   ActiveRecord::SchemaMigration Create (0.4ms)  INSERT INTO "schema_migrations" ("version") VALUES ($1) RETURNING "version"  [["version", "20220324032729"]]
[51234] 2022-03-23 22:27:36.373 DEBUG |   TRANSACTION (0.3ms)  COMMIT
[51234] 2022-03-23 22:27:36.374 INFO  | Migrating to CreateGoodJobProcesses (20220324032730)
== 20220324032730 CreateGoodJobProcesses: migrating ===========================
[51234] 2022-03-23 22:27:36.375 DEBUG |   TRANSACTION (0.1ms)  BEGIN
-- create_table(:good_job_processes, {:id=>:uuid})
[51234] 2022-03-23 22:27:36.420 DEBUG |    (42.5ms)  CREATE TABLE "good_job_processes" ("id" uuid DEFAULT gen_random_uuid() NOT NULL PRIMARY KEY, "created_at" timestamp(6) NOT NULL, "updated_at" timestamp(6) NOT NULL, "state" jsonb)
   -> 0.0440s
== 20220324032730 CreateGoodJobProcesses: migrated (0.0456s) ==================

[51234] 2022-03-23 22:27:36.422 DEBUG |   ActiveRecord::SchemaMigration Create (0.4ms)  INSERT INTO "schema_migrations" ("version") VALUES ($1) RETURNING "version"  [["version", "20220324032730"]]
[51234] 2022-03-23 22:27:36.423 DEBUG |   TRANSACTION (0.3ms)  COMMIT
[51234] 2022-03-23 22:27:36.424 INFO  | Migrating to IndexGoodJobJobsOnFinishedAt (20220324032731)
== 20220324032731 IndexGoodJobJobsOnFinishedAt: migrating =====================
-- add_index(:good_jobs, [:active_job_id], {:name=>:index_good_jobs_on_active_job_id, :algorithm=>:concurrently})
[51234] 2022-03-23 22:27:36.462 DEBUG |    (34.3ms)  CREATE INDEX CONCURRENTLY "index_good_jobs_on_active_job_id" ON "good_jobs" ("active_job_id")
   -> 0.0364s
-- add_index(:good_jobs, [:finished_at], {:where=>"retried_good_job_id IS NULL AND finished_at IS NOT NULL", :name=>:index_good_jobs_jobs_on_finished_at, :algorithm=>:concurrently})
[51234] 2022-03-23 22:27:36.469 DEBUG |    (6.2ms)  CREATE INDEX CONCURRENTLY "index_good_jobs_jobs_on_finished_at" ON "good_jobs" ("finished_at") WHERE retried_good_job_id IS NULL AND finished_at IS NOT NULL
[51234] 2022-03-23 22:27:36.471 DEBUG |    (0.5ms)  SELECT pg_advisory_unlock(186062436696592260)
rails aborted!
StandardError: An error has occurred, all later migrations canceled:

PG::UndefinedColumn: ERROR:  column "retried_good_job_id" does not exist
LINE 1: ...finished_at" ON "good_jobs" ("finished_at") WHERE retried_go...
                                                             ^
/Users/katedonaldson/Projects/pieforproviders/db/migrate/20220324032731_index_good_job_jobs_on_finished_at.rb:19:in `change'
/Users/katedonaldson/Projects/pieforproviders/bin/rails:10:in `<top (required)>'
/Users/katedonaldson/Projects/pieforproviders/bin/spring:15:in `require'
/Users/katedonaldson/Projects/pieforproviders/bin/spring:15:in `<top (required)>'

Caused by:
ActiveRecord::StatementInvalid: PG::UndefinedColumn: ERROR:  column "retried_good_job_id" does not exist
LINE 1: ...finished_at" ON "good_jobs" ("finished_at") WHERE retried_go...
                                                             ^
/Users/katedonaldson/Projects/pieforproviders/db/migrate/20220324032731_index_good_job_jobs_on_finished_at.rb:19:in `change'
/Users/katedonaldson/Projects/pieforproviders/bin/rails:10:in `<top (required)>'
/Users/katedonaldson/Projects/pieforproviders/bin/spring:15:in `require'
/Users/katedonaldson/Projects/pieforproviders/bin/spring:15:in `<top (required)>'

Caused by:
PG::UndefinedColumn: ERROR:  column "retried_good_job_id" does not exist
LINE 1: ...finished_at" ON "good_jobs" ("finished_at") WHERE retried_go...
                                                             ^
/Users/katedonaldson/Projects/pieforproviders/db/migrate/20220324032731_index_good_job_jobs_on_finished_at.rb:19:in `change'
/Users/katedonaldson/Projects/pieforproviders/bin/rails:10:in `<top (required)>'
/Users/katedonaldson/Projects/pieforproviders/bin/spring:15:in `require'
/Users/katedonaldson/Projects/pieforproviders/bin/spring:15:in `<top (required)>'
Tasks: TOP => db:migrate
(See full trace by running task with --trace)

[bensheldon]

@katelovescode Nuts! Were you previously running GoodJob v1.x and upgraded to v2.x? If so, you'll need to upgrade to v1.99, run migrations, then upgrade to the latest 2.x release:

https://github.com/bensheldon/good_job#upgrading-v1-to-v2

I think that may be what happened because the retried_good_job_id was introduced in v1.13.0

[katelovescode]

Okay let me give that a try! I'll report back.

[katelovescode]

This worked, thank you!

[ianbradbury-bizzibody]

I also had this issue and the "fix" was very effective. Thanks.

[pjmartorell]

I have the same issue and it appears when migrating from GoodJob 1.x to 3.x in one go. I guess I will need to migrate it in 2 steps or change the order of migrations so they can be run in one go.

[pjmartorell]

I can confirm that reordering migrations and placing AddActiveJobIdIndexAndConcurrencyKeyIndexToGoodJobs migration after AddRetriedGoodJobIdToGoodJobs migration fixed the issue.