Media does not start playing. No idea why

Plex Media Server Desktops & Laptops
, , ,
1

Server Version#: 1.19.1.2645-ccb6eb67e
Player Version#: 7.30.2.16712

I have trying to configure Plex. I have tried with default configuration, then also with modifications like disabling transcoding etc. I have made sure that Win 10 firewall permissions are correctly set up but for some reason, whether I try the android app or the Amazon Plex app on my tv, I can’t get it to play anything. It detects everything, downloads the thumbnails and cast details etc but after clicking play, it looks like it keeps buffering. No error. After looking at logs, the only thing I notice is funny is that there is this line “Content-Length is -1 (of total: -1).” that stands out for me. However the same line is not there when you load the media in the plex media player, this line appears after you click play. Also VLC for example will play these media files just fine when using a flash drive but even with VLC’s network option, when I try to go via Plex, it does the same thing. No idea why this happens. Any pointers would be very helpful. Thank you

2

For AndroidTV, there is an issue with Refresh Rate Switching and Resolution Switching that affects video playback. See the description in the articles linked below. It is a known issue and will be fixed in a future update.

If you are experiencing the same problem, as a workaround, in the Plex app settings, disable both Refresh Rate Switching and Resolution Switching.

Description and additional details:

3

thank you for the reply. but mod edited this Q and put Android TV tag in there which I am not using. I was using Plex media player that is on Amazon app store and was using the Fire TV Stick 4K but then just to confirm the issue, installed a plex media player on my android phone which S9.

4

FYI, Amazon FireTV devices run AndroidTV, albeit a highly customized version.

Plex creates separate AndroidTV app builds and publishes them in the Amazon store specifically for FireTV devices.

Amazon takes longer than Google to publish updates, so the app version in the Amazon store generally lags that in the Google store by days to weeks.

You can subscribe to the Android/AndroidTV Announcement thread to be notified when a new version is available.

1 Like
5

Thank you, I wasn’t aware of this.

Sorry but I couldn’t find options for disabling this. I just tested this on my S9 Galaxy plex player or are these options only for the Amazon app?

6

AndroidTV devices. Not in mobile devices.

It is in Plex app settings, Advanced section (scroll to bottom).

7

That means that if a transcode is needed, it won’t happen, so the file won’t play. Do not turn this off if you are testing things.

To identify the problem, you’ll need to recreate the issue then provide the log from the app.

8

I only did this when things weren’t working with the default settings. Basically it didn’t work either way.

Here’s the log when I tried to play Uncut Gems:

