Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Checksum mismatch in db migration #1517

Closed
eikek opened this issue Apr 16, 2022 · 39 comments
Closed

Checksum mismatch in db migration #1517

eikek opened this issue Apr 16, 2022 · 39 comments
Labels
bug Something isn't working or in unexpected ways docker All things regarding docker setup

Comments

@eikek
Copy link
Owner

eikek commented Apr 16, 2022

Spin off from issue #1488 it's better to have a separate issue. It seems to be a longer journey sadly. Context: #1488 (comment) and following comments.

@enkol Can you post me the full logs (from the start)? What is irritating is that 1.34.0 is not part of the fixup changesets. So changing the table flyway_fixup_history can only have an effect on the single fixup migration that is included.

@enkol
Copy link

enkol commented Apr 16, 2022

Coming from a running v0.34.0 and changing to v0.35.0 results in:

Apr 16, 2022 3:26:36 PM org.jline.utils.Log logr
WARNING: Unable to create a system terminal, creating a dumb terminal (enable debug logging for more information)
2022.04.16 15:26:35:988 io-compute-1 INFO docspell.config.ConfigFactory.default:36
    Using config file: /opt/docspell.conf
2022.04.16 15:26:37:0000 [io-comp...] [INFO ] docspell.restserver.Main.run:34 - 
***>  ______                          _ _
***>  |  _  \                        | | |
***>  | | | |___   ___ ___ _ __   ___| | |
***>  | | | / _ \ / __/ __| '_ \ / _ \ | |
***>  | |/ / (_) | (__\__ \ |_) |  __/ | |
***>  |___/ \___/ \___|___/ .__/ \___|_|_|
***>                      | |
***>                      |_| v0.35.0 (#f5958b3a)
***>  << REST Server >>
***>  Id:       rest1
***>  Base-Url: https://docspell.home
***>  Database: jdbc:postgresql://postgres.local:5432/docspell
***>  Fts:      PostgreSQL(default)
***>  Config:   /opt/docspell.conf
***>  FileRepo: DefaultDatabase(true)
***>  
2022.04.16 15:26:37:0001 [io-comp...] [INFO ] docspell.restserver.RestServer.serve:46 - Starting server with options ServerOptions(Duration(45000ms),false,1024)
2022.04.16 15:26:38:0000 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.createFlyway:38 - Creating Flyway for: List(classpath:db/fixups/postgresql, classpath:db/fixups/common)
2022.04.16 15:26:38:0001 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.runFixups:69 - !!! Running fixup migrations
2022.04.16 15:26:38:0002 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - Flyway Community Edition 8.5.8 by Redgate
2022.04.16 15:26:38:0003 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.8
2022.04.16 15:26:38:0004 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - 
2022.04.16 15:26:38:0005 [io-comp...] [INFO ] org.flywaydb.core.internal.database.base.BaseDatabaseType - Database: jdbc:postgresql://postgres.local:5432/docspell (PostgreSQL 14.2)
2022.04.16 15:26:38:0000 [io-comp...] [INFO ] org.http4s.blaze.client.PoolManager - Shutting down connection pool: curAllocated=0 idleQueues.size=0 waitQueue.size=0 maxWaitQueueLimit=256 closed=false
org.flywaydb.core.api.exception.FlywayValidateException: Validate failed: Migrations have failed validation
Migration checksum mismatch for migration version 1.33.0
-> Applied to database : 1347412019
-> Resolved locally    : 1776159438
Either revert the changes to the migration, or run repair to update the schema history.
Need more flexibility with validation rules? Learn more: https://rd.gt/3AbJUZE
        at org.flywaydb.core.Flyway$1.execute(Flyway.java:130)
        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$runFixups$8(FlywayMigrate.scala:70)
        at blocking @ fs2.io.file.FilesCompanionPlatform$AsyncFiles.exists(FilesPlatform.scala:204)
        at liftF @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$4(FlywayMigrate.scala:68)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$7(FlywayMigrate.scala:70)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)
        at liftF @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$4(FlywayMigrate.scala:68)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$1(FlywayMigrate.scala:64)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$createFlyway$1(FlywayMigrate.scala:38)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$createFlyway$1(FlywayMigrate.scala:38)
        at flatMap @ docspell.store.migrate.FlywayMigrate.createFlyway(FlywayMigrate.scala:37)
        at liftF @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$4(FlywayMigrate.scala:68)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$1(FlywayMigrate.scala:64)
        at filter @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$2(FlywayMigrate.scala:67)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$1(FlywayMigrate.scala:64)
        at blocking @ fs2.io.file.FilesCompanionPlatform$AsyncFiles.exists(FilesPlatform.scala:204)
        at as @ docspell.restserver.RestServer$.$anonfun$serve$4(RestServer.scala:70)

flyway_fixup_history:

installed_rank version description type script checksum installed_by installed_on execution_time success
1 1 << Flyway Baseline >> BASELINE << Flyway Baseline >> ; null 2022-03-22 14:36:31.618387 "0" 1
2 "1.33.0" fix reorganize files SQL V1.33.0__fix_reorganize_files.sql 1347412019 docspell 2022-04-16 14:25:40.151521 68 1

Deleting the 1.33.0 entry results in:

Apr 16, 2022 3:35:35 PM org.jline.utils.Log logr
WARNING: Unable to create a system terminal, creating a dumb terminal (enable debug logging for more information)
2022.04.16 15:35:34:826 io-compute-2 INFO docspell.config.ConfigFactory.default:36
    Using config file: /opt/docspell.conf
