Music Scanner getting stuck on music library

Plex Media Server Desktops & Laptops
1

Server Version#: 1.27.2.5929
Player Version#: Plex Web 4.76.1

Linux CentOS 7.8. I have a music library of about 50K tracks. It has always worked well and pretty snappy when I add a new album. But this time I’m having significant trouble.

I added a new folder under an existing album artist with 3 tracks. I tried to scan it and it started scan and quickly did the full “circle” in the status on Plex Web but hung on a particular album and never finished. A few hours later, I tried to cancel the scan but nothing happened. I went onto the server and force killed the Plex Media Scan process.

That was on 1.27.1, so I restarted Plex server, stopped it gracefully, yum upgrade to 1.27.2. I tried the scan again, still the same issue. It wasn’t adding the new content either, no changes to library. Killed process, shutdown and restarted server, then switched scanner from “Plex Music” to “Plex Music Scanner”.

With the Plex Music Scanner, it finished the scan and added the new tracks, but now it is stuck again, with Plex Media Scan process again pegged at 100% CPU. This time it is stuck on “Updating Metadata” for a specific album. I went to that album and it was showing the “spinning wand icon” on the center of it over and over and over, like it was constantly re-updating the metadata. That finally stopped but still seems stuck there.

I guess I could just kill it again and at least I got my tracks in there - but I’m worried that it might get stuck in maintenance or have other issues. So figure I should ask here. Appreciate any help!

Verbose logging off, debug has been on. It’s still spinning and 100% CPU on “Plex Media Scan” as of me getting the logs. The logs are attached.

Plex Media Server Logs_2022-07-05_16-10-41.zip (4.1 MB)

2

I killed the Plex Media Scan again after posting my last post. Then I switched back to the “Plex Music” agent, which triggered an automatic scan, which finished after about 15 seconds and found no changes (as I was able to get that album added through switching scanners), no hanging.

But I am still worried about what will happen with the next album I try to add - so hopefully the logs reveal some issue I can correct, I always like that better than when problems “mysteriously go away”. Also rather have problems mysteriously go away than be unfixable :slight_smile:

I do have a large group of classical CDs I still plan to rip and add to the library over the next few months.

3

No suggestions or anything, pointers to standard cleanup procedures, anything? I’m easy, I’ll do the work myself if it’s just a cleanup thing. What I don’t want to do is start over because I had to do quite a bit of custom work to get all the albums tagged and merged correctly!

I can hack this to work apparently by using old scanner but how long will that be available?

Any pointers or tips are appreciated. Thanks!

4

Well, I updated an album today and everything worked fine. Maybe it had something to do with the specific music files I was adding that time. I might make time to pore over the logs myself and see if anything sticks out.

5

Loving this conversation with myself… I am no expert at looking at these logs.

I can see evidence of the music scanner hanging in the “Plex Media Server.log” but can’t figure out why the hang.

So the new media was “Bruckner Symphony #9”. The Scanner finds it here:

Jul 05, 2022 15:34:39.406 [0x7f575f828b38] DEBUG - Skipping over directory 'Bruckner', as nothing has changed; removing 0 media items from map.
Jul 05, 2022 15:34:39.407 [0x7f575f828b38] DEBUG - Scanner: Processing directory /mnt/plex01/plexlib/musicClassical/Bruckner/Symphony 9 (parent: yes)
Jul 05, 2022 15:34:39.409 [0x7f575f828b38] DEBUG - Directory had 3 files, database had 0 files, can't skip.
Jul 05, 2022 15:34:39.410 [0x7f575f828b38] DEBUG - Activity: updated activity 92714bf3-4ce1-43a0-bac8-0cd2a10cbe13 - completed 50.0% - Scanning Gowans Music
Jul 05, 2022 15:34:39.411 [0x7f575f828b38] DEBUG - Scanner: Processing directory /mnt/plex01/plexlib/musicClassical/Bruckner/Bruckner Symph #4 & Sibelius

So it finds the new folder and notes that it can’t skip. The next time Bruckner Symphony #9 is mentioned is… never during that scan:

