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]: Items created through web client causes crash #3353

Closed
nichwall opened this issue Sep 1, 2024 · 5 comments
Closed

[Bug]: Items created through web client causes crash #3353

nichwall opened this issue Sep 1, 2024 · 5 comments
Labels
bug Something isn't working

Comments

@nichwall
Copy link
Contributor

nichwall commented Sep 1, 2024

What happened?

Things that are currently causing a crash:

  • Adding new podcasts through web UI
  • Uploading books through web UI

Scanning books added through the file system is working for creating new library items.

This may be related to some of the migrations away from the old data model.

What did you expect to happen?

Podcasts and books to be created and server to not crash

Steps to reproduce the issue

  1. Create new server of version 2.13.0
  2. Create a single podcast library
  3. Search for a new podcast. I tested with "Up First from NPR" and "Business Wars"
  4. Attempt to add podcast. Crash occurs after clicking "Submit" button on the pop-up
    image

Audiobookshelf version

v2.13.0

How are you running audiobookshelf?

Docker

What OS is your Audiobookshelf server hosted from?

Other (list in "Additional Notes" box)

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

None

Logs

Config /config /metadata
[2024-08-31 20:16:46.029] INFO: === Starting Server ===
[2024-08-31 20:16:46.031] INFO: [Server] Init v2.13.0
[2024-08-31 20:16:46.032] INFO: [Server] Node.js Version: v20.17.0
[2024-08-31 20:16:46.032] INFO: [Server] Platform: linux
[2024-08-31 20:16:46.032] INFO: [Server] Arch: x64
[2024-08-31 20:16:46.039] INFO: [Database] absdatabase.sqlite not found at /config/absdatabase.sqlite
[2024-08-31 20:16:46.040] INFO: [Database] Initializing db at "/config/absdatabase.sqlite"
[2024-08-31 20:16:46.137] INFO: [Database] Db connection was successful
[2024-08-31 20:17:00.317] INFO: [Database] Db initialized with models: user, library, libraryFolder, book, podcast, podcastEpisode, libraryItem, mediaProgress, series, bookSeries, author, bookAuthor, collection, collectionBook, playlist, playlistMediaItem, device, playbackSession, feed, feedEpisode, setting, customMetadataProvider, mediaItemShare
[2024-08-31 20:17:00.350] INFO: [LogManager] Init current daily log filename: 2024-08-31.txt
[2024-08-31 20:17:00.678] INFO: [BackupManager] 0 Backups Found
[2024-08-31 20:17:00.679] INFO: [BackupManager] Auto Backups are disabled
[2024-08-31 20:17:00.709] INFO: Listening on port :80
[2024-08-31 20:17:29.112] INFO: [Server] Initializing new server
[2024-08-31 20:17:32.208] INFO: [Auth] User "root" logged in from ip ::ffff:172.19.0.1
[2024-08-31 20:17:32.379] INFO: [SocketAuthority] Socket Connected nsAM0lA09lmiLworAAAB
[2024-08-31 20:17:50.790] INFO: [Watcher] Initializing watcher for "podcasts".
[2024-08-31 20:17:50.799] INFO: [Watcher] "podcasts" Ready
[2024-08-31 20:18:12.035] DEBUG: Set Log Level to DEBUG (Logger.js:99)
[2024-08-31 20:18:12.461] DEBUG: [ApiCacheManager] Array.afterUpsert: Clearing cache (ApiCacheManager.js:20)
[2024-08-31 20:18:14.341] DEBUG: [ApiCacheManager] count: 0 size: 0 (ApiCacheManager.js:47)
[2024-08-31 20:18:14.347] DEBUG: [ApiCacheManager] Cache miss: {"user":"root","url":"/libraries/3f00c863-8f65-4209-ac1b-6ac595e053f3?include=filterdata"} (ApiCacheManager.js:58)
[2024-08-31 20:18:14.412] DEBUG: [ApiCacheManager] count: 1 size: 772 (ApiCacheManager.js:47)
[2024-08-31 20:18:14.458] DEBUG: Loaded 0 of 0 items for "Continue Listening/Reading" in 0.03s (LibraryItem.js:641)
[2024-08-31 20:18:14.474] DEBUG: Loaded 0 of 0 episodes for "Newest Episodes" in 0.01s (LibraryItem.js:672)
[2024-08-31 20:18:14.490] DEBUG: Loaded 0 of 0 items for "Recently Added" in 0.02s (LibraryItem.js:688)
[2024-08-31 20:18:14.502] DEBUG: Loaded 0 of 0 items for "Listen/Read Again" in 0.01s (LibraryItem.js:750)
[2024-08-31 20:18:14.502] DEBUG: Loaded 0 personalized shelves in 0.07s (LibraryItem.js:769)
[2024-08-31 20:18:14.503] DEBUG: [ApiCacheManager] Cache miss: {"user":"root","url":"/libraries/3f00c863-8f65-4209-ac1b-6ac595e053f3/personalized?include=rssfeed,numEpisodesIncomplete,share"} (ApiCacheManager.js:58)
[2024-08-31 20:18:14.503] DEBUG: [ApiCacheManager] Caching with 1800000 ms TTL (ApiCacheManager.js:61)
[2024-08-31 20:18:16.900] DEBUG: [ApiCacheManager] count: 2 size: 824 (ApiCacheManager.js:47)
[2024-08-31 20:18:16.901] DEBUG: [ApiCacheManager] Cache hit: {"user":"root","url":"/libraries/3f00c863-8f65-4209-ac1b-6ac595e053f3?include=filterdata"} (ApiCacheManager.js:50)
[2024-08-31 20:18:16.944] DEBUG: [ApiCacheManager] count: 2 size: 824 (ApiCacheManager.js:47)
[2024-08-31 20:18:16.956] DEBUG: Loaded 0 of 0 items for libary page in 0.01s (LibraryItem.js:568)
[2024-08-31 20:18:16.956] DEBUG: [ApiCacheManager] Cache miss: {"user":"root","url":"/libraries/3f00c863-8f65-4209-ac1b-6ac595e053f3/items?page=0&minified=1"} (ApiCacheManager.js:58)
[2024-08-31 20:18:28.732] DEBUG: [iTunes] Searching for podcast with term "business bastards" (PodcastFinder.js:17)
[2024-08-31 20:18:29.214] DEBUG: [iTunes] Podcast search for "business bastards" returned 0 results (PodcastFinder.js:19)
[2024-08-31 20:18:35.594] DEBUG: [iTunes] Searching for podcast with term "business wars" (PodcastFinder.js:17)
[2024-08-31 20:18:35.959] DEBUG: [iTunes] Podcast search for "business wars" returned 43 results (PodcastFinder.js:19)
[2024-08-31 20:18:46.925] DEBUG: [podcastUtils] getPodcastFeed for "https://rss.art19.com/business-wars" (podcastUtils.js:229)
[2024-08-31 20:18:47.603] DEBUG: [podcastUtils] getPodcastFeed for "https://rss.art19.com/business-wars" success - parsing xml (podcastUtils.js:257)
[2024-08-31 20:18:51.143] FATAL: [Server] Unhandled rejection: TypeError: Cannot read properties of undefined (reading 'find'), promise: Promise {
  <rejected> TypeError: Cannot read properties of undefined (reading 'find')
      at ApiRouter.create (/server/controllers/PodcastController.js:47:43)
} (Server.js:185)