2022.04.16 15:35:35:0000 [io-comp...] [INFO ] docspell.restserver.Main.run:34 - 
***>  ______                          _ _
***>  |  _  \                        | | |
***>  | | | |___   ___ ___ _ __   ___| | |
***>  | | | / _ \ / __/ __| '_ \ / _ \ | |
***>  | |/ / (_) | (__\__ \ |_) |  __/ | |
***>  |___/ \___/ \___|___/ .__/ \___|_|_|
***>                      | |
***>                      |_| v0.35.0 (#f5958b3a)
***>  << REST Server >>
***>  Id:       rest1
***>  Base-Url: https://docspell.home
***>  Database: jdbc:postgresql://postgres.local:5432/docspell
***>  Fts:      PostgreSQL(default)
***>  Config:   /opt/docspell.conf
***>  FileRepo: DefaultDatabase(true)
***>  
2022.04.16 15:35:35:0001 [io-comp...] [INFO ] docspell.restserver.RestServer.serve:46 - Starting server with options ServerOptions(Duration(45000ms),false,1024)
2022.04.16 15:35:37:0000 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.createFlyway:38 - Creating Flyway for: List(classpath:db/fixups/postgresql, classpath:db/fixups/common)
2022.04.16 15:35:37:0001 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.runFixups:69 - !!! Running fixup migrations
2022.04.16 15:35:37:0002 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - Flyway Community Edition 8.5.8 by Redgate
2022.04.16 15:35:37:0003 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.8
2022.04.16 15:35:37:0004 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - 
2022.04.16 15:35:37:0005 [io-comp...] [INFO ] org.flywaydb.core.internal.database.base.BaseDatabaseType - Database: jdbc:postgresql://postgres.local:5432/docspell (PostgreSQL 14.2)
2022.04.16 15:35:37:0006 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbValidate - Successfully validated 2 migrations (execution time 00:00.030s)
2022.04.16 15:35:37:0007 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbMigrate - Current version of schema "public": 1
2022.04.16 15:35:37:0008 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbMigrate - Migrating schema "public" to version "1.33.0 - fix reorganize files"
2022.04.16 15:35:37:0009 [io-comp...] [INFO ] org.flywaydb.core.internal.sqlscript.DefaultSqlScriptExecutor - DB: table "valid_file_ids" does not exist, skipping
2022.04.16 15:35:37:0010 [io-comp...] [INFO ] org.flywaydb.core.internal.sqlscript.DefaultSqlScriptExecutor - DB: table "obsolete_files" does not exist, skipping
2022.04.16 15:35:37:0011 [io-comp...] [INFO ] org.flywaydb.core.internal.command.DbMigrate - Successfully applied 1 migration to schema "public", now at version v1.33.0 (execution time 00:00.133s)
2022.04.16 15:35:37:0012 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.createFlyway:38 - Creating Flyway for: List(classpath:db/migration/postgresql, classpath:db/migration/common)
2022.04.16 15:35:37:0013 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.run:53 - !!! Running main migrations
2022.04.16 15:35:37:0014 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - Flyway Community Edition 8.5.8 by Redgate
2022.04.16 15:35:37:0015 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.8
2022.04.16 15:35:37:0016 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - 
2022.04.16 15:35:37:0017 [io-comp...] [INFO ] org.flywaydb.core.internal.database.base.BaseDatabaseType - Database: jdbc:postgresql://postgres.local:5432/docspell (PostgreSQL 14.2)
2022.04.16 15:35:37:0000 [io-comp...] [INFO ] org.http4s.blaze.client.PoolManager - Shutting down connection pool: curAllocated=0 idleQueues.size=0 waitQueue.size=0 maxWaitQueueLimit=256 closed=false
org.flywaydb.core.api.exception.FlywayValidateException: Validate failed: Migrations have failed validation
Migration checksum mismatch for migration version 1.0.0
-> Applied to database : 317337288
-> Resolved locally    : -118882639
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.1.0
-> Applied to database : 655930044
-> Resolved locally    : -1102699734
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.2.0
-> Applied to database : 811358974
-> Resolved locally    : 1092778025
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.3.0
-> Applied to database : -1440002901
-> Resolved locally    : -186517118
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.4.0
-> Applied to database : 857738097
-> Resolved locally    : 290692248
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.5.0
-> Applied to database : 405891450
-> Resolved locally    : -1626360500
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.6.0
-> Applied to database : -1400448292
-> Resolved locally    : 1094333603
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.7.0
-> Applied to database : 945262447
-> Resolved locally    : 1006625579
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.8.0
-> Applied to database : 1074998524
-> Resolved locally    : -1218545371
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.9.0
-> Applied to database : -922383879
-> Resolved locally    : -837034213
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.9.1
-> Applied to database : -920209386
-> Resolved locally    : 1434270743
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.9.3
-> Applied to database : -807943034
-> Resolved locally    : 710044106
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.9.4
-> Applied to database : 770293754
-> Resolved locally    : 136218986
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.10.0
-> Applied to database : 175251272
-> Resolved locally    : -649911439
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.12.0
-> Applied to database : -1136859296
-> Resolved locally    : -1608113072
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.13.0
-> Applied to database : 1090781225
-> Resolved locally    : -1680178524
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.14.0
-> Applied to database : -1121419990
-> Resolved locally    : 916718441
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.15.0
-> Applied to database : -456374843
-> Resolved locally    : 18578961
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.16.0
-> Applied to database : 1011393315
-> Resolved locally    : -252417141
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.17.0
-> Applied to database : -491746438
-> Resolved locally    : -198654654
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.18.0
-> Applied to database : -828258448
-> Resolved locally    : 683920003
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.19.0
-> Applied to database : -1255719254
-> Resolved locally    : 943341824
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.20.0
-> Applied to database : 1870008223
-> Resolved locally    : -779274773
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.20.3
-> Applied to database : 763931359
-> Resolved locally    : 907574747
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.21.0
-> Applied to database : 1165916844
-> Resolved locally    : -1714022554
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.21.1
-> Applied to database : 352694567
-> Resolved locally    : -1005379095
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.23.0
-> Applied to database : 1152128793
-> Resolved locally    : 636649519
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.25.0
-> Applied to database : -943147294
-> Resolved locally    : 943175394
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.25.1
-> Applied to database : 1797712347
-> Resolved locally    : -2048732059
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.25.2
-> Applied to database : 396118090
-> Resolved locally    : 1542597368
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.25.3
-> Applied to database : -902371387
-> Resolved locally    : -603580747
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.26.2
-> Applied to database : 944511097
-> Resolved locally    : -1897063579
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.26.3
-> Applied to database : 1476446475
-> Resolved locally    : 684359551
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.27.1
-> Applied to database : -1354199549
-> Resolved locally    : 644010924
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.28.0
-> Applied to database : -1745510720
-> Resolved locally    : -400090870
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.28.1
-> Applied to database : -537116935
-> Resolved locally    : 553402105
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.29.0
-> Applied to database : -1762725568
-> Resolved locally    : 1802387995
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.29.1
-> Applied to database : 1582374027
-> Resolved locally    : 1814856936
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.30.0
-> Applied to database : 1647444395
-> Resolved locally    : 936029495
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.31.0
-> Applied to database : 1464170959
-> Resolved locally    : 525900721
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.32.0
-> Applied to database : 1586845926
-> Resolved locally    : 1750332662
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.32.1
-> Applied to database : -741341079
-> Resolved locally    : -722702183
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.33.0
-> Applied to database : 1583732153
-> Resolved locally    : 924153984
Either revert the changes to the migration, or run repair to update the schema history.
Migration checksum mismatch for migration version 1.34.0
-> Applied to database : -146289187
-> Resolved locally    : -750119324
Either revert the changes to the migration, or run repair to update the schema history.
Need more flexibility with validation rules? Learn more: https://rd.gt/3AbJUZE
        at org.flywaydb.core.Flyway$1.execute(Flyway.java:130)
        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$5(FlywayMigrate.scala:54)
        at blocking @ fs2.io.file.FilesCompanionPlatform$AsyncFiles.exists(FilesPlatform.scala:204)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$run$4(FlywayMigrate.scala:54)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$run$2(FlywayMigrate.scala:53)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$createFlyway$1(FlywayMigrate.scala:38)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$createFlyway$1(FlywayMigrate.scala:38)
        at flatMap @ docspell.store.migrate.FlywayMigrate.createFlyway(FlywayMigrate.scala:37)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$run$1(FlywayMigrate.scala:52)
        at blocking @ fs2.io.file.FilesCompanionPlatform$AsyncFiles.exists(FilesPlatform.scala:204)
        at liftF @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$4(FlywayMigrate.scala:68)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$7(FlywayMigrate.scala:70)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)
        at liftF @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$4(FlywayMigrate.scala:68)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$1(FlywayMigrate.scala:64)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)

