Skip to content

migrate: Print execution time of migrations

Will Chandler (ex-GitLab) requested to merge wc-praefect-migrat-print into master

Debugging slow migrations, as in issue #3973 (closed) is difficult because there is no indication which migration is being run. Admins will need to check pg_stat_activity, then search the Gitaly source for that query to find out which migration is misbehaving.

This MR updates the sql-migrate subcommand to execute migrations one by one and displays their execution times.

This requires a bit of work as the Exec API exposed by sql-migrate does not provide a simple way to execute only one migration. The obvious option of passing a slice with a single migration does not work due to how ToApply() works. If current is not empty, which will be when one or more migrations are up, then it will iterate over the migration slice until current is found, returning the remainder of the migrations. If current is not present in the slice, then an empty slice is returned and the target migration is not executed.

To work around this, we include all migrations prior to the target migration in the slice, ensuring that the current migration is present.

Example output:

praefect sql-migrate: migrations to apply: 3

=  2022-02-01T17:01:37 20211025113445_remove_cancelled_replication_events: migrating
== 2022-02-01T17:01:37 20211025113445_remove_cancelled_replication_events: applied (9.010133ms)
=  2022-02-01T17:01:37 20211105100456_check_non_null_repository_id: migrating
== 2022-02-01T17:01:37 20211105100456_check_non_null_repository_id: applied (8.423652ms)
=  2022-02-01T17:01:37 20211105100458_non_nullable_repository_id: migrating
== 2022-02-01T17:01:37 20211105100458_non_nullable_repository_id: applied (12.438743ms)

praefect sql-migrate: OK (applied 3 migrations)

Also, add a -verbose flag for sql-migrate to print the statement being executed for each migration.

Example output:

=  2022-02-01T16:00:56 20200109161404_hello_world: migrating
        [CREATE TABLE hello_world (id integer)]
== 2022-02-01T16:00:56 20200109161404_hello_world: applied (9.525348ms)
Edited by Will Chandler (ex-GitLab)

Merge request reports

Loading