Crash logs, from several download attempts, then attempt to use web UI to upload.

{"timestamp":"2024-08-31 20:15:47.121","source":"Server.js:185","message":"[Server] Unhandled rejection: SequelizeDatabaseError: SQLITE_READONLY: attempt to write a readonly database, promise: Promise {\n  <rejected> Error\n      at Database.<anonymous> (/node_modules/sequelize/lib/dialects/sqlite/query.js:185:27)\n      at /node_modules/sequelize/lib/dialects/sqlite/query.js:183:50\n      at new Promise (<anonymous>)\n      at Query.run (/node_modules/sequelize/lib/dialects/sqlite/query.js:183:12)\n      at /node_modules/sequelize/lib/sequelize.js:315:28\n      at async SQLiteQueryInterface.update (/node_modules/sequelize/lib/dialects/abstract/query-interface.js:355:12)\n      at async Book.save (/node_modules/sequelize/lib/model.js:2490:35)\n      at async Book.update (/node_modules/sequelize/lib/model.js:2598:12)\n      at async libraryItem.fullUpdateFromOld (/server/models/LibraryItem.js:373:9)\n      at async Database.updateLibraryItem (/server/Database.js:422:21) {\n    name: 'SequelizeDatabaseError',\n    parent: [Error: SQLITE_READONLY: attempt to write a readonly database] {\n      errno: 8,\n      code: 'SQLITE_READONLY',\n      sql: 'UPDATE `books` SET `ebookFile`=$1,`updatedAt`=$2 WHERE `id` = $3'\n    },\n    original: [Error: SQLITE_READONLY: attempt to write a readonly database] {\n      errno: 8,\n      code: 'SQLITE_READONLY',\n      sql: 'UPDATE `books` SET `ebookFile`=$1,`updatedAt`=$2 WHERE `id` = $3'\n    },\n    sql: 'UPDATE `books` SET `ebookFile`=$1,`updatedAt`=$2 WHERE `id` = $3',\n    parameters: {}\n  }\n}","levelName":"FATAL","level":5}
{"timestamp":"2024-08-31 20:18:51.143","source":"Server.js:185","message":"[Server] Unhandled rejection: TypeError: Cannot read properties of undefined (reading 'find'), promise: Promise {\n  <rejected> TypeError: Cannot read properties of undefined (reading 'find')\n      at ApiRouter.create (/server/controllers/PodcastController.js:47:43)\n}","levelName":"FATAL","level":5}
{"timestamp":"2024-08-31 20:21:13.931","source":"Server.js:185","message":"[Server] Unhandled rejection: TypeError: Cannot read properties of undefined (reading 'find'), promise: Promise {\n  <rejected> TypeError: Cannot read properties of undefined (reading 'find')\n      at ApiRouter.create (/server/controllers/PodcastController.js:47:43)\n}","levelName":"FATAL","level":5}
{"timestamp":"2024-08-31 20:22:21.956","source":"Server.js:185","message":"[Server] Unhandled rejection: TypeError: Cannot read properties of undefined (reading 'find'), promise: Promise {\n  <rejected> TypeError: Cannot read properties of undefined (reading 'find')\n      at ApiRouter.create (/server/controllers/PodcastController.js:47:43)\n}","levelName":"FATAL","level":5}
{"timestamp":"2024-08-31 20:30:56.824","source":"Server.js:185","message":"[Server] Unhandled rejection: TypeError: Cannot read properties of undefined (reading 'find'), promise: Promise {\n  <rejected> TypeError: Cannot read properties of undefined (reading 'find')\n      at ApiRouter.create (/server/controllers/PodcastController.js:47:43)\n}","levelName":"FATAL","level":5}
{"timestamp":"2024-08-31 20:32:18.919","source":"Server.js:185","message":"[Server] Unhandled rejection: TypeError: Cannot read properties of undefined (reading 'find'), promise: Promise {\n  <rejected> TypeError: Cannot read properties of undefined (reading 'find')\n      at ApiRouter.create (/server/controllers/PodcastController.js:47:43)\n}","levelName":"FATAL","level":5}
{"timestamp":"2024-08-31 20:35:48.515","source":"Server.js:185","message":"[Server] Unhandled rejection: TypeError: Cannot read properties of undefined (reading 'find'), promise: Promise {\n  <rejected> TypeError: Cannot read properties of undefined (reading 'find')\n      at ApiRouter.handleUpload (/server/controllers/MiscController.js:51:43)\n}","levelName":"FATAL","level":5}

