docspell
docspell copied to clipboard
eikek
Database upgrade from 0.32.0 fails
Hei there,
I didn't update my instance for a while and sat on v0.32.0. I read all the release notes and the DB migration issue from 0.32.0 to 0.33.0 and understood that it was solved in 0.34.0, so I tried to go to 0.38.0 right away.
Sadly, the migration to the new file ids seems to fail on me for a different reason than mentioned before in #1436. I get the following error and I get it for an upgrade to 0.33.0, 0.34.0 or 0.38.0:
Jul 23, 2022 12:08:37 AM org.jline.utils.Log logr
WARNING: Unable to create a system terminal, creating a dumb terminal (enable debug logging for more information)
2022.07.23 00:08:37:681 io-compute-4 INFO docspell.config.ConfigFactory.default:44
Using config from environment variables!
2022.07.23 00:08:38:0000 [io-comp...] [INFO ] docspell.restserver.Main.run:33 -
***> ______ _ _
***> | _ \ | | |
***> | | | |___ ___ ___ _ __ ___| | |
***> | | | / _ \ / __/ __| '_ \ / _ \ | |
***> | |/ / (_) | (__\__ \ |_) | __/ | |
***> |___/ \___/ \___|___/ .__/ \___|_|_|
***> | |
***> |_| v0.33.0 (#aafa73e7)
***> << REST Server >>
***> Id: rest1
***> Base-Url: http://localhost:7880
***> Database: jdbc:postgresql://db:5432/dbname
***> Fts: http://docspell-solr:8983/solr/docspell
***> Config:
***>
2022.07.23 00:08:39:0000 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate - Running db migrations...
2022.07.23 00:08:39:0001 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate - Using migration locations: List(classpath:db/migration/postgresql, classpath:db/migration/common)
2022.07.23 00:08:39:0002 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - Flyway Community Edition 8.5.2 by Redgate
2022.07.23 00:08:39:0003 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.2
2022.07.23 00:08:39:0004 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter -
2022.07.23 00:08:39:0005 [io-comp...] [INFO ] org.flywaydb.core.internal.database.base.BaseDatabaseType - Database: jdbc:postgresql://db:5432/dbname (PostgreSQL 13.4)
2022.07.23 00:08:39:0006 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbValidate - Successfully validated 57 migrations (execution time 00:00.065s)
2022.07.23 00:08:39:0007 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbMigrate - Current version of schema "public": 1.32.2
2022.07.23 00:08:39:0008 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbMigrate - Migrating schema "public" to version "1.33.0 - reorganize file ids"
2022.07.23 00:08:39:0009 [io-comp...] [INFO ] org.flywaydb.core.internal.sqlscript.DefaultSqlScriptExecutor - DB: table "file_migration_temp" does not exist, skipping
2022.07.23 00:08:44:0000 [io-comp...] [ERROR] org.flywaydb.core.internal.command.DbMigrate - Migration of schema "public" to version "1.33.0 - reorganize file ids" failed! Changes successfully rolled back.
org.flywaydb.core.internal.command.DbMigrate$FlywayMigrateException: Migration V1.33.0__reorganize_file_ids.sql failed
-------------------------------------------------
SQL State : 23505
Error Code : 0
Message : ERROR: duplicate key value violates unique constraint "file_migration_temp_original_file_key"
Detail: Key (original_file)=(4w5aJANWpxNrVVkAJRwuFLyr37FqPy5fLyrEzX7hNtgG) already exists.
Location : db/migration/postgresql/V1.33.0__reorganize_file_ids.sql (/opt/file:/opt/docspell-restserver-0.33.0/lib/com.github.eikek.docspell-store-0.33.0.jar!/db/migration/postgresql/V1.33.0__reorganize_file_ids.sql)
Line : 11
Statement : -- Source files
insert into file_migration_temp (original_file, cid, category, new_file)
select
rs.file_id as original_file,
i.cid,
'attachmentsource' as category,
i.cid || '/attachmentsource/' || rs.file_id as new_file
from attachment_source rs
inner join attachment ra on rs.id = ra.attachid
inner join item i on ra.itemid = i.itemid
at org.flywaydb.core.internal.command.DbMigrate.doMigrateGroup(DbMigrate.java:385)
at org.flywaydb.core.internal.command.DbMigrate.lambda$applyMigrations$1(DbMigrate.java:275)
at org.flywaydb.core.internal.jdbc.TransactionalExecutionTemplate.execute(TransactionalExecutionTemplate.java:55)
at org.flywaydb.core.internal.command.DbMigrate.applyMigrations(DbMigrate.java:274)
at org.flywaydb.core.internal.command.DbMigrate.migrateGroup(DbMigrate.java:247)
at org.flywaydb.core.internal.command.DbMigrate.lambda$migrateAll$0(DbMigrate.java:141)
at org.flywaydb.core.internal.database.postgresql.PostgreSQLAdvisoryLockTemplate.execute(PostgreSQLAdvisoryLockTemplate.java:69)
at org.flywaydb.core.internal.database.postgresql.PostgreSQLConnection.lock(PostgreSQLConnection.java:99)
at org.flywaydb.core.internal.schemahistory.JdbcTableSchemaHistory.lock(JdbcTableSchemaHistory.java:139)
at org.flywaydb.core.internal.command.DbMigrate.migrateAll(DbMigrate.java:141)
at org.flywaydb.core.internal.command.DbMigrate.migrate(DbMigrate.java:98)
at org.flywaydb.core.Flyway$1.execute(Flyway.java:172)
at org.flywaydb.core.Flyway$1.execute(Flyway.java:124)
at org.flywaydb.core.FlywayExecutor.execute(FlywayExecutor.java:205)
at org.flywaydb.core.Flyway.migrate(Flyway.java:124)
at docspell.store.migrate.FlywayMigrate$.$anonfun$run$1(FlywayMigrate.scala:41)
at delay @ docspell.store.migrate.FlywayMigrate$.run(FlywayMigrate.scala:21)
at map @ docspell.store.impl.StoreImpl.migrate(StoreImpl.scala:31)
Caused by: org.flywaydb.core.internal.sqlscript.FlywaySqlScriptException: Migration V1.33.0__reorganize_file_ids.sql failed
-------------------------------------------------
SQL State : 23505
Error Code : 0
Message : ERROR: duplicate key value violates unique constraint "file_migration_temp_original_file_key"
Detail: Key (original_file)=(4w5aJANWpxNrVVkAJRwuFLyr37FqPy5fLyrEzX7hNtgG) already exists.
Location : db/migration/postgresql/V1.33.0__reorganize_file_ids.sql (/opt/file:/opt/docspell-restserver-0.33.0/lib/com.github.eikek.docspell-store-0.33.0.jar!/db/migration/postgresql/V1.33.0__reorganize_file_ids.sql)
Line : 11
Statement : -- Source files
insert into file_migration_temp (original_file, cid, category, new_file)
select
rs.file_id as original_file,
i.cid,
'attachmentsource' as category,
i.cid || '/attachmentsource/' || rs.file_id as new_file
from attachment_source rs
inner join attachment ra on rs.id = ra.attachid
inner join item i on ra.itemid = i.itemid
at org.flywaydb.core.internal.sqlscript.DefaultSqlScriptExecutor.handleException(DefaultSqlScriptExecutor.java:275)
at org.flywaydb.core.internal.sqlscript.DefaultSqlScriptExecutor.executeStatement(DefaultSqlScriptExecutor.java:222)
at org.flywaydb.core.internal.sqlscript.DefaultSqlScriptExecutor.execute(DefaultSqlScriptExecutor.java:126)
at org.flywaydb.core.internal.resolver.sql.SqlMigrationExecutor.executeOnce(SqlMigrationExecutor.java:69)
at org.flywaydb.core.internal.resolver.sql.SqlMigrationExecutor.lambda$execute$0(SqlMigrationExecutor.java:58)
at org.flywaydb.core.internal.database.DefaultExecutionStrategy.execute(DefaultExecutionStrategy.java:27)
at org.flywaydb.core.internal.resolver.sql.SqlMigrationExecutor.execute(SqlMigrationExecutor.java:57)
at org.flywaydb.core.internal.command.DbMigrate.doMigrateGroup(DbMigrate.java:377)
at org.flywaydb.core.internal.command.DbMigrate.lambda$applyMigrations$1(DbMigrate.java:275)
at org.flywaydb.core.internal.jdbc.TransactionalExecutionTemplate.execute(TransactionalExecutionTemplate.java:55)
at org.flywaydb.core.internal.command.DbMigrate.applyMigrations(DbMigrate.java:274)
at org.flywaydb.core.internal.command.DbMigrate.migrateGroup(DbMigrate.java:247)
at org.flywaydb.core.internal.command.DbMigrate.lambda$migrateAll$0(DbMigrate.java:141)
at org.flywaydb.core.internal.database.postgresql.PostgreSQLAdvisoryLockTemplate.execute(PostgreSQLAdvisoryLockTemplate.java:69)
at org.flywaydb.core.internal.database.postgresql.PostgreSQLConnection.lock(PostgreSQLConnection.java:99)
at org.flywaydb.core.internal.schemahistory.JdbcTableSchemaHistory.lock(JdbcTableSchemaHistory.java:139)
at org.flywaydb.core.internal.command.DbMigrate.migrateAll(DbMigrate.java:141)
at org.flywaydb.core.internal.command.DbMigrate.migrate(DbMigrate.java:98)
at org.flywaydb.core.Flyway$1.execute(Flyway.java:172)
at org.flywaydb.core.Flyway$1.execute(Flyway.java:124)
at org.flywaydb.core.FlywayExecutor.execute(FlywayExecutor.java:205)
at org.flywaydb.core.Flyway.migrate(Flyway.java:124)
at docspell.store.migrate.FlywayMigrate$.$anonfun$run$1(FlywayMigrate.scala:41)
at cats.effect.IOFiber.runLoop(IOFiber.scala:358)
at cats.effect.IOFiber.execR(IOFiber.scala:1327)
at cats.effect.IOFiber.run(IOFiber.scala:139)
at cats.effect.unsafe.WorkerThread.run(WorkerThread.scala:461)
Caused by: org.postgresql.util.PSQLException: ERROR: duplicate key value violates unique constraint "file_migration_temp_original_file_key"
Detail: Key (original_file)=(4w5aJANWpxNrVVkAJRwuFLyr37FqPy5fLyrEzX7hNtgG) already exists.
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2675)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2365)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:355)
at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:490)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:408)
at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:329)
at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:315)
at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:291)
at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:286)
at org.flywaydb.core.internal.jdbc.JdbcTemplate.executeStatement(JdbcTemplate.java:201)
at org.flywaydb.core.internal.sqlscript.ParsedSqlStatement.execute(ParsedSqlStatement.java:95)
at org.flywaydb.core.internal.sqlscript.DefaultSqlScriptExecutor.executeStatement(DefaultSqlScriptExecutor.java:210)
... 25 more
The container then restarts and the same error occurs again.
The database seems to be still intact, since it still works with 0.32.0. Which is good news.
Some more info:
- I deploy Docspell on Docker
- I have a database dump from before any of the tried upgrades.
I hope this is enough information to get started and thanks for looking into this in advance!
Hi @davidclemens this is indeed a different problem than in the issue. THere seem to be duplicate references to files. Could you run this sql statement to see how many of them exist:
select file_id, count(id) from attachment_source group by file_id having count(id) > 1;
and maybe also for the other tables:
select filemetaid, count(attachid) from attachment group by filemetaid having count(attachid) > 1;
select file_id, count(id) from attachment_preview group by file_id having count(id) > 1;
If there are only a few, I think we should trace them to the respective item, it could be that one is orphaned (then we could delete it).
Wow, thanks for the ever swift response. So for the three queries I got the following outputs respectively:
file_id | count
----------------------------------------------+-------
4w5aJANWpxNrVVkAJRwuFLyr37FqPy5fLyrEzX7hNtgG | 2
(1 row)
filemetaid | count
------------+-------
(0 rows)
filemetaid | count
------------+-------
(0 rows)
It seems to be as you expected and only 1 Id is used twice. The Id also matches the error log from above. I'd be glad if you'd help me trace it down.
That looks not bad, at least it's just one! We can check all affected items with this query:
select a.attachid,a.itemid,s.file_id
from attachment_source s
inner join attachment a on a.attachid = s.id
where s.file_id = '4w5aJANWpxNrVVkAJRwuFLyr37FqPy5fLyrEzX7hNtgG';
you can use the itemid in the ui to look at the items (if you are on an item detail page, replace the last part in the url with an itemid from the result).
Thanks a million. I found the item in question and solved the issue. Here's how:
The item with itemid had 4 attachments. Two of the attachments were the same file - A.converted.pdf and A.converted.converted.pdf, where A is a placeholder name. I'm not sure, how I ended up with the reproscessed attachment. But after removing the A.converted.converted.pdf attachment, the duplicate file_id was gone and the upgrade from 0.32.0 to 0.38.0 worked out just fine.
I'm not sure if this happened due to some edge case issue. I added the item in January this year and don't really remember what I did there. I know that sometimes I attached a file and the preview thumbnail was missing (see screenshot) and I clicked to reprocess the attachment with the intention of the thumbnail being generated. Maybe that would have something to do with it?
Anyways. I'm glad I could do the upgrade now. Thanks for your swift help once again!
Great that it worked out! The reason for this duplicate is interesting. I currently have no good idea. But I'll try to reproduce it via the reprocessing as you said. Thanks for the hint!
A missing preview can have a few reasons. If you attach another file to an existing item, it might take a while until it is procesed and until then it shows this placeholder image. But some files are not able to create a preview for, for example all that could not be converted into a pdf.