flyway_fixup_history:

installed_rank version description type script checksum installed_by installed_on execution_time success
1 1 << Flyway Baseline >> BASELINE << Flyway Baseline >> ; null 2022-03-22 14:36:31.618387 "0" 1
2 "1.33.0" fix reorganize files SQL V1.33.0__fix_reorganize_files.sql 1776159438 docspell 2022-04-16 15:35:37.391163 70 1

For reference, latest five entries in flyway_schema_history:

installed_rank version description type script checksum installed_by installed_on execution_time success
54 "1.32.0" notification channel name SQL V1.32.0__notification_channel_name.sql 1586845926 docspell 2022-02-11 14:49:04.22228 1 1
55 1.32.1 notification hook multi channel SQL V1.32.1__notification_hook_multi_channel.sql -741341079 docspell 2022-02-11 14:49:04.228573 25 1
56 1.32.2 MigrateChannels JDBC db.migration.postgresql.V1_32_2__MigrateChannels docspell 2022-02-11 14:49:04.257781 39 1
57 "1.33.0" reorganize file ids SQL V1.33.0__reorganize_file_ids.sql 1583732153 docspell 2022-03-06 19:19:58.924624 131 1
58 "1.34.0" item relation SQL V1.34.0__item_relation.sql -146289187 docspell 2022-03-22 14:36:31.955354 26 1

Goging back to v.0.34.0 results in:

Apr 16, 2022 3:42:16 PM org.jline.utils.Log logr
WARNING: Unable to create a system terminal, creating a dumb terminal (enable debug logging for more information)
2022.04.16 15:42:15:842 io-compute-2 INFO docspell.config.ConfigFactory.default:36
    Using config file: /opt/docspell.conf
2022.04.16 15:42:16:0000 [io-comp...] [INFO ] docspell.restserver.Main.run:34 - 
***>  ______                          _ _
***>  |  _  \                        | | |
***>  | | | |___   ___ ___ _ __   ___| | |
***>  | | | / _ \ / __/ __| '_ \ / _ \ | |
***>  | |/ / (_) | (__\__ \ |_) |  __/ | |
***>  |___/ \___/ \___|___/ .__/ \___|_|_|
***>                      | |
***>                      |_| v0.34.0 (#c6da3eb0)
***>  << REST Server >>
***>  Id:       rest1
***>  Base-Url: https://docspell.home
***>  Database: jdbc:postgresql://postgres.local:5432/docspell
***>  Fts:      PostgreSQL(default)
***>  Config:   /opt/docspell.conf
***>  FileRepo: DefaultDatabase(true)
***>  
2022.04.16 15:42:18:0000 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.createFlyway:37 - Creating Flyway for: List(classpath:db/fixups/postgresql, classpath:db/fixups/common)
2022.04.16 15:42:18:0001 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.runFixups:64 - !!! Running fixup migrations
2022.04.16 15:42:18:0002 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - Flyway Community Edition 8.5.4 by Redgate
2022.04.16 15:42:18:0003 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.4
2022.04.16 15:42:18:0004 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - 
2022.04.16 15:42:18:0005 [io-comp...] [INFO ] org.flywaydb.core.internal.database.base.BaseDatabaseType - Database: jdbc:postgresql://postgres.local:5432/docspell (PostgreSQL 14.2)
2022.04.16 15:42:18:0000 [io-comp...] [INFO ] org.http4s.blaze.client.PoolManager - Shutting down connection pool: curAllocated=0 idleQueues.size=0 waitQueue.size=0 maxWaitQueueLimit=256 closed=false
org.flywaydb.core.api.exception.FlywayValidateException: Validate failed: Migrations have failed validation
Migration checksum mismatch for migration version 1.33.0
-> Applied to database : 1776159438
-> Resolved locally    : 1347412019
Either revert the changes to the migration, or run repair to update the schema history.
Need more flexibility with validation rules? Learn more: https://rd.gt/3AbJUZE
        at org.flywaydb.core.Flyway$1.execute(Flyway.java:130)
        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$runFixups$5(FlywayMigrate.scala:65)
        at blocking @ fs2.io.file.FilesCompanionPlatform$AsyncFiles.exists(FilesPlatform.scala:204)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$4(FlywayMigrate.scala:65)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$2(FlywayMigrate.scala:64)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$createFlyway$1(FlywayMigrate.scala:37)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$createFlyway$1(FlywayMigrate.scala:37)
        at flatMap @ docspell.store.migrate.FlywayMigrate.createFlyway(FlywayMigrate.scala:36)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$1(FlywayMigrate.scala:63)
        at blocking @ fs2.io.file.FilesCompanionPlatform$AsyncFiles.exists(FilesPlatform.scala:204)
        at as @ docspell.restserver.RestServer$.$anonfun$serve$1(RestServer.scala:67)
        at $anonfun$apply$10 @ fs2.Stream$.$anonfun$resourceWeak$3(Stream.scala:3624)
        at $anonfun$apply$10 @ fs2.Stream$.$anonfun$resourceWeak$3(Stream.scala:3624)
        at blocking @ fs2.io.file.FilesCompanionPlatform$AsyncFiles.exists(FilesPlatform.scala:204)
        at flatMap @ fs2.Compiler$Target.flatMap(Compiler.scala:162)
        at $anonfun$apply$10 @ fs2.Stream$.$anonfun$resourceWeak$3(Stream.scala:3624)

Deleting the 1.33.0 entry from flyway_fixup_history results in a new entry after startup, now without any errors and Docspell works fien as before with v0.34.0.

flyway_fixup_history:

installed_rank version description type script checksum installed_by installed_on execution_time success
1 1 << Flyway Baseline >> BASELINE << Flyway Baseline >> ; null 2022-03-22 14:36:31.618387 "0" 1
2 "1.33.0" fix reorganize files SQL V1.33.0__fix_reorganize_files.sql 1347412019 docspell 2022-04-16 15:44:10.942675 61 1

@eikek
Copy link
Owner Author

eikek commented Apr 16, 2022

Thank you very much for these good details! I'll take a deeper look , currently I admit I'm quite puzzled. It seems that the fix for the flyway_fixup_migration succeeded and then the same error happens to the main migration. That is very weird! No migration was changed, so checksums should not change as well.

I found one issue flyway/flyway#3431 that seems to describe this problem.

@enkol
Copy link

enkol commented Apr 16, 2022

This also happens with an "empty" database i used goging from postgres 13 to 14. If needed i can provide a dump of it alongside my docker-compose configuration.

@enkol
Copy link

enkol commented Apr 16, 2022

Thanks for all your efforts! For me this is far from urgent, as i was able to go back to v0.34.0 without issues. So I'm fine for now.

@eikek
Copy link
Owner Author

eikek commented Apr 16, 2022

Thanks @enkol ! I'll come back if I need more data, thanks for the proposal. If that happens even to an empty database, there is something very spooky going on :)! One more thing: How/which system are you running this on? Is it the docker arm images?

@enkol
Copy link

enkol commented Apr 16, 2022

I'm running with Docker in an Ubuntu 20.04 VM on a Intel i3 box with Proxmox 7. Postgres is also with Docker postgres:14-bullseye in the same VM.

@enkol
Copy link

enkol commented Apr 16, 2022

If that happens even to an empty database, there is something very spooky going on :)!

