Server Version#: 1.29.x - 1.30.2.6563
Player Version#: 4.100.1 Web client, AppleTV, Windows Desktop Client
Ubuntu 20.04 with plexinc/pms-docker container.
I’ve been fighting with this issue for a few weeks now, including deleting the entire install and scanning from scratch.
For instance, pressing “View XML” for Dune 2021 (4K DV) tries to open https://plex_url/library/metadata/4561?checkFiles=1&includeAllConcerts=1&includeBandwidths=1&includeChapters=1&includeChildren=1&includeConcerts=1&includeExtras=1&includeFields=1&includeGeolocation=1&includeLoudnessRamps=1&includeMarkers=1&includeOnDeck=1&includePopularLeaves=1&includePreferences=1&includeRelated=1&includeRelatedCount=1&includeReviews=1&includeStations=1&X-Plex-Token=plex_token
This spins forever and Plex eventually goes unresponsive. If I change includeRelated=1 to includeRelated=0 the XML loads instantly.
I’ve tried nearly everything. Deleting the library and rescanning everything. Deleting the entire Plex instance and rescanning everything. Starting from 1.29.1 and nearly every version between that and the latest public 1.30.2.6563
Generally on a fresh setup these items will work however after about a week things start breaking again.
Refresh Metadata & Analyze will fix this for certain items but not always. Currently the 4K version of Dune is broken regardless.
This also stops playback on most clients and when a friend attempts to play these items the entire server goes unresponsive. Sometimes the playback will continue for this item but the server will be completely unresponsive for everyone else. Logs are also nearly nonexistent during this.
Log Snippet, it’s not much help. You can see the request for the XML and no response. The page will load endlessly until autoheal restarts the Plex container for being unresponsive. (Which is generally over a minute)
4.830 [0x7fe313eaab38] DEBUG - Using X-Forwarded-For: myip as remote address
Feb 12, 2023 12:33:34.830 [0x7fe3133c2b38] DEBUG - Request: [172.18.0.1:41300 (WAN)] GET /library/metadata/4561?includeExternalMedia=1&includePreferences=1&includeExtras=1&includeChapters=1&checkFiles=1&asyncCheckFiles=0 (9 live) #3a62 GZIP Signed-in Token (Username) (Firefox)
Feb 12, 2023 12:33:34.836 [0x7fe3133c2b38] DEBUG - [Req#3a62] It took 10.000000 ms to retrieve 368 items.
Feb 12, 2023 12:33:34.842 [0x7fe3133c2b38] DEBUG - [Req#3a62] It took 10.000000 ms to retrieve 368 items.
Feb 12, 2023 12:33:34.844 [0x7fe3133c2b38] DEBUG - [Req#3a62] We're going to try to auto-select an audio stream for account 1.
Feb 12, 2023 12:33:34.844 [0x7fe3133c2b38] DEBUG - [Req#3a62] Selecting best audio stream for part ID 11190 (autoselect: 1 language: en)
Feb 12, 2023 12:33:34.844 [0x7fe3133c2b38] DEBUG - [Req#3a62] Audio Stream: 38564, Subtitle Stream: -1
Feb 12, 2023 12:33:34.868 [0x7fe313eaab38] DEBUG - Completed: [172.18.0.1:41300] 200 GET /library/metadata/4561?includeExternalMedia=1&includePreferences=1&includeExtras=1&includeChapters=1&checkFiles=1&asyncCheckFiles=0 (9 live) GZIP 37ms 8355 bytes (pipelined: 2)
Feb 12, 2023 12:33:35.293 [0x7fe3140adb38] DEBUG - Using X-Forwarded-For: myip as remote address
Feb 12, 2023 12:33:35.293 [0x7fe30e31fb38] DEBUG - Request: [172.18.0.1:41300 (WAN)] GET /statistics/bandwidth?timespan=6 (9 live) #3a69 GZIP Signed-in Token (Username) (Firefox)
Feb 12, 2023 12:33:35.294 [0x7fe3140adb38] DEBUG - Completed: [172.18.0.1:41300] 200 GET /statistics/bandwidth?timespan=6 (9 live) GZIP 1ms 1918 bytes (pipelined: 3)
Feb 12, 2023 12:33:35.586 [0x7fe3140adb38] DEBUG - Using X-Forwarded-For: 99.58.205.196 as remote address
Feb 12, 2023 12:33:35.586 [0x7fe3140adb38] DEBUG - Auth: authenticating user as guest
Feb 12, 2023 12:33:35.586 [0x7fe3140adb38] DEBUG - Request: [172.18.0.1:41320 (WAN)] GET /:/websockets/notifications (10 live) #3a67 GZIP Signed-in Token ()
Feb 12, 2023 12:33:35.586 [0x7fe3140adb38] DEBUG - Completed: [172.18.0.1:41320] 401 GET /:/websockets/notifications (10 live) GZIP 0ms 357 bytes
Feb 12, 2023 12:33:36.633 [0x7fe3140adb38] DEBUG - Using X-Forwarded-For: myip as remote address
Feb 12, 2023 12:33:36.633 [0x7fe3133c2b38] DEBUG - Request: [172.18.0.1:41374 (WAN)] GET /library/metadata/4561?checkFiles=1&includeAllConcerts=1&includeBandwidths=1&includeChapters=1&includeChildren=1&includeConcerts=1&includeExtras=1&includeFields=1&includeGeolocation=1&includeLoudnessRamps=1&includeMarkers=1&includeOnDeck=1&includePopularLeaves=1&includePreferences=1&includeRelated=1&includeRelatedCount=1&includeReviews=1&includeStations=1 (10 live) #3a6b GZIP Signed-in Token (Username) (Firefox)
Feb 12, 2023 12:33:36.639 [0x7fe3133c2b38] DEBUG - [Req#3a6b] It took 10.000000 ms to retrieve 368 items.
Feb 12, 2023 12:33:36.645 [0x7fe3133c2b38] DEBUG - [Req#3a6b] It took 0.000000 ms to retrieve 368 items.
Feb 12, 2023 12:33:36.647 [0x7fe3133c2b38] DEBUG - [Req#3a6b] We're going to try to auto-select an audio stream for account 1.
Feb 12, 2023 12:33:36.647 [0x7fe3133c2b38] DEBUG - [Req#3a6b] Selecting best audio stream for part ID 11190 (autoselect: 1 language: en)
Feb 12, 2023 12:33:36.647 [0x7fe3133c2b38] DEBUG - [Req#3a6b] Audio Stream: 38564, Subtitle Stream: -1
Feb 12, 2023 12:33:36.678 [0x7fe3133c2b38] DEBUG - [Req#3a6b] It took 10.000000 ms to retrieve 368 items.
Feb 12, 2023 12:33:37.119 [0x7fe3140adb38] DEBUG - Using X-Forwarded-For: myip as remote address
Feb 12, 2023 12:33:37.119 [0x7fe3140adb38] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
Feb 12, 2023 12:33:37.119 [0x7fe3140adb38] DEBUG - [HCl#1b2] HTTP requesting GET https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx&unknownToken=xxxxxxxxxxxxxxxxxxxx
Feb 12, 2023 12:33:37.296 [0x7fe312653b38] DEBUG - [HttpClient/HCl#1b2] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx&unknownToken=xxxxxxxxxxxxxxxxxxxx (reused)
Feb 12, 2023 12:33:37.297 [0x7fe3140adb38] DEBUG - MyPlex: updating with 11 access tokens
Feb 12, 2023 12:33:37.297 [0x7fe3140adb38] DEBUG - [HCl#1b3] HTTP requesting GET https://plex.tv/api/v2/server/users?auth_token=xxxxxxxxxxxxxxxxxxxx
Feb 12, 2023 12:33:37.297 [0x7fe30e928b38] DEBUG - [MediaProviderManager/HCl#1b4] HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Feb 12, 2023 12:33:37.431 [0x7fe313eaab38] DEBUG - Using X-Forwarded-For: myip as remote address
Feb 12, 2023 12:33:37.431 [0x7fe30e31fb38] DEBUG - Request: [172.18.0.1:41378 (WAN)] GET /statistics/bandwidth?timespan=6 (12 live) #3a6e GZIP Signed-in Token (Username) (Firefox)
Feb 12, 2023 12:33:37.432 [0x7fe313eaab38] DEBUG - Completed: [172.18.0.1:41378] 200 GET /statistics/bandwidth?timespan=6 (12 live) GZIP 1ms 1925 bytes (pipelined: 1)
Feb 12, 2023 12:33:37.453 [0x7fe312653b38] DEBUG - [HttpClient/HCl#1b4] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (reused)
Feb 12, 2023 12:33:37.454 [0x7fe30e928b38] DEBUG - [MediaProviderManager/HCl#1b5] HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Feb 12, 2023 12:33:37.458 [0x7fe312653b38] DEBUG - [HttpClient/HCl#1b3] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/api/v2/server/users?auth_token=xxxxxxxxxxxxxxxxxxxx (reused)
Feb 12, 2023 12:33:37.459 [0x7fe3113e1b38] DEBUG - [HCl#1b6] HTTP requesting GET https://plex.tv/api/v2/server/users/subscriptions?auth_token=xxxxxxxxxxxxxxxxxxxx
Feb 12, 2023 12:33:37.465 [0x7fe313eaab38] DEBUG - Using X-Forwarded-For: myip as remote address
Feb 12, 2023 12:33:37.465 [0x7fe30e31fb38] DEBUG - Request: [172.18.0.1:41390 (WAN)] GET /statistics/resources?timespan=6 (13 live) #3a6f GZIP Signed-in Token (Username) (Firefox)
Feb 12, 2023 12:33:37.466 [0x7fe313eaab38] DEBUG - Completed: [172.18.0.1:41390] 200 GET /statistics/resources?timespan=6 (13 live) GZIP 0ms 952 bytes (pipelined: 1)
Feb 12, 2023 12:33:37.612 [0x7fe312653b38] DEBUG - [HttpClient/HCl#1b5] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (reused)
Feb 12, 2023 12:33:37.612 [0x7fe30e928b38] DEBUG - [MediaProviderManager] discovered cloud provider (Metadata)
Feb 12, 2023 12:33:37.612 [0x7fe30e928b38] DEBUG - [MediaProviderManager] loading cloud provider details (Metadata) (alive: 1)
Feb 12, 2023 12:33:37.612 [0x7fe30e928b38] DEBUG - [MediaProviderManager] we had 1 cloud providers online, we now have 1
Feb 12, 2023 12:33:37.612 [0x7fe30e928b38] DEBUG - [MediaProviderManager] cloud provider (Metadata) is online and available
Feb 12, 2023 12:33:37.620 [0x7fe312653b38] DEBUG - [HttpClient/HCl#1b6] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/api/v2/server/users/subscriptions?auth_token=xxxxxxxxxxxxxxxxxxxx (reused)
Feb 12, 2023 12:33:37.620 [0x7fe3113e1b38] DEBUG - MyPlex: no cached data to load for request for https://plex.tv/api/v2/server/users/services?auth_token=xxxxxxxxxxxxxxxxxxxx
Feb 12, 2023 12:33:37.620 [0x7fe3140adb38] DEBUG - Auth: authenticating user as guest
Feb 12, 2023 12:33:37.620 [0x7fe3140adb38] DEBUG - Request: [172.18.0.1:41376 (WAN)] GET /media/providers (12 live) #3a6d GZIP Signed-in Token ()
Feb 12, 2023 12:33:37.621 [0x7fe3140adb38] DEBUG - Completed: [172.18.0.1:41376] 401 GET /media/providers (12 live) GZIP 0ms 357 bytes
