Plex Media Server Failing to load libraries consistantly

Plex Media Server
,
1

Server Version#: 1.41.0.8994
Player Version#:All
This has been driving me up a wall the past week and a half. Three or so weeks ago I migrated my plex media server to a new server, more cores, more RAM, etc. The first week it worked perfectly, and then as of this past weekend (Oct 6th or so) and if I recall a Plex server update, my home tab on any streaming device I use (web, firetv, roku, etc) lags significantly and most of the time will not load my continue watching. Combined with this I get frequent failures to load entire libraries (but will work other time randomly), as well as the recommended in most libraries now fails to load.

As I said all of this was working fine not only before my migration, but for at least a good week or more post migration. I’ve refreshed metadata on all libraries several times, I’ve run a database optimization several times. I’ve cleared out the cache and had it rebuild, I’ve even gone through and have run a DB repair found here.

Logs indicate that database transactions are being held to long suddenly and I’m not sure as to why (VM is running on 4 2.7TB 15k RPM SAS drives in a RAID5). I’ve also noticed something strange on my NAS where all my media is stored, in that every episode file now also has a .xml and .metathumb file associated with it in the same folder, as well as a “folder” jpg file in each season. None of these files were there before.

Oct 18, 2024 15:28:16.105 [4364] INFO - Running migrations. (EPG 1)
Oct 18, 2024 15:28:16.236 [4100] ERROR - DVR:Device: Error refreshing existing device device://tv.plex.grabbers.hdhomerun/1325DF15, marking as dead.
Oct 18, 2024 15:28:16.847 [5016] WARN - [Req#f9] SLOW QUERY: It took 468.750000 ms to retrieve 2 items.
Oct 18, 2024 15:28:17.000 [3644] WARN - [Req#119] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:17.000 [3644] WARN - [Req#119] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:17.177 [1488] WARN - [Req#118] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:17.177 [1488] WARN - [Req#118] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:17.471 [4568] WARN - [Req#11d] SLOW QUERY: It took 1156.250000 ms to retrieve 13 items.
Oct 18, 2024 15:28:17.650 [4568] INFO - [Req#12d] AutoUpdate: no updates available
Oct 18, 2024 15:28:19.065 [3644] WARN - [Req#119] SLOW QUERY: It took 2984.375000 ms to retrieve 50 items.
Oct 18, 2024 15:28:19.102 [1488] WARN - [Req#118] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:19.102 [1488] WARN - [Req#118] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:19.273 [11236] WARN - MPM: ignoring preferred-interface pref due to no matching valid address
Oct 18, 2024 15:28:22.061 [1488] WARN - [Req#118] SLOW QUERY: It took 2578.125000 ms to retrieve 50 items.
Oct 18, 2024 15:28:30.875 [1488] WARN - [Req#180] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:30.876 [1488] WARN - [Req#180] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:31.319 [1488] INFO - [Req#183] AutoUpdate: no updates available
Oct 18, 2024 15:28:41.063 [9008] WARN - Held transaction for too long (D:\gha\plex-media-server\plex-media-server\Statistics\StatisticsManager.cpp:294): 0.281250 seconds
Oct 18, 2024 15:28:46.986 [5996] WARN - [Req#19b] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 18, 2024 15:28:46.986 [5996] WARN - [Req#19b] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:46.986 [5996] WARN - [Req#19b] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:47.023 [4568] WARN - [Req#198] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 18, 2024 15:28:47.024 [4568] WARN - [Req#198] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:47.024 [4568] WARN - [Req#198] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:47.040 [8200] ERROR - [Req#1a7] Unknown metadata type: folder
Oct 18, 2024 15:28:47.040 [6108] ERROR - [Req#1a8] Unknown metadata type: folder
Oct 18, 2024 15:28:47.041 [8200] WARN - [Req#1a7] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:47.041 [8200] WARN - [Req#1a7] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:47.041 [6108] WARN - [Req#1a8] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:47.042 [6108] WARN - [Req#1a8] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:48.267 [5996] WARN - [Req#19b] SLOW QUERY: It took 1156.250000 ms to retrieve 50 items.
Oct 18, 2024 15:28:48.900 [6080] WARN - [Req#1b6/Req#1b7] SLOW QUERY: It took 265.625000 ms to retrieve 36 items.
Oct 18, 2024 15:28:48.952 [4568] WARN - [Req#198] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 18, 2024 15:28:48.952 [4568] WARN - [Req#198] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:48.952 [4568] WARN - [Req#198] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:49.031 [8200] WARN - [Req#1a7] SLOW QUERY: It took 1015.625000 ms to retrieve 24 items.
Oct 18, 2024 15:28:49.273 [6108] WARN - [Req#1a8] SLOW QUERY: It took 265.625000 ms to retrieve 24 items.
Oct 18, 2024 15:28:49.413 [6108] WARN - [Req#1c7/Req#1c8] SLOW QUERY: It took 578.125000 ms to retrieve 70 items.
Oct 18, 2024 15:28:49.438 [8528] INFO - [Req#1bc] AutoUpdate: no updates available
Oct 18, 2024 15:28:49.625 [5996] WARN - [Req#1d3/Req#1d6] SLOW QUERY: It took 343.750000 ms to retrieve 50 items.
Oct 18, 2024 15:28:50.232 [8200] WARN - [Req#1ee] SLOW QUERY: It took 843.750000 ms to retrieve 89 items.
Oct 18, 2024 15:28:50.324 [8528] WARN - [Req#1f9/Req#203] SLOW QUERY: It took 390.625000 ms to retrieve 26 items.
Oct 18, 2024 15:28:50.495 [6108] WARN - [Req#20b] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 18, 2024 15:28:50.495 [6108] WARN - [Req#20b] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:50.496 [6108] WARN - [Req#20b] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:50.977 [8528] WARN - [Req#20c] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 18, 2024 15:28:50.977 [8528] WARN - [Req#20c] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:50.978 [8528] WARN - [Req#20c] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:51.164 [8200] WARN - [Req#214/Req#216] SLOW QUERY: It took 468.750000 ms to retrieve 32 items.
Oct 18, 2024 15:28:51.400 [8200] WARN - [Req#21c/Req#21e] SLOW QUERY: It took 281.250000 ms to retrieve 1 items.
Oct 18, 2024 15:28:51.474 [4568] WARN - [Req#198] SLOW QUERY: It took 2718.750000 ms to retrieve 50 items.
Oct 18, 2024 15:28:51.546 [8200] WARN - [Req#21c/Req#21e] SLOW QUERY: It took 1031.250000 ms to retrieve 71 items.
Oct 18, 2024 15:28:51.565 [4568] WARN - [Req#198] SLOW QUERY: It took 359.375000 ms to retrieve 21 items.
Oct 18, 2024 15:28:51.828 [5996] WARN - [Req#221/Req#222] SLOW QUERY: It took 546.875000 ms to retrieve 1 items.
Oct 18, 2024 15:28:53.264 [5984] WARN - [Req#238/Req#239] SLOW QUERY: It took 234.375000 ms to retrieve 1 items.
Oct 18, 2024 15:28:53.381 [6108] WARN - [Req#20b] SLOW QUERY: It took 2156.250000 ms to retrieve 50 items.
Oct 18, 2024 15:28:53.485 [6108] WARN - [Req#20b] SLOW QUERY: It took 312.500000 ms to retrieve 17 items.
Oct 18, 2024 15:28:53.634 [6108] WARN - [Req#20b] SLOW QUERY: It took 203.125000 ms to retrieve 16 items.
Oct 18, 2024 15:28:53.651 [5996] WARN - [Req#23e/Req#240] SLOW QUERY: It took 218.750000 ms to retrieve 45 items.
Oct 18, 2024 15:28:54.063 [8200] WARN - [Req#24f/Req#252] SLOW QUERY: It took 359.375000 ms to retrieve 14 items.
Oct 18, 2024 15:28:54.566 [5984] WARN - [Req#263/Req#268] QueryParser: Invalid field 'having' found, ignoring.
Oct 18, 2024 15:28:54.725 [6728] WARN - [Req#264/Req#26c] SLOW QUERY: It took 234.375000 ms to retrieve 5 items.
Oct 18, 2024 15:28:54.792 [5996] WARN - [Req#26b/Req#26e] SLOW QUERY: It took 359.375000 ms to retrieve 18 items.
Oct 18, 2024 15:28:54.941 [5996] WARN - [Req#26b/Req#26e] SLOW QUERY: It took 625.000000 ms to retrieve 49 items.
Oct 18, 2024 15:28:54.956 [6728] WARN - [Req#264/Req#26c] SLOW QUERY: It took 265.625000 ms to retrieve 5 items.
Oct 18, 2024 15:28:55.035 [8200] WARN - [Req#267/Req#26d] SLOW QUERY: It took 281.250000 ms to retrieve 5 items.
Oct 18, 2024 15:28:55.061 [5996] WARN - [Req#26b/Req#26e] SLOW QUERY: It took 578.125000 ms to retrieve 54 items.
Oct 18, 2024 15:28:55.061 [6728] WARN - [Req#264/Req#26c] SLOW QUERY: It took 281.250000 ms to retrieve 19 items.
Oct 18, 2024 15:28:55.065 [8528] WARN - [Req#20c] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 18, 2024 15:28:55.065 [8528] WARN - [Req#20c] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:55.065 [8528] WARN - [Req#20c] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:55.156 [5996] WARN - [Req#26b/Req#26e] SLOW QUERY: It took 390.625000 ms to retrieve 46 items.
Oct 18, 2024 15:28:55.644 [8200] WARN - [Req#271] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 18, 2024 15:28:55.644 [8200] WARN - [Req#271] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:55.644 [8200] WARN - [Req#271] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 18, 2024 15:28:55.732 [6728] WARN - [Req#273/Req#274] QueryParser: Invalid field 'having' found, ignoring.
Oct 18, 2024 15:28:55.791 [5996] WARN - [Req#277/Req#278] QueryParser: Invalid field 'having' found, ignoring.
Oct 18, 2024 15:28:56.024 [5984] WARN - [Req#263/Req#268] SLOW QUERY: It took 218.750000 ms to retrieve 7 items.
Oct 18, 2024 15:28:56.142 [5984] WARN - [Req#263/Req#268] SLOW QUERY: It took 250.000000 ms to retrieve 5 items.
Oct 18, 2024 15:28:56.229 [5984] WARN - [Req#263/Req#268] SLOW QUERY: It took 406.250000 ms to retrieve 31 items.
Oct 18, 2024 15:28:56.961 [5984] WARN - [Req#223/Req#280] SLOW QUERY: It took 531.250000 ms to retrieve 46 items.
Oct 18, 2024 15:28:57.012 [5984] WARN - [Req#223/Req#280] SLOW QUERY: It took 265.625000 ms to retrieve 37 items.
Oct 18, 2024 15:28:57.074 [5996] WARN - [Req#277/Req#278] SLOW QUERY: It took 250.000000 ms to retrieve 42 items.
Oct 18, 2024 15:28:57.123 [6728] WARN - [Req#273/Req#274] SLOW QUERY: It took 265.625000 ms to retrieve 5 items.
Oct 18, 2024 15:28:57.248 [5996] WARN - [Req#277/Req#278] SLOW QUERY: It took 406.250000 ms to retrieve 25 items.
Oct 18, 2024 15:28:57.605 [8200] WARN - [Req#271] SLOW QUERY: It took 2468.750000 ms to retrieve 50 items.
Oct 18, 2024 15:28:57.625 [8200] WARN - [Req#271] SLOW QUERY: It took 203.125000 ms to retrieve 16 items.
2

An update.

I restored from a snapshot I took on 10/6, before windows updates, this didn’t appear to do anything. In the mean time I also went ahead and blew away all the .xml and .metathumb files on my NAS. While doing that I rolled my plex server version back to the last 1.40 available. Upon immediate loading of this version everything in my libraries, loading of continue watching, as well as recomended suddenly worked again. However as Plex started to rescan the libraries it started re-creating all of the .xml and .metathumb files again.

It would appear the longer I let it scan and create all these files, the less responsive my libraries become (especially the recommended tabs).

Did I miss something in my migration that’s causing this behavior? Is it a permission issue that Plex Media server is using a fail over mode and writing these files to my NAS instead?

Any help or guidance would be greatly appreciated.

3

I realize this isn’t an easy fix, but if anyone has any ideas as to why .xml, .metathumb, folder.jpg and plexmatch files keeps ending up in my media folders, I’d love to hear it. I’ve triple checked my appdata folder where the Metadata and db’s are stored and confirmed that my account (which plex server runs under) has full control, I’ve also confirmed that nothing in the folder tree is set to read-only or archive, and yet the files keep returning on in my media folders. I suspect that these sitting on my NAS are what is causing the problems with libraries, recommendations, and continue watching failing to load due to timeouts.

4

Not Plex. WD NAS?

5

Figured out last night that the files are actually unrelated, and being created by Sonarr (setting that had gotten missed in it’s migration as well). Still having a terrible time loading the home page, Continue Watching, or any recomended tab.

6

So I ran a db repair and re-index this morning, claimed everything in the DB was fine. Here’s some logs from the plex media server.log when I attempted to load up my home page from a different machine on the network:

Oct 22, 2024 09:44:41.855 [2076] DEBUG - Completed: [172.20.1.247:54503] 200 GET /hubs/promoted?contentDirectoryID=2&pinnedContentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1&excludeFields=summary&count=12&includeStations=1&includeLibraryPlaylists=1&includeRecentChannels=1&excludeContinueWatching=1 (8 live) #155 TLS GZIP 10996ms 13327 bytes (pipelined: 1)
Oct 22, 2024 09:44:46.170 [11480] DEBUG - Completed: [172.20.1.247:54502] 200 GET /tv.plex.providers.epg.cloud:9/hubs/discover?promoted=1&includeTypeFirst=1&contentDirectoryID=tv.plex.providers.epg.cloud%3A9&pinnedContentDirectoryID=tv.plex.providers.epg.cloud%3A9&includeMeta=1&excludeFields=summary&count=12&includeStations=1&includeLibraryPlaylists=1&includeRecentChannels=1&excludeContinueWatching=1 (8 live) #163 TLS GZIP 15168ms 6452 bytes (pipelined: 3)
Oct 22, 2024 09:44:59.808 [11456] DEBUG - [Req#152] HubCache: Computed '1/continueWatching/1/hubs/continueWatching/enexternal-media,indirect-media,hub-style-list/contentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&excludeFields=summary&includeMeta=1' in 28974 ms.
Oct 22, 2024 09:44:59.813 [2076] DEBUG - Completed: [172.20.1.247:54443] 200 GET /hubs/continueWatching?contentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1&excludeFields=summary (7 live) #152 TLS GZIP 28982ms 630 bytes (pipelined: 5)
Oct 22, 2024 09:44:59.847 [11456] DEBUG - Request: [172.20.1.247:54443 (Allowed Network (Subnet))] GET /hubs/home/recentlyAdded?type=2&sectionID=4&contentDirectoryID=4&pinnedContentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1 (7 live) #17a TLS Page 12-35 GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:44:59.851 [11456] WARN - [Req#17a] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 22, 2024 09:44:59.851 [11456] WARN - [Req#17a] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.852 [11456] WARN - [Req#17a] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.852 [7220] DEBUG - Request: [172.20.1.247:54503 (Allowed Network (Subnet))] GET /library/sections/2/all?sort=lastViewedAt:desc&unwatched=0&viewOffset=0&type=4&contentDirectoryID=2&pinnedContentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1 (6 live) #16c TLS Page 12-35 GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:44:59.853 [11604] DEBUG - Request: [172.20.1.247:54502 (Allowed Network (Subnet))] GET /hubs/home/recentlyAdded?type=2&sectionID=2&contentDirectoryID=2&pinnedContentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1 (6 live) #175 TLS Page 12-35 GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:44:59.860 [11604] WARN - [Req#175] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 22, 2024 09:44:59.861 [11604] WARN - [Req#175] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.861 [11604] WARN - [Req#175] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.863 [4852] DEBUG - Request: [172.20.1.247:54574 (Allowed Network (Subnet))] GET /library/sections/1/all?sort=addedAt:desc&contentDirectoryID=1&pinnedContentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1 (9 live) #157 TLS Page 12-35 GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:44:59.870 [4852] ERROR - [Req#157] Unknown metadata type: folder
Oct 22, 2024 09:44:59.871 [7220] ERROR - [Req#16c] Unknown metadata type: folder
Oct 22, 2024 09:44:59.872 [7220] WARN - [Req#16c] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.872 [7220] WARN - [Req#16c] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.872 [7220] DEBUG - [Req#16c] Setting container serialization range to [12, 35] (total=-1)
Oct 22, 2024 09:44:59.873 [4852] WARN - [Req#157] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.873 [4852] WARN - [Req#157] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.873 [4852] DEBUG - [Req#157] Setting container serialization range to [12, 35] (total=-1)
Oct 22, 2024 09:44:59.881 [2340] DEBUG - Request: [172.20.1.247:54576 (Allowed Network (Subnet))] GET /tv.plex.providers.epg.cloud:9/hubs/onnow/shows?contentDirectoryID=tv.plex.providers.epg.cloud%3A9&pinnedContentDirectoryID=tv.plex.providers.epg.cloud%3A9&includeMeta=1 (9 live) #17c TLS Page 12-35 GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:44:59.882 [7052] DEBUG - Request: [172.20.1.247:54577 (Allowed Network (Subnet))] GET /library/sections/8/all?type=9&sort=addedAt:desc&contentDirectoryID=8&pinnedContentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1 (9 live) #17d TLS Page 12-35 GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:44:59.883 [2340] DEBUG - [Req#17c] Setting container serialization range to [12, 35] (total=-1)
Oct 22, 2024 09:44:59.886 [7052] ERROR - [Req#17d] Unknown metadata type: folder
Oct 22, 2024 09:44:59.887 [7052] WARN - [Req#17d] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.887 [7052] WARN - [Req#17d] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 22, 2024 09:44:59.888 [7052] DEBUG - [Req#17d] Setting container serialization range to [12, 35] (total=-1)
Oct 22, 2024 09:45:00.225 [12904] DEBUG - Request: [172.20.1.247:54585 (Allowed Network (Subnet))] GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F588697%2Fthumb%2F1728106419%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (10 live) #17e TLS GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:45:00.226 [12904] DEBUG - [Req#17e] Photo transcoder: Request for url [/library/metadata/588697/thumb/1728106419?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (is local: 1 upscaled: 1)
Oct 22, 2024 09:45:00.235 [12344] DEBUG - Request: [172.20.1.247:54587 (Allowed Network (Subnet))] GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F592709%2Fthumb%2F1729552183%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (14 live) #180 TLS GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:45:00.235 [12344] DEBUG - [Req#180] Photo transcoder: Request for url [/library/metadata/592709/thumb/1729552183?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (is local: 1 upscaled: 1)
Oct 22, 2024 09:45:00.236 [12904] DEBUG - [Req#17e/Req#182] It took 62.500000 ms to retrieve 1 items.
Oct 22, 2024 09:45:00.237 [3980] DEBUG - Request: [172.20.1.247:54589 (Allowed Network (Subnet))] GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F577041%2Fthumb%2F1729551569%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (14 live) #181 TLS GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:45:00.238 [3980] DEBUG - [Req#181] Photo transcoder: Request for url [/library/metadata/577041/thumb/1729551569?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (is local: 1 upscaled: 1)
Oct 22, 2024 09:45:00.250 [12904] DEBUG - [Req#17e/Req#182] Calculated media file path for path [metadata://posters/tv.plex.agents.series_2373fb7821a2d3297cda3bcdead22d338928bcae]: ["C:\Users\Dragon\AppData\Local\Plex Media Server\Metadata\TV Shows\7\4d8ceb48a1f28da0b76ec7a3d1d6085270018e0.bundle\Contents\_combined\posters\tv.plex.agents.series_2373fb7821a2d3297cda3bcdead22d338928bcae"]
Oct 22, 2024 09:45:00.252 [12344] DEBUG - [Req#180/Req#185] It took 109.375000 ms to retrieve 41 items.
Oct 22, 2024 09:45:00.252 [5528] DEBUG - Request: [172.20.1.247:54588 (Allowed Network (Subnet))] GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F507721%2Fthumb%2F1727945500%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (14 live) #183 TLS GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:45:00.253 [5528] DEBUG - [Req#183] Photo transcoder: Request for url [/library/metadata/507721/thumb/1727945500?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (is local: 1 upscaled: 1)
Oct 22, 2024 09:45:00.254 [12344] DEBUG - [Req#180/Req#185] Calculated media file path for path [metadata://posters/tv.plex.agents.series_cf7c0d05f3313bd0f8dfa1d3c784d15049a81b33]: ["C:\Users\Dragon\AppData\Local\Plex Media Server\Metadata\TV Shows\7\690f34029b8f7a2cf3fdb122b1f2b006316c6f1.bundle\Contents\_combined\posters\tv.plex.agents.series_cf7c0d05f3313bd0f8dfa1d3c784d15049a81b33"]
Oct 22, 2024 09:45:00.254 [5528] DEBUG - Content-Length of C:\Users\Dragon\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\34\34b6449dcf1e3ee33d6d1442966fd256558b12a7.jpg is 25678 (of total: 25678).
Oct 22, 2024 09:45:00.262 [12604] DEBUG - Request: [172.20.1.247:54586 (Allowed Network (Subnet))] GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F544211%2Fthumb%2F1729551562%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (14 live) #17f TLS GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:45:00.262 [12604] DEBUG - [Req#17f] Photo transcoder: Request for url [/library/metadata/544211/thumb/1729551562?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (is local: 1 upscaled: 1)
Oct 22, 2024 09:45:00.271 [3980] DEBUG - [Req#181/Req#186] It took 234.375000 ms to retrieve 115 items.
Oct 22, 2024 09:45:00.272 [3980] DEBUG - [Req#181/Req#186] Calculated media file path for path [metadata://posters/tv.plex.agents.series_9c7bceee50f50a75cc320216f5287c6a2d3d68b8]: ["C:\Users\Dragon\AppData\Local\Plex Media Server\Metadata\TV Shows\3\224a3d477b0cedc74a275465f5e4927e715a7bd.bundle\Contents\_combined\posters\tv.plex.agents.series_9c7bceee50f50a75cc320216f5287c6a2d3d68b8"]
Oct 22, 2024 09:45:00.287 [12344] DEBUG - [Req#180] Calling back into ourselves for photo to transcode, optimizing the process (status: -1)
Oct 22, 2024 09:45:00.287 [3980] DEBUG - [Req#181] Calling back into ourselves for photo to transcode, optimizing the process (status: -1)
Oct 22, 2024 09:45:00.290 [12604] DEBUG - [Req#17f/Req#187] It took 140.625000 ms to retrieve 109 items.
Oct 22, 2024 09:45:00.291 [2076] DEBUG - Completed: [172.20.1.247:54588] 200 GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F507721%2Fthumb%2F1727945500%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (14 live) #183 TLS GZIP 39ms 25678 bytes (pipelined: 1)
Oct 22, 2024 09:45:00.292 [12604] DEBUG - [Req#17f/Req#187] Calculated media file path for path [metadata://posters/tv.plex.agents.series_fcdf309b351fdd46e2760adb44d5fbf908535f58]: ["C:\Users\Dragon\AppData\Local\Plex Media Server\Metadata\TV Shows\7\6fab087e459df27dd4ec5ebbe2e336f3af79473.bundle\Contents\_combined\posters\tv.plex.agents.series_fcdf309b351fdd46e2760adb44d5fbf908535f58"]
Oct 22, 2024 09:45:00.293 [12604] DEBUG - [Req#17f] Calling back into ourselves for photo to transcode, optimizing the process (status: -1)
Oct 22, 2024 09:45:00.300 [12904] DEBUG - [Req#17e] Calling back into ourselves for photo to transcode, optimizing the process (status: -1)
Oct 22, 2024 09:45:00.318 [5528] DEBUG - Request: [172.20.1.247:54592 (Allowed Network (Subnet))] GET /hubs/home/recentlyAdded?type=2&sectionID=4&contentDirectoryID=4&pinnedContentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1 (15 live) #184 TLS Page 12-35 GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:45:00.322 [5528] WARN - [Req#184] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 22, 2024 09:45:00.323 [5528] WARN - [Req#184] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 22, 2024 09:45:00.323 [5528] WARN - [Req#184] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 22, 2024 09:45:00.324 [2728] DEBUG - Request: [172.20.1.247:54593 (Allowed Network (Subnet))] GET /hubs/home/recentlyAdded?type=2&sectionID=2&contentDirectoryID=2&pinnedContentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1 (16 live) #18d TLS Page 12-35 GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:45:00.326 [12344] DEBUG - [Req#180] Photo cache obtained 392829 bytes from /library/metadata/592709/thumb/1729552183?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 22, 2024 09:45:00.326 [12344] DEBUG - [Req#180] Saving original media file to C:\Users\Dragon\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\77\77660e295b838db844a845b33ec71eefb46b474d.jpg
Oct 22, 2024 09:45:00.327 [2728] WARN - [Req#18d] QueryParser: Invalid field 'sectionID' found, ignoring.
Oct 22, 2024 09:45:00.327 [2728] WARN - [Req#18d] QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Oct 22, 2024 09:45:00.327 [2728] WARN - [Req#18d] QueryParser: Invalid field 'pinnedContentDirectoryID' found, ignoring.
Oct 22, 2024 09:45:00.346 [3980] DEBUG - [Req#181] Photo cache obtained 338213 bytes from /library/metadata/577041/thumb/1729551569?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 22, 2024 09:45:00.346 [3980] DEBUG - [Req#181] Saving original media file to C:\Users\Dragon\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\60\609051383b19907605d47c279e60bbf1f056390d.jpg
Oct 22, 2024 09:45:00.350 [12604] DEBUG - [Req#17f] Photo cache obtained 403863 bytes from /library/metadata/544211/thumb/1729551562?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 22, 2024 09:45:00.350 [12604] DEBUG - [Req#17f] Saving original media file to C:\Users\Dragon\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\f3\f3632a14f8c42456695db776551fe9c855b8f22b.jpg
Oct 22, 2024 09:45:00.382 [12904] DEBUG - [Req#17e] Photo cache obtained 614384 bytes from /library/metadata/588697/thumb/1728106419?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 22, 2024 09:45:00.382 [12904] DEBUG - [Req#17e] Saving original media file to C:\Users\Dragon\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\3b\3b8a93eed6140088e79cd03d4503e78b0d8480b6.jpg
Oct 22, 2024 09:45:00.459 [3980] DEBUG - [Req#181] Created thumbnail of size 240x360, has pixels: 1
Oct 22, 2024 09:45:00.477 [2076] DEBUG - Completed: [172.20.1.247:54589] 200 GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F577041%2Fthumb%2F1729551569%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (16 live) #181 TLS GZIP 241ms 24142 bytes (pipelined: 1)
Oct 22, 2024 09:45:00.488 [12604] DEBUG - [Req#17f] Created thumbnail of size 240x360, has pixels: 1
Oct 22, 2024 09:45:00.501 [11480] DEBUG - Completed: [172.20.1.247:54586] 200 GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F544211%2Fthumb%2F1729551562%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (16 live) #17f TLS GZIP 239ms 19241 bytes (pipelined: 1)
Oct 22, 2024 09:45:00.511 [12344] DEBUG - [Req#180] Created thumbnail of size 240x360, has pixels: 1
Oct 22, 2024 09:45:00.523 [2076] DEBUG - Completed: [172.20.1.247:54587] 200 GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F592709%2Fthumb%2F1729552183%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (16 live) #180 TLS GZIP 289ms 23011 bytes (pipelined: 1)
Oct 22, 2024 09:45:00.551 [12904] DEBUG - [Req#17e] Created thumbnail of size 240x360, has pixels: 1
Oct 22, 2024 09:45:00.565 [11480] DEBUG - Completed: [172.20.1.247:54585] 200 GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F588697%2Fthumb%2F1728106419%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (16 live) #17e TLS GZIP 341ms 26170 bytes (pipelined: 1)
Oct 22, 2024 09:45:00.947 [4852] WARN - [Req#157] SLOW QUERY: It took 265.625000 ms to retrieve 24 items.
Oct 22, 2024 09:45:00.970 [2076] DEBUG - Completed: [172.20.1.247:54574] 200 GET /library/sections/1/all?sort=addedAt:desc&contentDirectoryID=1&pinnedContentDirectoryID=4%2C2%2C1%2C8%2C6%2Cplaylists&includeMeta=1 (16 live) #157 TLS GZIP Page 12-35 1108ms 14276 bytes (pipelined: 1)
Oct 22, 2024 09:45:00.994 [4852] DEBUG - Request: [172.20.1.247:54585 (Allowed Network (Subnet))] GET /photo/:/transcode?width=240&height=360&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F431014%2Fthumb%2F1720939474%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (16 live) #192 TLS GZIP Signed-in Token (silverdragon6687) (Chrome)
Oct 22, 2024 09:45:00.994 [4852] DEBUG - [Req#192] Photo transcoder: Request for url [/library/metadata/431014/thumb/1720939474?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (is local: 1 upscaled: 1)
Oct 22, 2024 09:45:00.996 [11456] DEBUG - [Req#17a] It took 878

PlexServ_diskmark
PlexServ_diskmark480Ă—343 49.5 KB

7

Please provide the entirety of the PMS logs not just a snippet. Using the Download Logs action will create a zip that you should be able to attach in your comment.

1 Like
8

Plex Media Server Logs_2024-10-22_13-53-32.zip (5.6 MB)
Done. This is with Debug enabled, no verbos.

1 Like
9

you wouldn’t happen to have any updates would ya? I am experiencing the same. sonarry was out of date.

10

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.