MKV's With 10+ Subtitles No Longer Direct Play

Plex Players Streaming Devices
, ,
1

Server Version#: 1.22.0.4163
Player Version#: 8.13.2.23227

After a recent update I noticed a lot of my files no longer Direct Played on AndroidTV/FIreTV. It took me a while to pinpoint a correlation but it seems to be files with 10+ subtitle tracks. If no subtitle is selected the file will be Direct Streamed or Transcoded. However if you manually select a subtitle track before playback if will be Direct Played as normal

Normally a Direct-Stream (i.e. container remux) isn’t a huge deal because it uses relatively little resources. However there’s a longstanding PMS bug where audio bitrate metadata is not parsed properly for EAC3 audio tracks in MKV containers. This missing audio metadata causes the streaming brain to malfunction and unnecessarily transcode the video in any situation where a Direct-Play is not possible. This ends up being a huge problem for those of us running very low-powered servers (Happy Pi day btw!)

2 Likes
2

Still an issue on v8.15.3.24332 of the Fire TV Plex app

3

Here’s a snippet from the server logs:

Apr 26, 2021 18:07:44.548 [0x7fc212c2d700] DEBUG - Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:44.549 [0x7fc18a7fc700] DEBUG - Request: [ip_address:43990 (WAN)] GET /library/metadata/94436?includeChapters=1&includeLoudnessRamps=1&includeMarkers=1&includeRelated=1 (13 live) TLS GZIP Signed-in Token ([user_name])
Apr 26, 2021 18:07:44.577 [0x7fc18a7fc700] DEBUG - We're going to try to auto-select an audio stream for account [user_id].
Apr 26, 2021 18:07:44.577 [0x7fc18a7fc700] DEBUG - Selecting best audio stream for part ID 209860 (autoselect: 0 language: en)
Apr 26, 2021 18:07:44.577 [0x7fc18a7fc700] DEBUG - Audio Stream: 506866, Subtitle Stream: 0
Apr 26, 2021 18:07:44.592 [0x7fc212c2d700] DEBUG - Completed: [ip_address:43990] 200 GET /library/metadata/94436?includeChapters=1&includeLoudnessRamps=1&includeMarkers=1&includeRelated=1 (13 live) TLS GZIP 43ms 2683 bytes (pipelined: 4)
Apr 26, 2021 18:07:44.797 [0x7fc212c2d700] DEBUG - Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:44.798 [0x7fc210c29700] DEBUG - Request: [ip_address:43986 (WAN)] GET /video/:/transcode/universal/decision?audioBoost=100&autoAdjustQuality=0&directPlay=1&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=wan&maxVideoBitrate=200000&mediaBufferSize=74944&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F94436&protocol=*&session=67114cd243c59ed6-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (13 live) TLS GZIP Signed-in Token ([user_name])
Apr 26, 2021 18:07:44.798 [0x7fc210c29700] DEBUG - [Transcode] Found session GUID of 67114cd243c59ed6-com-plexapp-android in session start.
Apr 26, 2021 18:07:44.799 [0x7fc210c29700] DEBUG - [Transcode] TranscodeUniversalRequest: using augmented profile Android
Apr 26, 2021 18:07:44.799 [0x7fc210c29700] DEBUG - [Transcode] Downloading document http://127.0.0.1:32400/library/metadata/94436?includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=67114cd243c59ed6-com-plexapp-android
Apr 26, 2021 18:07:44.799 [0x7fc210c29700] DEBUG - [Transcode] Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:44.827 [0x7fc210c29700] DEBUG - [Transcode] We're going to try to auto-select an audio stream for account [user_id].
Apr 26, 2021 18:07:44.827 [0x7fc210c29700] DEBUG - [Transcode] Selecting best audio stream for part ID 209860 (autoselect: 0 language: en)
Apr 26, 2021 18:07:44.827 [0x7fc210c29700] DEBUG - [Transcode] Audio Stream: 506866, Subtitle Stream: 0
Apr 26, 2021 18:07:44.832 [0x7fc210c29700] DEBUG - [Transcode] Streaming Resource: Adding session 0x7fc17c074110:67114cd243c59ed6-com-plexapp-android which is using 3902kbps of WAN bandwidth.  Used is now 3902kbps
Apr 26, 2021 18:07:44.832 [0x7fc210c29700] DEBUG - [Transcode] Streaming Resource: Added session 0x7fc17c074110:67114cd243c59ed6-com-plexapp-android
Apr 26, 2021 18:07:44.832 [0x7fc210c29700] DEBUG - [Transcode] Streaming Resource: Reached Decision id=94436 codes=(MDE=1000,Direct play OK.) media=(id=202418 part=(id=209860 decision=direct play protocol=* streams=(Video=(id=506865 decision= width=1280 height=720) Audio=(id=506866 decision= channels=0 rate=0))))
Apr 26, 2021 18:07:44.833 [0x7fc212c2d700] DEBUG - Completed: [ip_address:43986] 200 GET /video/:/transcode/universal/decision?audioBoost=100&autoAdjustQuality=0&directPlay=1&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=wan&maxVideoBitrate=200000&mediaBufferSize=74944&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F94436&protocol=*&session=67114cd243c59ed6-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (13 live) TLS GZIP 35ms 1568 bytes (pipelined: 4)
Apr 26, 2021 18:07:45.755 [0x7fc212c2d700] DEBUG - Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:45.756 [0x7fc18a7fc700] DEBUG - Request: [ip_address:43996 (WAN)] GET /library/parts/209860/1619210424/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=74944 (14 live) TLS Signed-in Token ([user_name]) (range: bytes=0-) 
Apr 26, 2021 18:07:45.764 [0x7fc18a7fc700] DEBUG - Content-Length of /home/plex/amazon/Media/Television/Shadow and Bone/Season 01/Shadow and Bone - S01E01 - A Searing Burst of Light.mkv is 729341078 (of total: 729341078).
Apr 26, 2021 18:07:46.801 [0x7fc212c2d700] DEBUG - Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:46.802 [0x7fc2097fa700] DEBUG - Request: [ip_address:43998 (WAN)] GET /library/parts/209860/1619210424/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=74944 (15 live) TLS Signed-in Token ([user_name]) (range: bytes=729326497-) 
Apr 26, 2021 18:07:46.811 [0x7fc2097fa700] DEBUG - Content-Length of /home/plex/amazon/Media/Television/Shadow and Bone/Season 01/Shadow and Bone - S01E01 - A Searing Burst of Light.mkv is 14581 (of total: 729341078).
Apr 26, 2021 18:07:46.820 [0x7fc212c2d700] DEBUG - Completed: [ip_address:43998] 206 GET /library/parts/209860/1619210424/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=74944 (15 live) TLS 18ms 14581 bytes (range: bytes=729326497-) 
Apr 26, 2021 18:07:47.009 [0x7fc212c2d700] DEBUG - Failed to stream media, client probably disconnected after 4259840 bytes: 104 - Connection reset by peer
Apr 26, 2021 18:07:47.009 [0x7fc212c2d700] DEBUG - Completed after connection close: [ip_address:43996] 206 GET /library/parts/209860/1619210424/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=74944 (15 live) TLS 1253ms 4259840 bytes (range: bytes=0-) 
Apr 26, 2021 18:07:47.792 [0x7fc21242c700] DEBUG - Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:47.792 [0x7fc210c29700] DEBUG - Request: [ip_address:44000 (WAN)] GET /library/parts/209860/1619210424/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=74944 (15 live) TLS Signed-in Token ([user_name]) (range: bytes=8351-) 
Apr 26, 2021 18:07:47.800 [0x7fc210c29700] DEBUG - Content-Length of /home/plex/amazon/Media/Television/Shadow and Bone/Season 01/Shadow and Bone - S01E01 - A Searing Burst of Light.mkv is 729332727 (of total: 729341078).
Apr 26, 2021 18:07:49.097 [0x7fc21242c700] DEBUG - Failed to stream media, client probably disconnected after 5226496 bytes: 104 - Connection reset by peer
Apr 26, 2021 18:07:49.097 [0x7fc21242c700] DEBUG - Completed after connection close: [ip_address:44000] 206 GET /library/parts/209860/1619210424/file.mkv?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=74944 (14 live) TLS 1305ms 5226496 bytes (range: bytes=8351-) 
Apr 26, 2021 18:07:49.261 [0x7fc21242c700] DEBUG - Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:49.262 [0x7fc18a7fc700] DEBUG - Request: [ip_address:43988 (WAN)] GET /video/:/transcode/universal/decision?audioBoost=100&autoAdjustQuality=0&directPlay=0&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=wan&maxVideoBitrate=200000&mediaBufferSize=157248&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F94436&protocol=*&session=67114cd243c59ed6-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (13 live) TLS GZIP Signed-in Token ([user_name])
Apr 26, 2021 18:07:49.262 [0x7fc18a7fc700] DEBUG - [Transcode] Found session GUID of 67114cd243c59ed6-com-plexapp-android in session start.
Apr 26, 2021 18:07:49.263 [0x7fc18a7fc700] DEBUG - [Transcode] TranscodeUniversalRequest: using augmented profile Android
Apr 26, 2021 18:07:49.263 [0x7fc18a7fc700] DEBUG - [Transcode] Downloading document http://127.0.0.1:32400/library/metadata/94436?includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=67114cd243c59ed6-com-plexapp-android
Apr 26, 2021 18:07:49.263 [0x7fc18a7fc700] DEBUG - [Transcode] Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:49.291 [0x7fc18a7fc700] DEBUG - [Transcode] We're going to try to auto-select an audio stream for account [user_id].
Apr 26, 2021 18:07:49.291 [0x7fc18a7fc700] DEBUG - [Transcode] Selecting best audio stream for part ID 209860 (autoselect: 0 language: en)
Apr 26, 2021 18:07:49.291 [0x7fc18a7fc700] DEBUG - [Transcode] Audio Stream: 506866, Subtitle Stream: 0
Apr 26, 2021 18:07:49.294 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: Selected protocol hls; container: mkv
Apr 26, 2021 18:07:49.295 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: analyzing media item 202418
Apr 26, 2021 18:07:49.295 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: Direct Play is disabled
Apr 26, 2021 18:07:49.295 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: media must be transcoded in order to use the hls protocol
Apr 26, 2021 18:07:49.295 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: no direct play video profile exists for http/mkv/h264
Apr 26, 2021 18:07:49.295 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: no direct play video profile exists for http/mkv/h264/eac3
Apr 26, 2021 18:07:49.295 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: Shadow and Bone - S1 E1 - A Searing Burst of Light: selected media 0 / 202418
Apr 26, 2021 18:07:49.295 [0x7fc18a7fc700] DEBUG - [Transcode] Streaming Resource: Required bandwidth unknown (media requires deep analysis) Changing decision parameters provided by client to fit bandwidth limit of 200000kbps
Apr 26, 2021 18:07:49.295 [0x7fc18a7fc700] DEBUG - [Transcode] Streaming Resource: Determining preferred transcode encoders through transcode only decision.
Apr 26, 2021 18:07:49.296 [0x7fc18a7fc700] DEBUG - [Transcode] Scaled up video bitrate to 2787Kbps based on 1.500000x fudge factor.
Apr 26, 2021 18:07:49.296 [0x7fc18a7fc700] DEBUG - [Transcode] Scaled up video bitrate to 2787Kbps based on 1.500000x fudge factor.
Apr 26, 2021 18:07:49.297 [0x7fc18a7fc700] DEBUG - [Transcode] Streaming Resource: Reducing playback quality for 190476kbps stream bitrate: video resolution to 1280x720, audio channels to 6, quality to 99, disable video DS as 2147483647kbps is > the 9216kbps available, disable audio DS as 2147483647kbps is > the 768kbps available
Apr 26, 2021 18:07:49.297 [0x7fc18a7fc700] DEBUG - [Transcode] Scaled up video bitrate to 2787Kbps based on 1.500000x fudge factor.
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: Selected protocol hls; container: mkv
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: analyzing media item 202418
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: Direct Play is disabled
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: media must be transcoded in order to use the hls protocol
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: no direct play video profile exists for http/mkv/h264
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: no direct play video profile exists for http/mkv/h264/eac3
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: Direct Streaming is disabled, so video stream will be transcoded
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: no remuxable profile found, so video stream will be transcoded
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: Cannot direct stream video stream due to profile or setting limitations
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] Scaled up video bitrate to 2787Kbps based on 1.500000x fudge factor.
Apr 26, 2021 18:07:49.298 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: E1 - A Searing Burst of Light: Audio Direct Streaming is disabled, so video's audio stream will be transcoded
Apr 26, 2021 18:07:49.299 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: Cannot direct stream audio stream due to profile or setting limitations
Apr 26, 2021 18:07:49.299 [0x7fc18a7fc700] DEBUG - [Transcode] MDE: Shadow and Bone - S1 E1 - A Searing Burst of Light: selected media 0 / 202418
Apr 26, 2021 18:07:49.299 [0x7fc18a7fc700] DEBUG - [Transcode] Streaming Resource: Session 0x7fc17c074110:67114cd243c59ed6-com-plexapp-android changed from using 3902kbps to 3733kbps of WAN bandwidth.  Used bandwidth is now 3733kbps
Apr 26, 2021 18:07:49.299 [0x7fc18a7fc700] DEBUG - [Transcode] Streaming Resource: Session 0x7fc17c074110:67114cd243c59ed6-com-plexapp-android changed transcode slot usage to used.  Used slots is now 1
Apr 26, 2021 18:07:49.299 [0x7fc18a7fc700] DEBUG - [Transcode] Streaming Resource: Reached Decision id=94436 codes=(General=1001,Direct play not available; Conversion OK. Direct Play=3000,App cannot direct play this item. Direct play is disabled. Transcode=1001,Direct play not available; Conversion OK.) media=(id=202418 part=(id=209860 decision=transcode container=mkv protocol=hls streams=(Video=(id=506865 decision=transcode bitrate=2787 encoder=libx264 width=1280 height=720) Audio=(id=506866 decision=transcode bitrate=768 encoder=aac channels=6 rate=48000))))
Apr 26, 2021 18:07:49.304 [0x7fc21242c700] DEBUG - Completed: [ip_address:43988] 200 GET /video/:/transcode/universal/decision?audioBoost=100&autoAdjustQuality=0&directPlay=0&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=wan&maxVideoBitrate=200000&mediaBufferSize=157248&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F94436&protocol=*&session=67114cd243c59ed6-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (13 live) TLS GZIP 42ms 1455 bytes (pipelined: 5)
Apr 26, 2021 18:07:50.365 [0x7fc212c2d700] DEBUG - Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:50.366 [0x7fc2097fa700] DEBUG - Request: [ip_address:44002 (WAN)] GET /video/:/transcode/universal/start.m3u8?audioBoost=100&autoAdjustQuality=0&directPlay=0&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=wan&maxVideoBitrate=200000&mediaBufferSize=157248&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F94436&protocol=hls&session=67114cd243c59ed6-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (14 live) TLS Signed-in Token ([user_name]) (range: bytes=0-) 
Apr 26, 2021 18:07:50.366 [0x7fc2097fa700] DEBUG - [Transcode] Found session GUID of 67114cd243c59ed6-com-plexapp-android in session start.
Apr 26, 2021 18:07:50.367 [0x7fc2097fa700] DEBUG - [Transcode] TranscodeUniversalRequest: using augmented profile Android
Apr 26, 2021 18:07:50.367 [0x7fc2097fa700] DEBUG - [Transcode] Downloading document http://127.0.0.1:32400/library/metadata/94436?checkFiles=1&includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=67114cd243c59ed6-com-plexapp-android
Apr 26, 2021 18:07:50.367 [0x7fc2097fa700] DEBUG - [Transcode] Auth: authenticated user [user_id] as [user_name]
Apr 26, 2021 18:07:50.397 [0x7fc2097fa700] DEBUG - [Transcode] We're going to try to auto-select an audio stream for account [user_id].
Apr 26, 2021 18:07:50.397 [0x7fc2097fa700] DEBUG - [Transcode] Selecting best audio stream for part ID 209860 (autoselect: 0 language: en)
Apr 26, 2021 18:07:50.397 [0x7fc2097fa700] DEBUG - [Transcode] Audio Stream: 506866, Subtitle Stream: 0
Apr 26, 2021 18:07:50.400 [0x7fc2097fa700] DEBUG - [Transcode] Found session GUID of 67114cd243c59ed6-com-plexapp-android in session start.
Apr 26, 2021 18:07:50.400 [0x7fc2097fa700] DEBUG - [Transcode] Using session GUID 67114cd243c59ed6-com-plexapp-android for new transcode session.
Apr 26, 2021 18:07:50.400 [0x7fc2097fa700] DEBUG - [Transcode] Cleaning directory for session 67114cd243c59ed6-com-plexapp-android ()
Apr 26, 2021 18:07:50.401 [0x7fc212c2d700] DEBUG - Completed: [ip_address:44002] 206 GET /video/:/transcode/universal/start.m3u8?audioBoost=100&autoAdjustQuality=0&directPlay=0&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=wan&maxVideoBitrate=200000&mediaBufferSize=157248&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F94436&protocol=hls&session=67114cd243c59ed6-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (14 live) TLS 35ms 392 bytes (range: bytes=0-) 
Apr 26, 2021 18:07:51.208 [0x7fc18a7fc700] DEBUG - Request: [ip_address:44004 (WAN)] GET /video/:/transcode/universal/session/67114cd243c59ed6-com-plexapp-android/base/index.m3u8 (15 live) TLS Signed-in
Apr 26, 2021 18:07:51.208 [0x7fc18a7fc700] DEBUG - [Transcode] Found session GUID of 67114cd243c59ed6-com-plexapp-android in session start.
Apr 26, 2021 18:07:51.208 [0x7fc18a7fc700] DEBUG - [Transcode] Starting a transcode session 67114cd243c59ed6-com-plexapp-android at offset -1.0 (state=3)
Apr 26, 2021 18:07:51.209 [0x7fc18a7fc700] DEBUG - [Transcode] [Universal] Using local file path instead of URL: /home/plex/amazon/Media/Television/Shadow and Bone/Season 01/Shadow and Bone - S01E01 - A Searing Burst of Light.mkv
Apr 26, 2021 18:07:51.210 [0x7fc18a7fc700] DEBUG - [Transcode/JobRunner] Job running: EAE_ROOT='/tmp/pms-0908c306-17ad-41e6-91be-a8183751d856/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/73e06c8-3759-linux-x86_64/' X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxxk' '/usr/lib/plexmediaserver/Plex Transcoder' '-codec:0' 'h264' '-codec:1' 'eac3_eae' '-eae_prefix:1' '67114cd243c59ed6-com-plexapp-android_' '-analyzeduration' '20000000' '-probesize' '20000000' '-i' '/home/plex/amazon/Media/Television/Shadow and Bone/Season 01/Shadow and Bone - S01E01 - A Searing Burst of Light.mkv' '-filter_complex' '[0:0]scale=w=1280:h=720[0];[0]format=pix_fmts=yuv420p|nv12[1]' '-map' '[1]' '-codec:0' 'libx264' '-crf:0' '16' '-maxrate:0' '2787k' '-bufsize:0' '5574k' '-r:0' '23.975999999999999' '-preset:0' 'veryfast' '-level:0' '5.2' '-x264opts:0' 'subme=0:me_range=4:rc_lookahead=10:me=dia:no_chroma_me:8x8dct=0:partitions=none' '-force_key_frames:0' 'expr:gte(t,n_forced*3)' '-filter_complex' '[0:1] aresample=async=1:ocl='\''5.1'\'':rematrix_maxval=0.000000dB:osr=48000[2]' '-map' '[2]' '-metadata:s:1' 'language=eng' '-codec:1' 'aac' '-strict:1' 'experimental' '-aac_coder:1' 'fast' '-q:1' '0' '-segment_format' 'matroska' '-f' 'ssegment' '-individual_header_trailer' '0' '-flags' '+global_header' '-segment_format_options' 'output_ts_offset=10' '-segment_header_filename' 'header' '-segment_time' '3' '-segment_start_number' '0' '-segment_copyts' '1' '-segment_time_delta' '0.0625' '-segment_list' 'http://127.0.0.1:32400/video/:/transcode/session/67114cd243c59ed6-com-plexapp-android/1d728869-8a0a-4861-b71f-e36eb5516da4/seglist?X-Plex-Http-Pipeline=infinite' '-segment_list_type' 'csv' '-segment_list_size' '5' '-segment_list_separate_stream_times' '1' '-segment_list_unfinished' '1' '-max_delay' '5000000' '-avoid_negative_ts' 'disabled' '-map_metadata:g' '-1' '-map_metadata:c' '-1' '-map_chapters' '-1' 'media-%05d.ts' '-start_at_zero' '-copyts' '-vsync' 'cfr' '-y' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'error' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/67114cd243c59ed6-com-plexapp-android/1d728869-8a0a-4861-b71f-e36eb5516da4/progress'
Apr 26, 2021 18:07:51.210 [0x7fc18a7fc700] DEBUG - [Transcode/JobRunner] Jobs: Starting child process with pid 24348

