Apparent DB Locks, 1 CPU Core Locks until Plex goes offline

[Highbird]

Server Version#: 1.29.2.6364
Player Version#: 4.95.2

I’ve been using the linuxserver Plex docker on Unraid for years and have been battling this problem for few months. I’m about to lose my mind.

With no apparent rhyme or reason, Plex will 100% lock one of the CPU cores (in Unraid, it switches between cores but always keeps 1 locked) and remains like that until it causes my Plex server to kick itself offline and only comes back if I reboot the docker. Usually, as soon as Plex comes back online, it will immediately continue its behavior and lock one of the CPU cores until it kicks it offline again, it cycles like this for hours and after various reboots and reinstalls of the docker, Plex will start acting normal again.

My Plex database is on an SSD by itself, I’ve ran the integrity checks and repair commands, I’ve dumped and rebuilt it multiple times and the behavior continues. I’ve ran the database queries from this post and didn’t have any items with over 100 entries.

Logs are attached when this issue was happening. If anyone can provide some guidance, it would be greatly appreciated! Thank you! @ChuckPa

Plex Media Server Logs_2022-11-28_17-51-25.zip (3.7 MB)

[ChuckPa]

@Highbird

There is a lot going on in there but given the transcoding speeds and evidence of processor loafing around (except for those cases where it is burning subtitles), might you be ‘banging on the DB’ really hard ?

I have a quick way to test / fix that if the DB is still torn up after the metadata issue of last year.

It’s your call. The utility I wrote does the ‘heavy lifting’ database optimization PMS can’t do while it’s running.

Maybe (?) it will make a difference ?

[Highbird]

My library is 11k+ movies, 60k+ episodes so I dunno if that factors into it. I turned off the automated scanning and all that to see if that’s what was causing it but it made no difference. It still freaks out at random. I am constantly adding new stuff to the database but it never goes berserk during the scans/intro detects/metadata download/etc.

I’d love any tool or fix or something that can rid my life of this hell!

[ChuckPa]

I don’t know how much this will do but for everything we’ve used it on,

If it’s a database performance problem, This fixes it

What I recommend for you.

Steps

1. 1 - Check the DB’s…

2. 4 - Repair (really a full optimize by exporting & importing)

3. 3 - Reindex (rebuilds indexes before PMS starts)

GitHub - ChuckPa/PlexDBRepair: Database repair utility for Plex Media Server...

Lots of info in the Readme.MD

[Highbird]

I ran all 3 steps! Everything is running with the freshified databases.

edit: Hmm, so it appears to still be doing it. It is currently locking 1 of the cores and causing Plex to be less responsive network-wise. Like I know 2 people are currently watching something but I can’t actually see them if I open a new webUI. I can see the activity but it doesn’t show anyone using it.

Logs are attached.
Plex Media Server Logs_2022-11-29_11-49-32.zip (4.7 MB)

[Highbird]

New development, I notice the server basically sits idle, even when transcoding but, just now, when 1 user started Direct Playing a movie, it immediately does the core lock thing. When he pauses the stream, it drops back down to idle. He’s using the Plex desktop Windows app. How would a direct play be causing my CPU to spike and 100% lock one of the cores?

edit: Looks like its not exclusive to the desktop app, it appears to be any direct play is causing the CPU to spike. At least the database has not locked itself to the point of knocking Plex offline, so that’s progress! Spoke too soon, the database still got locked and caused Plex to go offline. So, so sad.

also: in the plex docker log, I have this error: “Jobs: Exec of ./CrashUploader failed. (2).” Could that be an issue?

[Highbird]

I’ve explored a little deeper into this and it SEEMS like it’s only specific titles that are causing this immediate CPU spike than the core lock.

For instance, I tried playing Gone Girl, a movie I’ve had on my server for years, and it will immediately lock the CPU and start making things go weird. But then I tried playing Troll (2022) which I just added today and it plays without issue, and the server basically stays idle. I tried removing Gone Girl, letting Plex delete it from the server, then re-added and played it again but the CPU spike/core lock still happens.

I gather that I have a lot of bad/corrupt metadata files and they’ve stuck around even after using your awesome database cleaning/repairing tool (which is truly neat!) and, obviously, removing the file from Plex is not removing whatever is causing the corruption.

@ChuckPa if you have any other way forward, it would be appreciated. I THINK I’ve at least made some headway instead of running in circles as I have been for months.

