Plex scan stuck on new files need to restart the server

Plex Media Server Desktops & Laptops
1

Server Version#: 1.32.4.7195
Player Version#: Plex Web 4.110.1 and others

Hi,
For a while now (since several previous server updates) I have been struggling with a problem in my server scans. Sometimes when I try to play something, either in an app or the web player, playback doesn’t start. Otherwise the server seems to be working. Upon checking the server on the browser I notice scan activity (apparently concluding as the circle is complete), but this scan won’t ever end. Trying to cancel the scan won’t work either. The only way to get the server responding is restarting it.

Additional context:
My scans are currently set only on new content using Cloudbox/autoscan.
Temporarily I disabled autoscan, and used only timed full library scans, but ending up getting the same problem so I returned to my previous setup.

I’ll attach a log of the most recent event. I tried to cancel the scan a few times without success.

com.plexapp.system.log (34.6 KB)

2

@jonatasgz

Thank you for that log but it’s not the right one.

I need the full log ZIP file (which also contains “Plex Media Server.*.log”)

That’s where I’ll see the scanner activity and any errors.

The ‘system’ log is only for the system bundle (which processes network requests)

3

Thank you for your response.

Here is the full log file.

Plex Media Server Logs_2023-07-05_17-43-38.zip (4.2 MB)

4

@jonatasgz

Thanks for these logs. They show me a great deal.

I immediately see the server working pretty hard performing intro detection.

