server icon indicating copy to clipboard operation
server copied to clipboard

Error with `emergency_access_invitations` db migration

Open jnware opened this issue 1 year ago • 3 comments

After updating my self-hosted docker instance using the latest ("v2") paradigm, my containers entered an infinite loop trying to start up and crashing.

I was able to track it down to a pair of initial errors in the auth.log

  1. First it creates emergency_access_invitations as a new table per the 1680597887475 migration. This then fails at the ALTER TABLE step to add the grantor foreign key.
  2. Then it tries to roll back and the container reboots, and it tries migrations again. This time it fails because it's trying to create emergency_access_invitations which already exists.

Note: For brevity, I truncated the list of migrations to just the last few starting with the one my logs report as being the most recent completed migration; but the rest of the log context is in tact.

localhost:3101 is up. Proceeding to startup.
query: SELECT VERSION() AS `version`
info: All classes found using provided glob pattern "...TRUNCATED...,dist/migrations/mysql/1678340701766-remove-authenticator-names-from-server.js,dist/migrations/mysql/1680597887475-emergency-access-invitations.js,dist/migrations/mysql/1681984540867-enable-u2f.js,dist/migrations/mysql/1682926032072-cache-entries.js,dist/migrations/mysql/1683017908845-change-cache-table-name.js"
query: SELECT * FROM `INFORMATION_SCHEMA`.`COLUMNS` WHERE `TABLE_SCHEMA` = 'standard_notes_db' AND `TABLE_NAME` = 'migrations'
query: SELECT * FROM `standard_notes_db`.`migrations` `migrations` ORDER BY `id` DESC
92 migrations are already loaded in the database.
79 migrations were found in the source code.
removeAuthenticatorNamesFromServer1678340701766 is the last executed migration. It was executed on Thu Mar 09 2023 05:45:01 GMT+0000 (Coordinated Universal Time).
4 migrations are new migrations must be executed.
query: START TRANSACTION
query: CREATE TABLE `emergency_access_invitations` (`uuid` varchar(36) NOT NULL, `grantor_uuid` varchar(36) NOT NULL, `grantee_uuid` varchar(36) NOT NULL, `status` varchar(36) NOT NULL, `expires_at` datetime NOT NULL, `created_at` datetime NOT NULL, `updated_at` datetime NOT NULL, PRIMARY KEY (`uuid`)) ENGINE=InnoDB
query: ALTER TABLE `emergency_access_invitations` ADD CONSTRAINT `grantor_uuid_fk` FOREIGN KEY (`grantor_uuid`) REFERENCES `users`(`uuid`) ON DELETE CASCADE ON UPDATE NO ACTION
query failed: ALTER TABLE `emergency_access_invitations` ADD CONSTRAINT `grantor_uuid_fk` FOREIGN KEY (`grantor_uuid`) REFERENCES `users`(`uuid`) ON DELETE CASCADE ON UPDATE NO ACTION
error: Error: Referencing column 'grantor_uuid' and referenced column 'uuid' in foreign key constraint 'grantor_uuid_fk' are incompatible.
query: ROLLBACK
localhost:3101 is up. Proceeding to startup.
query: SELECT VERSION() AS `version`
info: All classes found using provided glob pattern "dist/migrations/mysql/*.js" : "...TRUNCATED...,dist/migrations/mysql/1678340701766-remove-authenticator-names-from-server.js,dist/migrations/mysql/1680597887475-emergency-access-invitations.js,dist/migrations/mysql/1681984540867-enable-u2f.js,dist/migrations/mysql/1682926032072-cache-entries.js,dist/migrations/mysql/1683017908845-change-cache-table-name.js"
query: SELECT * FROM `INFORMATION_SCHEMA`.`COLUMNS` WHERE `TABLE_SCHEMA` = 'standard_notes_db' AND `TABLE_NAME` = 'migrations'
query: SELECT * FROM `standard_notes_db`.`migrations` `migrations` ORDER BY `id` DESC
92 migrations are already loaded in the database.
79 migrations were found in the source code.
removeAuthenticatorNamesFromServer1678340701766 is the last executed migration. It was executed on Thu Mar 09 2023 05:45:01 GMT+0000 (Coordinated Universal Time).
4 migrations are new migrations must be executed.
query: START TRANSACTION
query: CREATE TABLE `emergency_access_invitations` (`uuid` varchar(36) NOT NULL, `grantor_uuid` varchar(36) NOT NULL, `grantee_uuid` varchar(36) NOT NULL, `status` varchar(36) NOT NULL, `expires_at` datetime NOT NULL, `created_at` datetime NOT NULL, `updated_at` datetime NOT NULL, PRIMARY KEY (`uuid`)) ENGINE=InnoDB
query failed: CREATE TABLE `emergency_access_invitations` (`uuid` varchar(36) NOT NULL, `grantor_uuid` varchar(36) NOT NULL, `grantee_uuid` varchar(36) NOT NULL, `status` varchar(36) NOT NULL, `expires_at` datetime NOT NULL, `created_at` datetime NOT NULL, `updated_at` datetime NOT NULL, PRIMARY KEY (`uuid`)) ENGINE=InnoDB
error: Error: Table 'emergency_access_invitations' already exists
query: ROLLBACK

jnware avatar May 06 '23 01:05 jnware

Maybe this could help: https://github.com/standardnotes/server/issues/532

karolsojko avatar May 08 '23 06:05 karolsojko

Thanks, @karolsojko. It looks like I only searched open issues and not closed as I didn't find this one.

It does seem to be the same or similar issue. However, I don't see that the migration was ever fixed. It was closed with the workaround being to revert to an earlier image. The workaround of removing/rebuilding the table and adding a row looks like it doesn't actually work. Then the issue was closed.

jnware avatar May 08 '23 13:05 jnware

Nevermind, your suggested command did work to get the migration to finish:

    docker compose exec db sh -c "MYSQL_PWD=\$MYSQL_ROOT_PASSWORD mysql \$MYSQL_DATABASE -e \
      'INSERT INTO migrations (timestamp, name) VALUES (1680597887475, \"emergencyAccessInvitations1680597887475\");' \
    "

It seems like the migration itself still needs to be fixed. Also probably they need something like "if not exist" in the migration so that it can recover from a partially completed migration.

jnware avatar May 09 '23 18:05 jnware