Again, thank you for all the support you have provided thus far!!

[ChuckPa]

@Highbird

I’ve explored a little deeper into this and it SEEMS like it’s only specific titles that are causing this immediate CPU spike than the core lock.

Can you copy those files and create a new ‘Other Videos’ type library section?

By doing so, we can eliminate other PMS tasks for Movies, TV, Music.

[Highbird]

Copied 2 of the troublesome titles to a new Movies library and they played without issue. Woohoo, progress!

I figure that we need to get rid of all the bad metadata, the only issue I have is that I would like to keep that existing library (as well as the TV shows one which has the same issue) since I have a lot of people that use it. I don’t mind having to scan all my media again and fixing the metadata stuff.

I can just point the libraries at empty folders for Plex to remove everything but is there a way to forcibly remove all that old metadata? Is that where your database tool would purge all that stuff? If there’s a way to accomplish that, please let me know! If the only fix it is to completely delete the libraries and just make new ones, I can do that, but keeping the existing libraries would be ideal. Thanks again!

[Highbird]

@ChuckPa is that what “Clean Bundles” does? Or do I just take Plex offline and delete the metadata folder? I don’t want to corrupt my stuff or delete something that is necessary for Plex to function.

If you have anything else for me to try, I’m willing to do whatever might fix this. Thanks so much!!

[ChuckPa]

Clean Bundles removes old/outdated metadata (stored as ‘bundles’) from inside the server.

The process is:

1. Scan files and discover new media
2. PMS downloads metadata (partial) so you can see it and get started
3. Dependent on type of media, there will probably be more posters. PMS will get this as it finishes scanning
4. Dependent on type of media, during maintenance, sometimes metadata actually changes. PMS updates it.

Cleaning bundles looks through all the metadata you have and removes

1. Metadata for media items you no longer have
2. Metadata for media items which has upgraded (removes the outdated)

If you delete the Metadata folder, you’ll have

1. No posters
2. No descriptive text

[ChuckPa]

@Highbird

I can just point the libraries at empty folders for Plex to remove everything but is there a way to forcibly remove all that old metadata?

Delete the section, Optimize the database, Create the library section again

If you’re using a newer version of PMS 1.29.2 or above (I like 1.29.2 ),
you can enable cloud syncing of your viewstate history

With it all synced, it’ll download from the cloud when you create the section again.

[Highbird]

@ChuckPa so by delete section, you’re talking about the individual libraries within Plex (Movies, TV Shows, Wrasslin, etc) that I’ve created, correct? I’ll need to optimize AND do the clean bundles too, right? I imagine running your tool would be beneficial as well.

If none of this works, is there some way to keep all my users/watch history and rebuild a new server with that information? I want to be able to start from scratch best I can but at least keep my users and get rid of any random files that are sticking around causing whatever this issue is.

Your assistance is greatly appreciated!!

[ChuckPa]

@Highbird

so by delete section, you’re talking about the individual libraries within Plex (Movies, TV Shows, Wrasslin, etc)

Yes, I’m speaking to removing the library section (the definition).

1. Hover over the library name to expose the ellipsis (slide the cursor to the right)
2. Manage Library
3. Delete

[Highbird]

Thanks!

@ChuckPa Alrighty, I completely deleted all my libraries and made new ones with the same results. Plex will still lock itself up until it goes offline.

I installed a new docker (official Plex docker) and created a completely new server on a completely separate install location so everything is fresh and untainted. I created new libraries and loaded my media back in, and as soon as someone started streaming, Plex is doing the exact same thing. 1 core is locking and causing plex to freak out.

I’ve attached new logs as this is happening.
Plex Media Server Logs_2022-12-09_12-18-02.zip (4.5 MB)

If you have any clue what could be causing something like this, I would be so grateful!

[ChuckPa]

Your “Plex Media Server.log” is showing me

1. Normal Playback
2. Transcoder going to sloth mode because it’s that far ahead of playback requirement.

Here you see: Getting back to work (waking back up), sending, Player terminating (Roku)

