Remote Transcoding with External SRT subtitle not working

Plex Media Server
,
1

Server Version#: plexmediaserver-1.20.2.3343-c91f25744 on CentOS 7 - HW decoding with nvidia is enabled on a GeForce GTX 750

Player Version#: Android 8.7.0.20759

I tried to remote play a movie on my Android Phone, but it doesn’t play when I select an external SRT subtitle.
When I disable the subtitle the movie plays fine.

Here is a small portion of the Verbose log, these log messages repeats indefinitely as long as I try to play the movie with the subtitle enabled:

Sep 27, 2020 00:17:35.841 [0x7ff3a616e700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data…
Sep 27, 2020 00:17:35.862 [0x7ff3a596d700] VERBOSE - [TranscodeOutputStream] Delaying subtitle output to wait for video stream to catch up
Sep 27, 2020 00:17:35.941 [0x7ff3a616e700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data…
Sep 27, 2020 00:17:36.041 [0x7ff3a616e700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data…
Sep 27, 2020 00:17:36.062 [0x7ff3a596d700] VERBOSE - [TranscodeOutputStream] Delaying subtitle output to wait for video stream to catch up
Sep 27, 2020 00:17:36.142 [0x7ff3a616e700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data…
Sep 27, 2020 00:17:36.242 [0x7ff3a696f700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data…
Sep 27, 2020 00:17:36.262 [0x7ff3a596d700] VERBOSE - [TranscodeOutputStream] Delaying subtitle output to wait for video stream to catch up

1 Like
2

PMS 1.20.2 BETA is broken for nearly all transcoding.

Specifically it’s broken for anything which uses the i965 portion of the CPU.

Please uninstall 1.20.2 and reinstall 1.20.1 then retest

PS: Please use DEBUG logging only unless VERBOSE is requested.

3

I’m not using the i965 CPU, it’s using nvenc.

I tried version 1.20.1 but the same problem persists. I only have issues when the subtitle is selected. If I select No subtitle it is working fine (also is version 1.20.2)

This is the debug log:

Sep 27, 2020 01:20:09.810 [0x7f0681027700] DEBUG - Streaming Resource: Estimated bandwidth for 57aa0dd16037acdd-com-plexapp-android to be 9052kbps over 0.26s
Sep 27, 2020 01:20:09.840 [0x7f067bfff700] DEBUG - Completed: [77.63.2.111:46671] 200 GET /video/:/transcode/universal/session/57aa0dd16037acdd-com-plexapp-android/base/00001.ts (22 live) TLS 130ms 522640 bytes (pipelined: 1)
Sep 27, 2020 01:20:09.840 [0x7f067bfff700] DEBUG - Removed transcode data consumer, active count 2 => 1
Sep 27, 2020 01:20:09.932 [0x7f06277fe700] DEBUG - Transcoder segment range: 0 - 2 (2)
Sep 27, 2020 01:20:09.932 [0x7f0624ff9700] DEBUG - Transcoder segment range: 0 - 3 (2)
Sep 27, 2020 01:20:10.139 [0x7f0625ffb700] DEBUG - Transcoder segment range: 0 - 3 (3)
Sep 27, 2020 01:20:10.139 [0x7f06267fc700] DEBUG - Transcoder segment range: 0 - 4 (3)
Sep 27, 2020 01:20:10.348 [0x7f0626ffd700] DEBUG - Transcoder segment range: 0 - 4 (4)
Sep 27, 2020 01:20:10.354 [0x7f06427fc700] DEBUG - Transcoder segment range: 0 - 5 (4)
Sep 27, 2020 01:20:10.539 [0x7f0627fff700] DEBUG - Transcoder segment range: 0 - 5 (5)
Sep 27, 2020 01:20:10.540 [0x7f06277fe700] DEBUG - Transcoder segment range: 0 - 6 (5)
Sep 27, 2020 01:20:10.633 [0x7f067b7fe700] DEBUG - Streaming Resource: Estimated bandwidth for 57aa0dd16037acdd-com-plexapp-android to be 20521kbps over 1.09s
Sep 27, 2020 01:20:10.830 [0x7f0626ffd700] DEBUG - Transcoder segment range: 0 - 6 (6)
Sep 27, 2020 01:20:10.830 [0x7f0625ffb700] DEBUG - Transcoder segment range: 0 - 7 (6)
Sep 27, 2020 01:20:11.070 [0x7f0627fff700] DEBUG - Transcoder segment range: 0 - 7 (7)
Sep 27, 2020 01:20:11.070 [0x7f06257fa700] DEBUG - Transcoder segment range: 0 - 8 (7)
Sep 27, 2020 01:20:11.268 [0x7f06267fc700] DEBUG - Transcoder segment range: 0 - 8 (8)
Sep 27, 2020 01:20:11.268 [0x7f06427fc700] DEBUG - Transcoder segment range: 0 - 9 (8)
Sep 27, 2020 01:20:11.498 [0x7f06277fe700] DEBUG - Transcoder segment range: 0 - 9 (9)
Sep 27, 2020 01:20:11.498 [0x7f0626ffd700] DEBUG - Transcoder segment range: 0 - 10 (9)
Sep 27, 2020 01:20:11.686 [0x7f0625ffb700] DEBUG - Transcoder segment range: 0 - 10 (10)
Sep 27, 2020 01:20:11.686 [0x7f0627fff700] DEBUG - Transcoder segment range: 0 - 11 (10)
Sep 27, 2020 01:20:11.868 [0x7f0624ff9700] DEBUG - Transcoder segment range: 0 - 11 (11)
Sep 27, 2020 01:20:11.869 [0x7f0625ffb700] DEBUG - Transcoder segment range: 0 - 12 (11)
Sep 27, 2020 01:20:12.080 [0x7f0627fff700] DEBUG - Transcoder segment range: 0 - 12 (12)
Sep 27, 2020 01:20:12.081 [0x7f06427fc700] DEBUG - Transcoder segment range: 0 - 13 (12)
Sep 27, 2020 01:20:12.379 [0x7f06257fa700] DEBUG - Transcoder segment range: 0 - 13 (13)
Sep 27, 2020 01:20:12.380 [0x7f0624ff9700] DEBUG - Transcoder segment range: 0 - 14 (13)
Sep 27, 2020 01:20:12.584 [0x7f0625ffb700] DEBUG - Transcoder segment range: 0 - 14 (14)
Sep 27, 2020 01:20:12.584 [0x7f0627fff700] DEBUG - Transcoder segment range: 0 - 15 (14)
Sep 27, 2020 01:20:12.633 [0x7f066affd700] DEBUG - Streaming Resource: Estimated bandwidth for 57aa0dd16037acdd-com-plexapp-android to be 20521kbps over 3.09s
Sep 27, 2020 01:20:12.792 [0x7f0625ffb700] DEBUG - Transcoder segment range: 0 - 15 (15)
Sep 27, 2020 01:20:12.792 [0x7f0624ff9700] DEBUG - Transcoder segment range: 0 - 16 (15)
Sep 27, 2020 01:20:13.011 [0x7f0626ffd700] DEBUG - Transcoder segment range: 0 - 16 (16)
Sep 27, 2020 01:20:13.012 [0x7f0627fff700] DEBUG - Transcoder segment range: 0 - 17 (16)
Sep 27, 2020 01:20:13.214 [0x7f0625ffb700] DEBUG - Transcoder segment range: 0 - 17 (17)
Sep 27, 2020 01:20:13.215 [0x7f0624ff9700] DEBUG - Transcoder segment range: 0 - 18 (17)
Sep 27, 2020 01:20:13.294 [0x7f067bfff700] DEBUG - Completed: [10.0.0.10:65113] 200 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) TLS GZIP 20006ms 5 bytes (pipelined: 1)
Sep 27, 2020 01:20:13.310 [0x7f0680826700] DEBUG - Request came in with unrecognized domain / IP ‘hhwaard.nl’ in header Referer; treating as non-local
Sep 27, 2020 01:20:13.311 [0x7f0680826700] DEBUG - Auth: authenticated user 1 as MarkdV
Sep 27, 2020 01:20:13.311 [0x7f0627fff700] DEBUG - Request: [10.0.0.10:65113 (Allowed Network (Subnet))] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (21 live) TLS GZIP Signed-in Token (MarkdV)
Sep 27, 2020 01:20:13.311 [0x7f0627fff700] DEBUG - Content-Length is -1 (of total: -1).
Sep 27, 2020 01:20:13.417 [0x7f06257fa700] DEBUG - Transcoder segment range: 0 - 18 (18)
Sep 27, 2020 01:20:13.417 [0x7f06277fe700] DEBUG - Transcoder segment range: 0 - 19 (18)
Sep 27, 2020 01:20:13.620 [0x7f0625ffb700] DEBUG - Transcoder segment range: 0 - 19 (19)
Sep 27, 2020 01:20:13.620 [0x7f0624ff9700] DEBUG - Transcoder segment range: 0 - 20 (19)
Sep 27, 2020 01:20:13.824 [0x7f06427fc700] DEBUG - Transcoder segment range: 0 - 20 (20)
Sep 27, 2020 01:20:13.824 [0x7f0624ff9700] DEBUG - Transcoder segment range: 0 - 21 (20)
Sep 27, 2020 01:20:14.026 [0x7f0627fff700] DEBUG - Transcoder segment range: 0 - 21 (21)
Sep 27, 2020 01:20:14.026 [0x7f06257fa700] DEBUG - Transcoder segment range: 0 - 22 (21)
Sep 27, 2020 01:20:14.224 [0x7f06267fc700] DEBUG - Transcoder segment range: 0 - 22 (22)
Sep 27, 2020 01:20:14.224 [0x7f0626ffd700] DEBUG - Transcoder segment range: 0 - 23 (22)
Sep 27, 2020 01:20:14.246 [0x7f0627fff700] DEBUG - Session 57aa0dd16037acdd-com-plexapp-android (3) is throttling
Sep 27, 2020 01:20:14.246 [0x7f06257fa700] DEBUG - [Transcoder] Throttle - Going into sloth mode.
Sep 27, 2020 01:20:14.424 [0x7f0602ffd700] WARN - Connection Tester: Error testing media server plex.d-vrs.com in 10000 ms.
Sep 27, 2020 01:20:14.424 [0x7f0679bda700] DEBUG - Media Server: Tested all servers in 10.0 seconds.
Sep 27, 2020 01:20:14.424 [0x7f0679bda700] DEBUG - HTTP requesting GET /media/providers
Sep 27, 2020 01:20:14.425 [0x7f0679bda700] ERROR - Error issuing curl_easy_perform(handle): 3
Sep 27, 2020 01:20:14.425 [0x7f0679bda700] WARN - HTTP error requesting GET /media/providers (3, URL using bad/illegal format or missing URL) ()
Sep 27, 2020 01:20:14.633 [0x7f066b7fe700] DEBUG - Streaming Resource: Estimated bandwidth for 57aa0dd16037acdd-com-plexapp-android to be 20521kbps over 5.09s
Sep 27, 2020 01:20:15.130 [0x7f067bfff700] DEBUG - Auth: authenticated user 1 as MarkdV
Sep 27, 2020 01:20:15.130 [0x7f06257fa700] DEBUG - Request: [77.63.2.111:46673 (WAN)] GET /:/websockets/notifications (23 live) TLS GZIP Signed-in Token (MarkdV)
Sep 27, 2020 01:20:15.130 [0x7f06257fa700] DEBUG - WebSocket: Performing handshake from origin
Sep 27, 2020 01:20:15.130 [0x7f06257fa700] DEBUG - Beginning read from WebSocket
Sep 27, 2020 01:20:15.149 [0x7f067bfff700] DEBUG - Auth: authenticated user 1 as MarkdV
Sep 27, 2020 01:20:15.149 [0x7f06277fe700] DEBUG - Request: [77.63.2.111:46672 (WAN)] GET /:/websockets/notifications (23 live) TLS GZIP Signed-in Token (MarkdV)
Sep 27, 2020 01:20:15.150 [0x7f06277fe700] DEBUG - WebSocket: Performing handshake from origin
Sep 27, 2020 01:20:15.150 [0x7f06277fe700] DEBUG - Beginning read from WebSocket
Sep 27, 2020 01:20:16.633 [0x7f06437fe700] DEBUG - Streaming Resource: Estimated bandwidth for 57aa0dd16037acdd-com-plexapp-android to be 20521kbps over 7.09s
Sep 27, 2020 01:20:18.633 [0x7f067b7fe700] DEBUG - Streaming Resource: Estimated bandwidth for 57aa0dd16037acdd-com-plexapp-android to be 20521kbps over 9.09s
Sep 27, 2020 01:20:20.633 [0x7f0681027700] DEBUG - Streaming Resource: Estimated bandwidth for 57aa0dd16037acdd-com-plexapp-android to be 20521kbps over 11.09s

4

upload the log ZIP please? It’s impossible to diagnose from that small a snippet

5

I had the same issue, stuff that played fine that have external subtitles stopped showing subtitles in apps, and if playing through web give transcode error.
After downgrading to 1.20.1 and still getting the same issue, i did a metadata refresh on an episode that was doing it, which fixed it.
So after the downgrade do a metadata refresh.

6

DebugLog.zip (47.3 KB)

Attached is the Debug log.

What is did is restarted Plex Media Server

  1. Played the movie without subtitles (this was working)
  2. Stopped the play.
  3. Selected the subtitle for the movie
  4. Tried to play the movie again, but it now keeps loading forever
1 Like
7

Refreshing metadata did not work for me, so I hope the Plex team finds something usefull in the Debug Logs.

8

Just chiming in with the same issue, after server update the external subtitles are not working.

When I select the external subtitles the internal subtitles are used instead.

1 Like
9

Exactly the same issue and logs I’m encountering. Removing or burning subtitle will work smoothly, so frustrating! Check also Client Settings #3 it works because maximum quality and not burning the subtitle doesn’t require transcoding, I guess.

PS: It seems like “subtitle sync issue” waiting for the video stream to catch up which never happens when Automatically adjust quality is set to On
(Reference: [TranscodeOutputStream] Delaying subtitle output to wait for video stream to catch up).

Client Settings #1 (Not working at all, same issue) - Android / Android TV 8.8.x or 8.7.x

  • Settings > Quality > Automatically adjust quality: On
  • Settings > Quality > Remote streaming: 2 Mbps, 720p HD
  • Settings > Advanced > Subtitles > Burn subtitles: Automatic or Only image formats

Client Settings #2 (WORKING SMOOTHLY) - Android / Android TV 8.8.x or 8.7.x

  • Settings > Quality > Automatically adjust quality: On
  • Settings > Quality > Remote streaming: 2 Mbps, 720p HD
  • Settings > Advanced > Subtitles > Burn subtitles: Always

Client Settings #3 (WORKING SMOOTHLY) - Android / Android TV 8.8.x or 8.7.x

  • Settings > Quality > Automatically adjust quality: On
  • Settings > Quality > Remote streaming: Maximum
  • Settings > Advanced > Subtitles > Burn subtitles: Automatic or Only image formats

Client Settings #4 (WORKING SMOOTHLY) - Android / Android TV 8.8.x or 8.7.x

  • Settings > Quality > Automatically adjust quality: Off
  • Settings > Quality > Remote streaming: 2 Mbps, 720p HD
  • Settings > Advanced > Subtitles > Burn subtitles: Automatic or Only image formats

cc: @Plex, @elan, @ChuckPa

10

Thank you for the direct ping. I was NOT notified of the previous posts – my apologies.

Given how much time has passed, can we gather fresh logs and clean test case information?

I would like to:

  1. Confirm the server is set for DEBUG logging ON and VERBOSE logging OFF
  2. Confirm the Android app (settings - advanced) reports Debug logs to the server.
  3. Restart the server
  4. Give it 1 minute to stabilize
  5. Start the playback and play enough to replicate the problem
  6. Stop playback
  7. Wait 20 seconds for the logs to get to the disk cleanly.
  8. Download the logs ZIP file

Attach the following info as one reply:

  1. The logs ZIP file from above
  2. The XML from the file being played (hover over the file -> Get Info -> View XML) – media info only – don’t need genre/actor info
  3. Version of the Android app in use.
11
  1. Confirm the Android app (settings - advanced) reports Debug logs to the server.
    • do you mean Settings > Help & Support > Debugging > Network logging? Because I can’t see reports Debug logs to the server from Android app’s Advance Settings.

I can provide these things but please confirm #2. Thank you.

12

Hello @ChuckPa, here you go.

  1. :white_check_mark: Confirm the server is set for DEBUG logging ON and VERBOSE logging OFF
  2. :white_check_mark: Confirm the Android app (settings - advanced) reports Debug logs to the server.
  3. :white_check_mark: Restart the server
  4. :white_check_mark: Give it 1 minute to stabilize
  5. :white_check_mark: Start the playback and play enough to replicate the problem
  6. :white_check_mark: Stop playback
  7. :white_check_mark: Wait 20 seconds for the logs to get to the disk cleanly.
  8. :white_check_mark: Download the logs ZIP file

Attach the following info as one reply:

  1. :white_check_mark: The logs ZIP file from above
  2. :white_check_mark: The XML from the file being played (hover over the file → Get Info → View XML) – media info only – don’t need genre/actor info
  3. :white_check_mark: Version of the Android app in use.
    • version: 8.8.1.21331 (759417e7)
13

and here’s the client settings that I used. Please take note that I changed 720p to 480p because the video is already in 720p and it will be played directly instead of transcoding which is not reproducible in direct play.

thank you.

Client Settings

  • Settings > Quality > Automatically adjust quality: On
  • Settings > Quality > Remote streaming: 1.5 Mbps, 480p
  • Settings > Advanced > Subtitles > Burn subtitles: Automatic or Only image formats
14

@marksagal

yes - the logging which pushes to the server or allows you to download the player logs. Either or. ( Can you tell I’m not on any of the Player teams? )

I can see in the server sending 2.5 Mbps and then the player stops accepting data.
The server eventually times out and kills the connection.

This is observed behavior?

15

@ChuckPa

No, I’m not sure about that, maybe because I did #6 (Stop Playback), as you said w/c I did after 1-2mins of waiting. If I enable VERBOSE logging from PMS, I can see the logs is flooded by [TranscodeOutputStream] Delaying subtitle output to wait for video stream to catch up.

PS: If you’ll be requesting me to wait for 5 more minutes before stopping the play back, just let me know, I’ll do it again for you. But 1 thing I’m sure about, nothing will happen even if I wait for 1 whole day because it looks like stucked in a loophole.

16

Thank you for sharing that. I’m glad you clipped it out of the verbose logs. It must have been a mess. I greatly appreciate you taking that time.

I’m going to get one of the Android devs. I see what the server is doing but not what the android player is doing.

Out of stupidness / ignorance on my part,
Would you be kind enough to attach the SRT text file here in a ZIP for me to look at.
I recently saw a corrupt SRT cause the transcoder to go crazy.
I wonder if there is something else going on.

I can try your SRT on my system and then trace its behavior with apple devices to at least determine if server or player. I can’t yet see where this is server based

17

@ChuckPa
No worries, we should thank you for taking care of this case.

here you go, I also tested that using VLC, it’s working. And also, considering Client Settings #2 (burning subtitles) and Client Settings #4 (turning off auto adjust quality), those settings works pretty smooth.

NIKITA - S01 E01 - Pilot.en.zip (37.8 KB)

18

Thank you for that.

  1. Absolutely nothing wrong with that SRT – I didn’t expect it to be.
  2. I did a forced burn of the SRT at a lower bitrate
    Screenshot from 2020-10-27 20-44-05
    Screenshot from 2020-10-27 20-44-051041×480 244 KB
    Screenshot from 2020-10-27 20-43-30
    Screenshot from 2020-10-27 20-43-30327×408 140 KB

We need some help here above my basic “how to use” knowledge.

Which version of Android (the OS and device - in case that matters) are you using?

19

I used Android 7, it’s also reproducible with Android 8, 9 and 10 (tried and tested by me also).

Test Devices

  • Android 7 - Redmi 4x
  • Android TV 8 - 2015 Sony Bravia 4K
  • Android TV 9 - MI Box S
  • Android 10 - Samsung Galaxy A50s
20

Thanks. I’ve asked the android guys to peek in here.
They will know what to do with this info.

They’re sleeping currently (their time zone). :crossed_fingers: they can look first in the morning