Took a gamble to see if I could spot any differences between a successful client play (via android) and a faulty play (via Windows). I also happened to turn on Verbose logging in case anything happened to show up and have since turned it off. I am unsure if this is normal behavior, but a rather blatant difference appears to be in Part ID enumeration of the stream. For instance from the Window’s client (snipped to save space):
Dec 04, 2022 10:49:24.876 [0x7fa7eeb70b38] DEBUG - Completed: [192.168.1.240:61733] 200 GET /status/sessions (6 live) TLS GZIP 1ms 2250 bytes (pipelined: 1)
Dec 04, 2022 10:49:24.903 [0x7fa7e9b5bb38] DEBUG - [Req#f43d] PlayQueue: Client tfc2we7knojd1m6xya6xm7aa requested ownership of play queue 3785, but already had it.
Dec 04, 2022 10:49:24.905 [0x7fa7e9b5bb38] DEBUG - We’re going to try to auto-select an audio stream for account 24511356.
Dec 04, 2022 10:49:24.905 [0x7fa7e9b5bb38] DEBUG - Selecting best audio stream for part ID 8061 (autoselect: 1 language: en)
…
Dec 04, 2022 10:49:24.907 [0x7fa7e9b5bb38] DEBUG - Selecting best audio stream for part ID 8062 (autoselect: 1 language: en)
…
Dec 04, 2022 10:49:24.909 [0x7fa7e9b5bb38] DEBUG - Selecting best audio stream for part ID 8063 (autoselect: 1 language: en)
…
Dec 04, 2022 10:49:24.911 [0x7fa7e9b5bb38] DEBUG - Selecting best audio stream for part ID 8064 (autoselect: 1 language: en)
…
Dec 04, 2022 10:49:24.929 [0x7fa7e9b5bb38] DEBUG - Selecting best audio stream for part ID 8073 (autoselect: 1 language: en)
Dec 04, 2022 10:49:24.929 [0x7fa7e9b5bb38] DEBUG - We’re going to try to auto-select a subtitle.
Dec 04, 2022 10:49:24.929 [0x7fa7e9b5bb38] DEBUG - Subtitles: Found a candidate subtitle language [en] for a foreign film
Dec 04, 2022 10:49:24.929 [0x7fa7e9b5bb38] DEBUG - Audio Stream: 21619, Subtitle Stream: 21621
But when compared to a successful run of a client on the local network (the android client–snipped as well):
Dec 04, 2022 10:53:03.136 [0x7fa7ebde6b38] DEBUG - [Req#f6d8] We’re going to try to auto-select an audio stream for account 1.
Dec 04, 2022 10:53:03.136 [0x7fa7ebde6b38] DEBUG - [Req#f6d8] Selecting best audio stream for part ID 271 (autoselect: 0 language: en)
Dec 04, 2022 10:53:03.136 [0x7fa7ebde6b38] DEBUG - [Req#f6d8] Audio Stream: 20681, Subtitle Stream: -1
…
Dec 04, 2022 10:53:03.334 [0x7fa7e9b5bb38] DEBUG - [Req#f6f1] Selecting best audio stream for part ID 271 (autoselect: 0 language: en)
…
Dec 04, 2022 10:53:03.384 [0x7fa7ebde6b38] DEBUG - [Req#f5d1] Selecting best audio stream for part ID 271 (autoselect: 0 language: en)
…
Dec 04, 2022 10:53:05.540 [0x7fa7ebde6b38] DEBUG - Selecting best audio stream for part ID 271 (autoselect: 0 language: en)
Dec 04, 2022 10:53:05.540 [0x7fa7ebde6b38] DEBUG - Audio Stream: 20681, Subtitle Stream: -1
It reads to my layman’s eyes that the windows client is trying to start 12 streams simultaneously while the android client is just starting and updating one stream. Perhaps that’s not what’s happening and this is intended behavior?
Reviewing the client logs at the same time I see the following error:
Dec 04, 2022 10:49:23.495 [18820] ERROR - [Web] WebSocket connection to ‘wss://–REDACTED–.4db739e416524e7581a5b3e78c937e54.plex.direct:32400/:/websockets/notifications?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx’ failed: WebSocket is closed before the connection is established.
There also seems to be errors with using [Loopback], but the servers are still found…
Dec 04, 2022 10:49:39.504 [18820] INFO - [Web] [Connections] Testing legacy connection for [Loopback] at http://127.0.0.1:32400
Dec 04, 2022 10:49:41.539 [18820] ERROR - [Web] [Connections] [Loopback] is unavailable at http://127.0.0.1:32400/media/providers (Status 0)
Dec 04, 2022 10:49:41.539 [18820] ERROR - [Web] [Connections] [Loopback] is unavailable at http://127.0.0.1:32400/media/providers (Status 0)
Dec 04, 2022 10:49:41.542 [18820] ERROR - [Web] [Connections] All connections to [Loopback] failed
Dec 04, 2022 10:49:41.543 [18820] INFO - [Web] [Servers] Found all servers = Balthasar, plex.tv
Dec 04, 2022 10:49:46.260 [18820] ERROR - [Web] An entity does not exist with the type “servers” and id “undefined”
These seem much more promising to isolating the source of the error/troubleshooting. Any ideas?