Just to clarify, i meant 'empty' in terms of no documents uploaded. The database was used to test setting up Docspell with Postgres 14 in Februar. I can reproduce the checksum issues with this db switching between 0.34.0 and 0.35.0.

@Skyr
Copy link
Contributor

Skyr commented Apr 16, 2022

Same symptoms here. The flyway ticket mentioned shows the problem appears after moving from JDK 11 to JDK 17... did you change the JRE in the containers? If yes, then reverting to the old version might be a temproary fix.

My wild guess would be some strange encoding behaviour when reading text files (like changing the line endings)...

@eikek
Copy link
Owner Author

eikek commented Apr 16, 2022

I didn't change anything in that regard. Could be related to a new flyway version in combination with the alpine jdk. But have to reproduce this first. I don't use docker, but I tested the docker image and that worked here 🤷🏼

@eikek
Copy link
Owner Author

eikek commented Apr 22, 2022

So, unfortunately I can't reproduce it :( I even installed an Ubuntu 20.04 VM (via virtualbox) to run the docker containers (using docker-compose up -- db restserver - to only start the restserver). I first started with version 0.34.0 a few times and then moved to 0.35.0. I also tried the upgrade on a RPI4 (docker) and with OpenJDK17 on my amd notebook (no docker). The error doesn't occur.

From what I can see, flyway uses a CRC32 checksum and I don't see why this would change when upgrading java or anything else in the environment. It should only depend on its input, no? Their code didn't change as well. The docker images didn't change, besides from upgraded packages due to new image creation.

Not sure how to proceed :/ Maybe we can try to find common characteristics of the systems where this happens? Are you all on a VM, for example? or all using proxmox? Maybe a different openjdk is also worth a try, there could be a problem with openjdk11 and alpine… (but not for me :)). But since it happens for you only with 0.35.0 a change in the image that is triggered in your environment seems most likely to me for now.

Flyway just had another patch release, it could also be worth a try - you could run the nightly docker images that have this version.

@enkol
Copy link

enkol commented Apr 22, 2022

Thanks for having a deeper look into this and spending so much effort to reproduce it yourself!
I'll try a nightly image this weekend, to see if it changes anything. If not, I can see if I'm able to provide a docker-compose and pg-dump to reproduce the issue.

@eikek
Copy link
Owner Author

eikek commented Apr 22, 2022

Another option is what @Skyr said: charset/encoding changes. This would affect the input to the checksum algo, because flyway converts the bytes to characters and then converts characters back to bytes (line by line) using UTF-8. That means if the encoding to read the migration somehow changed, it could produce a different checksum. From what I saw, flyway is by default using UTF-8 (unless it is set explicitely). You could try to change the default encoding for java using the system property file.encoding. You can inject it by setting a special environment variable:

JAVA_TOOL_OPTIONS="-Dfile.encoding=UTF-8"

The migrations are in ascii, it doesn't matter so much (except for some esoteric and non-8-bit charsets) how they are read. But worth a try.

@enkol
Copy link

enkol commented Apr 23, 2022

Nightly build produces the same error, i'll try the encoding thingy next.
Edit: Changing the encoding didn't help either.

Apr 23, 2022 4:09:13 PM org.jline.utils.Log logr
WARNING: Unable to create a system terminal, creating a dumb terminal (enable debug logging for more information)
2022.04.23 16:09:12:881 io-compute-1 INFO docspell.config.ConfigFactory.default:36
    Using config file: /opt/docspell.conf
