[Bug]: Crashes on manual library scan

[bloggs-100]

What happened?

Running in docker in Unraid. Normal usage of app is fine, including the auto file system change where it picks up new books added to library. However, triggering a manual library scan crashes the app. When I click the scan button in the libraries, it instantly gives me a red "Socket Disconnected" error in the web app, it generates some errors in the logs, and kills the app (and the docker). I have tried removing recently added books from the library, but I don't trigger the manual scan often so I do not know exactly when this issue began. After restarting the app, everything continues working as normal unless another manual scan is triggered. Adding a new book to the watched library folders results in the book being added like normal. Only the manual scan causes the issue. Any assistance would be greatly appreciated. Full log below from startup to crash.

What did you expect to happen?

Normally the library scan has simply run in the background and completed successfully.

Steps to reproduce the issue

1. Trigger manual scan on library

Audiobookshelf version

2.13.4

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?

Chrome

Logs

Container started
Config /config /metadata
[2024-09-17 10:13:59.460] INFO: === Starting Server ===
[2024-09-17 10:13:59.462] INFO: [Server] Init v2.13.4
[2024-09-17 10:13:59.463] INFO: [Server] Node.js Version: v20.17.0
[2024-09-17 10:13:59.463] INFO: [Server] Platform: linux
[2024-09-17 10:13:59.464] INFO: [Server] Arch: x64
[2024-09-17 10:13:59.469] INFO: [Database] Initializing db at "/config/absdatabase.sqlite"
[2024-09-17 10:13:59.527] INFO: [Database] Db connection was successful
[2024-09-17 10:13:59.742] 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-09-17 10:14:00.062] INFO: [LogManager] Init current daily log filename: 2024-09-17.txt
[2024-09-17 10:14:01.765] INFO: [BackupManager] 13 Backups Found
[2024-09-17 10:14:01.791] INFO: [Watcher] Initializing watcher for "Main".
[2024-09-17 10:14:01.803] INFO: Listening on port :80
[2024-09-17 10:14:02.313] INFO: [SocketAuthority] Socket Connected hGqSegTDvV-ahCzOAAAB
[2024-09-17 10:14:12.306] INFO: [Watcher] "Main" Ready
[2024-09-17 10:15:51.147] INFO: [SocketAuthority] Socket hGqSegTDvV-ahCzOAAAB disconnected from client "root" after 108834ms (Reason: transport close)
[2024-09-17 10:15:51.565] INFO: [SocketAuthority] Socket Connected JCt_A2LsUjNVkv58AAAD
[2024-09-17 10:15:52.970] FATAL: [Server] Unhandled rejection: TypeError: Cannot read properties of undefined (reading 'join'), promise: Promise {
  <rejected> TypeError: Cannot read properties of undefined (reading 'join')
      at LibraryScanner.scan (/server/scanner/LibraryScanner.js:62:63)
      at ApiRouter.scan (/server/controllers/LibraryController.js:1071:26)
      at Layer.handle [as handle_request] (/node_modules/express/lib/router/layer.js:95:5)
      at next (/node_modules/express/lib/router/route.js:144:13)
      at ApiRouter.middleware (/server/controllers/LibraryController.js:1195:5)
} (Server.js:185)
09/17/2024
10:15:51 AM
Container stopped

Additional Notes

Docker hosted on Unraid

[nichwall]

Can you enable Debug logs in the server settings and try doing the scan again?

[bloggs-100]

Oops. I thought I had debug turned back on when I did the first one. Here you go. The error looks about the same -