If you look here –

  1. You see new media being scheduled for both Intros and Credits detection.
    Both these processes take time (single thread of the CPU ; so not very fast on our Xeon E5 machines.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217113, 1 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217114, 2 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217116, 3 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217117, 4 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217118, 5 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217119, 6 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217120, 7 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217121, 8 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217122, 9 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217123, 10 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217124, 11 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217125, 12 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217128, 13 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217129, 14 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217130, 15 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217131, 16 pending.
Jul 05, 2023 11:29:03.978 [140459047299896] DEBUG - LongRunningJobManager [CreditsDetector]: scheduling job for item 217132, 17 pending.
Jul 05, 2023 11:29:03.983 [140459047299896] DEBUG - Scheduling an intro detection job for Secret Invasion S01 (id: 215414)
Jul 05, 2023 11:29:03.983 [140459047299896] DEBUG - BackgroundTaskQueue: creating activity container for "media.generate.intros"
Jul 05, 2023 11:29:03.984 [140459047299896] DEBUG - Activity: registered new activity 5e2b4005-a12b-400f-889c-57e6f446e8d3 - "Detecting intros"
Jul 05, 2023 11:29:03.984 [140459047299896] DEBUG - Activity: registered new sub-activity d15e5c9d-a9e4-4165-97da-ee8586f4c9f4 - "Secret Invasion S01" parent: 5e2b4005-a12b-400f-889c-57e6f446e8d3 overall progress: 0.0% (0/1)
Jul 05, 2023 11:29:03.985 [140459045190456] DEBUG - Activity: updated activity 5e2b4005-a12b-400f-889c-57e6f446e8d3 - completed 0.0% - Detecting intros
Jul 05, 2023 11:29:03.988 [140459047299896] DEBUG - Scheduling an intro detection job for The Clearing S01 (id: 211263)
Jul 05, 2023 11:29:03.988 [140459047299896] DEBUG - Activity: registered new sub-activity 5a37951f-0d17-4633-9cdb-a94fce62eb4b - "The Clearing S01" parent: 5e2b4005-a12b-400f-889c-57e6f446e8d3 overall progress: 0.0% (0/2)
Jul 05, 2023 11:29:03.991 [140459047299896] DEBUG - Scheduling an intro detection job for Orphan Black S02 (id: 217115)
Jul 05, 2023 11:29:03.992 [140459047299896] DEBUG - Activity: registered new sub-activity 9a518b0d-9ee5-4e7b-a2d3-0ee5f3148c3f - "Orphan Black S02" parent: 5e2b4005-a12b-400f-889c-57e6f446e8d3 overall progress: 0.0% (0/3)
Jul 05, 2023 11:29:03.994 [140459047299896] DEBUG - Scheduling an intro detection job for The Idol (2023) S01 (id: 217127)
Jul 05, 2023 11:29:03.994 [140459047299896] DEBUG - Activity: registered new sub-activity 2b6f62c3-8b12-450d-9268-c94dfa1845df - "The Idol (2023) S01" parent: 5e2b4005-a12b-400f-889c-57e6f446e8d3 overall progress: 0.0% (0/4)
Jul 05, 2023 11:29:04.000 [140459063495480] DEBUG - Photo transcoder: Request for url [/library/metadata/217113/thumb/1688552797] (is local: 1 upscaled: 0)
Jul 05, 2023 11:29:04.003 [140459045190456] DEBUG - IntroDetector: Running intro detection for [215414] [Secret Invasion] [1]
  1. Later, After being restarted and resuming –

Finishing intro detection (part of the new media scan process)

Jul 05, 2023 12:05:52.882 [140459045190456] DEBUG - Activity: updated activity 5e2b4005-a12b-400f-889c-57e6f446e8d3 - completed 99.4% - Detecting intros
Jul 05, 2023 12:05:52.882 [140459045190456] DEBUG - IntroDetector: Less than half of episodes have an intro. Clearing intros for [208556]

Please explain how it gets ‘stuck’ ?

There are tasks which will take a long time on our xeon cpus because of the how the xeon works.

5

Thanks.
I just disabled intro and credit detection to see if I get this problem without that.

What I mean by stuck: scanning spinner active but with a full circle. Nothing on the console. I can see library items but playback won’t start. It happens with different libraries, movies, tv and music.

I left it for about six ours and it won’t stop (apparently) scanning the same file. The only thing that makes everything responsive again is a server restart.

6

when this happens next - Grab the logs ZIP and attach them please.

Let me see what it’s doing at that moment.

7

Here you go:

According to autoscan logs this particular scan was requested at 04:46:07.

It is 10:05 now, and the server is stuck apparently scanning the Wrath of Becky.

Plex Media Server Logs_2023-07-06_10-00-46.zip (4.2 MB)

8

I have the same problem, same PMS version running. Will be around here for testing potential solutions.

Thank you.

9

I’m seeing the problem.
I am also working on pinpointing a problem with Agent + Scanner changes.

Have you used 1.32.5.7120 ? (Beta)
( There were some fixes in 1.32.5 which weren’t published )

1 Like
10

I will try the beta. I’ll also reactivate credits and intro detection.

11

Disabled credits and intro detection and updated to beta version 1.32.5. Will have a look tomorrow if it still works. Thanks.

12

Still happening on the latest beta version, 1.32.5.xxxx

13

Yes, I can confirm. Not working with version 1.32.5.xxxx.

14

I am encountering this as well, it sounds like there are enough logs to troubleshoot at the moment but can provide mine as well. This seems to be causing issues with recent music items getting sonic analysis for my latest import.

EDIT: Cycling another round of stop / start in systemctl triggered a rebuild of the Sonic Trees. The albums showed as having been scanned as Plexamp would allow a track radio to attempt to start but would fail with a toast in the Plexamp UI and associated error messages in PMS.log so had a sense it was somewhere in purgatory between having been analyzed and having been incorporated into the db.

15

Sonic Analysis is (re)done whenever the path is new (or changes).
(This is a design weakness they know about and have on the list to address. For now, media should be placed once and not moved)

Plexamp is a player. While easily lumped into the server, it’s important to know and keep the distinction between where the backend is and what is done on the backend.

16

Thanks. I’m aware of all of this. I am curious if the issues related to the associated maintenance tasks have been identified or if I should provide additional logs

17

The issues haven’t been finitely identified.

There are several events all happening in there at the same time.

I’ve been working through them one at a time and mapping the events.

I unfortunately don’t have anything concrete (or even a wild guess) at this time

There are two POSSIBLE issues I see:

  1. inode exhaustion - Credit detection not ensuring it has clean work space after an unexpected shutdown

  2. Transcoder temp space exhaustion and associated pruning as the space fills. (possible regression)

18

#2 seems likely, looking at my /tmp I see music analysis folders and other items dating back more than a few weeks, some nearing 2 months.

drwxr-xr-x 2 plex plex      111 Jun  8 03:53 music-analysis-input-d4b005c3-1f89-41ac-9a99-c27b619fb1c8
drwxr-xr-x 2 plex plex     4096 Jun  8 03:53 music-analysis-input-dd224cbd-10cb-4f4c-a369-37cd08938a4c
drwxr-xr-x 2 plex plex     4096 Jun  8 03:51 music-analysis-input-e3a2cf72-1e45-452b-92b2-3f3e09c0883e
drwxr-xr-x 2 plex plex     4096 Jul  6 03:44 music-analysis-input-ef95a673-a87d-4ba1-9b2e-03401becd23d
drwxr-xr-x 2 plex plex      111 Jul  6 03:44 music-analysis-input-f5841fad-2f3a-4b2e-8e82-c873215ca56c
drwxr-xr-x 2 plex plex     4096 Jul  6 03:44 music-analysis-input-f6ea647e-45ef-40dd-b7ac-d7821c17f662
19

Is there already some more news on this? Have to reboot my system every day before it can be used. It’s always getting stuck while scanning, without having new content…

Thanks!

1 Like
20

Similarly curious, it sounded like there was some active investigation here albeit with an uncertain outcome.

Any updates from testing? Any additional detail or logging I can provide to assist here?