2022.04.23 16:09:14:0000 [io-comp...] [INFO ] docspell.restserver.Main.run:34 - 
***>  ______                          _ _
***>  |  _  \                        | | |
***>  | | | |___   ___ ___ _ __   ___| | |
***>  | | | / _ \ / __/ __| '_ \ / _ \ | |
***>  | |/ / (_) | (__\__ \ |_) |  __/ | |
***>  |___/ \___/ \___|___/ .__/ \___|_|_|
***>                      | |
***>                      |_| v0.36.0-SNAPSHOT (#d8727ef6)
***>  << REST Server >>
***>  Id:       rest1
***>  Base-Url: https://docspell.home
***>  Database: jdbc:postgresql://postgres.local:5432/docspell
***>  Fts:      PostgreSQL(default)
***>  Config:   /opt/docspell.conf
***>  FileRepo: DefaultDatabase(true)
***>  
2022.04.23 16:09:14:0001 [io-comp...] [INFO ] docspell.restserver.RestServer.serve:46 - Starting server with options ServerOptions(Duration(45000ms),false,1024)
2022.04.23 16:09:15:0000 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.createFlyway:38 - Creating Flyway for: List(classpath:db/fixups/postgresql, classpath:db/fixups/common)
2022.04.23 16:09:15:0001 [io-comp...] [INFO ] docspell.store.migrate.FlywayMigrate.runFixups:69 - !!! Running fixup migrations
2022.04.23 16:09:15:0002 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - Flyway Community Edition 8.5.9 by Redgate
2022.04.23 16:09:15:0003 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.9
2022.04.23 16:09:15:0004 [io-comp...] [INFO ] org.flywaydb.core.internal.license.VersionPrinter - 
2022.04.23 16:09:15:0005 [io-comp...] [INFO ] org.flywaydb.core.internal.database.base.BaseDatabaseType - Database: jdbc:postgresql://postgres.local:5432/docspell (PostgreSQL 14.2)
2022.04.23 16:09:15:0000 [io-comp...] [INFO ] org.http4s.blaze.client.PoolManager - Shutting down connection pool: curAllocated=0 idleQueues.size=0 waitQueue.size=0 maxWaitQueueLimit=256 closed=false
org.flywaydb.core.api.exception.FlywayValidateException: Validate failed: Migrations have failed validation
Migration checksum mismatch for migration version 1.33.0
-> Applied to database : 1347412019
-> Resolved locally    : 1776159438
Either revert the changes to the migration, or run repair to update the schema history.
Need more flexibility with validation rules? Learn more: https://rd.gt/3AbJUZE
        at org.flywaydb.core.Flyway$1.execute(Flyway.java:130)
        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$runFixups$8(FlywayMigrate.scala:70)
        at blocking @ fs2.io.file.FilesCompanionPlatform$AsyncFiles.exists(FilesPlatform.scala:204)
        at liftF @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$4(FlywayMigrate.scala:68)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$7(FlywayMigrate.scala:70)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)
        at liftF @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$4(FlywayMigrate.scala:68)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$1(FlywayMigrate.scala:64)
        at delay @ docspell.logging.impl.ScribeWrapper$Impl.log(ScribeWrapper.scala:28)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$createFlyway$1(FlywayMigrate.scala:38)
        at map @ docspell.store.migrate.FlywayMigrate.$anonfun$createFlyway$1(FlywayMigrate.scala:38)
        at flatMap @ docspell.store.migrate.FlywayMigrate.createFlyway(FlywayMigrate.scala:37)
        at liftF @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$4(FlywayMigrate.scala:68)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$1(FlywayMigrate.scala:64)
        at filter @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$2(FlywayMigrate.scala:67)
        at flatMap @ docspell.store.migrate.FlywayMigrate.$anonfun$runFixups$1(FlywayMigrate.scala:64)
        at blocking @ fs2.io.file.FilesCompanionPlatform$AsyncFiles.exists(FilesPlatform.scala:204)
        at as @ docspell.restserver.RestServer$.$anonfun$serve$4(RestServer.scala:70)

@enkol
Copy link

enkol commented Apr 23, 2022

I've prepared a minimal docker-compose to reproduce the issue:
https://1drv.ms/u/s!Ahri17Z7_U8VxU22A3LFjAIrp2tj?e=vFqbkA

@eikek
Copy link
Owner Author

eikek commented Apr 24, 2022

It is so strange! On all my machines, the checksum for the fixup migration is 1347412019. So I assume that this is the "correct" one :). It is now interesting how on earth the other value is generated. Can you imagine of anything that has changed in your environment (updates or something similar)? Not that it should have any influence on that value, but for some reason it does. And only to reassure again, if you go back to 0.34.0 it works? 🤯

Thank you for the example. I tried it as described - but it didn't produce the error for me.

What I can do is providing a "repair" option in the config file. This must be used with care, ofc. But it would allow to "fix" all checksums automatically. I would still love to know the cause of the problem.

Edit: I also tried out of curiosity to calculate checksums for every available charset on my system. There were a few that produced a different checksum, but none produced 1776159438.

@enkol
Copy link

enkol commented Apr 24, 2022

Indeed, this is very strange. For me it is reproduceable with the given example; as it isn't for you, it must be something docker host related on my side. I didn't change anything besides of the ordinary Ubuntu system security updates in the VM.

And only to reassure again, if you go back to 0.34.0 it works?

Yes, if it failed with 0.35.0 and i delete the fixup_history entry it runs without issues with 0.34.0 again (creates new fixup_history entry). Deleting fixup_history doesn't fix 0.35.0, only works for 0.34.0.

@eikek
Copy link
Owner Author

eikek commented Apr 24, 2022

For me it is reproduceable with the given example; as it isn't for you, it must be something docker host related on my side. I didn't change anything besides of the ordinary Ubuntu system security updates in the VM.

Yes, and there must be also something in the 0.35.0 package, since it manages to create a different checksum on your host. The only idea I have is that flyway or its dependencies (including the jvm) reads in something from the environment which it didn't before.

So on your system, 0.34.0 creates 1347412019 (correct) and version 0.35.0 creates 1776159438 ("wrong"). Can you maybe give me some other details: What version of java are you using and the environment of the process. There is a api call that returns some useful info as well:

curl -H 'Docspell-Admin-Secret: admin-secret' https://restserver:7880/api/v1/admin/info/system

It includes the java version for example, but not env variables. These could be obtained by running env in the container. If there is sensitive info, just redact it (or you can also send it privately to me).

@enkol
Copy link

enkol commented Apr 24, 2022

Java is not installed on my Docker host. The Docspell-Api system info outputs:

