Music Scanner Spinning A Long Time

[Stormdragon]

Server Version#: Version 1.18.2.2015

I have been noticing with the new music scanner that when something changes the spinner in the top right (that is shared with the dashboard link) will go through a number of items and then sit on one for a very long time (i.e. anywhere from 2 - 10 minutes) even if the new changes have already been updated.

I went into the console and noticed the following:

Drilling down into the errors show:

In the file system I searched for everything with Wonderful in it (e.g. Adam Ant) and removed them to see what would happen and then it sits on another item (e.g. Greatest Hits) but that starts to become tedious to try and narrow down the issue.

So I have downloaded the logs locally and since there is a lot of logs in it, I was wondering what I should be looking for as I suspect it must be some items causing this (as per the above it appears like 5 items?).

Editing this for additional info from the server log:

Nov 11, 2019 14:35:28.596 [3732] INFO - Notification: Scanning the "music" section - 
Nov 11, 2019 14:36:34.416 [5688] ERROR - LPE: unknown item 20888.
Nov 11, 2019 14:36:34.416 [5688] ERROR - Sync: failed to generate query for path library://4b7036c9-fd1c-475b-8b1f-f82a2d00b73f/item/%2Flibrary%2Fmetadata%2F20888 in sync item 30494092
Nov 11, 2019 14:36:34.417 [5688] ERROR - Sync: skipping items for sync list 23832759, sync item 30494092: unable to generate sync set query
Nov 11, 2019 14:36:34.417 [5688] ERROR - LPE: unknown item 21847.
Nov 11, 2019 14:36:34.417 [5688] ERROR - Sync: failed to generate query for path library://4b7036c9-fd1c-475b-8b1f-f82a2d00b73f/item/%2Flibrary%2Fmetadata%2F21847 in sync item 31432604
Nov 11, 2019 14:36:34.417 [5688] ERROR - Sync: skipping items for sync list 23832759, sync item 31432604: unable to generate sync set query
Nov 11, 2019 14:36:34.521 [5688] ERROR - LPE: unknown item 28854.
Nov 11, 2019 14:36:34.521 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28854 in sync item 39576803
Nov 11, 2019 14:36:34.521 [5688] ERROR - Sync: empty sync set, unable to update status for sync list 36229116, sync item 39576803
Nov 11, 2019 14:36:34.522 [5688] ERROR - LPE: unknown item 28855.
Nov 11, 2019 14:36:34.522 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28855 in sync item 39576817
Nov 11, 2019 14:36:34.522 [5688] ERROR - Sync: empty sync set, unable to update status for sync list 36229116, sync item 39576817
Nov 11, 2019 14:36:34.523 [5688] ERROR - LPE: unknown item 28861.
Nov 11, 2019 14:36:34.523 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28861 in sync item 39576852
Nov 11, 2019 14:36:34.523 [5688] ERROR - Sync: empty sync set, unable to update status for sync list 36229116, sync item 39576852
Nov 11, 2019 14:36:34.523 [5688] ERROR - LPE: unknown item 28868.
Nov 11, 2019 14:36:34.523 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28868 in sync item 39576863
Nov 11, 2019 14:36:34.524 [5688] ERROR - Sync: empty sync set, unable to update status for sync list 36229116, sync item 39576863
Nov 11, 2019 14:36:34.524 [5688] ERROR - LPE: unknown item 28869.
Nov 11, 2019 14:36:34.524 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28869 in sync item 39576868
Nov 11, 2019 14:36:34.524 [5688] ERROR - Sync: empty sync set, unable to update status for sync list 36229116, sync item 39576868
Nov 11, 2019 14:36:35.111 [5688] ERROR - LPE: unknown item 28854.
Nov 11, 2019 14:36:35.112 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28854 in sync item 39576803
Nov 11, 2019 14:36:35.112 [5688] WARN - Sync: sync item 39576803 has an empty sync set query, assuming sync item is no longer valid
Nov 11, 2019 14:36:35.112 [5688] ERROR - LPE: unknown item 28855.
Nov 11, 2019 14:36:35.112 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28855 in sync item 39576817
Nov 11, 2019 14:36:35.112 [5688] WARN - Sync: sync item 39576817 has an empty sync set query, assuming sync item is no longer valid
Nov 11, 2019 14:36:35.112 [5688] ERROR - LPE: unknown item 28861.
Nov 11, 2019 14:36:35.113 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28861 in sync item 39576852
Nov 11, 2019 14:36:35.113 [5688] WARN - Sync: sync item 39576852 has an empty sync set query, assuming sync item is no longer valid
Nov 11, 2019 14:36:35.113 [5688] ERROR - LPE: unknown item 28868.
Nov 11, 2019 14:36:35.113 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28868 in sync item 39576863
Nov 11, 2019 14:36:35.113 [5688] WARN - Sync: sync item 39576863 has an empty sync set query, assuming sync item is no longer valid
Nov 11, 2019 14:36:35.114 [5688] ERROR - LPE: unknown item 28869.
Nov 11, 2019 14:36:35.114 [5688] ERROR - Sync: failed to generate query for path library://620b8784-e36f-4f07-8af8-175d39eab6ad/item/%2Flibrary%2Fmetadata%2F28869 in sync item 39576868
Nov 11, 2019 14:36:35.114 [5688] WARN - Sync: sync item 39576868 has an empty sync set query, assuming sync item is no longer valid
Nov 11, 2019 14:36:35.119 [5688] ERROR - LPE: unknown item 20888.
Nov 11, 2019 14:36:35.119 [5688] ERROR - Sync: failed to generate query for path library://4b7036c9-fd1c-475b-8b1f-f82a2d00b73f/item/%2Flibrary%2Fmetadata%2F20888 in sync item 30494092
Nov 11, 2019 14:36:35.119 [5688] WARN - Sync: sync item 30494092 has an empty sync set query, assuming sync item is no longer valid
Nov 11, 2019 14:36:35.119 [5688] ERROR - LPE: unknown item 21847.
Nov 11, 2019 14:36:35.119 [5688] ERROR - Sync: failed to generate query for path library://4b7036c9-fd1c-475b-8b1f-f82a2d00b73f/item/%2Flibrary%2Fmetadata%2F21847 in sync item 31432604
Nov 11, 2019 14:36:35.120 [5688] WARN - Sync: sync item 31432604 has an empty sync set query, assuming sync item is no longer valid
Nov 11, 2019 14:37:21.099 [3732] INFO - Notification: Library scan complete - Extra information may still be downloading from the Internet
Nov 11, 2019 14:37:24.014 [3452] ERROR - Error response for update: 5 (Unhandled exception).
Nov 11, 2019 14:37:24.035 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.085 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.101 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.252 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.294 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.316 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.334 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.362 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.380 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.491 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.516 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.532 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.568 [3452] ERROR - Error response for update: 5 (Unhandled exception).
Nov 11, 2019 14:37:24.592 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.632 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.647 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.716 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.731 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.746 [3452] WARN - No matches for search.
Nov 11, 2019 14:37:24.808 [3452] WARN - No matches for search.