Dec 09, 2022 12:17:43.370 [0x14d9c251bb38] DEBUG - Request: [127.0.0.1:50586 (Loopback)] GET /identity (8 live) #15504e Signed-in
Dec 09, 2022 12:17:43.370 [0x14d9cf3f3b38] DEBUG - Completed: [127.0.0.1:50586] 200 GET /identity (8 live) 0ms 398 bytes (pipelined: 1)
Dec 09, 2022 12:17:43.887 [0x14d9c2cd3b38] DEBUG - [Req#15508a/Transcode/c2470d10-d333-4548-829a-bc8cac0fa271-184/ea14f2bb-52ab-4418-aaa4-03d85aebd966] Session c2470d10-d333-4548-829a-bc8cac0fa271-184 (2) is unthrottling
Dec 09, 2022 12:17:43.887 [0x14d9b4d8bb38] DEBUG - [Req#15508f/Transcode/c2470d10-d333-4548-829a-bc8cac0fa271-184/ea14f2bb-52ab-4418-aaa4-03d85aebd966] Throttle - Getting back to work.
Dec 09, 2022 12:17:43.974 [0x14d9b67a7b38] DEBUG - [Req#155083/Transcode/c2470d10-d333-4548-829a-bc8cac0fa271-184/ea14f2bb-52ab-4418-aaa4-03d85aebd966] Transcoder segment range: 0 - 32 (32)
Dec 09, 2022 12:17:43.975 [0x14d9c3f66b38] DEBUG - [Req#155093/Transcode/c2470d10-d333-4548-829a-bc8cac0fa271-184/ea14f2bb-52ab-4418-aaa4-03d85aebd966] Transcoder segment range: 0 - 33 (32)
Dec 09, 2022 12:17:44.268 [0x14d9c251bb38] DEBUG - [Req#155094/Transcode/c2470d10-d333-4548-829a-bc8cac0fa271-184/ea14f2bb-52ab-4418-aaa4-03d85aebd966] Transcoder segment range: 0 - 33 (33)
Dec 09, 2022 12:17:44.269 [0x14d9b2955b38] DEBUG - [Req#15509b/Transcode/c2470d10-d333-4548-829a-bc8cac0fa271-184/ea14f2bb-52ab-4418-aaa4-03d85aebd966] Transcoder segment range: 0 - 34 (33)
Dec 09, 2022 12:17:44.287 [0x14d9b2752b38] DEBUG - [Req#155092/Transcode/c2470d10-d333-4548-829a-bc8cac0fa271-184/ea14f2bb-52ab-4418-aaa4-03d85aebd966] Session c2470d10-d333-4548-829a-bc8cac0fa271-184 (2) is throttling
Dec 09, 2022 12:17:44.288 [0x14d9b69aab38] DEBUG - [Req#1550a5/Transcode/c2470d10-d333-4548-829a-bc8cac0fa271-184/ea14f2bb-52ab-4418-aaa4-03d85aebd966] Throttle - Going into sloth mode.
Dec 09, 2022 12:17:49.802 [0x14d9b254fb38] DEBUG - Request: [127.0.0.1:35788 (Loopback)] GET /identity (8 live) #15509c Signed-in
Dec 09, 2022 12:17:49.802 [0x14d9cf5f6b38] DEBUG - Completed: [127.0.0.1:35788] 200 GET /identity (8 live) 0ms 398 bytes (pipelined: 1)
Dec 09, 2022 12:17:52.752 [0x14d9cf5f6b38] DEBUG - Auth: authenticated user 167304643 as Jacklyn Cogburn
Dec 09, 2022 12:17:52.753 [0x14d9b67a7b38] DEBUG - Request: [172.56.105.253:52459 (WAN)] GET /:/timeline?playbackTime=95036&time=885000&state=playing&ratingKey=2585&key=%2Flibrary%2Fmetadata%2F2585&col=0&row=1&context=home%3Acontent.discover&duration=7489386&playQueueItemID=17 (7 live) #15507c TLS GZIP Signed-in Token (Jacklyn Cogburn)
Dec 09, 2022 12:17:52.754 [0x14d9b67a7b38] DEBUG - [Req#15507c] Client [cf848e4727bb7dc63a7192c323714a36] reporting timeline state playing, progress of 885000/7489386ms for guid=, playbackTime=95036ms ratingKey=2585 url=, key=/library/metadata/2585, containerKey=, metadataId=2585, source=
Dec 09, 2022 12:17:52.755 [0x14d9b67a7b38] DEBUG - [Req#15507c] Play progress on 2585 'Black Adam' - got played 885000 ms by account 167304643!
Dec 09, 2022 12:17:52.755 [0x14d9b67a7b38] DEBUG - [Req#15507c] [Now] User is Jacklyn Cogburn (ID: 167304643)
Dec 09, 2022 12:17:52.755 [0x14d9b67a7b38] DEBUG - [Req#15507c] [Now] Device is Roku (JQWELLYENTERTAINMENT).
Dec 09, 2022 12:17:52.755 [0x14d9b67a7b38] DEBUG - [Req#15507c] [Now] Profile is Roku-7.x
Dec 09, 2022 12:17:52.755 [0x14d9b67a7b38] DEBUG - [Req#15507c] [Now] Updated play state for /library/metadata/2585.
Dec 09, 2022 12:17:52.759 [0x14d9b67a7b38] DEBUG - [Req#15507c] It took 10.000000 ms to retrieve 103 items.
Dec 09, 2022 12:17:52.761 [0x14d9c3f66b38] DEBUG - Request: [192.168.50.122:62129 (Subnet)] GET /status/sessions (7 live) #15507f TLS GZIP Signed-in Token (Highbird) (Chrome)
Dec 09, 2022 12:17:53.478 [0x14d9b67a7b38] DEBUG - [Req#15507c] Statistics: (cf848e4727bb7dc63a7192c323714a36) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 167304643
Dec 09, 2022 12:17:53.478 [0x14d9c3f66b38] DEBUG - [Req#15507f] [Now] Adding 1 sessions.
Dec 09, 2022 12:17:53.480 [0x14d9cf3f3b38] DEBUG - Completed: [172.56.105.253:52459] 200 GET /:/timeline?playbackTime=95036&time=885000&state=playing&ratingKey=2585&key=%2Flibrary%2Fmetadata%2F2585&col=0&row=1&context=home%3Acontent.discover&duration=7489386&playQueueItemID=17 (7 live) TLS GZIP 726ms 848 bytes (pipelined: 6)
Dec 09, 2022 12:17:53.480 [0x14d9cf3f3b38] DEBUG - Completed: [192.168.50.122:62129] 200 GET /status/sessions (7 live) TLS GZIP 719ms 7004 bytes (pipelined: 6)
Dec 09, 2022 12:17:55.085 [0x14d9b254fb38] DEBUG - Request: [127.0.0.1:35802 (Loopback)] GET /identity (8 live) #1550b5 Signed-in
Dec 09, 2022 12:17:55.085 [0x14d9cf5f6b38] DEBUG - Completed: [127.0.0.1:35802] 200 GET /identity (8 live) 0ms 398 bytes (pipelined: 1)
Dec 09, 2022 12:17:59.239 [0x14d9cf5f6b38] DEBUG - WebSocket: client initiated close
Dec 09, 2022 12:17:59.239 [0x14d9cf3f3b38] DEBUG - NotificationStream: Removing because of close
Dec 09, 2022 12:17:59.270 [0x14d9b67a7b38] DEBUG - Request: [192.168.50.122:62129 (Subnet)] GET /:/prefs (7 live) #1550e3 TLS GZIP Signed-in Token (Highbird) (Chrome)

Can you capture and show me what’s happening at that instant?

nvidia-smi ?

[Highbird]

@ChuckPa this is what is happening while that transcoding is active.

Is there another type of log you need me to get from the GPU?

[ChuckPa]

@Highbird

That looks like a 1080p transcode ? ( 2160p for me is about 680 MB )

The PMS Server DEBUG (not VERBOSE) logs when it’s CPU spinning would be great.

Also, if you can open top and show which process is chewing up all the CPU would also be helpful. (there are multiple processes which support PMS and I’d like to eliminate any of those if possible)

[Highbird]

@ChuckPa Sorry, I had to restart Plex. To get the debug logs, I set “debug level: enabled” and to retrieve the logs, will they just be part of the regular bundle of Plex logs or will I have to copy what appears after I click this shortcut?

I have the debug logs enabled, so when it pins the CPU again, I can pull them. The htop command always shows TWO “/usr/lib/plexmediaserver/Plex Media Server” both using around 100% of CPU constantly.

edit to add:

and this is what is going that initiated the CPU spike:

[ChuckPa]

In top, you can expand the view ( "I"rix mode and “1” mode )

type “h” for help with the display customizations you can do.

Also, if you can open a tail -F "Plex Media Server.log" we can see the spinning in real time at your shell window.

(fix the path to the log file as appropriate for you).