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

[Bug]: SQLITE_CORRUPT error on upgrade from 2.16.2 to any 2.17.x version #3647

Closed
biuklija opened this issue Nov 24, 2024 · 8 comments
Closed
Labels
bug Something isn't working

Comments

@biuklija
Copy link
Contributor

What happened?

On upgrade to from 2.16.2, any newer version, the image crashes and reports corrupt database. Reverting back to 1.16.2 the same database works fine.
Migration failed: MigrationError: Migration v2.17.0-uuid-replacement.js (up) failed: Original error: SQLITE_CORRUPT: database disk image is malformed

What did you expect to happen?

Image should perform the database upgrade and start.

Steps to reproduce the issue

  1. Stop image
  2. Pull the latest image or 2.17.0, 2.17.1, 2.17.2
  3. Run image

Audiobookshelf version

2.17.2

How are you running audiobookshelf?

Docker

What OS is your Audiobookshelf server hosted from?

Linux

If the issue is being seen in the UI, what browsers are you seeing the problem on?

None

Logs

audiobookshelf-1  | [2024-11-24 13:08:10.495] INFO: === Starting Server ===
audiobookshelf-1  | [2024-11-24 13:08:10.505] INFO: [Server] Init v2.17.0
audiobookshelf-1  | [2024-11-24 13:08:10.507] INFO: [Server] Node.js Version: v20.18.0
audiobookshelf-1  | [2024-11-24 13:08:10.508] INFO: [Server] Platform: linux
audiobookshelf-1  | [2024-11-24 13:08:10.511] INFO: [Server] Arch: arm64
audiobookshelf-1  | [2024-11-24 13:08:10.535] INFO: [Database] Initializing db at "/config/absdatabase.sqlite"
audiobookshelf-1  | [2024-11-24 13:08:10.685] INFO: [Database] Loading extension /usr/local/lib/nusqlite3/libnusqlite3.so
audiobookshelf-1  | [2024-11-24 13:08:10.689] INFO: [Database] Successfully loaded extension /usr/local/lib/nusqlite3/libnusqlite3.so
audiobookshelf-1  | [2024-11-24 13:08:10.691] INFO: [Database] Db supports unaccent and unicode foldings
audiobookshelf-1  | [2024-11-24 13:08:10.694] INFO: [Database] Db connection was successful
audiobookshelf-1  | [2024-11-24 13:08:10.804] INFO: [MigrationManager] Migrating database up to version 2.17.0
audiobookshelf-1  | [2024-11-24 13:08:10.806] INFO: [MigrationManager] Migrations to run: v2.17.0-uuid-replacement.js
audiobookshelf-1  | [2024-11-24 13:08:12.675] INFO: Created a backup of the original database.
audiobookshelf-1  | [2024-11-24 13:08:12.685] INFO: { event: 'migrating', name: 'v2.17.0-uuid-replacement.js' }
audiobookshelf-1  | [2024-11-24 13:08:12.694] INFO: [2.17.0 migration] UPGRADE BEGIN: 2.17.0-uuid-replacement
audiobookshelf-1  | [2024-11-24 13:08:12.695] INFO: [2.17.0 migration] Changing libraryItems.mediaId column to UUID
audiobookshelf-1  | [2024-11-24 13:08:12.744] ERROR: [MigrationManager] Migration failed: MigrationError: Migration v2.17.0-uuid-replacement.js (up) failed: Original error: SQLITE_CORRUPT: database disk image is malformed
audiobookshelf-1  |     at /server/libs/umzug/umzug.js:150:17
audiobookshelf-1  |     at async Umzug.runCommand (/server/libs/umzug/umzug.js:112:12)
audiobookshelf-1  |     at async MigrationManager.runMigrations (/server/managers/MigrationManager.js:102:9)
audiobookshelf-1  |     at async Database.init (/server/Database.js:184:7)
audiobookshelf-1  |     at async Server.init (/server/Server.js:127:5)
audiobookshelf-1  |     at async Server.start (/server/Server.js:193:5) {
audiobookshelf-1  |   migration: {
audiobookshelf-1  |     direction: 'up',
audiobookshelf-1  |     name: 'v2.17.0-uuid-replacement.js',
audiobookshelf-1  |     path: '/config/migrations/v2.17.0-uuid-replacement.js',
audiobookshelf-1  |     context: { queryInterface: [SQLiteQueryInterface], logger: [Logger] }
audiobookshelf-1  |   },
audiobookshelf-1  |   [cause]: Error
audiobookshelf-1  |       at Database.<anonymous> (/node_modules/sequelize/lib/dialects/sqlite/query.js:185:27)
audiobookshelf-1  |       at /node_modules/sequelize/lib/dialects/sqlite/query.js:183:50
audiobookshelf-1  |       at new Promise (<anonymous>)
audiobookshelf-1  |       at Query.run (/node_modules/sequelize/lib/dialects/sqlite/query.js:183:12)
audiobookshelf-1  |       at /node_modules/sequelize/lib/sequelize.js:315:28
audiobookshelf-1  |       at async SQLiteQueryInterface.changeColumn (/node_modules/sequelize/lib/dialects/sqlite/query-interface.js:43:7)
audiobookshelf-1  |       at async Object.up (/server/migrations/v2.17.0-uuid-replacement.js:21:3)
audiobookshelf-1  |       at async /server/libs/umzug/umzug.js:148:11
audiobookshelf-1  |       at async Umzug.runCommand (/server/libs/umzug/umzug.js:112:12)
audiobookshelf-1  |       at async MigrationManager.runMigrations (/server/managers/MigrationManager.js:102:9) {
audiobookshelf-1  |     name: 'SequelizeDatabaseError',
audiobookshelf-1  |     parent: [Error: SQLITE_CORRUPT: database disk image is malformed] {
audiobookshelf-1  |       errno: 11,
audiobookshelf-1  |       code: 'SQLITE_CORRUPT',
audiobookshelf-1  |       sql: 'INSERT INTO `libraryItems_backup` SELECT `id`, `ino`, `path`, `relPath`, `mediaId`, `mediaType`, `isFile`, `isMissing`, `isInvalid`, `mtime`, `ctime`, `birthtime`, `size`, `lastScan`, `lastScanVersion`, `libraryFiles`, `extraData`, `createdAt`, `updatedAt`, `libraryId`, `libraryFolderId` FROM `libraryItems`;'
audiobookshelf-1  |     },
audiobookshelf-1  |     original: [Error: SQLITE_CORRUPT: database disk image is malformed] {
audiobookshelf-1  |       errno: 11,
audiobookshelf-1  |       code: 'SQLITE_CORRUPT',
audiobookshelf-1  |       sql: 'INSERT INTO `libraryItems_backup` SELECT `id`, `ino`, `path`, `relPath`, `mediaId`, `mediaType`, `isFile`, `isMissing`, `isInvalid`, `mtime`, `ctime`, `birthtime`, `size`, `lastScan`, `lastScanVersion`, `libraryFiles`, `extraData`, `createdAt`, `updatedAt`, `libraryId`, `libraryFolderId` FROM `libraryItems`;'
audiobookshelf-1  |     },
audiobookshelf-1  |     sql: 'INSERT INTO `libraryItems_backup` SELECT `id`, `ino`, `path`, `relPath`, `mediaId`, `mediaType`, `isFile`, `isMissing`, `isInvalid`, `mtime`, `ctime`, `birthtime`, `size`, `lastScan`, `lastScanVersion`, `libraryFiles`, `extraData`, `createdAt`, `updatedAt`, `libraryId`, `libraryFolderId` FROM `libraryItems`;',
audiobookshelf-1  |     parameters: {}
audiobookshelf-1  |   }
audiobookshelf-1  | }
audiobookshelf-1  | [2024-11-24 13:08:12.767] INFO: [MigrationManager] Saved the failed database as absdatabase.failed.sqlite.
audiobookshelf-1  | [2024-11-24 13:08:12.771] INFO: [MigrationManager] Restored the original database from the backup.
audiobookshelf-1  | [2024-11-24 13:08:12.773] INFO: [MigrationManager] Migration failed. Exiting Audiobookshelf with code 1.