Additional Notes

Synology NAS

Crashes continued to occur after adding a book through the file system and trying to both add a podcast and upload a book through the web client.

@nichwall nichwall added the bug Something isn't working label Sep 1, 2024
@nichwall
Copy link
Contributor Author

nichwall commented Sep 1, 2024

For reference, the lines causing the above crash are here:

const folder = library.libraryFolders.find((fold) => fold.id === payload.folderId)

const folder = library.libraryFolders.find((fold) => fold.id === folderId)

@StuartHawkes
Copy link

StuartHawkes commented Sep 1, 2024

I saw this issue when running a dev version over the last couple of weeks. It occurred post-commit 5d13fae and I could fix it by moving some of the uploadHandler code in MiscController.js back to the old model, roughly:

library.libraryFolders.find TO library.folders.find

libraryModel.findByPk TO libraryModel.getOldById

folder.path TO folder.fullPath

I don’t know enough about the new model to fix it properly, and I assumed it was related to a TODO in the dev version which would be fixed before the version release. Surprised to see it still there in 2.13.0.

BTW, I’m not using a NAS for this and the crash also occurred when I created a fresh installation with a fresh library.

@nichwall
Copy link
Contributor Author

nichwall commented Sep 1, 2024

Thanks for the help in narrowing it down. I've started investigating on a dev version as well.

In the future if you can open an issue mentioning any problem with the edge container or a dev image, that helps catch errors before a release. The test architecture is still pretty primitive and requires a lot of manual testing, so if problems are not reported they tend to not get fixed. Even if you get a response of "oh yes this is planned", this helps to make sure details don't get overlooked when there is a GH issue attached to it.

@StuartHawkes
Copy link

Will do - I wasn’t sure if I should report issues with an unreleased dev version, I didn’t want to get a "Yes, we know" response, so thanks for the advice.

@advplyr advplyr added the awaiting release Issue is resolved and will be in the next release label Sep 1, 2024
Copy link

github-actions bot commented Sep 1, 2024

Fixed in v2.13.1.

@github-actions github-actions bot closed this as completed Sep 1, 2024
@github-actions github-actions bot removed the awaiting release Issue is resolved and will be in the next release label Sep 1, 2024
nichwall pushed a commit to nichwall/audiobookshelf that referenced this issue Sep 13, 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

Successfully merging a pull request may close this issue.

3 participants