I may be totally off base here but it looks like it’s trying to Direct Play but failing with a lot of:

Failed to stream media, client probably disconnected after 4259840 bytes: 104 - Connection reset by peer

And then it gives up and falls back to transcoding? It’s really weird as this only affects files with 10 or more embedded subs. And only if the “None” subtitle option is selected. If you manually pre-select any of the embedded subtitle it Direct Plays as normal

Edit: Also this section may be of note:

Streaming Resource: Reached Decision id=94436 codes=(MDE=1000,Direct play OK.) media=(id=202418 part=(id=209860 decision=direct play protocol=* streams=(Video=(id=506865 decision= width=1280 height=720) Audio=(id=506866 decision= channels=0 rate=0))))

It seems like it initially tries with a protocol of * and the video/audio decisions are both blank

4

Here’s a snippet from the device logs:

04-27 00:08:34.573  i: [Player][ExoPlayer] Setting initial track selection...
04-27 00:08:34.574  i: [TrackSelectorHelper] Initialising (Video: 1, Audio: 1, Text: 33)
04-27 00:08:34.576  i: [TrackSelectorHelper] Type: 2 Auto
04-27 00:08:34.576  i: [TrackSelectorHelper] Type: 1 Media Index: 1
04-27 00:08:34.577  i: [TrackSelectorHelper] Renderer: MediaCodecAudioRenderer Track: 0
04-27 00:08:34.578  i: [TrackSelectorHelper] Type: 3 Disabled
04-27 00:08:34.579  i: [Player][ExoPlayer] Switching video surface to use MediaCodec surface.
04-27 00:08:34.580  i: [Player] onSurfaceChangeRequested
04-27 00:08:34.580  i: [ExoPlayer][EventLogger] videoInputFormat [eventTime=4.64, mediaPos=0.00, window=0, period=0, id=0, mimeType=video/avc, codecs=h264, res=1280x720, fps=23.976025]
04-27 00:08:34.581  i: [FF][MediaPeriod] Selecting tracks.
04-27 00:08:34.582  i: [ExoPlayer][EventLogger] surfaceSize [eventTime=4.69, mediaPos=0.00, window=0, period=0, 1920, 1080]
04-27 00:08:34.582  i: [FF][MediaPeriod] Releasing.
04-27 00:08:34.583  i: [FF] Loading canceled (released: true)
04-27 00:08:34.584  i: [FFmpeg] [INFO] Demuxer has been successfully interupted.
04-27 00:08:34.584  i: [ExoPlayer][EventLogger] audioDecoderInitialized [eventTime=4.71, mediaPos=0.00, window=0, period=0, OMX.dolby.eac3.decoder]
04-27 00:08:34.585  i: [ExoPlayer][EventLogger] audioInputFormat [eventTime=4.71, mediaPos=0.00, window=0, period=0, id=1, mimeType=audio/eac3, bitrate=0, codecs=eac3, channels=6, sample_rate=48000, language=english]
04-27 00:08:34.586  i: [TranscodeSession] Updating session status
04-27 00:08:34.587  i: [ExoPlayer][EventLogger] videoDisabled [eventTime=4.72, mediaPos=0.00, window=0, period=0]
04-27 00:08:34.588  i: [ExoPlayer][EventLogger] audioDisabled [eventTime=4.72, mediaPos=0.00, window=0, period=0]
04-27 00:08:34.589  i: [FF] Releasing demuxer.
04-27 00:08:34.589  i: [FFmpeg] [INFO] Demuxer closing.
04-27 00:08:34.590  e: [ExoPlayer][EventLogger] playerFailed [eventTime=4.73, mediaPos=0.00, window=0, period=0
  com.google.android.exoplayer2.ExoPlaybackException: Unexpected runtime error
      at com.google.android.exoplayer2.l0.handleMessage(SourceFile:30)
      at android.os.Handler.dispatchMessage(Handler.java:98)
      at android.os.Looper.loop(Looper.java:154)
      at android.os.HandlerThread.run(HandlerThread.java:61)
  Caused by: android.media.MediaCodec$CodecException: Error 0x80001001
      at android.media.MediaCodec.native_flush(Native Method)
      at android.media.MediaCodec.flush(MediaCodec.java:2068)
      at com.google.android.exoplayer2.mediacodec.q.flush(SourceFile:1)
      at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.t(SourceFile:3)
      at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.s(SourceFile:1)
      at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.onPositionReset(SourceFile:7)
      at com.google.android.exoplayer2.audio.c0.onPositionReset(SourceFile:1)
      at com.google.android.exoplayer2.d0.resetPosition(SourceFile:4)
      at com.google.android.exoplayer2.l0.j0(SourceFile:26)
      at com.google.android.exoplayer2.l0.handleMessage(SourceFile:16)
      ... 3 more
]
04-27 00:08:34.591  e: [Player][ExoPlayer] Playback error detected
04-27 00:08:34.593  i: [FFmpeg] [INFO] [Cache] Close requested, terminating.
04-27 00:08:34.594  i: [FFmpeg] [INFO] [Cache] Terminating thread.
04-27 00:08:34.595  i: [Player][Timeline] Handling player error
04-27 00:08:34.596  i: [Player][Timeline] Playback stopped (error: true)
04-27 00:08:34.596  i: [FFmpeg] [INFO] [Cache] Thread has been terminated.
04-27 00:08:34.597  i: [Player][Timeline] Player error not known by server, reporting original player error (or a playback interrupted one)
04-27 00:08:34.598  i: [Player] Error reported: UnknownError (null)
04-27 00:08:34.598  i: [Player][Timeline] Playback stopped (error: false)
04-27 00:08:34.599  i: [FFmpeg] [INFO] [Cache] Cache has been closed, interrupting AVIO ...
04-27 00:08:34.599  i: [TranscodeFallbackBehaviour] Detected direct play failed, falling back to transcode (starting: true)

