Some videos transcode until I change (or disable/enable) subtitle tracks, but only on Android

[timardis]

I’m playing some new 4K content from my Plex server (from streamfab), and it will always transcode the video until I change the subtitle selection.

I don’t mean always picking a different track, but also disabling subtitles will do the trick. Similarly, if the episode starts with no subtitles, then it will transcode until I select a subtitle track. Very odd behavior.

This has been the same for MP4, MKV, and MP4-w/-standalone-SRT’s

It’s not too big of a hassle, except for it causing a bunch of client crashes before I’m able to switch the subtitle track.

Here’s a selected log from starting a video with subtitles ON (transcoded) before turning subtitles OFF (Direct Play):

Jan 21, 2024 15:36:24.246 [140485246749496] DEBUG - [Req#165571/Transcode] MDE: *****: Audio Direct Streaming is disabled, so video's audio stream will be transcoded
Jan 21, 2024 15:36:24.246 [140485246749496] DEBUG - [Req#165571/Transcode] MDE: Cannot direct stream audio stream due to profile or setting limitations
Jan 21, 2024 15:36:24.246 [140485246749496] DEBUG - [Req#165571/Transcode] MDE: *****: selected media 0 / 5292
Jan 21, 2024 15:36:24.247 [140485246749496] DEBUG - [Req#165571/Transcode] Streaming Resource: Session 0x7fc55580bcb8:751405f2cfb0f0f9-com-plexapp-android changed transcode slot usage to used.  Used slots is now 1
Jan 21, 2024 15:36:24.247 [140485246749496] DEBUG - [Req#165571/Transcode] Streaming Resource: Reached Decision id=3570 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=5292 part=(id=5293 decision=transcode container=mkv protocol=hls streams=(Video=(id=14100 decision=transcode bitrate=82944 encoder=h264_vaapi width=3840 height=2160) Audio=(id=14101 decision=transcode bitrate=768 encoder=libopus channels=6 rate=48000))))
Jan 21, 2024 15:36:24.248 [140485564705592] DEBUG - Completed: [192.168.29.100:43706] 200 GET /video/:/transcode/universal/decision?audioBoost=100&autoAdjustQuality=0&directPlay=0&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=lan&maxVideoBitrate=200000&mediaBufferSize=209664&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F3570&protocol=*&session=751405f2cfb0f0f9-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (8 live) #165571 TLS GZIP 101ms 3888 bytes (pipelined: 8)
Jan 21, 2024 15:36:24.486 [140485244640056] DEBUG - Request: [192.168.29.100:43706 (Subnet)] GET /video/:/transcode/universal/start.m3u8?audioBoost=100&autoAdjustQuality=0&directPlay=0&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=lan&maxVideoBitrate=200000&mediaBufferSize=209664&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F3570&protocol=hls&session=751405f2cfb0f0f9-com-plexapp-android&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (8 live) #165576 TLS GZIP Signed-in Token (*****) (SHIELD Android TV)

...<Disabling subtitles>...

Jan 21, 2024 15:37:09.788 [140485246749496] DEBUG - [Req#1656ae/Transcode] Streaming Resource: Reached Decision id=3570 codes=(MDE=1000,Direct play OK.) media=(id=5292 part=(id=5293 decision=direct play protocol=* streams=(Video=(id=14100 decision= width=3840 height=2160) Audio=(id=14101 decision= channels=0 rate=0) Subtitle=(id=14106 decision=ignore languageCode= location=embedded))))
Jan 21, 2024 15:37:09.789 [140485566815032] DEBUG - Completed: [192.168.29.100:43706] 200 GET /video/:/transcode/universal/decision?advancedSubtitles=text&audioBoost=100&autoAdjustQuality=0&directPlay=1&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=lan&maxVideoBitrate=200000&mediaBufferSize=209664&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F3570&protocol=*&session=751405f2cfb0f0f9-com-plexapp-android&skipSubtitles=1&subtitleSize=100&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (11 live) #1656ae TLS GZIP 18ms 4181 bytes (pipelined: 37)
Jan 21, 2024 15:37:09.799 [140485255187256] DEBUG - Request: [192.168.29.100:43706 (Subnet)] GET /library/parts/5293/1705858831/file.mp4?autoAdjustQuality=0&hasMDE=1&location=lan&mediaBufferSize=209664 (11 live) #1656b2 TLS Signed-in Token (*****) (SHIELD Android TV)

Server Version#: 1.32.8.7639
Player Version#: 10.7.0.5386 (Nvidia Shield Pro 2019)

[ChuckPa]

Going to need your server DEBUG logs which capture this.

I just tested using a Shield Pro 2019 with 2160p DoVi and PGS Subtitles.

I get DirectPlay.

Turning subtitles ON/OFF has no impact on the server (The Shield is doing everything)

I’m using play app version 10.4.04843.

Are you using beta or am I behind?

[timardis]

After some more investigation, Plex Server seems perfectly happy with the content, and shows Direct Stream for video and audio is occurring (even shows playback progress despite the client being stuck) – it’s only the client/player complaining.

Same issue happens with 1080p / EAC3 (Stereo) content from StreamFab, as well as resolving if I change another playback setting (like audio track), not just subtitles.

I was able to reproduce this from Plex on my Android phone and grab the client logs, here’s a snippet from the first error (full “snippet” attached):

01-22 13:05:33.741  e: [FFmpegExtractor] Extraction operation failed with exception.
01-22 13:05:33.741  e: An exception occurred: java.nio.BufferUnderflowException
01-22 13:05:33.741  e: Stacktrace: java.nio.BufferUnderflowException
	at java.nio.DirectByteBuffer.get(DirectByteBuffer.java:255)
	at com.plexapp.plex.ff.io.SharedOutputBuffer.drainAsByteArray(SourceFile:5)
	at com.plexapp.player.engines.exoplayer.extractor.ExtractorBinding.b(SourceFile:107)
	at com.plexapp.player.engines.exoplayer.extractor.a$a.invokeSuspend(SourceFile:361)
	at kotlin.coroutines.jvm.internal.a.resumeWith(SourceFile:12)
	at gy.a1.run(SourceFile:124)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
	at java.lang.Thread.run(Thread.java:1012)

01-22 13:05:33.766  i: [MediaCodecVideoSyncRenderer] Decoder initialised, after 0 attempts.
01-22 13:05:33.767  i: [ExoPlayer][EventLogger] videoDecoderInitialized [eventTime=1.33, mediaPos=0.00, window=0, period=0, OMX.qcom.video.decoder.avc]
01-22 13:05:33.767  i: [ExoPlayer][DMCodecAdapterFactory] Creating an asynchronous MediaCodec adapter for track type audio
01-22 13:05:33.767  i: [ExoPlayer][EventLogger] videoInputFormat [eventTime=1.33, mediaPos=0.00, window=0, period=0, id=0, mimeType=video/avc, bitrate=8639365, codecs=h264, res=1920x1080, fps=29.97003]
01-22 13:05:33.795  i: [ExoPlayer][EventLogger] audioDecoderInitialized [eventTime=1.36, mediaPos=0.00, window=0, period=0, c2.dolby.eac3.decoder]
01-22 13:05:33.795  i: [ExoPlayer][EventLogger] audioInputFormat [eventTime=1.36, mediaPos=0.00, window=0, period=0, id=1, mimeType=audio/eac3, codecs=eac3, channels=2, sample_rate=48000, language=english, selectionFlags=[forced]]
01-22 13:05:33.795  i: [TranscodeSession] Updating session status
01-22 13:05:33.796  i: [TranscodeSession] Direct Play
01-22 13:05:33.834  e: [ExoPlayer][LoadTask] Unexpected exception loading stream
  java.nio.BufferUnderflowException
      at java.nio.DirectByteBuffer.get(DirectByteBuffer.java:255)
      at com.plexapp.plex.ff.io.SharedOutputBuffer.drainAsByteArray(SourceFile:5)
      at com.plexapp.player.engines.exoplayer.extractor.ExtractorBinding.b(SourceFile:107)
      at com.plexapp.player.engines.exoplayer.extractor.a$a.invokeSuspend(SourceFile:361)
      at kotlin.coroutines.jvm.internal.a.resumeWith(SourceFile:12)
      at gy.a1.run(SourceFile:124)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
      at java.lang.Thread.run(Thread.java:1012)

01-22 13:05:33.836  e: [ExoPlayer][ExoPlayerImplInternal] Playback error
  androidx.media3.exoplayer.ExoPlaybackException: Source error
      at androidx.media3.exoplayer.ExoPlayerImplInternal.handleIoException(SourceFile:17)
      at androidx.media3.exoplayer.ExoPlayerImplInternal.handleMessage(SourceFile:284)
      at android.os.Handler.dispatchMessage(Handler.java:102)
      at android.os.Looper.loopOnce(Looper.java:226)
      at android.os.Looper.loop(Looper.java:313)
      at android.os.HandlerThread.run(HandlerThread.java:67)
  Caused by: androidx.media3.exoplayer.upstream.Loader$UnexpectedLoaderException: Unexpected BufferUnderflowException: null
      at androidx.media3.exoplayer.upstream.Loader$LoadTask.run(SourceFile:146)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
      at java.lang.Thread.run(Thread.java:1012)
  Caused by: java.nio.BufferUnderflowException
      at java.nio.DirectByteBuffer.get(DirectByteBuffer.java:255)
      at com.plexapp.plex.ff.io.SharedOutputBuffer.drainAsByteArray(SourceFile:5)
      at com.plexapp.player.engines.exoplayer.extractor.ExtractorBinding.b(SourceFile:107)
      at com.plexapp.player.engines.exoplayer.extractor.a$a.invokeSuspend(SourceFile:361)
      at kotlin.coroutines.jvm.internal.a.resumeWith(SourceFile:12)
      at gy.a1.run(SourceFile:124)
      ... 3 more

transcode-full-log.txt (73.2 KB)

I was able to process these files with ffmpeg on Windows without any errors (if that’s of any help).

Android App version is 10.2.0.4488

UPDATE:

Tried playing from Plex on an Apple TV 4K and everything ran smooth – immediate Direct Play

ExoPlayer bug?

[ChuckPa]

App version 10.2 ?? Isn’t that a bit older? (I know my 10.4 is behind current)

I ask because we’ll need to confirm this is an issue with current release before can submit it.

[timardis]

Good point, just updated to 10.7.0.5386 and confirmed the same error occurs.

BUT, funny enough, googling the older version I was on pulled up this post on Reddit, looks like the same issue

[ChuckPa]

I can’t recreate this.

Ripped from my BluRay disk,
TrueHD audio
Subtitles enabled.

Shield connected to Onkyo TX-RZ receiver then to TV.

The receiver can accept TrueHD ??

How many actual streams are there in the file ?
I have only 4 . Video, TrueHD, AC-3, and subtitles.

Certain TVs, think Samsung is one of them, which will balk when there are more than 28 streams in total. It forces PMS to remux and back off / transcode the audio

EDIT: Upgraded to 10.7.0.5386. Still cannot reproduce the problem.

[timardis]

Not surprising, I think you’ll have a hard time reproducing it on your own – none of my other videos have this problem, just the new ones.

I’ll try to create a small sample video to hopefully reproduce it on your end.

[timardis]

I made a short clip that shows this behavior on my end, but it’s larger than I can attach on here (25MB) – what’s the best way to share it?

[Drakonas]

One of your developers confirmed subtitles as an issue on a reddit thread, and they also replied to a related fix on GIST with comments on a confirmed subtitle overhaul they are working on.

The issue is related to burn-in, it seems. With certain hardware, Plex seems to assume that the burn-in requires software transcoding, even though it should be supported with hardware transcoding. Using external subtitle files seem to get around the issue. But embedded ones trigger it for certain hardware.

I know I’m bringing transcoding into an issue related to direct play, but I’m wondering if these issues are related.

This isn’t affecting everyone, but it is affecting a number of people, including me with my Quadro P1000 in my Debian server.

EDIT: Seeing below, it seems you are already aware of this. Praying you guys don’t have too rough of a release.

Color corruption on resize when HW transcoding HEVC content - Synology DS920+

Subtitle burning has been the bane of transcoding since the beginning. That said … We found a way to burn in PGS, VOBSUB, and DVDRIP subtitles in hardware We’re finishing that work now and hope to have it in a Forum Preview sometime this first quarter. (Windows PMS is currently getting some sorely needed love)

[timardis]

I think that’s a different issue, but it definitely made it more difficult to track down anyone else facing this one.

I’m using external subtitles, but whether I start the video with them ON or OFF, I still have to change the playback setting in some way to get Direct Play to start working correctly.

Also, once Direct Play starts working correctly, I can start changing subtitle/audio settings without any transcoding occurring.

What’s even weirder is that once Direct Play starts, I can close Plex and come back later to “resume” watching and everything works fine (subtitles or not).

It seems like it’s some kind of corner case that happens only right when playback starts at the beginning of the video and the client falls back to transcoding (even though the server is direct streaming).