Additional Notes

I have tried running all version post 2.16.2, the crash occurs on all of them.

@biuklija biuklija added the bug Something isn't working label Nov 24, 2024
@nichwall
Copy link
Contributor

Is your database stored on a network drive? Looks like the database has gotten corrupted.

Does reverting to an older version work? So like 2.15.1 or 2.15.0, to make sure the downgrade migration is working? If the migration fails for any reason, the failed database is renamed to absdatabase.sqlite.failed and the original database is restored so you can continue using an old version without losing data. If you try a downgrade and you get a similar error there is definitely something wrong with the database.

@biuklija
Copy link
Contributor Author

The database is stored on the local drive, the config directory is in the same directory as docker-compose.yaml.
Versions 2.16.x run absolutely fine on the same database. So does the the downgrade to 2.15.0 and the subsequent upgrade to 2.16.2.
Upgrade to 2.17.x fails and dumps the absdatabase.failed.sqlite.

Attaching to audiobookshelf-1
audiobookshelf-1  | Config /config /metadata
audiobookshelf-1  | [2024-11-24 15:53:42.181] INFO: === Starting Server ===
audiobookshelf-1  | [2024-11-24 15:53:42.189] INFO: [Server] Init v2.15.0
audiobookshelf-1  | [2024-11-24 15:53:42.190] INFO: [Server] Node.js Version: v20.18.0
audiobookshelf-1  | [2024-11-24 15:53:42.192] INFO: [Server] Platform: linux
audiobookshelf-1  | [2024-11-24 15:53:42.194] INFO: [Server] Arch: arm64
audiobookshelf-1  | [2024-11-24 15:53:42.212] INFO: [Database] Initializing db at "/config/absdatabase.sqlite"
audiobookshelf-1  | [2024-11-24 15:53:42.371] INFO: [Database] Loading extension /usr/local/lib/nusqlite3/libnusqlite3.so
audiobookshelf-1  | [2024-11-24 15:53:42.376] INFO: [Database] Successfully loaded extension /usr/local/lib/nusqlite3/libnusqlite3.so
audiobookshelf-1  | [2024-11-24 15:53:42.377] INFO: [Database] Db supports unaccent and unicode foldings
audiobookshelf-1  | [2024-11-24 15:53:42.380] INFO: [Database] Db connection was successful
audiobookshelf-1  | [2024-11-24 15:53:42.485] INFO: [MigrationManager] Migrating database down to version 2.15.0
audiobookshelf-1  | [2024-11-24 15:53:42.486] INFO: [MigrationManager] Migrations to run: v2.15.2-index-creation.js, v2.15.1-reindex-nocase.js
audiobookshelf-1  | [2024-11-24 15:53:43.800] INFO: Created a backup of the original database.
audiobookshelf-1  | [2024-11-24 15:53:43.808] INFO: { event: 'reverting', name: 'v2.15.2-index-creation.js' }
audiobookshelf-1  | [2024-11-24 15:53:43.817] INFO: [2.15.2 migration] DOWNGRADE BEGIN: 2.15.2-index-creation
audiobookshelf-1  | [2024-11-24 15:53:43.818] INFO: [2.15.2 migration] Removing index for bookAuthors
audiobookshelf-1  | [2024-11-24 15:53:43.871] INFO: [2.15.2 migration] Removing index for bookSeries
audiobookshelf-1  | [2024-11-24 15:53:43.886] INFO: [2.15.2 migration] Deleting existing podcastEpisode index
audiobookshelf-1  | [2024-11-24 15:53:43.897] INFO: [2.15.2 migration] Creating original index for podcastEpisode createdAt
audiobookshelf-1  | [2024-11-24 15:53:43.916] INFO: [2.15.2 migration] DOWNGRADE END: 2.15.2-index-creation
audiobookshelf-1  | [2024-11-24 15:53:43.950] INFO: {
audiobookshelf-1  |   event: 'reverted',
audiobookshelf-1  |   name: 'v2.15.2-index-creation.js',
audiobookshelf-1  |   durationSeconds: 0.143
audiobookshelf-1  | }
audiobookshelf-1  | [2024-11-24 15:53:43.952] INFO: { event: 'reverting', name: 'v2.15.1-reindex-nocase.js' }
audiobookshelf-1  | [2024-11-24 15:53:43.954] INFO: [2.15.1 migration] DOWNGRADE BEGIN: 2.15.1-reindex-nocase
audiobookshelf-1  | [2024-11-24 15:53:43.955] INFO: [2.15.1 migration] No action required for downgrade
audiobookshelf-1  | [2024-11-24 15:53:43.956] INFO: [2.15.1 migration] DOWNGRADE END: 2.15.1-reindex-nocase
audiobookshelf-1  | [2024-11-24 15:53:43.992] INFO: {
audiobookshelf-1  |   event: 'reverted',
audiobookshelf-1  |   name: 'v2.15.1-reindex-nocase.js',
audiobookshelf-1  |   durationSeconds: 0.039
audiobookshelf-1  | }
audiobookshelf-1  | [2024-11-24 15:53:44.017] INFO: [MigrationManager] Migrations successfully applied to the original database.
audiobookshelf-1  | [2024-11-24 15:53:44.721] INFO: [Database] Db initialized with models: SequelizeMeta, user, library, libraryFolder, book, podcast, podcastEpisode, libraryItem, mediaProgress, series, bookSeries, author, bookAuthor, collection, collectionBook, playlist, playlistMediaItem, device, playbackSession, feed, feedEpisode, setting, customMetadataProvider, mediaItemShare
audiobookshelf-1  | [2024-11-24 15:53:44.748] DEBUG: Set Log Level to DEBUG
audiobookshelf-1  | [2024-11-24 15:53:44.983] INFO: [Database] Server upgrade detected from 2.16.0 to 2.15.0
audiobookshelf-1  | [2024-11-24 15:53:45.029] DEBUG: Daily Log file found 2024-11-18.txt
audiobookshelf-1  | [2024-11-24 15:53:45.030] DEBUG: Daily Log file found 2024-11-19.txt
audiobookshelf-1  | [2024-11-24 15:53:45.031] DEBUG: Daily Log file found 2024-11-20.txt
audiobookshelf-1  | [2024-11-24 15:53:45.032] DEBUG: Daily Log file found 2024-11-21.txt
audiobookshelf-1  | [2024-11-24 15:53:45.033] DEBUG: Daily Log file found 2024-11-22.txt
audiobookshelf-1  | [2024-11-24 15:53:45.035] DEBUG: Daily Log file found 2024-11-23.txt
audiobookshelf-1  | [2024-11-24 15:53:45.036] DEBUG: Daily Log file found 2024-11-24.txt

