While it’s sitting there spinning / being visibly slow, Please grab me the DEBUG logs ZIP file and attach here.
Let’s see what is happening. There might be a problem underneath.
Plex Media Server.log (1.3 MB)
The last bit of the log is where the Movies Library takes a while to load the Recommended page.
Plex Media Server Logs_2025-01-12_04-05-33.zip (4.1 MB)
Here’s the entire logs folder, too!
Thanks,
I found out what’s happening but don’t have any idea WHY it’s happening.
Jan 12, 2025 03:33:21.293 [22555561270072] DEBUG - Completed: [127.0.0.1:50610] 206 PUT /video/:/transcode/session/F532F7B4-E66C-400E-B3C4-772397E3EA1B/ba97e80f-e928-4f89-8820-67c112d6566a/progress?progress=20.7&size=-22&remaining=-1&vdec_packets=14776&vdec_hw_ok=14774&vdec_hw_status=1 (55 live) #6f1583 0ms 371 bytes (pipelined: 1236) (range: bytes=0-)
Look at this: (pipelined: 1236)
There are 1,236 requests queued against the server.
There should be no more than about 20.
Something is HAMMERING the API and causing it to get all jammed up.
Do you have any third party apps running and pointing to the server ?
Anything you know of which could generate this much activity ?
Hmm thats interesting.
I only have the following running;
Overseerr
Sonarr
Radarr
Tautulli
Trakt scrobbler
Notifiarr
Is there a way to find out?
I use Radarr, Sonarr, and Overseerr so those are known OK.
Tautulli isn’t the cause either. JonnyWong would be all over that if it were.
That leaves tract and notifier.
By process of elimination:
- Disable both
- Reboot the server
- Check its responsiveness (generate activity)
- Get into the logs directory and grep ‘Plex Media Server.log’ for
pipelined - Let it run for a while and check again.
- See if it stays low
- One at a time, repeating the same grep scans, enable each one SLOWLY.
- Wait long enough between each activation to know you’re getting an accurate activity count.
You might need wait an hour or more between activations. It all depends on how frequently they update ( check the refresh settings in each ?? )
Ill get on that and report back afterwards! Thanks
So i decided to stop all of the ones you recommended, and keave Plex for 12+ hours, and the slow behaviour is still occuring.
Here’s the latest logs
I see the server start normally, perform normally, then nosedive the moment you have a dozen or so users connect and start transcoding.
It goes from this: (SLOW QUERY – which is not good)
Jan 12, 2025 17:05:11.833 [23018947369784] WARN - [Req#149] SLOW QUERY: It took 510.000000 ms to retrieve 38 items.
Jan 12, 2025 17:05:11.839 [23019078363960] DEBUG - handleStreamRead code 2: End of file
Jan 12, 2025 17:05:11.839 [23019078363960] DEBUG - NotificationStream: Removing because of error
Jan 12, 2025 17:05:11.839 [23019078363960] DEBUG - Completed after connection close: [90.199.20.84:33770] -3 GET /:/websockets/notifications (40 live) #1d TLS GZIP 53ms 0 bytes (pipelined: 2)
Jan 12, 2025 17:05:11.850 [23019080473400] DEBUG - handleStreamRead code 2: End of file
Jan 12, 2025 17:05:11.850 [23019080473400] DEBUG - NotificationStream: Removing because of error
Jan 12, 2025 17:05:11.850 [23019080473400] DEBUG - Completed after connection close: [86.25.236.210:47548] -3 GET /:/websockets/notifications (39 live) #23 TLS GZIP 64ms 0 bytes (pipelined: 2)
Jan 12, 2025 17:05:11.850 [23018949479224] DEBUG - Request: [2.99.115.131:53499 (WAN)] GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/1/472.m4s (39 live) #339 TLS GZIP Signed-in (range: bytes=0-)
Jan 12, 2025 17:05:11.851 [23019080473400] DEBUG - Completed: [2.99.115.131:53499] 404 GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/1/472.m4s (38 live) #339 TLS GZIP 0ms 288 bytes (pipelined: 4) (range: bytes=0-)
Jan 12, 2025 17:05:11.859 [23018931714872] DEBUG - Request: [2.99.115.131:53498 (WAN)] GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/0/474.m4s (38 live) #338 TLS GZIP Signed-in (range: bytes=0-)
Jan 12, 2025 17:05:11.859 [23018931714872] DEBUG - Request: [100.99.195.57:33394 (WAN)] GET /media/providers (38 live) #327 TLS GZIP Signed-in Token (ItsThatJA) (Chrome)
Jan 12, 2025 17:05:11.859 [23019080473400] DEBUG - Completed: [2.99.115.131:53498] 404 GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/0/474.m4s (38 live) #338 TLS GZIP 0ms 288 bytes (pipelined: 124) (range: bytes=0-)
Jan 12, 2025 17:05:11.866 [23019080473400] DEBUG - handleStreamRead code 2: End of file
Jan 12, 2025 17:05:11.866 [23019080473400] DEBUG - NotificationStream: Removing because of error
Jan 12, 2025 17:05:11.866 [23019080473400] DEBUG - Completed after connection close: [194.156.224.30:30424] -3 GET /:/websockets/notifications (38 live) #22 TLS GZIP 79ms 0 bytes (pipelined: 2)
Jan 12, 2025 17:05:11.884 [23019072764728] DEBUG - Request: [2.99.115.131:53498 (WAN)] GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/1/473.m4s (38 live) #33f TLS GZIP Signed-in (range: bytes=0-)
Jan 12, 2025 17:05:11.885 [23019078363960] DEBUG - Completed: [2.99.115.131:53498] 404 GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/1/473.m4s (38 live) #33f TLS GZIP 0ms 288 bytes (pipelined: 125) (range: bytes=0-)
Jan 12, 2025 17:05:11.893 [23019067030328] DEBUG - Request: [2.99.115.131:53499 (WAN)] GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/0/475.m4s (39 live) #33e TLS GZIP Signed-in (range: bytes=0-)
Jan 12, 2025 17:05:11.894 [23019080473400] DEBUG - Completed: [2.99.115.131:53499] 404 GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/0/475.m4s (39 live) #33e TLS GZIP 1ms 288 bytes (pipelined: 5) (range: bytes=0-)
to this – All in 2 minutes.
Jan 12, 2025 17:07:17.181 [23018852088632] DEBUG - Request: [2.99.115.131:53500 (WAN)] GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/1/4333.m4s (54 live) #2c15 TLS GZIP Signed-in (range: bytes=0-)
Jan 12, 2025 17:07:17.181 [23018960943928] DEBUG - Request: [2.99.115.131:53499 (WAN)] GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/0/4334.m4s (54 live) #2c14 TLS GZIP Signed-in (range: bytes=0-)
Jan 12, 2025 17:07:17.182 [23019078363960] DEBUG - Completed: [2.99.115.131:53500] 404 GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/1/4333.m4s (54 live) #2c15 TLS GZIP 0ms 288 bytes (pipelined: 3849) (range: bytes=0-)
Jan 12, 2025 17:07:17.182 [23019080473400] DEBUG - Completed: [2.99.115.131:53499] 404 GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/0/4334.m4s (54 live) #2c14 TLS GZIP 0ms 288 bytes (pipelined: 3681) (range: bytes=0-)
Jan 12, 2025 17:07:17.215 [23019067030328] DEBUG - Request: [2.99.115.131:53500 (WAN)] GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/0/4335.m4s (55 live) #2c17 TLS GZIP Signed-in (range: bytes=0-)
Jan 12, 2025 17:07:17.216 [23018901814072] DEBUG - Request: [2.99.115.131:53499 (WAN)] GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/1/4334.m4s (55 live) #2c18 TLS GZIP Signed-in (range: bytes=0-)
Jan 12, 2025 17:07:17.216 [23019078363960] DEBUG - Completed: [2.99.115.131:53500] 404 GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/0/4335.m4s (55 live) #2c17 TLS GZIP 0ms 288 bytes (pipelined: 3850) (range: bytes=0-)
Jan 12, 2025 17:07:17.216 [23019078363960] DEBUG - Completed: [2.99.115.131:53499] 404 GET /video/:/transcode/universal/session/fyuq9mreu5p7p7qrd1mow9qa/1/4334.m4s (55 live) #2c18 TLS GZIP 0ms 288 bytes (pipelined: 3682) (range: bytes=0-)
Jan 12, 2025 17:07:17.226 [23018883304248] DEBUG - Request: [100.99.195.57:39394 (WAN)] GET /diagnostics/logs (55 live) #2be9 TLS GZIP Signed-in Token (ItsThatJA) (Chrome)
Everything occurring is a software transcode. You have a 2690-v2 (10 core version of my 2690 v4). I had to buy a GPU card (P2200) for it to properly function as a server and support transcoding.
Have you run my DBRepair to optimize and prune the DB and metadata ?
It doesn’t look like you have.
I have a GTX 1650 and all transcodes are running via hw as displayed in the activity tab (see image below), so not sure what is wrong with the transcoding. However, I am transcoding to RAM, via /dev/shm in the container settings, could this be the issue?
1080p > SD (eek)
I have pruned, however it said there was nothing to prune.
I did run the auto tool though.
Yes, this could be. If you’re using HDDs, they are more than fast enough to keep up with transcoding. ( A 150 MB/sec HDD will support 1200 Mbps of video transcoding output.
When you transcode to /dev/shm, you put (memory) pressure on the OS and rob them of buffer memory which could easily be the cause of the SLOW QUERY
Array is HDD 54TB and I have 4 2x TB SSD’s for use for my appdata on UNRAID.
The only reason I switched to RAM transcoding, is because I have 96GB of RAM and only use around 8GB, I thought I could utilise the RAM for transcoding, which would also save read/write cycles on an NVME drive!
I’ve just switched transcoding to one of the NVME drives.
I’ll report back after some activity and see how performance is.
Yeah, so this made no difference at all.
I cleared logs, restarted the server with the new transcode directory, and I still see alot of Slow Queries in the logs, and recommended is taking 2+ minutes to load up. Two people are active on the server at this time, one transcoding, and I am the 3rd doing test force transcodes on my phone to mimic activity.
Here are those logs
Is it possible for you to:
-
create a second ‘test’ server,
-
One section at a time until all sections are loaded,
– Load up the media for that section
– Let it get all the metadata
– Run DBRepair to optimize the DB -
Compare the performance of the new with the old.
Yup, our brains are aligned. I have already got a 2nd instance running that I started the day I posted this thread, the TV Shows - Kids (700 shows) took almost 2 days to scan in, Movies - Kids was about an hour.
I have noticed, these Libraries are instant for loading the Recommended page for the two libraries, while of course my main server, is really slow.
Without having to add the 3 biggest Libraries to the new test server, I can pretty much say with quite a certainty, after checking on 3 different devices (S24U, Fire TV Max, Plex Web) that there is a clear real world difference between the main server, and the said test server.
The only difference between the two is, the test server is using linuxserver.io image, and my main server is using the plexinc official image, now I’m sure this makes no difference, as they’re the same version. Both are latest PlexPass version.
I’m going to float an idea here, and would like your input in regards to this.
I currently have Generate video preview thumbnails enabled, intro detection, end credits (online only) all as media added and scheduled task. I also have sonic analysis enabled, with a large music library.
I’m not opposed to losing the video preview thumbnails. My blobs file since adding these has ballooned in size quite considerably.
What does the .blobs file hold and what kind of information? I ask as I saw a Reddit thread discussing this, and they and others mention they deleted it (with no ill effects) and it significantly improved loading times, crashes and corruption errors on their servers. One poster also acknowledges they have a large Music library and they moved this to a separate instance as they noticed the .blobs fille ballooned in size only after they added their Music Library./
I suppose, what I am asking is, could my issue be linked as there are similarities between my server and the Reddit thread?
How I solved DB lockups & frequent crashing / stalling of my Plex server : PleX
All the sonic analysis, intro, and credit detection data go into Blobs.
I have just over 20.000 music files. I don’t use Sonic Analysis
I personally don’t see the need as all my files are flac (vinyl or CD rips)
Regarding blobs, specifically deletion, you will lose that stored data
You won’t impact the rest of PMS unless you’re transcoding / playing the audio files.
This is how my Databases look right now:
( my media plus all the PMS test files I have – plus some 800 full TV series test files )
File Counts:
[chuck@glockner Databases.2006]$ find /vol/media -type f -print | wc -l
73824
[chuck@glockner Databases.2007]$ find /vol/plex/qa/tv -type f -print | wc -l
119816
[chuck@glockner Databases.2008]$
Databases
[chuck@glockner Databases.2004]$ ls -lah
total 3.1G
drwxr-xr-x 2 plex plex 4.0K Jan 12 02:02 ./
drwxr-xr-x 7 plex plex 120 Oct 7 02:39 ../
-rw-rw-r-- 1 plex plex 14M Jan 9 02:06 com.plexapp.plugins.library.blobs.db
-rw-r--r-- 1 plex plex 14M Jan 3 02:10 com.plexapp.plugins.library.blobs.db-2025-01-03
-rw-r--r-- 1 plex plex 14M Jan 6 02:06 com.plexapp.plugins.library.blobs.db-2025-01-06
-rw-r--r-- 1 plex plex 14M Jan 9 02:06 com.plexapp.plugins.library.blobs.db-2025-01-09
-rw-r--r-- 1 plex plex 14M Jan 12 02:02 com.plexapp.plugins.library.blobs.db-2025-01-12
-rw-rw-r-- 1 plex plex 32K Jan 11 12:16 com.plexapp.plugins.library.blobs.db-shm
-rw-rw-r-- 1 plex plex 0 Jan 11 12:16 com.plexapp.plugins.library.blobs.db-wal
-rw-rw-r-- 1 plex plex 612M Jan 12 15:42 com.plexapp.plugins.library.db
-rw-r--r-- 1 plex plex 607M Jan 3 02:10 com.plexapp.plugins.library.db-2025-01-03
-rw-r--r-- 1 plex plex 624M Jan 6 02:06 com.plexapp.plugins.library.db-2025-01-06
-rw-r--r-- 1 plex plex 624M Jan 9 02:06 com.plexapp.plugins.library.db-2025-01-09
-rw-r--r-- 1 plex plex 612M Jan 12 02:02 com.plexapp.plugins.library.db-2025-01-12
-rw-rw-r-- 1 plex plex 32K Jan 12 17:02 com.plexapp.plugins.library.db-shm
-rw-rw-r-- 1 plex plex 4.5M Jan 12 17:02 com.plexapp.plugins.library.db-wal
-rw-r--r-- 1 root root 3.2K Oct 7 22:15 DBRepair.log
[chuck@glockner Databases.2005]$
Video preview thumbnails take up space in the filesystem.
They have a single entry in the main DB to attach the thumbnail to the video.
Could your performance be based on all the data in blobs? Yes.
Can I confirm that? No.
What I can say is that I don’t experience any slowdowns on this CPU which is the 14 core version of what you have.
So, backing up the main .db file, and the .blobs file and then deleting the .blobs and restarting the server, and if the server is performing on par with the test server, this would confirm that it is indeed the blobs file that was bloated?
If that still didn’t fix it, restoring the backup and starting the server back up, would bring everything in the blobs back and part of my main server?
Is there any harm in testing this?
There is NO HARM testing it this way.
It’s a great way to do it.
Then this is what I shall do in the next couple of hours as part of my maintenance in upgrading to UNRAID 7!
I’ll report back.