Container started
Config /config /metadata
[2024-09-17 10:40:40.719] INFO: === Starting Server ===
[2024-09-17 10:40:40.721] INFO: [Server] Init v2.13.4
[2024-09-17 10:40:40.721] INFO: [Server] Node.js Version: v20.17.0
[2024-09-17 10:40:40.722] INFO: [Server] Platform: linux
[2024-09-17 10:40:40.722] INFO: [Server] Arch: x64
[2024-09-17 10:40:40.730] INFO: [Database] Initializing db at "/config/absdatabase.sqlite"
[2024-09-17 10:40:40.779] INFO: [Database] Db connection was successful
[2024-09-17 10:40:40.971] 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-09-17 10:40:40.981] DEBUG: Set Log Level to DEBUG (Logger.js:99)
[2024-09-17 10:40:41.322] DEBUG: Daily Log file found 2024-09-11.txt (LogManager.js:94)
[2024-09-17 10:40:41.323] DEBUG: Daily Log file found 2024-09-12.txt (LogManager.js:94)
[2024-09-17 10:40:41.323] DEBUG: Daily Log file found 2024-09-13.txt (LogManager.js:94)
[2024-09-17 10:40:41.324] DEBUG: Daily Log file found 2024-09-14.txt (LogManager.js:94)
[2024-09-17 10:40:41.324] DEBUG: Daily Log file found 2024-09-15.txt (LogManager.js:94)
[2024-09-17 10:40:41.325] DEBUG: Daily Log file found 2024-09-16.txt (LogManager.js:94)
[2024-09-17 10:40:41.325] DEBUG: Daily Log file found 2024-09-17.txt (LogManager.js:94)
[2024-09-17 10:40:41.326] INFO: [LogManager] Init current daily log filename: 2024-09-17.txt
[2024-09-17 10:40:41.326] DEBUG: [LogManager] Daily log file already exists - set in Logger (LogManager.js:71)
[2024-09-17 10:40:41.331] DEBUG: [DailyLog] 2024-09-17: Loaded 117 Logs (DailyLog.js:132)
[2024-09-17 10:40:41.522] DEBUG: [BackupManager] Backup found "2024-09-05T0130" (BackupManager.js:282)
[2024-09-17 10:40:41.639] DEBUG: [BackupManager] Backup found "2024-09-06T0130" (BackupManager.js:282)
[2024-09-17 10:40:41.737] DEBUG: [BackupManager] Backup found "2024-09-07T0130" (BackupManager.js:282)
[2024-09-17 10:40:41.842] DEBUG: [BackupManager] Backup found "2024-09-08T0130" (BackupManager.js:282)
[2024-09-17 10:40:41.952] DEBUG: [BackupManager] Backup found "2024-09-09T0130" (BackupManager.js:282)
[2024-09-17 10:40:42.073] DEBUG: [BackupManager] Backup found "2024-09-10T0130" (BackupManager.js:282)
[2024-09-17 10:40:42.180] DEBUG: [BackupManager] Backup found "2024-09-11T0130" (BackupManager.js:282)
[2024-09-17 10:40:42.294] DEBUG: [BackupManager] Backup found "2024-09-12T0130" (BackupManager.js:282)
[2024-09-17 10:40:42.402] DEBUG: [BackupManager] Backup found "2024-09-13T0130" (BackupManager.js:282)
[2024-09-17 10:40:42.513] DEBUG: [BackupManager] Backup found "2024-09-14T0130" (BackupManager.js:282)
[2024-09-17 10:40:42.612] DEBUG: [BackupManager] Backup found "2024-09-15T0130" (BackupManager.js:282)
[2024-09-17 10:40:42.724] DEBUG: [BackupManager] Backup found "2024-09-16T0130" (BackupManager.js:282)
[2024-09-17 10:40:42.823] DEBUG: [BackupManager] Backup found "2024-09-17T0130" (BackupManager.js:282)
[2024-09-17 10:40:42.824] INFO: [BackupManager] 13 Backups Found
[2024-09-17 10:40:42.849] INFO: [Watcher] Initializing watcher for "Main".
[2024-09-17 10:40:42.850] DEBUG: [Watcher] Init watcher for library folder path "/audiobooks" (Watcher.js:61)
[2024-09-17 10:40:42.860] INFO: Listening on port :80
[2024-09-17 10:40:44.128] INFO: [SocketAuthority] Socket Connected AMBMbVCz9HOXrox_AAAB
[2024-09-17 10:40:44.187] DEBUG: [SocketAuthority] User Online root (SocketAuthority.js:209)
[2024-09-17 10:40:48.857] DEBUG: [SocketAuthority] User Offline root (SocketAuthority.js:140)
[2024-09-17 10:40:48.858] INFO: [SocketAuthority] Socket AMBMbVCz9HOXrox_AAAB disconnected from client "root" after 4730ms (Reason: transport close)
[2024-09-17 10:40:49.273] INFO: [SocketAuthority] Socket Connected 4qdsWiD9pAliREppAAAD
[2024-09-17 10:40:49.366] DEBUG: [ApiCacheManager] count: 0 size: 0 (ApiCacheManager.js:47)
[2024-09-17 10:40:49.548] DEBUG: [ApiCacheManager] Cache miss: {"user":"root","url":"/libraries"} (ApiCacheManager.js:58)
[2024-09-17 10:40:49.572] DEBUG: [SocketAuthority] User Online root (SocketAuthority.js:209)
[2024-09-17 10:40:51.164] FATAL: [Server] Unhandled rejection: TypeError: Cannot read properties of undefined (reading 'join'), promise: Promise {
  <rejected> TypeError: Cannot read properties of undefined (reading 'join')
      at LibraryScanner.scan (/server/scanner/LibraryScanner.js:62:63)
      at ApiRouter.scan (/server/controllers/LibraryController.js:1071:26)
      at Layer.handle [as handle_request] (/node_modules/express/lib/router/layer.js:95:5)
      at next (/node_modules/express/lib/router/route.js:144:13)
      at ApiRouter.middleware (/server/controllers/LibraryController.js:1195:5)
} (Server.js:185)
09/17/2024
10:40:50 AM
Container stopped

[advplyr]

Did you recently upgrade from an older server version? That library doesn't have the metadata precedence.

You should be able to fix this by editing the library and changing one of the settings. Press save and you can change it back.

[advplyr]

This will be fixed in the next release. I confirmed that you can fix the issue now by toggling any setting on a library and saving.

[bloggs-100]

I have probably updated a couple times since the last time I tried a manual library scan. I don't do that very often as the file watcher does a very good job of picking up new things.

I tried going into the library to change a setting and turned the setting for Audiobooks Only to on and saved. It appeared to save in the GUI, but when re-opening the settings on the library I can see that it did not actually save my change. I tried a couple other settings in that screen as well with the same behavior. When I try to change the settings, it does not generate any logs from the event, even with debug on. If you think the next release may resolve the issue, I am more than happy to wait and try it. Otherwise I will provide any other information that would be useful for you here.

[stanstrup]

I see the same. Also cannot fix it by saving settings. Same in "edge".

EDIT: No I was wrong. "edge" works.

[github-actions]

Fixed in v2.14.0.