@dom_a2345 @telfordje Can you please enable Debug logging on your PMS’s and provide new logs?
@jakehoms @xxrazorxx I’m getting more eyes on this issue. Thank you for your logs.
I dont know what happened, but I did the latest docker update a few days ago and the issue stopped.
I had an issue with the metadata constantly updating and getting stuck and choking up the CPU, so I now dont have current debug logs to supply.
There was either a fix in the latest docker release or this is a database issue which resolved itself when I updated, I had however, already run a repair on my database which didnt resolve the issue.
Thanks for the help @Atomatth. This is still happening all the time to my server so I’m happy to offer any further info I can if it helps.
Please see my logs attached, with debug logging on.
I discovered various “simple” Plex actions slowed when my Unraid storage reached close to capacity. Plex Media Server actions such as scanning media libraries seemed fine however updating media Played/Unplayed was very slow – might take 10-15 seconds to complete updating Played/Unplayed state during which Plex would not allow playback to start on other media.
Restoring and maintaining a reasonable amount of available/unused space on media volume seems to have resolved this problem on my Plex/Unraid setup. Because I have Plex Media Server appdata stored on the NVME SSD (taking up 261GB leaving 238GB free storage) didn’t Plex Media Server performance to be impacted when the media storage volume (HDDs) get filled close to their maximum capacity.
1x 500GB Samsung SSD (EVO 960) M.2 NVME Used for Plex Media Server app data
6x 8TB Segate IronWolf HDD (ST8000VN0022) Storage
1x 8TB Segate IronWolf HDD (ST8000VN0022) Parity
Total Usable Storage for General/Video Media: 48TB
When available/unused storage reached about 6TB (1TB on each HDD) certain Plex Media Server actions seemed to slow down dramatically. Maintaining at least 6-7TB on each storage disk seems enough to maintain excellent/expected Plex/Unraid performance.
My experience might help you troubleshoot a similar problem with your Plex/Unraid setup. I wish you all the best.
PMS 1.24.1.4931
DSM 7.0-41890
Recently Installed PMS on Syno NAS 1813+ (4GB ram) - well its a pig compared to the SHIELD (which is connected to the NAS via SMB).
Only indexed 1 large Music folder (Music/Artist/Album1 Album2 etc.)
After a week of indexing, PlexAmp barely loads - it lists Soundtracks (561), Playlists (8), Genres (25), Record Labels (4.039) but never loads Artists, Albums, Tracks or Moods.
Used renice -20 command today to give PlexMediaServer user priority which marginally helped. CPU, RAM are all below 50%, at least 2TB free space, permissions are set correctly.
Disabled all unnecessary features including relay. clean bundles and optimised database - still terribly slow. with errors all over the logs.
Feels like there is either a coding issue or its just a very inefficient app as the NAS runs a mail server, docker containers, surveillance station with 6 cameras etc without any issues.
Aug 27, 2021 16:12:32.427 [0x7f6b61082b38] WARN - SLOW QUERY: It took 670.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:32.529 [0x7f6b61082b38] WARN - SLOW QUERY: It took 340.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:32.597 [0x7f6b61082b38] WARN - SLOW QUERY: It took 240.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:32.674 [0x7f6b61082b38] WARN - SLOW QUERY: It took 260.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:32.768 [0x7f6b61082b38] WARN - SLOW QUERY: It took 320.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:33.369 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1510.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:33.608 [0x7f6b61082b38] WARN - SLOW QUERY: It took 570.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:33.763 [0x7f6b61082b38] WARN - SLOW QUERY: It took 550.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:34.052 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1090.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:34.350 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1090.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:34.444 [0x7f6b61082b38] WARN - SLOW QUERY: It took 350.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:34.549 [0x7f6b61082b38] WARN - SLOW QUERY: It took 400.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:34.749 [0x7f6b61082b38] WARN - SLOW QUERY: It took 730.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:35.325 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1960.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:36.075 [0x7f6b61082b38] WARN - SLOW QUERY: It took 2160.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:36.294 [0x7f6b61082b38] WARN - SLOW QUERY: It took 680.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:36.437 [0x7f6b61082b38] WARN - SLOW QUERY: It took 460.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:36.579 [0x7f6b61082b38] WARN - SLOW QUERY: It took 470.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:36.640 [0x7f6b61082b38] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:36.716 [0x7f6b61082b38] WARN - SLOW QUERY: It took 240.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:36.797 [0x7f6b61082b38] WARN - SLOW QUERY: It took 290.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:36.859 [0x7f6b61082b38] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:36.922 [0x7f6b61082b38] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:37.177 [0x7f6b61082b38] WARN - SLOW QUERY: It took 870.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:37.377 [0x7f6b61082b38] WARN - SLOW QUERY: It took 620.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:37.499 [0x7f6b61082b38] WARN - SLOW QUERY: It took 380.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:37.603 [0x7f6b61082b38] WARN - SLOW QUERY: It took 340.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:37.786 [0x7f6b61082b38] WARN - SLOW QUERY: It took 390.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:37.857 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:37.972 [0x7f6b61082b38] WARN - SLOW QUERY: It took 400.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:38.236 [0x7f6b61082b38] WARN - SLOW QUERY: It took 980.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:38.403 [0x7f6b61082b38] WARN - SLOW QUERY: It took 580.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:38.510 [0x7f6b61082b38] WARN - SLOW QUERY: It took 310.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:38.587 [0x7f6b61082b38] WARN - SLOW QUERY: It took 270.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:38.661 [0x7f6b61082b38] WARN - SLOW QUERY: It took 270.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:38.930 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1020.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:39.149 [0x7f6b61082b38] WARN - SLOW QUERY: It took 780.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:39.372 [0x7f6b61082b38] WARN - SLOW QUERY: It took 780.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:39.577 [0x7f6b61082b38] WARN - SLOW QUERY: It took 550.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:39.895 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1170.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:40.136 [0x7f6b61082b38] WARN - SLOW QUERY: It took 880.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:40.368 [0x7f6b61082b38] WARN - SLOW QUERY: It took 640.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:40.467 [0x7f6b61082b38] WARN - SLOW QUERY: It took 350.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:40.660 [0x7f6b61082b38] WARN - SLOW QUERY: It took 390.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:41.019 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1020.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:41.509 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1610.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:41.693 [0x7f6b61082b38] WARN - SLOW QUERY: It took 480.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:42.263 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1610.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:42.782 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1530.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:42.996 [0x7f6b61082b38] WARN - SLOW QUERY: It took 650.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:43.180 [0x7f6b61082b38] WARN - SLOW QUERY: It took 630.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:43.391 [0x7f6b61082b38] WARN - SLOW QUERY: It took 600.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:43.891 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1120.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:44.101 [0x7f6b61082b38] WARN - SLOW QUERY: It took 560.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:44.256 [0x7f6b61082b38] WARN - SLOW QUERY: It took 330.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:44.708 [0x7f6b61082b38] WARN - SLOW QUERY: It took 950.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:44.868 [0x7f6b61082b38] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:45.105 [0x7f6b61082b38] WARN - SLOW QUERY: It took 510.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:45.518 [0x7f6b61082b38] WARN - SLOW QUERY: It took 870.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:45.941 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1010.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:46.357 [0x7f6b61082b38] WARN - SLOW QUERY: It took 960.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:46.738 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1090.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:47.012 [0x7f6b61082b38] WARN - SLOW QUERY: It took 870.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:47.162 [0x7f6b61082b38] WARN - SLOW QUERY: It took 500.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:47.263 [0x7f6b61082b38] WARN - SLOW QUERY: It took 350.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:47.403 [0x7f6b61082b38] WARN - SLOW QUERY: It took 500.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:47.705 [0x7f6b61082b38] WARN - SLOW QUERY: It took 840.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:47.857 [0x7f6b61082b38] WARN - SLOW QUERY: It took 470.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:48.192 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1210.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:48.403 [0x7f6b61082b38] WARN - SLOW QUERY: It took 690.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:48.465 [0x7f6b61082b38] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:48.570 [0x7f6b61082b38] WARN - SLOW QUERY: It took 390.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:48.942 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1320.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:49.080 [0x7f6b61082b38] WARN - SLOW QUERY: It took 510.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:49.222 [0x7f6b61082b38] WARN - SLOW QUERY: It took 520.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:49.416 [0x7f6b61082b38] WARN - SLOW QUERY: It took 400.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:49.545 [0x7f6b61082b38] WARN - SLOW QUERY: It took 490.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:49.661 [0x7f6b61082b38] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:49.750 [0x7f6b61082b38] WARN - SLOW QUERY: It took 240.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:49.948 [0x7f6b61082b38] WARN - SLOW QUERY: It took 690.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:50.091 [0x7f6b61082b38] WARN - SLOW QUERY: It took 470.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:50.157 [0x7f6b61082b38] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:50.257 [0x7f6b61082b38] WARN - SLOW QUERY: It took 340.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:50.376 [0x7f6b61082b38] WARN - SLOW QUERY: It took 420.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:50.472 [0x7f6b61082b38] WARN - SLOW QUERY: It took 350.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:50.568 [0x7f6b61082b38] WARN - SLOW QUERY: It took 340.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:50.647 [0x7f6b61082b38] WARN - SLOW QUERY: It took 280.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:50.734 [0x7f6b61082b38] WARN - SLOW QUERY: It took 320.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:50.828 [0x7f6b61082b38] WARN - SLOW QUERY: It took 330.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.012 [0x7f6b61082b38] WARN - SLOW QUERY: It took 580.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.168 [0x7f6b61082b38] WARN - SLOW QUERY: It took 510.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.277 [0x7f6b61082b38] WARN - SLOW QUERY: It took 390.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.360 [0x7f6b61082b38] WARN - SLOW QUERY: It took 290.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.432 [0x7f6b61082b38] WARN - SLOW QUERY: It took 240.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.509 [0x7f6b61082b38] WARN - SLOW QUERY: It took 270.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.579 [0x7f6b61082b38] WARN - SLOW QUERY: It took 240.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.685 [0x7f6b61082b38] WARN - SLOW QUERY: It took 260.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.769 [0x7f6b61082b38] WARN - SLOW QUERY: It took 290.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.845 [0x7f6b61082b38] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:51.941 [0x7f6b61082b38] WARN - SLOW QUERY: It took 330.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:52.164 [0x7f6b61082b38] WARN - SLOW QUERY: It took 780.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:52.235 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:52.342 [0x7f6b61082b38] WARN - SLOW QUERY: It took 370.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:52.661 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1070.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:52.746 [0x7f6b61082b38] WARN - SLOW QUERY: It took 310.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:53.053 [0x7f6b61082b38] WARN - SLOW QUERY: It took 510.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:53.209 [0x7f6b61082b38] WARN - SLOW QUERY: It took 540.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:53.710 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1630.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:53.876 [0x7f6b61082b38] WARN - SLOW QUERY: It took 590.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:54.286 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1430.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:54.461 [0x7f6b61082b38] WARN - SLOW QUERY: It took 510.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:54.515 [0x7f6b5e9fdb38] WARN - SLOW QUERY: It took 380.000000 ms to retrieve 0 items.
Aug 27, 2021 16:12:54.815 [0x7f6b61082b38] WARN - SLOW QUERY: It took 870.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:55.170 [0x7f6b61082b38] WARN - SLOW QUERY: It took 870.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:55.394 [0x7f6b61082b38] WARN - SLOW QUERY: It took 500.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:55.965 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1230.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:56.153 [0x7f6b61082b38] WARN - SLOW QUERY: It took 570.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:56.634 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1290.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:56.880 [0x7f6b61082b38] WARN - SLOW QUERY: It took 530.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:57.123 [0x7f6b5e996b38] WARN - Held transaction for too long (../Statistics/StatisticsManager.cpp:249): 1.470000 seconds
Aug 27, 2021 16:12:57.141 [0x7f6b61082b38] WARN - SLOW QUERY: It took 690.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:57.274 [0x7f6b5e996b38] WARN - Held transaction for too long (../Statistics/StatisticsManager.cpp:252): 0.230000 seconds
Aug 27, 2021 16:12:57.771 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1380.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:58.011 [0x7f6b61082b38] WARN - SLOW QUERY: It took 490.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:58.384 [0x7f6b61082b38] WARN - SLOW QUERY: It took 780.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:58.634 [0x7f6b61082b38] WARN - SLOW QUERY: It took 680.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:59.026 [0x7f6b61082b38] WARN - SLOW QUERY: It took 880.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:59.427 [0x7f6b61082b38] WARN - SLOW QUERY: It took 850.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:59.663 [0x7f6b61082b38] WARN - SLOW QUERY: It took 440.000000 ms to retrieve 1 items.
Aug 27, 2021 16:12:59.858 [0x7f6b61082b38] WARN - SLOW QUERY: It took 360.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:00.118 [0x7f6b61082b38] WARN - SLOW QUERY: It took 390.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:00.436 [0x7f6b61082b38] WARN - SLOW QUERY: It took 480.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:00.899 [0x7f6b61082b38] WARN - SLOW QUERY: It took 590.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:01.156 [0x7f6b61082b38] WARN - SLOW QUERY: It took 560.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:01.240 [0x7f6b61082b38] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:01.319 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:01.523 [0x7f6b61082b38] WARN - SLOW QUERY: It took 440.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:01.778 [0x7f6b61082b38] WARN - SLOW QUERY: It took 570.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:02.098 [0x7f6b61082b38] WARN - SLOW QUERY: It took 680.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:02.382 [0x7f6b61082b38] WARN - SLOW QUERY: It took 380.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:02.692 [0x7f6b61082b38] WARN - SLOW QUERY: It took 570.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:02.822 [0x7f6b61082b38] WARN - SLOW QUERY: It took 330.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:03.087 [0x7f6b61082b38] WARN - SLOW QUERY: It took 590.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:03.239 [0x7f6b61082b38] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:03.374 [0x7f6b61082b38] WARN - SLOW QUERY: It took 420.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:03.654 [0x7f6b61082b38] WARN - SLOW QUERY: It took 570.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:03.737 [0x7f6b61082b38] WARN - SLOW QUERY: It took 260.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:03.943 [0x7f6b61082b38] WARN - SLOW QUERY: It took 460.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:04.067 [0x7f6b61082b38] WARN - SLOW QUERY: It took 260.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:04.309 [0x7f6b61082b38] WARN - SLOW QUERY: It took 760.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:04.517 [0x7f6b61082b38] WARN - SLOW QUERY: It took 470.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:04.747 [0x7f6b61082b38] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:04.904 [0x7f6b61082b38] WARN - SLOW QUERY: It took 320.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:05.101 [0x7f6b61082b38] WARN - SLOW QUERY: It took 440.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:05.438 [0x7f6b61082b38] WARN - SLOW QUERY: It took 660.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:05.587 [0x7f6b61082b38] WARN - SLOW QUERY: It took 360.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:05.984 [0x7f6b61082b38] WARN - SLOW QUERY: It took 910.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:06.492 [0x7f6b61082b38] WARN - SLOW QUERY: It took 700.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:06.755 [0x7f6b61082b38] WARN - SLOW QUERY: It took 530.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:07.080 [0x7f6b61082b38] WARN - SLOW QUERY: It took 800.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:07.320 [0x7f6b61082b38] WARN - SLOW QUERY: It took 280.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:07.791 [0x7f6b61082b38] WARN - SLOW QUERY: It took 600.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:08.155 [0x7f6b61082b38] WARN - SLOW QUERY: It took 450.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:08.718 [0x7f6b61082b38] WARN - SLOW QUERY: It took 720.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:09.098 [0x7f6b61082b38] WARN - SLOW QUERY: It took 850.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:09.242 [0x7f6b61082b38] WARN - SLOW QUERY: It took 300.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:09.794 [0x7f6b61082b38] WARN - SLOW QUERY: It took 410.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:10.107 [0x7f6b61082b38] WARN - SLOW QUERY: It took 420.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:10.421 [0x7f6b61082b38] WARN - SLOW QUERY: It took 590.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:10.620 [0x7f6b61082b38] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:11.032 [0x7f6b61082b38] WARN - SLOW QUERY: It took 400.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:11.283 [0x7f6b61082b38] WARN - SLOW QUERY: It took 470.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:11.988 [0x7f6b61082b38] WARN - SLOW QUERY: It took 1330.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:12.260 [0x7f6b61082b38] WARN - SLOW QUERY: It took 310.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:12.697 [0x7f6b61082b38] WARN - SLOW QUERY: It took 800.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:12.940 [0x7f6b61082b38] WARN - SLOW QUERY: It took 460.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:13.497 [0x7f6b61082b38] WARN - SLOW QUERY: It took 600.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:13.875 [0x7f6b61082b38] WARN - SLOW QUERY: It took 270.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:14.312 [0x7f6b61082b38] WARN - SLOW QUERY: It took 420.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:14.590 [0x7f6b61082b38] WARN - SLOW QUERY: It took 270.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:15.186 [0x7f6b61082b38] WARN - SLOW QUERY: It took 360.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:16.013 [0x7f6b61082b38] WARN - SLOW QUERY: It took 460.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:16.295 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:16.940 [0x7f6b61082b38] WARN - SLOW QUERY: It took 460.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:17.341 [0x7f6b61082b38] WARN - SLOW QUERY: It took 390.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:17.700 [0x7f6b61082b38] WARN - SLOW QUERY: It took 360.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:18.087 [0x7f6b61082b38] WARN - SLOW QUERY: It took 350.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:18.528 [0x7f6b61082b38] WARN - SLOW QUERY: It took 440.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:19.063 [0x7f6b61082b38] WARN - SLOW QUERY: It took 350.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:19.346 [0x7f6b61082b38] WARN - SLOW QUERY: It took 280.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:19.581 [0x7f6b61082b38] WARN - SLOW QUERY: It took 230.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:19.961 [0x7f6b61082b38] WARN - SLOW QUERY: It took 380.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:20.804 [0x7f6b61082b38] WARN - SLOW QUERY: It took 290.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:21.382 [0x7f6b61082b38] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:21.808 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:22.367 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:22.910 [0x7f6b61082b38] WARN - SLOW QUERY: It took 550.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:23.212 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:23.504 [0x7f6b61082b38] WARN - SLOW QUERY: It took 260.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:24.744 [0x7f6b61082b38] WARN - SLOW QUERY: It took 560.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:25.154 [0x7f6b61082b38] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:25.740 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:26.267 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:27.583 [0x7f6b5e9fdb38] WARN - Held transaction for too long (../Statistics/StatisticsManager.cpp:249): 0.350000 seconds
Aug 27, 2021 16:13:27.612 [0x7f6b61082b38] WARN - SLOW QUERY: It took 300.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:27.894 [0x7f6b61082b38] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 1 items.
Aug 27, 2021 16:13:28.108 [0x7f6b61082b38] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 1 items.
Aug 27, 2021 16:25:57.948 [0x7f6b61082b38] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 1 items.
Aug 27, 2021 16:25:59.177 [0x7f6b61082b38] WARN - SLOW QUERY: It took 240.000000 ms to retrieve 1 items.
Aug 27, 2021 16:25:59.927 [0x7f6b61082b38] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 1 items.
Aug 27, 2021 16:26:04.283 [0x7f6b61082b38] WARN - SLOW QUERY: It took 330.000000 ms to retrieve 1 items.
Aug 27, 2021 16:26:17.411 [0x7f6b6105fb38] ERROR - LPE: unknown section 3.
Aug 27, 2021 16:26:17.411 [0x7f6b60fcbb38] ERROR - LPE: unknown section 3.
Aug 27, 2021 16:26:17.450 [0x7f6b60fcbb38] WARN - LPE: falling back to slow path evaluation: /library/sections/3/all?type=10&album.addedAt%3E%3E=-1mon&sort=album.addedAt:desc
Aug 27, 2021 16:26:17.450 [0x7f6b6105fb38] WARN - LPE: falling back to slow path evaluation: /library/sections/3/all?type=10&album.addedAt%3E%3E=-1mon&sort=album.addedAt:desc
Aug 27, 2021 16:26:17.468 [0x7f6b60fcbb38] ERROR - downloadContainer: expected MediaContainer element, found html
Aug 27, 2021 16:26:17.468 [0x7f6b60fcbb38] ERROR - LPE: failed to get container for path: /library/sections/3/all?type=10&album.addedAt%3E%3E=-1mon&sort=album.addedAt:desc
Aug 27, 2021 16:26:17.468 [0x7f6b6105fb38] ERROR - downloadContainer: expected MediaContainer element, found html
Aug 27, 2021 16:26:17.468 [0x7f6b6105fb38] ERROR - LPE: failed to get container for path: /library/sections/3/all?type=10&album.addedAt%3E%3E=-1mon&sort=album.addedAt:desc
Aug 27, 2021 16:26:17.468 [0x7f6b6105fb38] ERROR - Failed to generate a query from uri library://x/directory/%2Flibrary%2Fsections%2F3%2Fall%3Ftype%3D10%26album.addedAt%253E%253E%3D-1mon%26sort%3Dalbum.addedAt%3Adesc
Aug 27, 2021 16:26:17.468 [0x7f6b60fcbb38] ERROR - Failed to generate a query from uri library://x/directory/%2Flibrary%2Fsections%2F3%2Fall%3Ftype%3D10%26album.addedAt%253E%253E%3D-1mon%26sort%3Dalbum.addedAt%3Adesc
Aug 27, 2021 16:26:51.695 [0x7f6b60f0fb38] INFO - AutoUpdate: no updates available
Aug 27, 2021 16:27:29.716 [0x7f6b5e9fdb38] WARN - NAT: PMP, timed out waiting for response.
Aug 27, 2021 16:27:32.720 [0x7f6b5e9fdb38] ERROR - Error issuing curl_easy_perform(handle): 28
Aug 27, 2021 16:33:10.496 [0x7f6b5e00db38] WARN - Held transaction for too long (../Statistics/StatisticsManager.cpp:249): 0.240000 seconds
Aug 27, 2021 16:33:12.893 [0x7f6b61082b38] WARN - SLOW QUERY: It took 250.000000 ms to retrieve 1 items.
Aug 27, 2021 16:33:15.734 [0x7f6b60eecb38] INFO - AutoUpdate: no updates available
Aug 27, 2021 16:33:18.449 [0x7f6b60fcbb38] ERROR - LPE: unknown section 3.
Aug 27, 2021 16:33:18.478 [0x7f6b61082b38] WARN - SLOW QUERY: It took 330.000000 ms to retrieve 1 items.
Aug 27, 2021 16:33:18.489 [0x7f6b60fcbb38] WARN - LPE: falling back to slow path evaluation: /library/sections/3/all?type=10&album.addedAt%3E%3E=-1mon&sort=album.addedAt:desc
Aug 27, 2021 16:33:18.492 [0x7f6b60fcbb38] ERROR - downloadContainer: expected MediaContainer element, found html
Aug 27, 2021 16:33:18.492 [0x7f6b60fcbb38] ERROR - LPE: failed to get container for path: /library/sections/3/all?type=10&album.addedAt%3E%3E=-1mon&sort=album.addedAt:desc
Aug 27, 2021 16:33:18.492 [0x7f6b60fcbb38] ERROR - Failed to generate a query from uri library://x/directory/%2Flibrary%2Fsections%2F3%2Fall%3Ftype%3D10%26album.addedAt%253E%253E%3D-1mon%26sort%3Dalbum.addedAt%3Adesc
Aug 27, 2021 16:33:18.610 [0x7f6b60eecb38] ERROR - LPE: unknown section 3.
Aug 27, 2021 16:33:18.610 [0x7f6b60eecb38] WARN - LPE: falling back to slow path evaluation: /library/sections/3/all?type=10
Aug 27, 2021 16:33:18.613 [0x7f6b60eecb38] ERROR - downloadContainer: expected MediaContainer element, found html
Aug 27, 2021 16:33:18.613 [0x7f6b60eecb38] ERROR - LPE: failed to get container for path: /library/sections/3/all?type=10
Aug 27, 2021 16:33:18.613 [0x7f6b60eecb38] ERROR - Failed to generate a query from uri library://x/directory/%2Flibrary%2Fsections%2F3%2Fall%3Ftype%3D10
Aug 27, 2021 16:33:18.703 [0x7f6b60a85b38] ERROR - LPE: unknown section 3.
Aug 27, 2021 16:33:18.703 [0x7f6b60a85b38] WARN - LPE: falling back to slow path evaluation: /library/sections/3/all?type=10&album.addedAt%3E%3E=-1mon&sort=album.addedAt:desc
Aug 27, 2021 16:33:18.705 [0x7f6b60a85b38] ERROR - downloadContainer: expected MediaContainer element, found html
Aug 27, 2021 16:33:18.705 [0x7f6b60a85b38] ERROR - LPE: failed to get container for path: /library/sections/3/all?type=10&album.addedAt%3E%3E=-1mon&sort=album.addedAt:desc
Aug 27, 2021 16:33:18.705 [0x7f6b60a85b38] ERROR - Failed to generate a query from uri library://x/directory/%2Flibrary%2Fsections%2F3%2Fall%3Ftype%3D10%26album.addedAt%253E%253E%3D-1mon%26sort%3Dalbum.addedAt%3Adesc
Aug 27, 2021 16:33:18.786 [0x7f6b6105fb38] ERROR - LPE: unknown section 3.
Aug 27, 2021 16:33:18.786 [0x7f6b6105fb38] WARN - LPE: falling back to slow path evaluation: /library/sections/3/all?type=10
Aug 27, 2021 16:33:18.788 [0x7f6b6105fb38] ERROR - downloadContainer: expected MediaContainer element, found html
Aug 27, 2021 16:33:18.788 [0x7f6b6105fb38] ERROR - LPE: failed to get container for path: /library/sections/3/all?type=10
Aug 27, 2021 16:33:18.788 [0x7f6b6105fb38] ERROR - Failed to generate a query from uri library://x/directory/%2Flibrary%2Fsections%2F3%2Fall%3Ftype%3D10
Aug 27, 2021 16:33:18.821 [0x7f6b61082b38] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 1 items.
Aug 27, 2021 16:33:18.838 [0x7f6b60f0fb38] ERROR - LPE: unknown section 3.
Aug 27, 2021 16:33:18.839 [0x7f6b60f0fb38] WARN - LPE: falling back to slow path evaluation: /library/sections/3/all?type=10&lastViewedAt%3E%3E=-2w&group=guid&having=min(album.originallyAvailableAt)&sort=lastViewedAt:desc
Aug 27, 2021 16:33:18.844 [0x7f6b60f0fb38] ERROR - downloadContainer: expected MediaContainer element, found html
Aug 27, 2021 16:33:18.844 [0x7f6b60f0fb38] ERROR - LPE: failed to get container for path: /library/sections/3/all?type=10&lastViewedAt%3E%3E=-2w&group=guid&having=min(album.originallyAvailableAt)&sort=lastViewedAt:desc
Aug 27, 2021 16:33:18.845 [0x7f6b60f0fb38] ERROR - Failed to generate a query from uri library://x/directory/%2Flibrary%2Fsections%2F3%2Fall%3Ftype%3D10%26lastViewedAt%253E%253E%3D-2w%26group%3Dguid%26having%3Dmin(album.originallyAvailableAt)%26sort%3DlastViewedAt%3Adesc
Aug 27, 2021 16:33:41.149 [0x7f6b5e9fdb38] WARN - Held transaction for too long (../Statistics/StatisticsManager.cpp:249): 0.140000 seconds
I am running Plex on a dual socket Xeon and PCIe SSDs. I doubt it’s a resource issue.
Can you please enable Debug logging on your PMS and provide zipped logs?
@Atomatth - second PM is with logs with debug enabled.
Found this thread while searching for causes/solution to the slow query repetated entries.
Running Plex on a microk8 cluster (8c / 32gb) mounting nfs to a freenas (4c / 32 gb , dedicated to file serving).
Would more logs help?
I also have the Kubernetes yaml spec for the setup (ns, service, deployment, IngressRoute), if it helps to repro.
@Atomatth after the issue disappearing for a about a week it was suddenly back tonight. I have enabled debug logging and will wait for the next occurrence and then supply logs
1 Like
interesting i have 128tb capacity with 21tb free, i wonder if this is the issue, would seem strange though considering the plex metadata is not on the main storage array and that ssd has 500gb free out of 1tb available.
I am not about to delete 100tb of data to find out though.
After discussing this topic with some team members, I want to share some observations/suggestions.
- Please have debugging enabled
- The SLOW QUERY message may not be an indication to an issue
- The time is recorded in ms, so 240.000000ms is still rather quick
- If the time is greater 5s or 5000.000000ms, that would be significate and warrant investigation. This is an example not a threshold.
- Attempt to Optimize your DB and Clean Bundles
- Check your Plex Media Scanner Matcher.log and Plex Media Scanner Analysis.log for possible bad files, locked DB messages or other errors.
- It maybe worth mentioning your
Settings > LibraryandSettings > Scheduled Taskssettings that pertain to scanning
I’m also curious if anyone is running any 3rd party apps or scripts that touch Plex that maybe invoking scans or metadata updates.
1 Like
my plex server just got stuck doing a sonic analysis of 0 albums.
I have no music on my plex server.
Debug logs will be sent shortly
@Atomatth debug logs dm’d to you.
I have overseerr installed also, but the issue started long after that was installed.
Overseer running in Docker but that has always been installed. I run 2 servers (one on NAS (Synology) and other on Shield) I just find PMS on NAS extremely sluggish mostly shows up as Unavailable. Only indexed large Music folder (approx. 30k albums). What gets me is PlexMediaServer process is always only using around 200MB ram and 15% CPU at most even when scanning or running scheduling tasks.
about. 6 hours ago I downgraded to
image: plexinc/pms-docker:1.23.6.4881-e2e58f321
And I see a lot fewer slow query messages (which is not a very good indicator, there might just be less debug info in the codebase calling that). But more importantly I see less occurrences of the scanning stalling.
This is not a deterministic test, I’ll probably redo the setup from scratch to try and confirm if the 1.24 is to blame or I’m just hunting for an easy prey.
Aug 31, 2021 08:09:45.921 [0x7fdaa4987b38] Error — Error issuing curl_easy_perform(handle): 28
Aug 31, 2021 08:18:16.266 [0x7fdaa49e2b38] Error — Resources:CPUUtilization: Unexpected result when reading /proc/5733/stat
Aug 31, 2021 08:24:40.179 [0x7fdaa47c9b38] Error — Resources:CPUUtilization: Unexpected result when reading /proc/9176/stat
Aug 31, 2021 08:31:10.119 [0x7fdaa4c62b38] Error — Error issuing curl_easy_perform(handle): 28
Aug 31, 2021 08:38:28.845 [0x7fdaa6e07b38] Info — Plex Media Server v1.24.1.4931-1a38e63c6 - Synology DS1813+ x86_64 - build: linux-x86_64 synology-dsm7 - GMT 10:00
Aug 31, 2021 08:38:28.854 [0x7fdaa6e07b38] Info — Linux version: DSM 7.0.41890-0, language: en-US
Aug 31, 2021 08:38:28.855 [0x7fdaa6e07b38] Info — Processor Intel(R) Atom(TM) CPU D2701 @ 2.13GHz
Aug 31, 2021 08:38:28.855 [0x7fdaa6e07b38] Info — Compiler is - Clang 11.0.1 (https://plex.tv e0c29d5827bc4eaaa2ceb882cbeed224b0960173)
Aug 31, 2021 08:38:28.855 [0x7fdaa6e07b38] Info — /volume1/@appstore/PlexMediaServer/Plex Media Server
Aug 31, 2021 08:41:08.225 [0x7fdaa4addb38] Error — Error issuing curl_easy_perform(handle): 28
Aug 31, 2021 08:53:00.163 [0x7fdaa4688b38] Error — Resources:CPUUtilization: Unexpected result when reading /proc/23280/stat
Aug 31, 2021 09:07:09.451 [0x7fdaa4c3fb38] Error — Error issuing curl_easy_perform(handle): 28
Aug 31, 2021 09:07:12.676 [0x7fdaa4750b38] Error — Error issuing curl_easy_perform(handle): 28
Aug 31, 2021 09:08:56.304 [0x7fdaa4e5fb38] Error — Failed to begin transaction (../Library/MetadataItem.cpp:3813) (tries=1): Cannot begin transaction. database is locked
Aug 31, 2021 09:11:55.091 [0x7fdaa557eb38] Error — Failed to begin transaction (../Library/Dir.cpp:40) (tries=1): Cannot begin transaction. database is locked
Aug 31, 2021 09:11:57.631 [0x7fdaa557eb38] Error — Failed to begin transaction (../Library/Dir.cpp:40) (tries=2): Cannot begin transaction. database is locked
Aug 31, 2021 09:12:25.603 [0x7fdaa3859b38] Error — Failed to begin transaction (../Library/MetadataItem.cpp:1122) (tries=1): Cannot begin transaction. database is locked