@nichwall
Copy link
Contributor

Thank you for confirming that you have your database stored on the same drive (storing it in a network drive can lead to corruption) and that downgrading is still working for you.

If you are willing to share your database privately (both the original and the failed backup of it), that would be very helpful in figuring out what is causing the migration to say the database is malformed. You can just zip both of them together to make the databases much smaller.

I am out of town for the week so I won't be able to investigate further for a bit.

@biuklija
Copy link
Contributor Author

Sure, where or how do you want the databases sent?

@nichwall
Copy link
Contributor

An email to the account on my GitHub profile or a DM on Discord works. You can either send it as an attachment or a link to download the zip from. I can forward it to other developers if you don't mind me doing that.

@nichwall
Copy link
Contributor

nichwall commented Dec 1, 2024

@biuklija sent me their database file. Running PRAGMA integrity_check on the file, looks like the media progress index got messed up prior to v2.17.0, so the 2.17.0 migration fails.

Error is:

wrong # of entries in index sqlite_autoindex_mediaProgresses_1

I attempted to rebuild the index using REINDEX sqlite_autoindex_mediaProgresses_1; and just a plain REINDEX;, but I am now getting an error of

*** in database main ***
Freelist: size is 193 but should be 198

It definitely looks like the database is corrupted. You mentioned that the database is located on a local drive and not accessed over the network. Have you ever ran multiple instances of ABS and pointed them at the same database or attempted to open the database in another program/script while the ABS server is running?

@nichwall
Copy link
Contributor

nichwall commented Dec 1, 2024

I was able to recover the database and upgrade to 2.17.3 using the following command in the terminal (without server running) to dump the raw SQL and recreate the database:

sqlite3 absdatabase.sqlite ".dump" | sqlite3 temp.db
mv temp.db absdatabase.sqlite

@biuklija
Copy link
Contributor Author

biuklija commented Dec 1, 2024

Have you ever ran multiple instances of ABS and pointed them at the same database or attempted to open the database in another program/script while the ABS server is running?

Not that I know of, but it is possible that I've run docker compose at some point while the image was running. I've also had an SSD failure on my server a few months ago, I was able to recover files, but the database could have been corrupted.

Thank you for your help, I've recreated the database and successfully upgraded it to the latest image. At least we've established that there's no underlying issue in ABS.

@advplyr advplyr closed this as not planned Won't fix, can't repro, duplicate, stale Dec 1, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

3 participants