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]: While the Quick Match docker server is crashing. #3909

Closed
Pan-Tata opened this issue Jan 29, 2025 · 1 comment
Closed

[Bug]: While the Quick Match docker server is crashing. #3909

Pan-Tata opened this issue Jan 29, 2025 · 1 comment
Labels
bug Something isn't working

Comments

@Pan-Tata
Copy link

What happened?

While using the Quick Match function, server is crashing randomly.
There is no obvious reason for the crash:

  • the same audiobooks can be matched manually without an issue after a Quick Match crash using the same provider.
  • the number of audiobooks selected for the Quick March is not significant: some Quick Matches process dozens of audiobooks without any issue, some crash just on a single audiobook.

What did you expect to happen?

I am looking for a reliable Quick March process, i.e., no server crash

Steps to reproduce the issue

  1. Select audiobooks or a single audiobook.
  2. Start Quick March process (three dots menu)
  3. Check docker container status

Audiobookshelf version

2.18.1

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

[2025-01-29 13:58:05.895] DEBUG: [fileUtils] Downloading file to /audiobooks/_gotowe_audiobooks/C/Ciszewski Marcin/Ciszewski Marcin  - Major/cover
[2025-01-29 13:58:06.708] DEBUG: [CacheManager] Going to purge 820739d1-32cd-4e82-b59f-6c00fd70e4c4_400.webp
[2025-01-29 13:58:06.721] INFO: [CoverManager] Downloaded libraryItem cover "/audiobooks/_gotowe_audiobooks/C/Ciszewski Marcin/Ciszewski Marcin  - Major/cover.jpg" from url "https://staticaudiotekacom.imgix.net/pl/images/products/marcin-ciszewski/major-original.jpg?w=300&auto=format"
[2025-01-29 13:58:06.794] DEBUG: [ApiCacheManager] Object.afterBulkDestroy: Clearing cache
[2025-01-29 13:58:06.796] INFO: [Scanner] quickMatchBookBuildUpdatePayload: Removed author "Ciszewski Marcin" from "Major"
[2025-01-29 13:58:06.852] DEBUG: [ApiCacheManager] bookSeries.afterCreate: Clearing cache
[2025-01-29 13:58:06.854] INFO: [Scanner] quickMatchBookBuildUpdatePayload: Added series "www" to "Major"
[2025-01-29 13:58:06.873] FATAL: [Server] Unhandled rejection: Error: WHERE parameter "id" has invalid "undefined" value
    at SQLiteQueryGenerator.whereItemQuery (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:1743:13)
    at /node_modules/sequelize/lib/dialects/abstract/query-generator.js:1734:25
    at Array.forEach (<anonymous>)
    at SQLiteQueryGenerator.whereItemsQuery (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:1732:35)
    at SQLiteQueryGenerator.getWhereConditions (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:2075:19)
    at SQLiteQueryGenerator.deleteQuery (/node_modules/sequelize/lib/dialects/sqlite/query-generator.js:197:28)
    at SQLiteQueryInterface.delete (/node_modules/sequelize/lib/dialects/abstract/query-interface.js:370:37)
    at BookSeries.destroy (/node_modules/sequelize/lib/model.js:2627:60)
    at async Scanner.quickMatchBookBuildUpdatePayload (/server/scanner/Scanner.js:338:13)
    at async Scanner.quickMatchLibraryItem (/server/scanner/Scanner.js:82:35)