{
    "id": "rest1",
    "pidHost": "1@5b601d9e1e0e",
    "ncpu": 2,
    "inputArgs": [
        "-Dconfig.file=/opt/docspell-restserver-0.34.0/bin/../conf/docspell-server.conf",
        "-XX:+UseG1GC"
    ],
    "libraryPath": "/usr/lib/jvm/java-11-openjdk/lib/server:/usr/lib/jvm/java-11-openjdk/lib:/usr/lib/jvm/java-11-openjdk/../lib:/usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib",
    "specVendor": "Oracle Corporation",
    "specVersion": "11",
    "startTime": 1650820718629,
    "uptime": 667327,
    "vmName": "OpenJDK 64-Bit Server VM",
    "vmVendor": "Alpine",
    "vmVersion": "11.0.14+9-alpine-r0",
    "heapUsage": {
        "init": 98566144,
        "used": 26075648,
        "comitted": 142606336,
        "max": 1549795328,
        "free": 1523719680,
        "description": "init=94.00M, used=24.87M, comitted=136.00M, max=1.44G, free=1.42G"
    },
    "props": {
        "java.io.tmpdir": "/tmp",
        "line.separator": "\n",
        "path.separator": ":",
        "user.home": "/root",
        "com.zaxxer.hikari.pool_number": "1",
        "sun.os.patch.level": "unknown",
        "user.country": "US",
        "jna.loaded": "true",
        "os.name": "Linux",
        "sun.management.compiler": "HotSpot 64-Bit Tiered Compilers",
        "sun.cpu.endian": "little",
        "java.specification.version": "11",
        "java.vm.specification.name": "Java Virtual Machine Specification",
        "java.vendor": "Alpine",
        "java.vm.specification.version": "11",
        "sun.arch.data.model": "64",
        "sun.boot.library.path": "/usr/lib/jvm/java-11-openjdk/lib",
        "user.dir": "/opt",
        "java.library.path": "/usr/lib/jvm/java-11-openjdk/lib/server:/usr/lib/jvm/java-11-openjdk/lib:/usr/lib/jvm/java-11-openjdk/../lib:/usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib",
        "sun.cpu.isalist": "",
        "os.arch": "amd64",
        "java.vm.version": "11.0.14+9-alpine-r0",
        "java.runtime.version": "11.0.14+9-alpine-r0",
        "java.vm.info": "mixed mode",
        "java.runtime.name": "OpenJDK Runtime Environment",
        "java.version.date": "2022-01-18",
        "mail.mime.uudecode.ignoreerrors": "true",
        "mail.mime.encodefilename": "true",
        "file.separator": "/",
        "java.class.version": "55.0",
        "mail.mime.parameters.strict": "false",
        "java.specification.name": "Java Platform API Specification",
        "file.encoding": "UTF-8",
        "user.timezone": "Europe/Berlin",
        "jna.platform.library.path": "/usr/lib:/lib",
        "java.specification.vendor": "Oracle Corporation",
        "jnidispatch.path": "/root/.cache/JNA/temp/jna10563872938398853065.tmp",
        "sun.java.launcher": "SUN_STANDARD",
        "java.vm.compressedOopsMode": "32-bit",
        "os.version": "5.4.0-109-generic",
        "config.file": "/opt/docspell.conf",
        "java.vm.specification.vendor": "Oracle Corporation",
        "sun.jnu.encoding": "UTF-8",
        "user.language": "en",
        "mail.mime.splitlongparameters": "false",
        "mail.mime.uudecode.ignoremissingbeginend": "true",
        "java.vendor.url": "https://alpinelinux.org/",
        "java.awt.printerjob": "sun.print.PSPrinterJob",
        "java.awt.graphicsenv": "sun.awt.X11GraphicsEnvironment",
        "awt.toolkit": "sun.awt.X11.XToolkit",
        "java.class.path": "/opt/docspell-restserver-0.34.0/lib/com.github.eikek.docspell-restserver-0.34.0-classpath.jar",
        "java.vm.vendor": "Alpine",
        "jdk.debug": "release",
        "java.vendor.url.bug": "https://gitlab.alpinelinux.org/alpine/aports/issues",
        "user.name": "root",
        "mail.mime.decodefilename": "true",
        "java.vm.name": "OpenJDK 64-Bit Server VM",
        "sun.java.command": "docspell.restserver.Main /opt/docspell.conf",
        "java.home": "/usr/lib/jvm/java-11-openjdk",
        "mail.mime.setcontenttypefilename": "false",
        "java.version": "11.0.14",
        "sun.io.unicode.encoding": "UnicodeLittle"
    }
}

Environment in the restserver container:

HOSTNAME=5b601d9e1e0e
PWD=/opt
TZ=Europe/Berlin
HOME=/root
TERM=xterm
SHLVL=1
DOCSPELL_HEADER_VALUE=**********
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
_=/usr/bin/env

@enkol
Copy link

enkol commented Apr 24, 2022

I tried to compare checksum generation within docspell/restserver docker containers 0.34.0 and 0.35.0.

For the same file, I get different results:

  • 0.34.0: 1438454349
  • 0.35.0: -1934287952

Tested with:

import java.util.*;
import org.flywaydb.core.internal.resource.filesystem.*;
import org.flywaydb.core.internal.resolver.*;
import org.flywaydb.core.internal.resource.*;
import org.flywaydb.core.api.Location;
import java.nio.charset.*;

public class Program {

    public static void main( String[] args ) throws Exception{
        Location loc = null;
        String filepath = args[0];
        FileSystemResource r = new FileSystemResource(loc, filepath,Charset.forName("UTF-8"), false);
        int cs = ChecksumCalculator.calculate(r);
        System.out.println(cs);
    }
}

I've created the above file as test.java on my docker host, mounted it in the container and changed the containers entrypoint to just run this file to calculate it's checksum:

  docspell34:
    image: docspell/restserver:v0.34.0
    entrypoint: java -cp /opt/docspell-restserver-0.34.0/lib/org.flywaydb.flyway-core-8.5.4.jar /test.java /test.java
    volumes:
      - /home/enno/test.java:/test.java

  docspell35:
    image: docspell/restserver:v0.35.0
    entrypoint: java -cp /opt/docspell-restserver-0.35.0/lib/org.flywaydb.flyway-core-8.5.8.jar /test.java /test.java
    volumes:
      - /home/enno/test.java:/test.java

Running docker-compose run --rm docspell34 outputs 1438454349
Running docker-compose run --rm docspell35 outputs -1934287952

Maybe this can help? Is there anything else to test or compare?

@enkol
Copy link

enkol commented Apr 24, 2022

Both 0.34.0 and 0.35.0 seem to have the same Java version. Printing all Java system properties generates the exact same output:

awt.toolkit: sun.awt.X11.XToolkit
java.specification.version: 11
sun.cpu.isalist: 
sun.jnu.encoding: UTF-8
java.class.path: /test.java
java.vm.vendor: Alpine
sun.arch.data.model: 64
java.vendor.url: https://alpinelinux.org/
user.timezone: 
os.name: Linux
java.vm.specification.version: 11
sun.java.launcher: SUN_STANDARD
user.country: US
sun.boot.library.path: /usr/lib/jvm/java-11-openjdk/lib
sun.java.command: jdk.compiler/com.sun.tools.javac.launcher.Main /test.java
jdk.debug: release
sun.cpu.endian: little
user.home: /root
user.language: en
java.specification.vendor: Oracle Corporation
java.version.date: 2022-01-18
java.home: /usr/lib/jvm/java-11-openjdk
file.separator: /
java.vm.compressedOopsMode: 32-bit
line.separator: 

java.specification.name: Java Platform API Specification
java.vm.specification.vendor: Oracle Corporation
java.awt.graphicsenv: sun.awt.X11GraphicsEnvironment
jdk.module.main.class: com.sun.tools.javac.launcher.Main
sun.management.compiler: HotSpot 64-Bit Tiered Compilers
java.runtime.version: 11.0.14+9-alpine-r0
user.name: root
path.separator: :
os.version: 5.4.0-109-generic
java.runtime.name: OpenJDK Runtime Environment
file.encoding: UTF-8
java.vm.name: OpenJDK 64-Bit Server VM
java.vendor.url.bug: https://gitlab.alpinelinux.org/alpine/aports/issues
java.io.tmpdir: /tmp
java.version: 11.0.14
user.dir: /opt
os.arch: amd64
java.vm.specification.name: Java Virtual Machine Specification
java.awt.printerjob: sun.print.PSPrinterJob
sun.os.patch.level: unknown
java.library.path: /usr/lib/jvm/java-11-openjdk/lib/server:/usr/lib/jvm/java-11-openjdk/lib:/usr/lib/jvm/java-11-openjdk/../lib:/usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib
java.vm.info: mixed mode
java.vendor: Alpine
java.vm.version: 11.0.14+9-alpine-r0
sun.io.unicode.encoding: UnicodeLittle
java.class.version: 55.0

Generated with:

import java.util.*;

public class Program {

    public static void main( String[] args ) throws Exception{
        Properties p = System.getProperties();
        Enumeration keys = p.keys();
        while (keys.hasMoreElements()) {
            String key = (String)keys.nextElement();
            String value = (String)p.get(key);
            System.out.println(key + ": " + value);
        }
    }
}

@enkol
Copy link

enkol commented Apr 24, 2022

Found another recent mention about Flyway checksum issues: madler/zlib#618

Comparing Flyway 8.5.4 used in Docspell 0.34.0 with 8.5.8 used in 0.35.0 doesn't give more insights. Maybe the updated AWS S3 dependencies brought in an new zlib version which relates to the above mentioned issue?

@eikek
Copy link
Owner Author

eikek commented Apr 24, 2022

Thank you so much @enkol ! Your test with the java program was great. It's easer to work with an isolated program and It shows clearly that the checksum calculator produces different results for the same input. On my system, it produces the same output.

I think the issue you found sounds very much like the cause. I can't imagine anything else than a jvm or native change… which is quite rare in my experience! I didn't know that javas CRC32 class reaches out to a C library - now I know :). It would also explain why it is so hard to reproduce. On my ubuntu vm that I created to reproduce this, there is zlib 1.2.11 installed.

@enkol
Copy link

enkol commented Apr 24, 2022

On my Docker host (Ubuntu VM) zlib is version 1:1.2.11.dfsg-2ubuntu1.3
Docspell Docker container 0.34.0 has zlib-1.2.11-r3
Docspell Docker container 0.35.0 has zlib-1.2.12-r0

As mentioned in madler/zlib#618 (comment), it's maybe also cpu dependent, if it happens or not. My system runs on a Intel i3-1005G1, but it could be affected also by Proxmox/Quemu kvm64 emulation. Maybe I should consider to test with different cpu emulation setting (e.g. host).

@eikek
Copy link
Owner Author

eikek commented Apr 24, 2022

Yes, that sounds also interesting to try out. I tried here on AMD Ryzen7, ARM on RPi4 and Intel Atom x5. Since it works on your system with 0.34.0, I would currently bet on the zlib version. It could be interesting to try out your test program on an image based on 0.34.0 and 0.35.0. Sorry, was too late yesterday… :) Would be indeed interesting to play with cpu settings to get 0.35.0 with zlib 1.2.12 working.

@enkol
Copy link

enkol commented Apr 25, 2022

Ok, i can confirm it's definitly zlib related. I've modified the v0.35.0 container to use newest zlib-1.2.12.r1 from apline/edge instead of zlib.1.2.12-r0 from apline/3.14 and now it works again.

So this issue should be gone, once the base docker apline image contains the fixed zlib version.

Checksum testing now succeds:

  docspell34:
    image: docspell/restserver:v0.34.0
    entrypoint: java -cp /opt/docspell-restserver-0.34.0/lib/org.flywaydb.flyway-core-8.5.4.jar /test.java /test.java
    volumes:
      - ./test.java:/test.java

  docspell35:
    image: docspell/restserver:v0.35.0
    entrypoint: java -cp /opt/docspell-restserver-0.35.0/lib/org.flywaydb.flyway-core-8.5.8.jar /test.java /test.java
    volumes:
      - ./test.java:/test.java

  docspell35b:
    image: docspell/restserver:v0.35.0
    entrypoint: /entry.sh
    volumes:
      - ./test.java:/test.java
      - ./entry.sh:/entry.sh

test.java from #1517 (comment) and entry.sh is:

#!/bin/bash
echo 'http://dl-cdn.alpinelinux.org/alpine/edge/main' >> /etc/apk/repositories
apk add 'zlib=1.2.12-r1'
java -cp /opt/docspell-restserver-0.35.0/lib/org.flywaydb.flyway-core-8.5.8.jar /test.java /test.java

Running docker-compose run --rm docspell34 outputs 1438454349
Running docker-compose run --rm docspell35 outputs -1934287952
Running docker-compose run --rm docspell35b outputs 1438454349

This means, for the meantime I can run Docspell v0.35.0 with:

docker-compose:

service:
  docspell:
    image: docspell/restserver:v0.35.0
    entrypoint: /entry.sh
    volumes:
      - ./entry.sh:/entry.sh

entry.sh:

