Plex server locks CPU usage at 100% after scheduled maintenance

Plex Media Server Desktops & Laptops
1

Server Version#: 1.25.2.5319
Running on a Mac Mini on Debian 4.19.171-2

For a few days now (it did not happen before), I woke up to my Plex server’s fans going mental and I had no idea why. Plex Server was locked on 100% CPU.

Checking on the syslog I noticed this happened always after the scheduled maintenance time was over (5AM) while scanning audio files metadata. The last thing Plex seems to be doing is:

INFO: Created TensorFlow Lite XNNPACK delegate for CPU.

Which extra information should I provide here for you to single out this problem? I tried to get the Plex logs now but they don’t go as far back as syslog. Here’s some of syslog right after it got stuck. I notice it’s trying to do something with a network interface (changing mac address???) but I am not sure that’s related to Plex being stuck at 100%

Jan  5 04:39:21 macmini Plex Media Server[14389]:     Stream #0:0: Audio: pcm_s16le ([1][0][0][0] / 0x0001), 16000 Hz, mono, s16, 256 kb/s
Jan  5 04:39:21 macmini Plex Media Server[14389]:     Metadata:
Jan  5 04:39:21 macmini Plex Media Server[14389]:       encoder         : Lavc58.117.101 pcm_s16le
Jan  5 04:39:21 macmini Plex Media Server[14389]:     Side data:
Jan  5 04:39:21 macmini Plex Media Server[14389]:       replaygain: track gain - -6.800000, track peak - unknown, album gain - unknown, album peak - unknown,
Jan  5 04:39:22 macmini Plex Media Server[14389]: size=       0kB time=00:00:00.00 bitrate=N/A speed=   0x    #015size=    4864kB time=00:02:36.18 bitrate= 255.1kbits/s speed= 156x    #015size=    2048kB time=00:01:08.93 bitrate= 243.4kbits/s speed= 138x    #015size=    6912kB time=00:03:44.39 bitrate= 252.3kbits/s speed= 150x    #015size=    4096kB time=00:02:15.31 bitrate= 248.0kbits/s speed= 135x    #015size=    9216kB time=00:04:56.93 bitrate= 254.3kbits/s speed= 148x    #015[mp3 @ 0x7f1f7f6b1b00] Header missing
Jan  5 04:39:22 macmini Plex Media Server[14389]: Error while decoding stream #0:0: Invalid data found when processing input
Jan  5 04:39:22 macmini Plex Media Server[14389]: size=    9886kB time=00:05:16.35 bitrate= 256.0kbits/s speed= 147x
Jan  5 04:39:22 macmini Plex Media Server[14389]: video:0kB audio:9886kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.002331%
Jan  5 04:39:23 macmini Plex Media Server[14389]: size=    6400kB time=00:03:26.94 bitrate= 253.4kbits/s speed= 138x    #015[mp3 @ 0x7ffa691064c0] Header missing
Jan  5 04:39:23 macmini Plex Media Server[14389]: Error while decoding stream #0:0: Invalid data found when processing input
Jan  5 04:39:23 macmini Plex Media Server[14389]: size=    7615kB time=00:04:03.67 bitrate= 256.0kbits/s speed= 138x
Jan  5 04:39:23 macmini Plex Media Server[14389]: video:0kB audio:7615kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 0.003334%
Jan  5 04:39:23 macmini Plex Media Server[14389]: INFO: Created TensorFlow Lite XNNPACK delegate for CPU.
Jan  5 04:39:45 macmini NetworkManager[799]: <info>  [1641375585.7821] device (wlp3s0b1): set-hw-addr: set MAC address to XX:XX:XX:XX:XX:XX (scanning)
Jan  5 04:39:45 macmini kernel: [157745.989532] b43-phy0: Loading firmware version 666.2 (2011-02-23 01:15:07)
Jan  5 04:39:46 macmini kernel: [157746.153507] IPv6: ADDRCONF(NETDEV_UP): wlp3s0b1: link is not ready
Jan  5 04:39:46 macmini NetworkManager[799]: <info>  [1641375586.1886] device (wlp3s0b1): supplicant interface state: inactive -> disconnected
Jan  5 04:39:46 macmini NetworkManager[799]: <info>  [1641375586.1921] device (wlp3s0b1): supplicant interface state: disconnected -> inactive
Jan  5 04:39:46 macmini wpa_supplicant[798]: wlp3s0b1: Reject scan trigger since one is already pending
Jan  5 04:40:10 macmini kernel: [157770.311203] CPU2: Package temperature above threshold, cpu clock throttled (total events = 513064)
Jan  5 04:40:10 macmini kernel: [157770.311204] CPU0: Package temperature above threshold, cpu clock throttled (total events = 513059)
Jan  5 04:40:10 macmini kernel: [157770.311206] CPU3: Package temperature above threshold, cpu clock throttled (total events = 513043)
Jan  5 04:40:10 macmini kernel: [157770.311208] CPU1: Package temperature above threshold, cpu clock throttled (total events = 513065)
Jan  5 04:40:10 macmini kernel: [157770.312218] CPU3: Package temperature/speed normal
Jan  5 04:40:10 macmini kernel: [157770.312219] CPU1: Package temperature/speed normal
Jan  5 04:40:10 macmini kernel: [157770.312220] CPU0: Package temperature/speed normal
Jan  5 04:40:10 macmini kernel: [157770.312853] CPU2: Package temperature/speed normal
Jan  5 04:45:01 macmini NetworkManager[799]: <info>  [1641375901.7701] device (wlp3s0b1): set-hw-addr: set MAC address to XX:XX:XX:XX:XX:XX (scanning)
Jan  5 04:45:01 macmini kernel: [158062.204600] b43-phy0: Loading firmware version 666.2 (2011-02-23 01:15:07)
Jan  5 04:45:02 macmini kernel: [158062.364663] IPv6: ADDRCONF(NETDEV_UP): wlp3s0b1: link is not ready
Jan  5 04:45:02 macmini NetworkManager[799]: <info>  [1641375902.1577] device (wlp3s0b1): supplicant interface state: inactive -> disconnected
Jan  5 04:45:02 macmini NetworkManager[799]: <info>  [1641375902.1620] device (wlp3s0b1): supplicant interface state: disconnected -> inactive
Jan  5 04:45:02 macmini wpa_supplicant[798]: wlp3s0b1: Reject scan trigger since one is already pending
Jan  5 04:45:10 macmini kernel: [158070.476374] CPU0: Package temperature above threshold, cpu clock throttled (total events = 543977)
Jan  5 04:45:10 macmini kernel: [158070.476375] CPU2: Package temperature above threshold, cpu clock throttled (total events = 543981)
Jan  5 04:45:10 macmini kernel: [158070.476377] CPU3: Package temperature above threshold, cpu clock throttled (total events = 543961)
Jan  5 04:45:10 macmini kernel: [158070.476378] CPU1: Package temperature above threshold, cpu clock throttled (total events = 543983)
Jan  5 04:45:10 macmini kernel: [158070.477390] CPU3: Package temperature/speed normal
Jan  5 04:45:10 macmini kernel: [158070.477391] CPU1: Package temperature/speed normal
Jan  5 04:45:10 macmini kernel: [158070.477392] CPU2: Package temperature/speed normal
Jan  5 04:45:10 macmini kernel: [158070.478148] CPU0: Package temperature/speed normal
Jan  5 04:50:17 macmini NetworkManager[799]: <info>  [1641376217.7822] device (wlp3s0b1): set-hw-addr: set MAC address to XX:XX:XX:XX:XX:XX (scanning)
Jan  5 04:50:17 macmini kernel: [158378.245316] b43-phy0: Loading firmware version 666.2 (2011-02-23 01:15:07)
Jan  5 04:50:18 macmini kernel: [158378.405356] IPv6: ADDRCONF(NETDEV_UP): wlp3s0b1: link is not ready
Jan  5 04:50:18 macmini NetworkManager[799]: <info>  [1641376218.1698] device (wlp3s0b1): supplicant interface state: inactive -> disconnected
Jan  5 04:50:18 macmini NetworkManager[799]: <info>  [1641376218.1741] device (wlp3s0b1): supplicant interface state: disconnected -> inactive
Jan  5 04:50:18 macmini wpa_supplicant[798]: wlp3s0b1: Reject scan trigger since one is already pending
Jan  5 04:55:33 macmini NetworkManager[799]: <info>  [1641376533.7770] device (wlp3s0b1): set-hw-addr: set MAC address to 96:6F:8D:2A:5C:5D (scanning)
Jan  5 04:55:33 macmini kernel: [158694.228653] b43-phy0: Loading firmware version 666.2 (2011-02-23 01:15:07)
Jan  5 04:55:34 macmini kernel: [158694.389408] IPv6: ADDRCONF(NETDEV_UP): wlp3s0b1: link is not ready
Jan  5 04:55:34 macmini NetworkManager[799]: <info>  [1641376534.1536] device (wlp3s0b1): supplicant interface state: inactive -> disabled
Jan  5 04:55:34 macmini NetworkManager[799]: <info>  [1641376534.1545] device (wlp3s0b1): supplicant interface state: disabled -> inactive
Jan  5 04:55:34 macmini wpa_supplicant[798]: wlp3s0b1: Reject scan trigger since one is already pending
Jan  5 04:57:59 macmini kernel: [158839.594224] CPU1: Core temperature above threshold, cpu clock throttled (total events = 450140)
Jan  5 04:57:59 macmini kernel: [158839.594225] CPU3: Core temperature above threshold, cpu clock throttled (total events = 450137)
Jan  5 04:57:59 macmini kernel: [158839.594227] CPU0: Package temperature above threshold, cpu clock throttled (total events = 553439)
Jan  5 04:57:59 macmini kernel: [158839.594229] CPU2: Package temperature above threshold, cpu clock throttled (total events = 553444)
Jan  5 04:57:59 macmini kernel: [158839.594232] CPU3: Package temperature above threshold, cpu clock throttled (total events = 553424)
Jan  5 04:57:59 macmini kernel: [158839.595036] CPU1: Package temperature above threshold, cpu clock throttled (total events = 553446)
Jan  5 04:57:59 macmini kernel: [158839.595205] CPU0: Package temperature/speed normal
Jan  5 04:57:59 macmini kernel: [158839.595206] CPU2: Package temperature/speed normal
Jan  5 04:57:59 macmini kernel: [158839.595802] CPU3: Core temperature/speed normal
Jan  5 05:00:49 macmini NetworkManager[799]: <info>  [1641376849.7699] device (wlp3s0b1): set-hw-addr: set MAC address to XX:XX:XX:XX:XX:XX (scanning)
Jan  5 05:00:49 macmini kernel: [159009.831659] b43-phy0: Loading firmware version 666.2 (2011-02-23 01:15:07)
Jan  5 05:00:50 macmini kernel: [159009.991970] IPv6: ADDRCONF(NETDEV_UP): wlp3s0b1: link is not ready
Jan  5 05:00:50 macmini NetworkManager[799]: <info>  [1641376850.1368] device (wlp3s0b1): supplicant interface state: inactive -> disconnected
Jan  5 05:00:50 macmini NetworkManager[799]: <info>  [1641376850.1418] device (wlp3s0b1): supplicant interface state: disconnected -> inactive
Jan  5 05:00:50 macmini wpa_supplicant[798]: wlp3s0b1: Reject scan trigger since one is already pending
Jan  5 05:01:45 macmini ovpn-openvpn[855]: TLS: tls_process: killed expiring key
Jan  5 05:01:53 macmini ovpn-openvpn[855]: VERIFY OK: depth=2, C=PA, O=NordVPN, CN=NordVPN Root CA
Jan  5 05:01:53 macmini ovpn-openvpn[855]: VERIFY OK: depth=1, C=PA, O=NordVPN, CN=NordVPN CA6
Jan  5 05:01:53 macmini ovpn-openvpn[855]: VERIFY KU OK
Jan  5 05:01:53 macmini ovpn-openvpn[855]: Validating certificate extended key usage
Jan  5 05:01:53 macmini ovpn-openvpn[855]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Jan  5 05:01:53 macmini ovpn-openvpn[855]: VERIFY EKU OK
Jan  5 05:01:53 macmini ovpn-openvpn[855]: VERIFY OK: depth=0, CN=us6829.nordvpn.com
Jan  5 05:01:53 macmini ovpn-openvpn[855]: Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jan  5 05:01:53 macmini ovpn-openvpn[855]: Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Jan  5 05:01:53 macmini ovpn-openvpn[855]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 4096 bit RSA
Jan  5 05:02:59 macmini kernel: [159139.496797] CPU3: Core temperature above threshold, cpu clock throttled (total events = 460098)
Jan  5 05:02:59 macmini kernel: [159139.496799] CPU1: Core temperature above threshold, cpu clock throttled (total events = 460102)
Jan  5 05:02:59 macmini kernel: [159139.496801] CPU0: Package temperature above threshold, cpu clock throttled (total events = 563401)
Jan  5 05:02:59 macmini kernel: [159139.496802] CPU2: Package temperature above threshold, cpu clock throttled (total events = 563406)
Jan  5 05:02:59 macmini kernel: [159139.496805] CPU1: Package temperature above threshold, cpu clock throttled (total events = 563408)
Jan  5 05:02:59 macmini kernel: [159139.497550] CPU3: Package temperature above threshold, cpu clock throttled (total events = 563386)
2

