Upgrade from 4.15 to 5.8 failed DB migration on 5.8 schema error on geofenceids and fails to start

Stoyan2 years ago

Hello. I tried to upgrade from version 4.15 to 5.8 and had DB migration issues. It appears that migration 5.0-5.7 worked okay but there are errors on the last one. I tried starting 5.0-5.7 one by one and they all run fine so currently running 5.7. I can see another thread that discussed a similar issue but the error trace I have appears to be different but still related to
Can't DROP 'geofenceids'; check that column/key exists [Failed SQL: (1091) ALTER TABLE traccar.tc_devices DROP COLUMN geofenceids

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   timestamp   |                                                                                                       message                                                                                                        |
|---------------|----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| 1686782778191 | Running Changeset: changelog-5.8::changelog-5.8::author                                                                                                                                                              |
| 1686782778404 | Exception in thread "main" java.lang.RuntimeException: com.google.inject.ProvisionException: Unable to provision, see the following errors:                                                                          |
| 1686782778404 | 1) [Guice/ErrorInCustomProvider]: CommandExecutionException: LiquibaseException: MigrationFailedException: Migration failed for changeset changelog-5.8::changelog-5.8::author:                                      |
| 1686782778404 |      Reason: DatabaseException: Can't DROP 'geofenceids'; check that column/key exists [Failed SQL: (1091) ALTER TABLE traccar.tc_devices DROP COLUMN geofenceids]                                                   |
| 1686782778404 |   at DatabaseModule.provideDataSource(DatabaseModule.java:46)                                                                                                                                                        |
| 1686782778404 |   at DatabaseStorage.<init>(DatabaseStorage.java:48)                                                                                                                                                                 |
| 1686782778404 |       \_ for 2nd parameter                                                                                                                                                                                           |
| 1686782778404 |   while locating DatabaseStorage                                                                                                                                                                                     |
| 1686782778404 |   at MainModule.provideStorage(MainModule.java:120)                                                                                                                                                                  |
| 1686782778404 |   while locating Storage                                                                                                                                                                                             |
| 1686782778404 | Learn more:                                                                                                                                                                                                          |
| 1686782778404 |   https://github.com/google/guice/wiki/ERROR_IN_CUSTOM_PROVIDER                                                                                                                                                      |
| 1686782778404 | 1 error                                                                                                                                                                                                              |
| 1686782778404 | ======================                                                                                                                                                                                               |
| 1686782778404 | Full classname legend:                                                                                                                                                                                               |
| 1686782778404 | ======================                                                                                                                                                                                               |
| 1686782778404 | CommandExecutionException: "liquibase.exception.CommandExecutionException"                                                                                                                                           |
| 1686782778404 | DatabaseException:         "liquibase.exception.DatabaseException"                                                                                                                                                   |
| 1686782778404 | DatabaseModule:            "org.traccar.storage.DatabaseModule"                                                                                                                                                      |
| 1686782778404 | DatabaseStorage:           "org.traccar.storage.DatabaseStorage"                                                                                                                                                     |
| 1686782778404 | LiquibaseException:        "liquibase.exception.LiquibaseException"                                                                                                                                                  |
| 1686782778404 | MainModule:                "org.traccar.MainModule"                                                                                                                                                                  |
| 1686782778404 | MigrationFailedException:  "liquibase.exception.MigrationFailedException"                                                                                                                                            |
| 1686782778404 | Storage:                   "org.traccar.storage.Storage"                                                                                                                                                             |
| 1686782778404 | ========================                                                                                                                                                                                             |
| 1686782778404 | End of classname legend:                                                                                                                                                                                             |
| 1686782778404 | ========================                                                                                                                                                                                             |
| 1686782778404 |  at org.traccar.Main.run(Main.java:154)                                                                                                                                                                              |
| 1686782778404 |  at org.traccar.Main.main(Main.java:114)                                                                                                                                                                             |
| 1686782778407 | Caused by: com.google.inject.ProvisionException: Unable to provision, see the following errors:                                                                                                                      |
| 1686782778407 | 1) [Guice/ErrorInCustomProvider]: CommandExecutionException: LiquibaseException: MigrationFailedException: Migration failed for changeset changelog-5.8::changelog-5.8::author:                                      |
| 1686782778407 |      Reason: DatabaseException: Can't DROP 'geofenceids'; check that column/key exists [Failed SQL: (1091) ALTER TABLE traccar.tc_devices DROP COLUMN geofenceids]                                                   |
| 1686782778407 |   at DatabaseModule.provideDataSource(DatabaseModule.java:46)                                                                                                                                                        |
| 1686782778407 |   at DatabaseStorage.<init>(DatabaseStorage.java:48)                                                                                                                                                                 |
| 1686782778407 |       \_ for 2nd parameter                                                                                                                                                                                           |
| 1686782778407 |   while locating DatabaseStorage                                                                                                                                                                                     |
| 1686782778407 |   at MainModule.provideStorage(MainModule.java:120)                                                                                                                                                                  |
| 1686782778407 |   while locating Storage                                                                                                                                                                                             |
| 1686782778407 | Learn more:                                                                                                                                                                                                          |
| 1686782778407 |   https://github.com/google/guice/wiki/ERROR_IN_CUSTOM_PROVIDER                                                                                                                                                      |
| 1686782778407 | 1 error                                                                                                                                                                                                              |
| 1686782778407 | ======================                                                                                                                                                                                               |
| 1686782778407 | Full classname legend:                                                                                                                                                                                               |
| 1686782778407 | ======================                                                                                                                                                                                               |
| 1686782778407 | CommandExecutionException: "liquibase.exception.CommandExecutionException"                                                                                                                                           |
| 1686782778407 | DatabaseException:         "liquibase.exception.DatabaseException"                                                                                                                                                   |
| 1686782778407 | DatabaseModule:            "org.traccar.storage.DatabaseModule"                                                                                                                                                      |
| 1686782778407 | DatabaseStorage:           "org.traccar.storage.DatabaseStorage"                                                                                                                                                     |
| 1686782778407 | LiquibaseException:        "liquibase.exception.LiquibaseException"                                                                                                                                                  |
| 1686782778407 | MainModule:                "org.traccar.MainModule"                                                                                                                                                                  |
| 1686782778407 | MigrationFailedException:  "liquibase.exception.MigrationFailedException"                                                                                                                                            |
| 1686782778407 | Storage:                   "org.traccar.storage.Storage"                                                                                                                                                             |
| 1686782778407 | ========================                                                                                                                                                                                             |
| 1686782778407 | End of classname legend:                                                                                                                                                                                             |
| 1686782778407 | ========================                                                                                                                                                                                             |
| 1686782778407 |  at com.google.inject.internal.InternalProvisionException.toProvisionException(InternalProvisionException.java:251)                                                                                                  |
| 1686782778407 |  at com.google.inject.internal.InjectorImpl$1.get(InjectorImpl.java:1151)                                                                                                                                            |
| 1686782778407 |  at com.google.inject.internal.InjectorImpl.getInstance(InjectorImpl.java:1186)                                                                                                                                      |
| 1686782778407 |  at org.traccar.Main.run(Main.java:126)                                                                                                                                                                              |
| 1686782778407 |  ... 1 more                                                                                                                                                                                                          |
| 1686782778407 | Caused by: liquibase.exception.CommandExecutionException: liquibase.exception.LiquibaseException: liquibase.exception.MigrationFailedException: Migration failed for changeset changelog-5.8::changelog-5.8::author: |
| 1686782778407 |      Reason: liquibase.exception.DatabaseException: Can't DROP 'geofenceids'; check that column/key exists [Failed SQL: (1091) ALTER TABLE traccar.tc_devices DROP COLUMN geofenceids]                               |
| 1686782778407 |  at liquibase.command.CommandScope.execute(CommandScope.java:235)                                                                                                                                                    |
| 1686782778407 |  at liquibase.Liquibase.lambda$update$0(Liquibase.java:237)                                                                                                                                                          |
| 1686782778407 |  at liquibase.Scope.lambda$child$0(Scope.java:194)                                                                                                                                                                   |
| 1686782778407 |  at liquibase.Scope.child(Scope.java:203)                                                                                                                                                                            |
| 1686782778407 |  at liquibase.Scope.child(Scope.java:193)                                                                                                                                                                            |
| 1686782778407 |  at liquibase.Scope.child(Scope.java:172)                                                                                                                                                                            |
| 1686782778407 |  at liquibase.Liquibase.runInScope(Liquibase.java:1605)                                                                                                                                                              |
| 1686782778407 |  at liquibase.Liquibase.update(Liquibase.java:229)                                                                                                                                                                   |
| 1686782778407 |  at liquibase.Liquibase.update(Liquibase.java:213)                                                                                                                                                                   |
| 1686782778407 |  at liquibase.Liquibase.update(Liquibase.java:198)                                                                                                                                                                   |
| 1686782778407 |  at org.traccar.storage.DatabaseModule.provideDataSource(DatabaseModule.java:96)                                                                                                                                     |
| 1686782778407 |  at org.traccar.storage.DatabaseModule$$FastClassByGuice$$1be764.GUICE$TRAMPOLINE(<generated>)                                                                                                                       |
| 1686782778407 |  at org.traccar.storage.DatabaseModule$$FastClassByGuice$$1be764.apply(<generated>)                                                                                                                                  |
| 1686782778407 |  at com.google.inject.internal.ProviderMethod$FastClassProviderMethod.doProvision(ProviderMethod.java:260)                                                                                                           |
| 1686782778407 |  at com.google.inject.internal.ProviderMethod.doProvision(ProviderMethod.java:171)                                                                                                                                   |
| 1686782778407 |  at com.google.inject.internal.InternalProviderInstanceBindingImpl$CyclicFactory.provision(InternalProviderInstanceBindingImpl.java:185)                                                                             |
| 1686782778407 |  at com.google.inject.internal.InternalProviderInstanceBindingImpl$CyclicFactory.get(InternalProviderInstanceBindingImpl.java:162)                                                                                   |
| 1686782778407 |  at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)                                                                                                        |
| 1686782778407 |  at com.google.inject.internal.SingletonScope$1.get(SingletonScope.java:169)                                                                                                                                         |
| 1686782778407 |  at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:45)                                                                                                        |
| 1686782778407 |  at com.google.inject.internal.SingleParameterInjector.inject(SingleParameterInjector.java:40)                                                                                                                       |
| 1686782778407 |  at com.google.inject.internal.SingleParameterInjector.getAll(SingleParameterInjector.java:60)                                                                                                                       |
| 1686782778407 |  at com.google.inject.internal.ConstructorInjector.provision(ConstructorInjector.java:113)                                                                                                                           |
| 1686782778407 |  at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:91)                                                                                                                            |
| 1686782778407 |  at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:300)                                                                                                                   |
| 1686782778407 |  at com.google.inject.internal.InjectorImpl$1.get(InjectorImpl.java:1148)                                                                                                                                            |
| 1686782778407 |  at com.google.inject.internal.InjectorImpl.getInstance(InjectorImpl.java:1186)                                                                                                                                      |
| 1686782778407 |  at org.traccar.MainModule.provideStorage(MainModule.java:123)                                                                                                                                                       |
| 1686782778407 |  at org.traccar.MainModule$$FastClassByGuice$$f604a.GUICE$TRAMPOLINE(<generated>)                                                                                                                                    |
| 1686782778407 |  at org.traccar.MainModule$$FastClassByGuice$$f604a.apply(<generated>)                                                                                                                                               |
| 1686782778407 |  at com.google.inject.internal.ProviderMethod$FastClassProviderMethod.doProvision(ProviderMethod.java:260)                                                                                                           |
| 1686782778407 |  at com.google.inject.internal.ProviderMethod.doProvision(ProviderMethod.java:171)                                                                                                                                   |
| 1686782778407 |  at com.google.inject.internal.InternalProviderInstanceBindingImpl$CyclicFactory.provision(InternalProviderInstanceBindingImpl.java:185)                                                                             |
| 1686782778407 |  at com.google.inject.internal.InternalProviderInstanceBindingImpl$CyclicFactory.get(InternalProviderInstanceBindingImpl.java:162)                                                                                   |
| 1686782778407 |  at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)                                                                                                        |
| 1686782778407 |  at com.google.inject.internal.SingletonScope$1.get(SingletonScope.java:169)                                                                                                                                         |
| 1686782778407 |  at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:45)                                                                                                        |
| 1686782778407 |  at com.google.inject.internal.InjectorImpl$1.get(InjectorImpl.java:1148)                                                                                                                                            |
| 1686782778407 |  ... 3 more                                                                                                                                                                                                          |
| 1686782778407 | Caused by: liquibase.exception.LiquibaseException: liquibase.exception.MigrationFailedException: Migration failed for changeset changelog-5.8::changelog-5.8::author:                                                |
| 1686782778408 |      Reason: liquibase.exception.DatabaseException: Can't DROP 'geofenceids'; check that column/key exists [Failed SQL: (1091) ALTER TABLE traccar.tc_devices DROP COLUMN geofenceids]                               |
| 1686782778408 |  at liquibase.changelog.ChangeLogIterator.run(ChangeLogIterator.java:121)                                                                                                                                            |
| 1686782778408 |  at liquibase.command.core.AbstractUpdateCommandStep.lambda$run$0(AbstractUpdateCommandStep.java:103)                                                                                                                |
| 1686782778408 |  at liquibase.Scope.lambda$child$0(Scope.java:194)                                                                                                                                                                   |
| 1686782778408 |  at liquibase.Scope.child(Scope.java:203)                                                                                                                                                                            |
| 1686782778408 |  at liquibase.Scope.child(Scope.java:193)                                                                                                                                                                            |
| 1686782778408 |  at liquibase.Scope.child(Scope.java:172)                                                                                                                                                                            |
| 1686782778408 |  at liquibase.command.core.AbstractUpdateCommandStep.run(AbstractUpdateCommandStep.java:100)                                                                                                                         |
| 1686782778408 |  at liquibase.command.CommandScope.execute(CommandScope.java:212)                                                                                                                                                    |
| 1686782778408 |  ... 40 more                                                                                                                                                                                                         |
| 1686782778408 | Caused by: liquibase.exception.MigrationFailedException: Migration failed for changeset changelog-5.8::changelog-5.8::author:                                                                                        |
| 1686782778408 |      Reason: liquibase.exception.DatabaseException: Can't DROP 'geofenceids'; check that column/key exists [Failed SQL: (1091) ALTER TABLE traccar.tc_devices DROP COLUMN geofenceids]                               |
| 1686782778408 |  at liquibase.changelog.ChangeSet.execute(ChangeSet.java:759)                                                                                                                                                        |
| 1686782778408 |  at liquibase.changelog.visitor.UpdateVisitor.visit(UpdateVisitor.java:61)                                                                                                                                           |
| 1686782778409 |  at liquibase.changelog.ChangeLogIterator$2.lambda$null$0(ChangeLogIterator.java:109)                                                                                                                                |
| 1686782778409 |  at liquibase.Scope.lambda$child$0(Scope.java:194)                                                                                                                                                                   |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:203)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:193)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:172)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.changelog.ChangeLogIterator$2.lambda$run$1(ChangeLogIterator.java:109)                                                                                                                                 |
| 1686782778409 |  at liquibase.Scope.lambda$child$0(Scope.java:194)                                                                                                                                                                   |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:203)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:193)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:172)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:260)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.changelog.ChangeLogIterator$2.run(ChangeLogIterator.java:92)                                                                                                                                           |
| 1686782778409 |  at liquibase.Scope.lambda$child$0(Scope.java:194)                                                                                                                                                                   |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:203)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:193)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:172)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:260)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.Scope.child(Scope.java:264)                                                                                                                                                                            |
| 1686782778409 |  at liquibase.changelog.ChangeLogIterator.run(ChangeLogIterator.java:66)                                                                                                                                             |
| 1686782778409 |  ... 47 more                                                                                                                                                                                                         |
| 1686782778409 | Caused by: liquibase.exception.DatabaseException: Can't DROP 'geofenceids'; check that column/key exists [Failed SQL: (1091) ALTER TABLE traccar.tc_devices DROP COLUMN geofenceids]                                 |
| 1686782778409 |  at liquibase.executor.jvm.JdbcExecutor$ExecuteStatementCallback.doInStatement(JdbcExecutor.java:445)                                                                                                                |
| 1686782778409 |  at liquibase.executor.jvm.JdbcExecutor.execute(JdbcExecutor.java:77)                                                                                                                                                |
| 1686782778409 |  at liquibase.executor.jvm.JdbcExecutor.execute(JdbcExecutor.java:160)                                                                                                                                               |
| 1686782778409 |  at liquibase.database.AbstractJdbcDatabase.execute(AbstractJdbcDatabase.java:1287)                                                                                                                                  |
| 1686782778409 |  at liquibase.database.AbstractJdbcDatabase.executeStatements(AbstractJdbcDatabase.java:1269)                                                                                                                        |
| 1686782778409 |  at liquibase.changelog.ChangeSet.execute(ChangeSet.java:717)                                                                                                                                                        |
| 1686782778409 |  ... 67 more                                                                                                                                                                                                         |
| 1686782778409 | Caused by: java.sql.SQLSyntaxErrorException: Can't DROP 'geofenceids'; check that column/key exists                                                                                                                  |
| 1686782778409 |  at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:121)                                                                                                                                      |
| 1686782778409 |  at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)                                                                                                              |
| 1686782778409 |  at com.mysql.cj.jdbc.StatementImpl.executeInternal(StatementImpl.java:763)                                                                                                                                          |
| 1686782778409 |  at com.mysql.cj.jdbc.StatementImpl.execute(StatementImpl.java:648)                                                                                                                                                  |
| 1686782778409 |  at liquibase.executor.jvm.JdbcExecutor$ExecuteStatementCallback.doInStatement(JdbcExecutor.java:441)                                                                                                                |
| 1686782778409 |  ... 72 more                                                                                                                                                                                                         |
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Anton Tananaev2 years ago