promise: Promise {
  <rejected> Error: WHERE parameter "id" has invalid "undefined" value
      at SQLiteQueryGenerator.whereItemQuery (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:1743:13)
      at /node_modules/sequelize/lib/dialects/abstract/query-generator.js:1734:25
      at Array.forEach (<anonymous>)
      at SQLiteQueryGenerator.whereItemsQuery (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:1732:35)
      at SQLiteQueryGenerator.getWhereConditions (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:2075:19)
      at SQLiteQueryGenerator.deleteQuery (/node_modules/sequelize/lib/dialects/sqlite/query-generator.js:197:28)
      at SQLiteQueryInterface.delete (/node_modules/sequelize/lib/dialects/abstract/query-interface.js:370:37)
      at BookSeries.destroy (/node_modules/sequelize/lib/model.js:2627:60)
      at async Scanner.quickMatchBookBuildUpdatePayload (/server/scanner/Scanner.js:338:13)
      at async Scanner.quickMatchLibraryItem (/server/scanner/Scanner.js:82:35)
----------------------
[2025-01-29 13:12:40.017] DEBUG: [ApiCacheManager] book.afterUpdate: Clearing cache
[2025-01-29 13:12:40.041] DEBUG: [ApiCacheManager] libraryItem.afterUpdate: Clearing cache
[2025-01-29 13:12:40.089] DEBUG: [ApiCacheManager] libraryItem.afterUpdate: Clearing cache
[2025-01-29 13:12:40.090] DEBUG: [LibraryItem] Saved metadata for "Traktat o higienie: dzieje doktora Skórzewskiego" file to "/audiobooks/_opisane/Andrzej Pilipiuk/Światy Pilipiuka/Traktat o higienie - dzieje doktora Skórzewskiego/metadata.json"
[2025-01-29 13:12:40.157] DEBUG: [FfmpegHelpers] Resize Image Cmd: ffmpeg -i /audiobooks/_opisane/Andrzej Pilipiuk/Światy Pilipiuka/Traktat o higienie - dzieje doktora Skórzewskiego/cover.jpg -y -vf scale=400:-1 /metadata/cache/covers/d634a20a-405c-42ec-b70d-541722c241fa_400.webp
[2025-01-29 13:12:40.343] DEBUG: [FfmpegHelpers] Image resized Successfully
[2025-01-29 13:12:49.273] DEBUG: [Scanner] Updating cover "https://staticaudiotekacom.imgix.net/pl/images/products/tomasz-piatek/rydzyk-i-przyjaciele-wielkie-zniwo-original.jpeg?w=300&auto=format"
[2025-01-29 13:12:49.286] DEBUG: [fileUtils] Downloading file to /audiobooks/_opisane/Tomasz Piątek/Rydzyk i przyjaciele/Rydzyk i przyjaciele. Wielkie żniwo/cover
[2025-01-29 13:12:49.812] DEBUG: [CoverManager] Removing old cover from metadata "/audiobooks/_opisane/Tomasz Piątek/Rydzyk i przyjaciele/Rydzyk i przyjaciele. Wielkie żniwo/cover.png"
[2025-01-29 13:12:49.847] DEBUG: [CacheManager] Going to purge 23916d0e-7978-47ef-ada6-a662f330c0a5_400.webp
[2025-01-29 13:12:49.855] INFO: [CoverManager] Downloaded libraryItem cover "/audiobooks/_opisane/Tomasz Piątek/Rydzyk i przyjaciele/Rydzyk i przyjaciele. Wielkie żniwo/cover.jpg" from url "https://staticaudiotekacom.imgix.net/pl/images/products/tomasz-piatek/rydzyk-i-przyjaciele-wielkie-zniwo-original.jpeg?w=300&auto=format"
[2025-01-29 13:12:49.901] DEBUG: [ApiCacheManager] Object.afterBulkDestroy: Clearing cache
[2025-01-29 13:12:49.903] INFO: [Scanner] quickMatchBookBuildUpdatePayload: Removed author "Piątek Tomasz" from "Rydzyk i przyjaciele. Wielkie żniwo"
[2025-01-29 13:12:49.932] FATAL: [Server] Unhandled rejection: Error: You attempted to save an instance with no primary key, this is not allowed since it would result in a global update
    at BookSeries.save (/node_modules/sequelize/lib/model.js:2413:15)
    at Scanner.quickMatchBookBuildUpdatePayload (/server/scanner/Scanner.js:309:45)
    at async Scanner.quickMatchLibraryItem (/server/scanner/Scanner.js:82:35)
    at async ApiRouter.batchQuickMatch (/server/controllers/LibraryItemController.js:744:27)
promise: Promise {
  <rejected> Error: You attempted to save an instance with no primary key, this is not allowed since it would result in a global update
      at BookSeries.save (/node_modules/sequelize/lib/model.js:2413:15)
      at Scanner.quickMatchBookBuildUpdatePayload (/server/scanner/Scanner.js:309:45)
      at async Scanner.quickMatchLibraryItem (/server/scanner/Scanner.js:82:35)
      at async ApiRouter.batchQuickMatch (/server/controllers/LibraryItemController.js:744:27)
}
--------------------------------
[2025-01-29 17:28:03.921] DEBUG: [ApiCacheManager] count: 1 size: 248423
[2025-01-29 17:28:04.062] DEBUG: Loaded 48 of 3072 items for libary page in 0.14s
[2025-01-29 17:28:04.066] DEBUG: [ApiCacheManager] Cache miss: {"user":"marcinz","url":"/libraries/25d97b92-344f-4d3f-b9fb-ba30ade55444/items?sort=addedAt&desc=1&limit=48&page=0&minified=1&include=rssfeed,numEpisodesIncomplete,share"}
[2025-01-29 17:28:04.289] DEBUG: [ApiCacheManager] count: 2 size: 326179
[2025-01-29 17:28:04.291] DEBUG: [ApiCacheManager] count: 2 size: 326179
[2025-01-29 17:28:04.664] DEBUG: Loaded 48 of 3072 items for libary page in 0.37s
[2025-01-29 17:28:04.668] DEBUG: [ApiCacheManager] Cache miss: {"user":"marcinz","url":"/libraries/25d97b92-344f-4d3f-b9fb-ba30ade55444/items?sort=addedAt&desc=1&limit=48&page=24&minified=1&include=rssfeed,numEpisodesIncomplete,share"}
[2025-01-29 17:28:04.676] DEBUG: Loaded 48 of 3072 items for libary page in 0.38s
[2025-01-29 17:28:04.679] DEBUG: [ApiCacheManager] Cache miss: {"user":"marcinz","url":"/libraries/25d97b92-344f-4d3f-b9fb-ba30ade55444/items?sort=addedAt&desc=1&limit=48&page=25&minified=1&include=rssfeed,numEpisodesIncomplete,share"}
[2025-01-29 17:28:20.769] DEBUG: [Scanner] Updating cover "https://staticaudiotekacom.imgix.net/pl/images/products/haruki-murakami/1q84-tom2-original.jpeg?w=300&auto=format"
[2025-01-29 17:28:20.779] DEBUG: [fileUtils] Downloading file to /audiobooks/_opisane/Haruki Murakami/1Q84 tom 2/cover
[2025-01-29 17:28:21.718] DEBUG: [CacheManager] Going to purge c43f128d-28bd-41d0-a361-8259b886ce32_400.webp
[2025-01-29 17:28:21.724] INFO: [CoverManager] Downloaded libraryItem cover "/audiobooks/_opisane/Haruki Murakami/1Q84 tom 2/cover.jpg" from url "https://staticaudiotekacom.imgix.net/pl/images/products/haruki-murakami/1q84-tom2-original.jpeg?w=300&auto=format"
[2025-01-29 17:28:21.775] DEBUG: [ApiCacheManager] series.afterCreate: Clearing cache
[2025-01-29 17:28:21.805] DEBUG: [ApiCacheManager] bookSeries.afterCreate: Clearing cache
[2025-01-29 17:28:21.808] INFO: [Scanner] quickMatchBookBuildUpdatePayload: Added series "1Q84" to "1Q84 tom 2"
[2025-01-29 17:28:21.826] FATAL: [Server] Unhandled rejection: Error: WHERE parameter "id" has invalid "undefined" value
    at SQLiteQueryGenerator.whereItemQuery (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:1743:13)
    at /node_modules/sequelize/lib/dialects/abstract/query-generator.js:1734:25
    at Array.forEach (<anonymous>)
    at SQLiteQueryGenerator.whereItemsQuery (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:1732:35)
    at SQLiteQueryGenerator.getWhereConditions (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:2075:19)
    at SQLiteQueryGenerator.deleteQuery (/node_modules/sequelize/lib/dialects/sqlite/query-generator.js:197:28)
    at SQLiteQueryInterface.delete (/node_modules/sequelize/lib/dialects/abstract/query-interface.js:370:37)
    at BookSeries.destroy (/node_modules/sequelize/lib/model.js:2627:60)
    at async Scanner.quickMatchBookBuildUpdatePayload (/server/scanner/Scanner.js:338:13)
    at async Scanner.quickMatchLibraryItem (/server/scanner/Scanner.js:82:35)
promise: Promise {
  <rejected> Error: WHERE parameter "id" has invalid "undefined" value
      at SQLiteQueryGenerator.whereItemQuery (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:1743:13)
      at /node_modules/sequelize/lib/dialects/abstract/query-generator.js:1734:25
      at Array.forEach (<anonymous>)
      at SQLiteQueryGenerator.whereItemsQuery (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:1732:35)
      at SQLiteQueryGenerator.getWhereConditions (/node_modules/sequelize/lib/dialects/abstract/query-generator.js:2075:19)
      at SQLiteQueryGenerator.deleteQuery (/node_modules/sequelize/lib/dialects/sqlite/query-generator.js:197:28)
      at SQLiteQueryInterface.delete (/node_modules/sequelize/lib/dialects/abstract/query-interface.js:370:37)
      at BookSeries.destroy (/node_modules/sequelize/lib/model.js:2627:60)
      at async Scanner.quickMatchBookBuildUpdatePayload (/server/scanner/Scanner.js:338:13)
      at async Scanner.quickMatchLibraryItem (/server/scanner/Scanner.js:82:35)
}

Additional Notes

  1. I was trying with different number of audiobooks to process.
  2. I was trying to observe any regularity in the audiobooks selected for the process. The most suspicious seem to be those audiobooks with series name/number.
  3. The same audiobook can cause the crash several times, but:
  4. The same audiobook after manual matching can be processed without issues.
  5. The last log example:
    [2025-01-29 17:30:39.060] DEBUG: [Scanner] Updating cover "https://staticaudiotekacom.imgix.net/pl/images/products/haruki-murakami/1q84-tom2-original.jpeg?w=300&auto=format"
    [2025-01-29 17:30:39.066] DEBUG: [fileUtils] Downloading file to /audiobooks/_opisane/Haruki Murakami/1Q84 tom 2/cover
    [2025-01-29 17:30:39.506] INFO: [CoverManager] Downloaded libraryItem cover "/audiobooks/_opisane/Haruki Murakami/1Q84 tom 2/cover.jpg" from url "https://staticaudiotekacom.imgix.net/pl/images/products/haruki-murakami/1q84-tom2-original.jpeg?w=300&auto=format"

is causing an issue every Quick Match restart.
After manual match, the audiobook is processed correctly and there is a fail on another one.

@Pan-Tata Pan-Tata added the bug Something isn't working label Jan 29, 2025
@nichwall
Copy link
Contributor

Duplicate of #3883

@advplyr advplyr closed this as completed Jan 29, 2025
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