So it’s definitely trying to Direct Play, failing, and falling back to Transcoding. I can provide the full logs if anyone is wants them

Edit: Just for good measure here’s a snippet of the Fire TV device log for same file Direct Playing when you pre-select a subtitle track. There’s no Unexpected runtime error and the file plays normally:

04-27 00:48:14.452  i: [Player][ExoPlayer] Setting initial track selection...
04-27 00:48:14.453  i: [TrackSelectorHelper] Initialising (Video: 1, Audio: 1, Text: 33)
04-27 00:48:14.454  i: [TrackSelectorHelper] Type: 2 Auto
04-27 00:48:14.455  i: [TrackSelectorHelper] Type: 1 Media Index: 1
04-27 00:48:14.456  i: [TrackSelectorHelper] Renderer: MediaCodecAudioRenderer Track: 0
04-27 00:48:14.457  i: [TrackSelectorHelper] Type: 3 Media Index: 2
04-27 00:48:14.458  i: [TrackSelectorHelper] Renderer: TextRenderer Track: 0
04-27 00:48:14.459  i: [Player][ExoPlayer] Switching video surface to use MediaCodec surface.
04-27 00:48:14.460  i: [Player] onSurfaceChangeRequested
04-27 00:48:14.461  i: [ExoPlayer][EventLogger] videoInputFormat [eventTime=4.68, mediaPos=0.00, window=0, period=0, id=0, mimeType=video/avc, codecs=h264, res=1280x720, fps=23.976025]
04-27 00:48:14.463  i: [ExoPlayer][EventLogger] surfaceSize [eventTime=4.74, mediaPos=0.00, window=0, period=0, 1920, 1080]
04-27 00:48:14.464  i: [ExoPlayer][EventLogger] audioDecoderInitialized [eventTime=4.76, mediaPos=0.00, window=0, period=0, OMX.dolby.eac3.decoder]
04-27 00:48:14.465  i: [ExoPlayer][EventLogger] audioInputFormat [eventTime=4.76, mediaPos=0.00, window=0, period=0, id=1, mimeType=audio/eac3, bitrate=0, codecs=eac3, channels=6, sample_rate=48000, language=english]
04-27 00:48:14.466  i: [TranscodeSession] Updating session status
04-27 00:48:14.467  i: [TranscodeSession] Direct Play
04-27 00:48:14.468  i: [ExoPlayer][EventLogger] videoDecoderInitialized [eventTime=4.82, mediaPos=0.00, window=0, period=0, OMX.MTK.VIDEO.DECODER.AVC]
04-27 00:48:14.469  i: [ExoPlayer][EventLogger] audioSessionId [eventTime=4.89, mediaPos=0.00, window=0, period=0, 113]
04-27 00:48:14.470  i: [Player] onDisplaySizeChanged(1280x720 at 0x0)
04-27 00:48:14.471  i: [ExoPlayer][EventLogger] videoSize [eventTime=5.03, mediaPos=0.00, window=0, period=0, 1280, 720]
04-27 00:48:14.472  i: [ExoPlayer][EventLogger] renderedFirstFrame [eventTime=5.03, mediaPos=0.00, window=0, period=0, Surface(name=null)/@0x3e60fb3]
04-27 00:48:14.473  i: [Player][DimensionsLayout] Resizing: 1920 x 1080
04-27 00:48:14.474  i: [EngineEventManager] onBufferingEnded
04-27 00:48:14.475  i: [EngineEventManager] onPlaybackStarted: Delay-1728871695
04-27 00:48:14.476  i: [MetricsLatencyBehaviour] Latency recorded for playback: 5159
04-27 00:48:14.477  i: [PlaybackTimeBehaviour] Initialising
04-27 00:48:14.478  i: [PlaybackTimeBehaviour] Starting stopwatch
04-27 00:48:14.480  i: [VideoAwakeBehaviour] Keep screen awake has been requested enabled for VideoAwakeBehaviour.
04-27 00:48:14.481  i: [VideoAwakeBehaviour] Keeping screen on
04-27 00:48:14.482  i: [AudioFocusBehaviour] Playback started
04-27 00:48:14.483  i: [AudioFocusBehaviour] Gained focus.
04-27 00:48:14.484  i: [TranscodeSession] Media choice updated
04-27 00:48:14.485  i: [PlayQueueProgressBehaviour] Updating PlayQueueManager state, isPlaying: true
04-27 00:48:14.486  i: [PlayQueueBehaviour] Clearing audio PQ because video playback has started.
04-27 00:48:14.487  i: [Player][ExoPlayer] Passing subtitle offset of 0.
04-27 00:48:14.488  i: [WiFiLockBehaviour] Aquiring WiFi lock since playback was started.
04-27 00:48:14.490  i: [DelayedPlayQueueBehaviour] Resolving Play Queue...
04-27 00:48:14.491  i: [DelayedRemotePlayQueue] Resolving delayed Play Queue...
04-27 00:48:14.492  i: [PlayQueueAPIHelperBase] No item path provided, will generate a new one
04-27 00:48:14.494  i: [MediaSessionHelper] Releasing media session with tag: music
04-27 00:48:14.495  i: [MediaSessionHelper] Starting media session with tag: video
04-27 00:48:14.496  i: [MediaSessionHelper] Creating media session with tag: video
04-27 00:48:14.497  i: [TranscodeSession] Media choice updated
04-27 00:48:14.498  i: [TranscodeSession] Updating session status
04-27 00:48:14.499  i: [Player] onPlaybackStarted
5

Still bugged on the latest versions of Plex for Android TV and Fire TV. Looks like it only comes into play if:

  1. The audio codec is being decoded by the device
    AND
  2. The file contains 10+ subtitles

If you have a setup that supports it, passing through the audio will result in the expected Direct-Play behavior. However if you disable passthrough the file will be Direct-Streamed (container transcode). But if you trim the MKV down to 9 or less subtitle tracks the file will Direct-Play as expected even with passthrough disabled. Hopefully this helps pinpoint the issue

1 Like
6

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