This error message probably means that you're already tried running it once and it failed. Did you have to release the database lock after the first upgrade attempt?

Stoyan2 years ago

Thank you so much for the quick reply. I did have to do that yes. The problem is that the initial 4.15 to 5.8 migration was not verbose and did not spit any errors.

---------------------------------------------------------------------------
|   timestamp   |                         message                         |
|---------------|---------------------------------------------------------|
| 1686779541311 | Running Changeset: changelog-5.0::changelog-5.0::author |
| 1686779541855 | Running Changeset: changelog-5.1::changelog-5.1::author |
| 1686779542120 | Running Changeset: changelog-5.2::changelog-5.2::author |
| 1686779542347 | Running Changeset: changelog-5.3::changelog-5.3::author |
| 1686779542808 | Running Changeset: changelog-5.4::changelog-5.4::author |
| 1686779543069 | Running Changeset: changelog-5.5::changelog-5.5::author |
| 1686779543119 | Running Changeset: changelog-5.6::changelog-5.6::author |
| 1686779543633 | Running Changeset: changelog-5.7::changelog-5.7::author |
| 1686779543808 | Running Changeset: changelog-5.8::changelog-5.8::author |
---------------------------------------------------------------------------

It is possible my health check nuked the container after 5 minutes and interrupted the DB migration. Then it was complaining about the lock so I removed the lock. Then I started from 5.0 and all the migrations were either successful of were there from the 5.8 migration. Each version I ran independently was speedy so I doubt it'll need 5 minutes. Do you reckon there is a way to repair the DB schema so the 5.7 to 5.8 migration succeeds or am I looking at a DB restore?