[Stormdragon]

In doing more testing, I have also been noticing that if I trigger a scan (i.e. move a music folder out of the library, move a music folder back into the library), the alerts area shows all of the loading and processing of metadata, but it appears to be scanning things it has already scanned and processed.

First scan:

Second scan:

The time stamps are different but the entries are the same.

This seems odd as I have the Run a partial scan when changes are detected turned on, meaning I would think that I would only see the changed file(s) here.

[Stormdragon]

Been about a week and a half so just checking in to see if anyone else is experiencing this or has some thoughts.

[Stormdragon]

Figured it’s been over a month since the last ping so I thought I would reach out and see if anyone has experienced this, any potential tips/logs I can look more into in order to help troubleshoot this, etc?

I have gone through steps to check if the db was corrupted but it came back clean. I have also gone through the tracks/albums that it was showing in the drop down and redid the meta data via MusicBrainz and plex danced…this seemed to help with some but not all. The more that were corrected seemed to just bring up different ones, even if they were corrected.

I was going to try and just recreate the music folder from scratch but that is more of a “nuclear option” for me

note: since this was first posted I have upgraded to the most recent server version of 1.18.4.2171. The behaviour is still there though I now see the issue happens on thread 14728…though if the threads are dynamically created then this might not mean anything.

edit: I have also gone through emptying trash, clean bundles and optimize database.

[leelynds]

@Stormdragon

Figured it’s been over a month since the last ping so I thought I would reach out and see if anyone has experienced this, any potential tips/logs I can look more into in order to help troubleshoot this, etc?

The new music scanner seems to be a little too aggressive in its scanning. It appears to me, from the “Alerts” page, the “Console” page, and my limited ability to read logs, that any change to the library will set off a scan of all unmatched artists and albums. It also looks like (to me) the number of scans initiated is equivalent to the number of albums/artists you have added at that time. So, 2 albums = 2 scans, 5 albums = 5 scans, etc., etc.

Sadly, even though it scans the unmatched albums, it doesn’t actually do anything, like, I dunno, match it to an available match at MusicBrainz.

@Stormdragon

I was going to try and just recreate the music folder from scratch

I’ve tried that twice myself. Basically the same result, but maybe you’ll have better luck.

@Stormdragon

I have the Run a partial scan when changes are detected turned on, meaning I would think that I would only see the changed file(s) here.

Another annoyance, the music scanner doesn’t appear to respect those settings, and does whatever it wants.

There’s several threads on the excessive scanning of the music library, so we’re not alone. It isn’t something the Plex team is willing to admit might be a problem so far, though.