Jul 05, 2022 15:34:40.477 [0x7f575f828b38] DEBUG - Scanner: Processing directory /mnt/plex01/plexlib/musicClassical/Bach/Sonatas and Partitas (parent: yes)
Jul 05, 2022 15:34:40.488 [0x7f575f828b38] DEBUG - Skipping over directory 'Bach/Sonatas and Partitas', as nothing has changed; removing 32 media items from map.
Jul 05, 2022 15:34:40.489 [0x7f575f828b38] DEBUG - Activity: updated activity 92714bf3-4ce1-43a0-bac8-0cd2a10cbe13 - completed 99.0% - Scanning Gowans Music
Jul 05, 2022 15:34:40.489 [0x7f575f828b38] DEBUG - Activity: updated activity 92714bf3-4ce1-43a0-bac8-0cd2a10cbe13 - completed 99.0% - Scanning Gowans Music
Jul 05, 2022 15:34:41.100 [0x7f57608f7b38] DEBUG - Request: [127.0.0.1:52906 (Loopback)] GET /user/services/acoustid (16 live) #871 GZIP Signed-in Token (danielg1976) (GowansPlex)
Jul 05, 2022 15:34:41.100 [0x7f575f7f4b38] DEBUG - Completed: [127.0.0.1:52906] 200 GET /user/services/acoustid (16 live) GZIP 0ms 498 bytes (pipelined: 1)
Jul 05, 2022 15:34:47.334 [0x7f575f7d1b38] DEBUG - Completed: [192.168.11.40:4907] 200 GET /player/proxy/poll?

So after updating to 99%, there are no more updates from the scanner. The status on the WebUI corroborated this, it was hung on “Bach Sonatas and Partitas” and the scan sat there for 4 minutes. After 4 minutes I tried to cancel it:

Jul 05, 2022 15:38:14.219 [0x7f575ec25b38] INFO - Request: [192.168.11.40:5939 (Allowed Network (Subnet))] DELETE /library/sections/10/refresh (7 live) #5e8e GZIP Signed-in
Jul 05, 2022 15:38:14.219 [0x7f575ec25b38] DEBUG - [Req#5e8e] Scanner [Plex Music]: Cancelling scan.
Jul 05, 2022 15:38:14.279 [0x7f5760871b38] DEBUG - Request: [192.168.11.40:5972 (Allowed Network (Subnet))] GET /library/sections/10/firstCharacter?type=10&sort=artist.titleSort%2Calbum.titleSort%2Calbum.year%2Ctrack.absoluteIndex%2Ctrack.index%2Ctrack.titleSort

After another minute of waiting, I went in and did a “Kill -9” on the scanner:

Jul 05, 2022 15:39:22.449 [0x7f575f7d1b38] DEBUG - Completed: [192.168.11.40:6119] 200 GET /library/sections/10/all?type=10&sort=artist.titleSort%2Calbum.titleSort%2Calbum.year%2Ctrack.absoluteIndex%2Ctrack.index%2Ctrack.titleSort%2Ctrack.id&includeCollections=1&includeExternalMedia=1 (9 live) GZIP Page 0-124 423ms 12072 bytes (pipelined: 5)
Jul 05, 2022 15:39:23.247 [0x7f575df20b38] ERROR - Error parsing content.
Jul 05, 2022 15:39:23.247 [0x7f575df20b38] ERROR - Error parsing XML: Error parsing file.
Jul 05, 2022 15:39:23.248 [0x7f575df20b38] DEBUG - Killing job.
Jul 05, 2022 15:39:23.248 [0x7f575df20b38] DEBUG - Signalling job ID 2448 with 9
Jul 05, 2022 15:39:23.248 [0x7f575df20b38] DEBUG - Native Scanner: Executed Match stage in 283.84 sec.
Jul 05, 2022 15:39:23.248 [0x7f5761155b38] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Media Scanner' exit code for process 2448 is -9 (signal: Killed)
Jul 05, 2022 15:39:23.248 [0x7f575df20b38] DEBUG - Native Scanner: Executed Add to Database stage in 0.00 sec.
Jul 05, 2022 15:39:23.248 [0x7f575df20b38] DEBUG - Native Scanner: Executed Media Analysis stage in 0.00 sec.
Jul 05, 2022 15:39:23.248 [0x7f575ec25b38] DEBUG - [Req#5e8e] Job was already killed, not killing again.
Jul 05, 2022 15:39:23.248 [0x7f575f828b38] DEBUG - Scanner [Plex Music]: Idle and left with 14772 media items.
Jul 05, 2022 15:39:23.253 [0x7f575f828b38] DEBUG - Removing 0 media items that were left.
Jul 05, 2022 15:39:23.253 [0x7f575f828b38] DEBUG - Removing 1 directories that were left.
Jul 05, 2022 15:39:23.255 [0x7f575f828b38] DEBUG - Deleting directory [Bruckner/Bruckner- Symphony No.9] (4393)
Jul 05, 2022 15:39:23.269 [0x7f575f828b38] DEBUG - Updating directory 'Bruckner' (ID 4178) to time 2022-07-05 15:24:39.
Jul 05, 2022 15:39:23.269 [0x7f575f828b38] DEBUG - Updating directory 'Bruckner/Symphony 9' (ID 4394) to time 2022-07-05 15:24:41.
Jul 05, 2022 15:39:23.391 [0x7f575f828b38] DEBUG - Collections: Found 0 collections tags in section 10.

I don’t know why the “Executed Match” stage was almost 5 minutes. Usually it finishes in less than 30 seconds. Maybe something was going on this time that took a lot longer and I needed to be more patient?

Obviously the Add to Database stage (which would have added Bruckner Symphony #9 to the DB) was 0 seconds as I’d killed the scanner I’m sure state was lost.

That’s pretty much it. Nothing else in the logs covers the period from 15:34:40 when it hits 99% to 15:39:14 where I try to cancel the scan. Then I kill the agent and restart the server, and it seems at that point like most of the logs just start over - but most of the old ones end at 15:33…

Anyway so it seems there isn’t really enough to go on. Maybe I’m mistaken, but looks like I just should hope it doesn’t happen again :slight_smile:

6

Hi,
I’m sorry I didn’t see this until now. I somehow didn’t get a notification of your post.

Looking at your logs paints the picture of the backside (part 2) of media scanning not completing before the frontside (looking for new media) causing it to restart.

I don’t see where you’re using the “Automatically scan when changes are detected”.

Is the media on a NAS or on local media ?

If on a NAS, what is the periodic scanning interval and do you have it set to perform a partial scan?

7

Thanks for the response!

I’m only manually scanning, “Automatically scan when changes are detected” is off. I put new files into the folders, then “Scan Library Files” manually, then I go check the results and tweak any metadata after it’s done.

The media is on a USB drive mounted on /mnt/plex01. I have a second USB drive mounted that I rsync to nightly (cronjob) to keep a mirror.

I also have periodic scanning and partial scan all turned off. So scanning only happens when I tell it to.

image

So if looking for new media caused it to restart, it might have been me being impatient? Since it usually takes less than a minute to add a little new media to my music library, after 4 minutes I tried to cancel it, and when it wouldn’t cancel I tried to kill the scanner on the Linux command line. But it wouldn’t kill after another 30 seconds so I did a force kill from Linux command line. After killing the music scanner, I restarted the plexmediaserver service completely then tried it all again. So the logs might be a little messed up because of me killing the scanner and restarting then manually trying the scan again?

8

Remember how the music scanner works.

The process is:

  1. Get the filename(s)
  2. See if they look like an album
  3. Make an acoustic fingerprint of the first and last songs in the album.
  4. Use the fingerprints and filenames to attempt to make a match
  5. If match found, conclude the album is as stated and add metadata for all.
  6. If no match found, fingerprint all files in the album (this takes time)
  7. Using fingerprints from all files, retry the match
  8. If math found, add the metadata for the files.
  9. If no match, skip and requeue for scanning (which it will do on its own)

I would look at the album which is not scanning / causing it to hang ,
Then move that album out of the library section.
Attempt to scan and get the rest completed.

If the rest completes then you know there is a problem with the naming or fingerprints of that album.

9

Thanks, that’s a great list on what to expect. I’ll mark it as solved since I worked around it and haven’t had the problem again, and this is good general advice and information.

The music I was adding was kind of esoteric so it could make sense that it might have had to do retrying and so forth, and that could explain it taking longer. It might have just been that I needed to wait a little longer, but you also give a good tip on problematic files.

Appreciate it!

10

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.