Anton Tananaev2 years ago

Migration from 5.7 to 5.8 will take a long time because it modifies positions table.

Stoyan2 years ago

I guess restoring the DB and going again without interrupting the migration is my only option in this case. Thank you for your help.

Anton Tananaev2 years ago

You can also do migrations yourself, but you need to know what's failed and what you need to do. Restoring and rerunning is definitely easier.

Stoyan2 years ago

For any future references and people searching, there were 2 issues with the initial upgrade I ran:

  1. My DB ran out of disk space as the migration from 5.7 to 5.8 seems to require as much free space as you are currently using for data (for me it was ~22GB). I made sure I have at least double what I'm using this time around.
  2. My health check killed my service (docker) before it would have finished as it takes quite a while. It took ~15 min for the amount of data I had.
    It might be a good idea to document both the time requirement and the space requirement on the DB. I had over-provisioned so I had ~65% utilisation which is extremely low and the migration still crashed. If this is not a requirement and it will just use any available space, that's fine but I didn't want to risk it as it's quite involved to do a roll-back.
    I am currently successfully upgraded to 5.8.
Anton Tananaev2 years ago

The behavior basically depends on the database engine you're using. MySQL will copy the whole positions table when we add a new column. Some other databases might not.

Gps mana year ago

https://dev.mysql.com/blog-archive/mysql-8-0-innodb-now-supports-instant-add-column/ -- I understand that now INSTANT is supported. Does it not work while adding this new column in positions table.

My positions table is more then 1.5 TB.

Any help

Anton Tananaeva year ago

Depends on the database version and configuration.

Gps mana year ago

I m using mysql 8.0.33..... any suggestions to get this execution thru without allotting double space to the db as i see you mentioned that mysql copies the table when we add new column.

Stoyana year ago

When I upgraded last year I was running MySQL 5.7 on RDS.

Gps mana year ago

No it happens in zippy…. So even large table adding column works fine