Time to clean out the dust bunnies ?

3

If you mean dust in the computer, that’s not it. Not only this is the first thing I tried, the problem is still consistently locking up at the same point every single night. Also kinda doubt dust wil force a process to get stuck at 100% :roll_eyes:

It just happened again last night, this morning I checked the syslog again and once more the last thing Plex does, point at which it gets stuck, was "Created TensorFlow Lite XNNPACK delegate for CPU."

I looked tensorFlow up and it’s something related to machine learning, so I am guessing this is something connected to the audio analysis data for Plexamp? In any case, this wasn’t happening before, an anybody please look into it/help?

4

The computer is getting too hot to keep working at full speed.

My ancient Mac Mini started doing this too. Replacing the thermal paste and cleaning the mud out really helped. The Mini is a tiny complicated little thing with special annoying screws. It was an annoying process.

Have you added any media recently? It’s possible that there are damaged files that can’t be analyzed. If this has just started, you could remove any added media to identify if that’s related.

5

Again I would believe this is a heat/computer problem if this was happening all the time at any time, I also suspected there could be some particular media that was causing the problem, but the log clearly denotes that it’s not always analyzing the same file when it gets stuck. so I discarded that possibility.

It’s however always at the same point in time (when scheduled tasks time is about to end) on the SAME TASK (mentioned above), so can we move past “it’s the computer”?