Apr 13, 2020 22:34:46.401 [16632] Debug — Completed: [192.168.1.20:3500] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (4 live) TLS GZIP 20001ms 5 bytes (pipelined: 10)
Apr 13, 2020 22:34:46.420 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:34:46.420 [16592] Debug — Request: [192.168.1.20:3500 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (4 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:34:46.420 [16592] Debug — Content-Length is -1 (of total: -1).
Apr 13, 2020 22:34:47.275 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:34:47.275 [16592] Debug — Request: [192.168.1.154:41912 (Subnet)] GET /media/providers?includePreferences=1 (6 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:34:47.277 [1640] Debug — Completed: [192.168.1.154:41912] 200 GET /media/providers?includePreferences=1 (6 live) TLS GZIP 2ms 4020 bytes (pipelined: 1)
Apr 13, 2020 22:34:47.471 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:34:47.471 [16592] Debug — Request: [192.168.1.154:41914 (Subnet)] GET /clients (6 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:34:47.472 [16632] Debug — Completed: [192.168.1.154:41914] 200 GET /clients (6 live) TLS GZIP 0ms 682 bytes (pipelined: 1)
Apr 13, 2020 22:34:49.213 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:34:49.213 [16592] Debug — Request: [192.168.1.154:41978 (Subnet)] GET /:/websockets/notifications (7 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:34:49.213 [16592] Debug — WebSocket: Performing handshake from origin 
Apr 13, 2020 22:34:49.213 [16592] Debug — Beginning read from WebSocket
Apr 13, 2020 22:34:49.226 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:34:49.226 [16592] Debug — Request: [192.168.1.154:41912 (Subnet)] GET /hubs?contentDirectoryID=1%2C3%2C2&count=20&excludeElements=media%2Cvast%2Ctopic&excludeFields=summary&includeRecentChannels=1&includeTypeFirst=1&promoted=1 (7 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:34:49.226 [16592] Debug — HubCache: Retrieving '1/home.continue/1/hubs/en-gb/contentDirectoryID=1%2C3%2C2&count=20&excludeElements=media%2Cvast%2Ctopic&excludeFields=summary&includeRecentChannels=1&includeTypeFirst=1' from the cache.
Apr 13, 2020 22:34:49.226 [16592] Debug — HubCache: 10 hubs cached, 37.5% hit ratio.
Apr 13, 2020 22:34:49.226 [16592] Debug — HubCache: Retrieving '1/home.ondeck/1/hubs/en-gb/contentDirectoryID=1%2C3%2C2&count=20&excludeElements=media%2Cvast%2Ctopic&excludeFields=summary&includeRecentChannels=1&includeTypeFirst=1' from the cache.
Apr 13, 2020 22:34:49.226 [16592] Debug — HubCache: Retrieving '1/home.movies.recent/1/hubs/en-gb/contentDirectoryID=1%2C3%2C2&count=20&excludeElements=media%2Cvast%2Ctopic&excludeFields=summary&includeRecentChannels=1&includeTypeFirst=1' from the cache.
Apr 13, 2020 22:34:49.227 [16592] Debug — HubCache: Retrieving '1/home.television.recent/1/hubs/en-gb/contentDirectoryID=1%2C3%2C2&count=20&excludeElements=media%2Cvast%2Ctopic&excludeFields=summary&includeRecentChannels=1&includeTypeFirst=1' from the cache.
Apr 13, 2020 22:34:49.228 [16592] Debug — HubCache: Retrieving '1/home.videos.recent/1/hubs/en-gb/contentDirectoryID=1%2C3%2C2&count=20&excludeElements=media%2Cvast%2Ctopic&excludeFields=summary&includeRecentChannels=1&includeTypeFirst=1' from the cache.
Apr 13, 2020 22:34:49.228 [16592] Debug — HubCache: Retrieving '1/home.photos.recent/1/hubs/en-gb/contentDirectoryID=1%2C3%2C2&count=20&excludeElements=media%2Cvast%2Ctopic&excludeFields=summary&includeRecentChannels=1&includeTypeFirst=1' from the cache.
Apr 13, 2020 22:34:49.228 [16592] Debug — HubCache: Retrieving '1/home.music.recent/1/hubs/en-gb/contentDirectoryID=1%2C3%2C2&count=20&excludeElements=media%2Cvast%2Ctopic&excludeFields=summary&includeRecentChannels=1&includeTypeFirst=1' from the cache.
Apr 13, 2020 22:34:49.234 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:34:49.234 [16592] Debug — Selecting best audio stream for part ID 122 (autoselect: 0 language: en)
Apr 13, 2020 22:34:49.234 [16592] Debug — Audio Stream: 457, Subtitle Stream: -1
Apr 13, 2020 22:34:49.237 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:34:49.237 [16592] Debug — Selecting best audio stream for part ID 123 (autoselect: 0 language: en)
Apr 13, 2020 22:34:49.237 [16592] Debug — Audio Stream: 461, Subtitle Stream: -1
Apr 13, 2020 22:34:49.239 [16632] Debug — Completed: [192.168.1.154:41912] 200 GET /hubs?contentDirectoryID=1%2C3%2C2&count=20&excludeElements=media%2Cvast%2Ctopic&excludeFields=summary&includeRecentChannels=1&includeTypeFirst=1&promoted=1 (7 live) TLS GZIP 13ms 4786 bytes (pipelined: 2)
Apr 13, 2020 22:34:49.725 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:34:49.725 [16592] Debug — Request: [192.168.1.154:41976 (Subnet)] GET /:/websockets/notifications (7 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:34:49.725 [16592] Debug — WebSocket: Performing handshake from origin 
Apr 13, 2020 22:34:49.725 [16592] Debug — Beginning read from WebSocket
Apr 13, 2020 22:35:06.421 [16632] Debug — Completed: [192.168.1.20:3500] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (7 live) TLS GZIP 20000ms 5 bytes (pipelined: 11)
Apr 13, 2020 22:35:06.438 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:06.438 [16592] Debug — Request: [192.168.1.20:3500 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (7 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:06.438 [16592] Debug — Content-Length is -1 (of total: -1).
Apr 13, 2020 22:35:23.942 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:23.942 [16592] Debug — Request: [192.168.1.154:42046 (Subnet)] GET /library/metadata/9?asyncAugmentMetadata=1&checkFiles=1&includeExternalMetadata=1&includeExtras=1&includeRelated=1&includeRelatedCount=0&includeReviews=1 (7 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:23.948 [16592] Debug — It took 0.000000 ms to retrieve 139 items.
Apr 13, 2020 22:35:23.951 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:35:23.951 [16592] Debug — Selecting best audio stream for part ID 9 (autoselect: 0 language: en)
Apr 13, 2020 22:35:23.951 [16592] Debug — Audio Stream: 208, Subtitle Stream: -1
Apr 13, 2020 22:35:23.963 [16592] Debug — Activity: registered new activity dc372802-6849-4ac4-a646-418a402cdb11 - Refreshing
Apr 13, 2020 22:35:23.964 [1980] Debug — Activity: updated activity dc372802-6849-4ac4-a646-418a402cdb11 - completed 0.0% - Refreshing
Apr 13, 2020 22:35:23.965 [16632] Debug — Completed: [192.168.1.154:42046] 200 GET /library/metadata/9?asyncAugmentMetadata=1&checkFiles=1&includeExternalMetadata=1&includeExtras=1&includeRelated=1&includeRelatedCount=0&includeReviews=1 (7 live) TLS GZIP 22ms 8133 bytes (pipelined: 1)
Apr 13, 2020 22:35:24.302 [19556] Debug — Augment: Found a provider match for 'Uncut.Gems.2019.1080p.WEBRip.x264-RARBG'.
Apr 13, 2020 22:35:24.302 [19556] Debug — Augment: Completed movie augmentation in 0.3 sec.
Apr 13, 2020 22:35:24.302 [1980] Debug — Activity: Ended activity dc372802-6849-4ac4-a646-418a402cdb11.
Apr 13, 2020 22:35:25.868 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:25.868 [16592] Debug — Request: [192.168.1.154:42046 (Subnet)] GET /library/sections (7 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:25.871 [1640] Debug — Completed: [192.168.1.154:42046] 200 GET /library/sections (7 live) TLS GZIP 2ms 992 bytes (pipelined: 2)
Apr 13, 2020 22:35:26.010 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:26.010 [16592] Debug — Request: [192.168.1.154:42046 (Subnet)] GET /library/metadata/augmentations/4?wait=1 (7 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:26.011 [1640] Debug — Completed: [192.168.1.154:42046] 200 GET /library/metadata/augmentations/4?wait=1 (7 live) TLS GZIP 1ms 1608 bytes (pipelined: 3)
Apr 13, 2020 22:35:26.240 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:26.240 [16592] Debug — Request: [192.168.1.154:42048 (Subnet)] GET /library/metadata/9/similar (9 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:26.245 [16592] Debug — It took 0.000000 ms to retrieve 139 items.
Apr 13, 2020 22:35:26.253 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:35:26.253 [16592] Debug — Selecting best audio stream for part ID 5 (autoselect: 0 language: en)
Apr 13, 2020 22:35:26.253 [16592] Debug — Audio Stream: 146, Subtitle Stream: -1
Apr 13, 2020 22:35:26.254 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:35:26.254 [16592] Debug — Selecting best audio stream for part ID 7 (autoselect: 0 language: en)
Apr 13, 2020 22:35:26.254 [16592] Debug — Audio Stream: 204, Subtitle Stream: -1
Apr 13, 2020 22:35:26.255 [16632] Debug — Completed: [192.168.1.154:42048] 200 GET /library/metadata/9/similar (9 live) TLS GZIP 15ms 6143 bytes (pipelined: 1)
Apr 13, 2020 22:35:26.438 [1640] Debug — Completed: [192.168.1.20:3500] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (9 live) TLS GZIP 19999ms 5 bytes (pipelined: 12)
Apr 13, 2020 22:35:26.453 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:26.453 [16592] Debug — Request: [192.168.1.20:3500 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (9 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:26.453 [16592] Debug — Content-Length is -1 (of total: -1).
Apr 13, 2020 22:35:26.765 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:26.765 [16592] Debug — Request: [192.168.1.154:42066 (Subnet)] GET /photo/:/transcode?width=1440&url=http%3A%2F%2F127.0.0.1%3A32400%2Flibrary%2Fmetadata%2F9%2Fart%2F1586799814&height=1440 (9 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:26.765 [16592] Debug — Photo transcoder: Request for url [http://127.0.0.1:32400/library/metadata/9/art/1586799814] (is local: 1 upscaled: 0)
Apr 13, 2020 22:35:26.767 [16592] Debug — Content-Length of C:\Users\Voldemort\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\6a\6ac2664aa9b4a537f2b81fa0cdd95ae08bc256be.jpg is 214616 (of total: 214616).
Apr 13, 2020 22:35:32.746 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:32.747 [16592] Debug — Request: [192.168.1.154:42046 (Subnet)] GET /library/metadata/9?includeChapters=1&includeLoudnessRamps=1&includeRelated=1 (9 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:32.756 [16592] Debug — It took 0.000000 ms to retrieve 139 items.
Apr 13, 2020 22:35:32.757 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:35:32.757 [16592] Debug — Selecting best audio stream for part ID 9 (autoselect: 0 language: en)
Apr 13, 2020 22:35:32.757 [16592] Debug — Audio Stream: 208, Subtitle Stream: -1
Apr 13, 2020 22:35:32.769 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:35:32.769 [16592] Debug — Selecting best audio stream for part ID 5 (autoselect: 0 language: en)
Apr 13, 2020 22:35:32.769 [16592] Debug — Audio Stream: 146, Subtitle Stream: -1
Apr 13, 2020 22:35:32.769 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:35:32.769 [16592] Debug — Selecting best audio stream for part ID 7 (autoselect: 0 language: en)
Apr 13, 2020 22:35:32.769 [16592] Debug — Audio Stream: 204, Subtitle Stream: -1
Apr 13, 2020 22:35:32.771 [16632] Debug — Completed: [192.168.1.154:42046] 200 GET /library/metadata/9?includeChapters=1&includeLoudnessRamps=1&includeRelated=1 (9 live) TLS GZIP 24ms 10026 bytes (pipelined: 4)
Apr 13, 2020 22:35:33.049 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:33.049 [16592] Debug — Request: [192.168.1.154:42048 (Subnet)] GET /video/:/transcode/universal/decision?audioBoost=100&autoAdjustQuality=0&directPlay=1&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=lan&maxVideoBitrate=200000&mediaBufferSize=74944&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F9&protocol=*&session=80880c4130cd60ca-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (9 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:33.049 [16592] Debug — Found session GUID of 80880c4130cd60ca-com-plexapp-android in session start.
Apr 13, 2020 22:35:33.060 [16592] Debug — TranscodeUniversalRequest: using augmented profile Android
Apr 13, 2020 22:35:33.061 [16592] Debug — Downloading document http://127.0.0.1:32400/library/metadata/9?includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=80880c4130cd60ca-com-plexapp-android
Apr 13, 2020 22:35:33.063 [16592] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:33.079 [16592] Debug — It took 15.625000 ms to retrieve 139 items.
Apr 13, 2020 22:35:33.082 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:35:33.082 [16592] Debug — Selecting best audio stream for part ID 9 (autoselect: 0 language: en)
Apr 13, 2020 22:35:33.082 [16592] Debug — Audio Stream: 208, Subtitle Stream: -1
Apr 13, 2020 22:35:33.088 [16592] Debug — Streaming Resource: Reached Decision id=9 codes=(MDE=1000,Direct play OK.) media=(id=9 part=(id=9 decision=direct play protocol=* streams=(Video=(id=207 decision= width=1920 height=804) Audio=(id=208 decision= channels=0 rate=0))))
Apr 13, 2020 22:35:33.090 [16632] Debug — Completed: [192.168.1.154:42048] 200 GET /video/:/transcode/universal/decision?audioBoost=100&autoAdjustQuality=0&directPlay=1&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=lan&maxVideoBitrate=200000&mediaBufferSize=74944&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F9&protocol=*&session=80880c4130cd60ca-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (9 live) TLS GZIP 41ms 4964 bytes (pipelined: 2)
Apr 13, 2020 22:35:37.347 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:37.347 [16592] Debug — Request: [192.168.1.154:42072 (Subnet)] GET /photo/:/transcode?width=1440&url=http%3A%2F%2F127.0.0.1%3A32400%2Flibrary%2Fmetadata%2F9%2Fart%2F1586799814&height=1440 (10 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:37.347 [16592] Debug — Photo transcoder: Request for url [http://127.0.0.1:32400/library/metadata/9/art/1586799814] (is local: 1 upscaled: 0)
Apr 13, 2020 22:35:37.350 [16592] Debug — Content-Length of C:\Users\Voldemort\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\6a\6ac2664aa9b4a537f2b81fa0cdd95ae08bc256be.jpg is 214616 (of total: 214616).
Apr 13, 2020 22:35:42.369 [1640] Debug — Failed to stream media, client probably disconnected after 131072 bytes: 10054 - An existing connection was forcibly closed by the remote host
Apr 13, 2020 22:35:42.369 [1640] Debug — Completed after connection close: [192.168.1.154:42066] 200 GET /photo/:/transcode?width=1440&url=http%3A%2F%2F127.0.0.1%3A32400%2Flibrary%2Fmetadata%2F9%2Fart%2F1586799814&height=1440 (10 live) TLS GZIP 15603ms 131072 bytes (pipelined: 1)
Apr 13, 2020 22:35:46.453 [16632] Debug — Completed: [192.168.1.20:3500] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (9 live) TLS GZIP 19999ms 5 bytes (pipelined: 13)
Apr 13, 2020 22:35:46.460 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:35:46.460 [16592] Debug — Request: [192.168.1.20:3500 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (9 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:35:46.460 [16592] Debug — Content-Length is -1 (of total: -1).
Apr 13, 2020 22:36:03.607 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:36:03.607 [16592] Debug — Request: [192.168.1.154:42074 (Subnet)] GET /library/parts/9/1580506077/file.mp4?autoAdjustQuality=0&hasMDE=1&location=lan&mediaBufferSize=74944 (9 live) TLS Signed-in Token (XXXXXXXXXXX@outlook.com) (range: bytes=0-) 
Apr 13, 2020 22:36:03.613 [16592] Debug — Content-Length of E:\Movies\Uncut.Gems.2019.1080p.WEBRip.x264-RARBG\Uncut.Gems.2019.1080p.WEBRip.x264-RARBG.mp4 is 2779415327 (of total: 2779415327).
Apr 13, 2020 22:36:06.461 [16632] Debug — Completed: [192.168.1.20:3500] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (8 live) TLS GZIP 20001ms 5 bytes (pipelined: 14)
Apr 13, 2020 22:36:06.498 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:36:06.498 [16592] Debug — Request: [192.168.1.20:3500 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (8 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:36:06.499 [16592] Debug — Content-Length is -1 (of total: -1).
Apr 13, 2020 22:36:11.070 [1640] Debug — Failed to stream media, client probably disconnected after 212992 bytes: 10054 - An existing connection was forcibly closed by the remote host
Apr 13, 2020 22:36:11.070 [1640] Debug — Completed after connection close: [192.168.1.154:42072] 200 GET /photo/:/transcode?width=1440&url=http%3A%2F%2F127.0.0.1%3A32400%2Flibrary%2Fmetadata%2F9%2Fart%2F1586799814&height=1440 (8 live) TLS GZIP 33723ms 212992 bytes (pipelined: 1)
Apr 13, 2020 22:36:11.972 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:36:11.973 [16592] Debug — Request: [192.168.1.154:42076 (Subnet)] GET /library/parts/9/1580506077/file.mp4?autoAdjustQuality=0&hasMDE=1&location=lan&mediaBufferSize=74944 (8 live) TLS Signed-in Token (XXXXXXXXXXX@outlook.com) (range: bytes=2773976123-) 
Apr 13, 2020 22:36:11.983 [16592] Debug — Content-Length of E:\Movies\Uncut.Gems.2019.1080p.WEBRip.x264-RARBG\Uncut.Gems.2019.1080p.WEBRip.x264-RARBG.mp4 is 5439204 (of total: 2779415327).
Apr 13, 2020 22:36:12.000 [1640] Debug — Failed to stream media, client probably disconnected after 262144 bytes: 10054 - An existing connection was forcibly closed by the remote host
Apr 13, 2020 22:36:12.000 [1640] Debug — Completed after connection close: [192.168.1.154:42074] 206 GET /library/parts/9/1580506077/file.mp4?autoAdjustQuality=0&hasMDE=1&location=lan&mediaBufferSize=74944 (8 live) TLS 8392ms 262144 bytes (range: bytes=0-) 
Apr 13, 2020 22:36:15.870 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:36:15.871 [16592] Debug — Request: [192.168.1.154:42078 (Subnet)] GET /library/metadata/9?asyncAugmentMetadata=1&checkFiles=1&includeExternalMetadata=1&includeExtras=1&includeRelated=1&includeRelatedCount=0&includeReviews=1 (8 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:36:15.886 [16592] Debug — It took 0.000000 ms to retrieve 139 items.
Apr 13, 2020 22:36:15.891 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:36:15.891 [16592] Debug — Selecting best audio stream for part ID 9 (autoselect: 0 language: en)
Apr 13, 2020 22:36:15.891 [16592] Debug — Audio Stream: 208, Subtitle Stream: -1
Apr 13, 2020 22:36:15.907 [16592] Debug — Activity: registered new activity e31c0f62-7a54-487a-83f7-07a32d59a5e9 - Refreshing
Apr 13, 2020 22:36:15.908 [9396] Debug — Activity: updated activity e31c0f62-7a54-487a-83f7-07a32d59a5e9 - completed 0.0% - Refreshing
Apr 13, 2020 22:36:15.909 [1640] Debug — Completed: [192.168.1.154:42078] 200 GET /library/metadata/9?asyncAugmentMetadata=1&checkFiles=1&includeExternalMetadata=1&includeExtras=1&includeRelated=1&includeRelatedCount=0&includeReviews=1 (8 live) TLS GZIP 38ms 8134 bytes (pipelined: 1)
Apr 13, 2020 22:36:16.381 [11624] Debug — Augment: Found a provider match for 'Uncut.Gems.2019.1080p.WEBRip.x264-RARBG'.
Apr 13, 2020 22:36:16.382 [11624] Debug — Augment: Completed movie augmentation in 0.5 sec.
Apr 13, 2020 22:36:16.382 [9396] Debug — Activity: Ended activity e31c0f62-7a54-487a-83f7-07a32d59a5e9.
Apr 13, 2020 22:36:17.484 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:36:17.484 [16592] Debug — Request: [192.168.1.154:42078 (Subnet)] GET /library/sections (8 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:36:17.490 [1640] Debug — Completed: [192.168.1.154:42078] 200 GET /library/sections (8 live) TLS GZIP 6ms 992 bytes (pipelined: 2)
Apr 13, 2020 22:36:17.516 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:36:17.516 [16592] Debug — Request: [192.168.1.154:42078 (Subnet)] GET /library/metadata/9/similar (8 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:36:17.530 [16592] Debug — It took 0.000000 ms to retrieve 139 items.
Apr 13, 2020 22:36:17.543 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:36:17.543 [16592] Debug — Selecting best audio stream for part ID 5 (autoselect: 0 language: en)
Apr 13, 2020 22:36:17.543 [16592] Debug — Audio Stream: 146, Subtitle Stream: -1
Apr 13, 2020 22:36:17.544 [16592] Debug — We're going to try to auto-select an audio stream for account 1.
Apr 13, 2020 22:36:17.544 [16592] Debug — Selecting best audio stream for part ID 7 (autoselect: 0 language: en)
Apr 13, 2020 22:36:17.544 [16592] Debug — Audio Stream: 204, Subtitle Stream: -1
Apr 13, 2020 22:36:17.546 [1640] Debug — Completed: [192.168.1.154:42078] 200 GET /library/metadata/9/similar (9 live) TLS GZIP 29ms 6143 bytes (pipelined: 3)
Apr 13, 2020 22:36:17.546 [16632] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:36:17.546 [16592] Debug — Request: [192.168.1.154:42110 (Subnet)] GET /library/metadata/augmentations/5?wait=1 (9 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:36:17.547 [16632] Debug — Completed: [192.168.1.154:42110] 200 GET /library/metadata/augmentations/5?wait=1 (9 live) TLS GZIP 1ms 1608 bytes (pipelined: 1)
Apr 13, 2020 22:36:21.594 [16632] Debug — WebSocket: client initiated close
Apr 13, 2020 22:36:21.595 [1640] Debug — NotificationStream: Removing because of close
Apr 13, 2020 22:36:21.605 [16632] Debug — handleStreamRead code 2: End of file
Apr 13, 2020 22:36:21.606 [16632] Debug — Completed after connection close: [192.168.1.154:41976] -3 GET /:/websockets/notifications (9 live) TLS GZIP 91880ms 2173 bytes
Apr 13, 2020 22:36:22.741 [1640] Debug — handleStreamRead code 1: stream truncated
Apr 13, 2020 22:36:22.742 [1640] Debug — NotificationStream: Removing because of error
Apr 13, 2020 22:36:22.742 [1640] Debug — Completed after connection close: [192.168.1.154:41978] -3 GET /:/websockets/notifications (6 live) TLS GZIP 93529ms 2171 bytes
Apr 13, 2020 22:36:24.634 [16632] Debug — Failed to stream media, client probably disconnected after 98304 bytes: 10054 - An existing connection was forcibly closed by the remote host
Apr 13, 2020 22:36:24.634 [16632] Debug — Completed after connection close: [192.168.1.154:42076] 206 GET /library/parts/9/1580506077/file.mp4?autoAdjustQuality=0&hasMDE=1&location=lan&mediaBufferSize=74944 (5 live) TLS 12661ms 98304 bytes (range: bytes=2773976123-) 
Apr 13, 2020 22:36:26.499 [1640] Debug — Completed: [192.168.1.20:3500] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (4 live) TLS GZIP 20001ms 5 bytes (pipelined: 15)
Apr 13, 2020 22:36:26.516 [1640] Debug — Auth: authenticated user 1 as XXXXXXXXXXX@outlook.com
Apr 13, 2020 22:36:26.516 [16592] Debug — Request: [192.168.1.20:3500 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (4 live) TLS GZIP Signed-in Token (XXXXXXXXXXX@outlook.com)
Apr 13, 2020 22:36:26.516 [16592] Debug — Content-Length is -1 (of total: -1).
9

Please post the entire log as a text file. There’s about 2s of info and doesn’t provide enough info.

1 Like
10

Plex Media Server.log (190.5 KB)

Thank you

11

Apr 13, 2020 22:35:33.088 [16592] DEBUG - Streaming Resource: Reached Decision id=9 codes=(MDE=1000,Direct play OK.) media=(id=9 part=(id=9 decision=direct play protocol=* streams=(Video=(id=207 decision= width=1920 height=804) Audio=(id=208 decision= channels=0 rate=0))))

Hmm. That doesn’t look right. Can you post the XML data for that file?

13

Sorry I went to bed after my last message. Where can I get the XML data from?

14

From Plex Web, hover over the poster for that video, find the … option, select get info, then select view XML. Save that as a text file and upload the file.

15

I am attaching the xml for one film and the other tv show I tried. 9.txt (31.1 KB) 66.txt (4.2 KB)

16

The XML looks fine so not sure why PMS is showing blanks. Can you try playing that movie again, this time grab the log from the Android app?

17

Thanks. There are loads of them, I am attaching the top one, let me know if others are of us as well.

image
image739×450 28.3 KB
com.plexapp.android 2020-04-14 19-18.log (1006.9 KB)

I noticed a java.io.IOException: Broken pipe in there (which has something to do with socket connection being closed by the other party) but I have no idea if this is the main problem or something else masked by this exception. Btw I have tried disabling Windows firewall and antivirus to see if it plays but to no avail.

18

I’m seeing those errors plus others in your log. The app is really struggling on your device for some reason. Try restarting your phone, server, and router just in case this is a network issue?

19

didn’t work. Could I post this log file for developers to see somewhere perhaps?

20

I’ll forward the one you already posted.

1 Like
21

Thank you, much appreciated.