#!/bin/bash
echo 'http://dl-cdn.alpinelinux.org/alpine/edge/main' >> /etc/apk/repositories
apk add 'zlib=1.2.12-r1'
/opt/docspell-restserver/bin/docspell-restserver -J-XX:+UseG1GC /opt/docspell.conf

And similar for docspell/joex.

@Skyr
Copy link
Contributor

Skyr commented Apr 25, 2022

@enkol 🤯 excellent work, Sherlock!

@eikek
Copy link
Owner Author

eikek commented Apr 25, 2022

Amazing @enkol thank you for this work! I think I can add your patch to the current dockerfiles, wdyt?

I have to think about the future of the images anyways. The problem is that wkhtmltopdf was removed from alpine, but the replacement didn't show as good results. I'd like to keep wkhtmltopdf for now. So maybe I need to use latest alpine, install wkhtmtopdf from a previous alpine and zlib from edge :)

@enkol
Copy link

enkol commented Apr 25, 2022

I don't know what happens if alpine/edge moves on, if it could then break the fix.
Maybe it's safer to wait for alpine to include the fixed zlib and only point people having issues to the solution here?
I'd expect them to include it rather quickly, maybe even in a 3.15.x minor version, as the zlib crc32 issue seems to affect a lot of software.

I'm also not familiar with alpine and it's package manager apk. The current fix was just a quick try based on some google search. It may have sideeffects or there is a better way to do it.

@eikek
Copy link
Owner Author

eikek commented Apr 25, 2022

Yes, these are valid points. It wouldn't be such a problem I had hoped, because the images are fixed once build and the next time they build it would hopefully fail when the packages are not compatible anymore. But it's a risk and not necessary as you said. The images can be upgraded to 3.15 (when the new zlib arrives) with finding a solution for the wkhtmltopdf problem.

@eikek
Copy link
Owner Author

eikek commented May 21, 2022

Alpine 3.14 now also has zlib 1.2.12-r1 - so I think the next image should not have this issue. 🤞🏼

@eikek eikek added this to the Docspell 0.36.0 milestone May 21, 2022
@eikek eikek added bug Something isn't working or in unexpected ways docker All things regarding docker setup labels May 21, 2022
eikek added a commit that referenced this issue May 21, 2022
@eikek
Copy link
Owner Author

eikek commented May 22, 2022

Closing it going to make a release soon. If it still persists, we can reopen :)

@eikek eikek closed this as completed May 22, 2022
@enkol
Copy link

enkol commented May 22, 2022

With v0.36.0 and nightly I still get wrong checksums. Checking zlib version in container still says 1.2.12.r0:

$ apk list zlib
zlib-1.2.12-r0 x86_64 {zlib} (Zlib) [installed]
zlib-1.2.12-r1 x86_64 {zlib} (Zlib) [upgradable from: zlib-1.2.12-r0

@eikek
Copy link
Owner Author

eikek commented May 22, 2022

Oh no 😱 ! Thank you @enkol for checking this. I was assuming that when the package is listed here - it will be installed on next build!

@eikek
Copy link
Owner Author

eikek commented May 22, 2022

It seems that if I explicitly say apk add 'zlib=1.2.12-r1' it will install it

Edit: Hm, I tried the same test on the latest images. It looks different for me 🤔

❯ docker-compose exec joex /bin/bash
bash-5.1# apk list zlib
zlib-1.2.12-r1 x86_64 {zlib} (Zlib) [installed]

@enkol
Copy link

enkol commented May 23, 2022

I had only tested with restserver (smaller download 😺), joex works for me too.

$ docker run --rm --entrypoint '' docspell/joex:nightly bash -c 'apk list zlib'
zlib-1.2.12-r1 x86_64 {zlib} (Zlib) [installed]
 
$ docker run --rm --entrypoint '' docspell/restserver:nightly bash -c 'apk list zlib'
zlib-1.2.12-r0 x86_64 {zlib} (Zlib) [installed]
zlib-1.2.12-r1 x86_64 {zlib} (Zlib) [upgradable from: zlib-1.2.12-r0]

@eikek
Copy link
Owner Author

eikek commented May 23, 2022

Indeed, the restserver has a different zlib. What a mess, not sure if I should make a new image. Another way is to not run the migrations from the restserver, only from joex.

@eikek eikek reopened this May 23, 2022
eikek added a commit that referenced this issue May 25, 2022
zlib 1.2.12-r0 is not working with openjdk, it affects the checksum
calculation of the db migrations. It must be at least 1.2.12-r1. For
some reason joex has this newer version, but the restserver image not.
They are installed explicitely now on both images.

That's why the migration is now disabled on rest-server in the
docker-compose file. It is ok if this is run on one server. It can now
happen that on first start joex is migrating the db and the restserver
tries to do things that don't work yet - it is a corner case. This is
removed with the next version.

Refs: #1517
@eikek
Copy link
Owner Author

eikek commented May 25, 2022

So… I decided to take the pragmatic approach. I changed the current docker-compose file so that the db migration is only executed for joex.There the r1 zlib is installed. I'll remove this for the next release. Then I now explicitly added this zlib version to both images. I find it strange that although it is available in the repos, that the old version is present on the restserver image (but not on joex image). Could be some transitive dependency thing. So the nightly images should work fine now - I hope. If someone could check ihis, would be great!

@enkol
Copy link

enkol commented May 26, 2022

I can confirm, that it works to run current nightly images (v0.37.0-SNAPSHOT) without having checksum errors.

I stopped joex and restserver containers running with v0.35.0 images, changed image tags to nightly and then started first joex (so it can run fixups), then restserver (so it starts with fixed db).
I just had to restart joex, as it failed with exceptions, i think due to restserver not being available for pubsub connection.

@eikek
Copy link
Owner Author

eikek commented May 26, 2022

Thank you very much @enkol ! I'll close this again. The exceptions on start for joex can be ignored. It is as you said - it can't find the restserver to publish some job-done messages. But these are not important usually.

@eikek eikek closed this as completed May 26, 2022
eikek added a commit that referenced this issue Jun 4, 2022
This was done to avoid running them on restserver as the image
contained a broken zlib package. (#1517)
eikek added a commit that referenced this issue Nov 24, 2022
The explicit install was added earlier due to a broken zlib
package (see issue #1517). This has now been fixed for a while in
alpine and can be removed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working or in unexpected ways docker All things regarding docker setup
Projects
None yet
Development

No branches or pull requests

3 participants