Since it seems to get stuck into something related to machine learning (a little official help here would help, I am not a dev, I’m just a dude googling stuff around), what I have done today is disable Analyze audio tracks for loudness and Analyze audio tracks for sonic features. These are as far as I know the only features that probably use that, but it’d suck to lose them, and as I said before, they were working fine until like a week ago. Whether this makes the problem go away, we’ll only know tomorrow.

Can someone on the dev team please look into this or shed more light into the matter?

6

May I see the DEBUG Log files please ?

I’ve never seen tensors used in Plex media analysis before. I would like to see where it’s happening so I can then go speak to the appropriate engineer.

7

I’m sending you a log file via DM. Thank you.
[edit] well, seems like this forum does not allow me to do that. Don’t wanna post logs with tons of media/private info in here.

By the way, this information about TensorFlow appears in SYSLOG and not in the Plex log.

8

Tensor Flow is involved in the new fancy sonic analysis.
But it should only use half of your CPU’s cores by default.

9

Well you’re probably right, because if I understand the top output well enough, it’s jamming up only one core to 100%. Plex is not unresponsive during this time, I can do other things with it, but the system is throttling because it’s overheating, so it’s quite slow.

The only “solution” at that point is to restart the Plex service.

10

If your system is throttling when only one core is pegged at 100%, it is time to check the cooling system.

A properly working server can have all its cores pegged at 100% for hours, without going into thermal throttling.

11

But it’s stuck while showing no activity on the console, the server is not “doing anything” according to itself.

12

Sonic analysis for a regularly sized album can take several minutes. And that’s on a CPU like my old Core i7 4770.
Anything older/slower than that will take even longer.

And if you happen to have an album with lots of tracks (like some “box sets” or a custom album), then this could take even hours.

Also to keep in mind that this analysis uses temporary .WAV copies of all tracks of an album in your general /tmp folder. If this one is sitting on a partition with low free capacity, analysis might even never finish.

13

The Sonic Analysis Plex does is a real workout.

You could try something like stress and s-tui to isolate how your system behaves without using Plex.

What’s your CPU? If it’s a 2011, something like a i5-2415M? i7-2620m? If it’s earlier is it a Core 2 Duo?

14

OK that’s some good points, I just find it weird that neither the console nor syslog say anything about this. I will try to leave it doing its thing and see what happens. ChuckPa also noted that the constant network interface changes could be getting in the way. These are due to an unused wifi adapter, I will disable that.

Also, I will take on the annoying tsk of cleaning this machine thoroughly, just to be certain that it’s working fine. I never replaced the thermal paste on it.

Hopefully I won’t return to this thread without success. for the time being, I disabled the extra music analysis.

1 Like
15

That’s why we’re all jumping on “overheating” - from your logs:

Package temperature above threshold, cpu clock throttled (total events = 563386)

The poor little hot thing is continuously taking breaks so it doesn’t kill itself.

16

Sorry, your message came in after I sent mine.
The CPU is an i5-2520M @ 2.50GHz

I’ll try stress, but my other concern I voiced before is, this wasn’t happening before, and I went thru the music library with extended analysis, when I got Plex Pass last month. This only started happening like a week ago or 10 days ago.

1 Like
17

There were some interesting internal changes between PMS 1.24 and 1.25.

You could try the last version of 1.24 to see if the behavior is different. If the fundamental problem is overheating, it won’t help. But if it makes progress or reports progress differently, uses CPUs differently, etc., that would be interesting.

18

How can I downgrade to 1.24? I use apt-get to update the server.

19

I don’t have a Debian system in front of me.

If you use apt, isn’t it just apt install plexmediaserver=<version>?

Check /var/log/dpkg.log or /var/log/apt/history.log to see what was upgraded, and when, and the previous version.

If this began recently, was Plex upgraded recently?

20

sorry i am not 100% fluent on Linux, I didn’t know about that, thanks!
As for the history, it’s pretty much empty. I don’t remember the last time Plex got updated, but the version I have is from December 14th. I must have updated it soon after that, and that would coincide with me noticing this issue around after Christmas time.

That also means I’ve been using 1.25 for a little while but being that I upgraded to Plex Pass during Thanksgiving, version 1.24 was fine. Will try a downgrade to 1.24.5.5173 see what happens.