[BUG] Intermittent transcoding on LG WebOS when direct playing

Plex Players Smart TVs
21

@ChuckPa I think I know whats going on:

The decision to transcode is made after [TranscodeOutputStream] (which is a transcoding process for .srt subs) timed out for the 4th time (see errorCount in [ui-chrome-webos]) - this limit seems to be hardcoded into the webos client.
First timeout

Jun 18, 2019 14:50:12.794 [1208] DEBUG - [TranscodeOutputStream] Timed out waiting for data
Jun 18, 2019 14:50:12.795 [1208] DEBUG - Removed transcode data consumer, active count 1 => 0
Jun 18, 2019 14:50:12.795 [1852] DEBUG - [TranscodeOutputStream] Input processing thread exited after writing 84383 bytes, m_closed=1, m_endOfFileReached=1, session->isStopped()=0
Jun 18, 2019 14:50:12.842 [1208] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:50:12.843 [8440] DEBUG - Request: [192.168.178.23:37284 (Subnet)] POST /log (10 live) GZIP Signed-in Token (alexmannsbart@gmail.com)
Jun 18, 2019 14:50:12.844 [8440] WARN - [ui-chrome-webos] [Subtitles] Request failed. statusCode:0 state:4 errorCount:1

Second timeout

Jun 18, 2019 14:51:29.272 [1208] DEBUG - [TranscodeOutputStream] Timed out waiting for data
Jun 18, 2019 14:51:29.272 [1208] DEBUG - Removed transcode data consumer, active count 1 => 0
Jun 18, 2019 14:51:29.273 [6204] DEBUG - [TranscodeOutputStream] Input processing thread exited after writing 84305 bytes, m_closed=1, m_endOfFileReached=1, session->isStopped()=0
Jun 18, 2019 14:51:29.288 [7604] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:51:29.288 [8440] DEBUG - Request: [192.168.178.23:37344 (Subnet)] POST /log (11 live) GZIP Signed-in Token (alexmannsbart@gmail.com)
Jun 18, 2019 14:51:29.289 [8440] WARN - [ui-chrome-webos] [Subtitles] Request failed. statusCode:0 state:4 errorCount:2

Third timeout

Jun 18, 2019 14:52:45.212 [1208] DEBUG - [TranscodeOutputStream] Timed out waiting for data
Jun 18, 2019 14:52:45.212 [1208] DEBUG - Removed transcode data consumer, active count 1 => 0
Jun 18, 2019 14:52:45.213 [12452] DEBUG - [TranscodeOutputStream] Input processing thread exited after writing 83750 bytes, m_closed=1, m_endOfFileReached=1, session->isStopped()=0
Jun 18, 2019 14:52:45.229 [1208] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:52:45.229 [19520] DEBUG - Request: [192.168.178.23:37262 (Subnet)] POST /log (14 live) GZIP Signed-in Token (alexmannsbart@gmail.com)
Jun 18, 2019 14:52:45.230 [19520] WARN - [ui-chrome-webos] [Subtitles] Request failed. statusCode:0 state:4 errorCount:3

Fourth & final timeout after that a transcode is started

Jun 18, 2019 14:54:00.805 [7604] DEBUG - [TranscodeOutputStream] Timed out waiting for data
Jun 18, 2019 14:54:00.805 [7604] DEBUG - Removed transcode data consumer, active count 1 => 0
Jun 18, 2019 14:54:00.806 [6388] DEBUG - [TranscodeOutputStream] Input processing thread exited after writing 83286 bytes, m_closed=1, m_endOfFileReached=1, session->isStopped()=0
Jun 18, 2019 14:54:00.822 [7604] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:54:00.823 [8328] DEBUG - Request: [192.168.178.23:37364 (Subnet)] POST /log (11 live) GZIP Signed-in Token (alexmannsbart@gmail.com)
Jun 18, 2019 14:54:00.823 [8328] WARN - [ui-chrome-webos] [Subtitles] Request failed. statusCode:0 state:4 errorCount:4 
Jun 18, 2019 14:54:00.824 [1208] DEBUG - Completed: [192.168.178.23:37364] 200 POST /log (11 live) GZIP 1ms 274 bytes (pipelined: 6)
Jun 18, 2019 14:54:00.955 [7604] DEBUG - Failed to stream media, client probably disconnected after 2018246656 bytes: 10054 - Eine vorhandene Verbindung wurde vom Remotehost geschlossen
Jun 18, 2019 14:54:00.956 [7604] DEBUG - Completed: [192.168.178.23:37288] 200 GET /library/parts/1479/1560493742/file.mkv (11 live) 304603ms 2018246656 bytes (range: bytes=12013141026-) 
Jun 18, 2019 14:54:01.050 [1208] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:54:01.050 [8328] DEBUG - Request: [192.168.178.23:37364 (Subnet)] GET /video/:/transcode/universal/decision?hasMDE=1&path=%2Flibrary%2Fmetadata%2F653&mediaIndex=0&partIndex=0&protocol=hls&fastSeek=1&directPlay=0&directStream=1&subtitleSize=100&audioBoost=100&location=lan&directStreamAudio=1&session=5xsge29vxp2xzuxr63svb536&subtitles=burn&Accept-Language=de (10 live) GZIP Signed-in Token (alexmannsbart@gmail.com)
Jun 18, 2019 14:54:01.050 [8328] DEBUG - Found session GUID of 5xsge29vxp2xzuxr63svb536 in session start.
Jun 18, 2019 14:54:01.051 [8328] DEBUG - TranscodeUniversalRequest: using augmented profile HTML TV App
Jun 18, 2019 14:54:01.051 [8328] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/653?includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=01yj2g72ti2ro1ortc2d8pz4
Jun 18, 2019 14:54:01.052 [8328] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:54:01.061 [8328] DEBUG - It took 0.000000 ms to retrieve 114 items.
Jun 18, 2019 14:54:01.063 [8328] DEBUG - Audio Stream: 3636, Subtitle Stream: 3917
Jun 18, 2019 14:54:01.068 [8328] DEBUG - Codecs: testing h264_qsv (encoder)
Jun 18, 2019 14:54:01.068 [8328] DEBUG - Codecs: hardware transcoding: testing API qsv
Jun 18, 2019 14:54:01.094 [7604] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:54:01.095 [11776] DEBUG - Request: [192.168.178.23:37298 (Subnet)] POST /log (10 live) GZIP Signed-in Token (alexmannsbart@gmail.com)
Jun 18, 2019 14:54:01.095 [11776] INFO - [ui-chrome-webos]   X-Plex-Session-Identifier: 01yj2g72ti2ro1ortc2d8pz4
Jun 18, 2019 14:54:01.095 [11776] INFO - [ui-chrome-webos]   directStreamAudio: 1
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   location: lan
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   audioBoost: 100
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   subtitleSize: 100
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   directStream: 1
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   directPlay: 0
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   fastSeek: 1
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   protocol: hls
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   partIndex: 0
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   mediaIndex: 0
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   path: /library/metadata/653
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   hasMDE: 1
Jun 18, 2019 14:54:01.098 [11776] INFO - [ui-chrome-webos] [Transcoder] Video (decision) options
Jun 18, 2019 14:54:01.098 [11776] INFO - [ui-chrome-webos] [Player] Stream codec is: ac3, selected: ac3
Jun 18, 2019 14:54:01.098 [11776] INFO - [ui-chrome-webos] [Player] Can direct stream? true (isAllowed: true)
Jun 18, 2019 14:54:01.099 [11776] INFO - [ui-chrome-webos]   X-Plex-Client-Profile-Extra: add

After that the webOS app requests a transcode as seen here in the request part.

Jun 18, 2019 14:54:00.955 [7604] DEBUG - Failed to stream media, client probably disconnected after 2018246656 bytes: 10054 - Eine vorhandene Verbindung wurde vom Remotehost geschlossen
Jun 18, 2019 14:54:00.956 [7604] DEBUG - Completed: [192.168.178.23:37288] 200 GET /library/parts/1479/1560493742/file.mkv (11 live) 304603ms 2018246656 bytes (range: bytes=12013141026-) 
Jun 18, 2019 14:54:01.050 [1208] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:54:01.050 [8328] DEBUG - Request: [192.168.178.23:37364 (Subnet)] GET /video/:/transcode/universal/decision?hasMDE=1&path=%2Flibrary%2Fmetadata%2F653&mediaIndex=0&partIndex=0&protocol=hls&fastSeek=1&directPlay=0&directStream=1&subtitleSize=100&audioBoost=100&location=lan&directStreamAudio=1&session=5xsge29vxp2xzuxr63svb536&subtitles=burn&Accept-Language=de (10 live) GZIP Signed-in Token (alexmannsbart@gmail.com)
22

This seems to be related.
The question of all questions seems to be: Why is [TranscodeOutputStream] timing out in the first place?

23

I was going to recommend starting to go backwards in versions to see if this were replicated in older versions.

The MDE decision is always performed when ā€œPlayā€ is pressed.

The MDE re-running because of timeouts is a new concept.

I am very sorry I am not an app guy. I need to go ask for more information.

24

No worries - thanks for the quick response :slight_smile:

25

I tried 1.15.5.994 and it did the same thing. Unfortunately I donā€™t have any older copies lying around or I would go further back. Itā€™s a shame thereā€™s no way to go back to an older version of the LG app to determine if thatā€™s the cause.

@likeadoc have you seen the issue if you start playback from the beginning of the movie and just let it play?

26

I am chatting with the app team.

Given this has the chromecast linked in as well,
and that PMS is not falling back gracefully from soft subtitles to hard (burned),
coupled with what I know of PMS not falling back gracefully from HW transcoding to SW transcoding,

ā€¦ pretty much leads to one conclusionā€¦

PMS has not yet fixed the problem.

I know the transcoder is being overhauled/updated now.
I can only hope this gets fixed with that work. (Iā€™m lumping this with that general problem).
This isnā€™t an idea situation by any stretch.

Perhaps setting subtitles to always-burn will avoid the timeout at start and the fallback which fails?

27

The problem with doing that is you lose all the benefits of the 4K HDR video. Not to mention it used to work up until relatively recently. As it seems to now occur with a version of PMS that was previously ok would that not suggest it might be an app rather than PMS issue?

28

@Krazeh unfortunately yes - it does not matter if I start a movie from the beginning or continue watchingā€¦

@ChuckPa are you sure this is on PMS and not on the client side (chromecast, webOS app)?
From my standpoint it seems to be the decision of the client to start a transcode (i.e. burn subtitles because of the afformentioned timeouts) as seen below

Jun 18, 2019 14:54:01.050 [8328] DEBUG - Found session GUID of 5xsge29vxp2xzuxr63svb536 in session start.
Jun 18, 2019 14:54:01.051 [8328] DEBUG - TranscodeUniversalRequest: using augmented profile HTML TV App
Jun 18, 2019 14:54:01.051 [8328] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/653?includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=01yj2g72ti2ro1ortc2d8pz4
Jun 18, 2019 14:54:01.052 [8328] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:54:01.061 [8328] DEBUG - It took 0.000000 ms to retrieve 114 items.
Jun 18, 2019 14:54:01.063 [8328] DEBUG - Audio Stream: 3636, Subtitle Stream: 3917
Jun 18, 2019 14:54:01.068 [8328] DEBUG - Codecs: testing h264_qsv (encoder)
Jun 18, 2019 14:54:01.068 [8328] DEBUG - Codecs: hardware transcoding: testing API qsv
Jun 18, 2019 14:54:01.094 [7604] DEBUG - Auth: authenticated user 1 as alexmannsbart@gmail.com
Jun 18, 2019 14:54:01.095 [11776] DEBUG - Request: [192.168.178.23:37298 (Subnet)] POST /log (10 live) GZIP Signed-in Token (alexmannsbart@gmail.com)
Jun 18, 2019 14:54:01.095 [11776] INFO - [ui-chrome-webos]   X-Plex-Session-Identifier: 01yj2g72ti2ro1ortc2d8pz4
Jun 18, 2019 14:54:01.095 [11776] INFO - [ui-chrome-webos]   directStreamAudio: 1
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   location: lan
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   audioBoost: 100
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   subtitleSize: 100
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   directStream: 1
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   directPlay: 0
Jun 18, 2019 14:54:01.096 [11776] INFO - [ui-chrome-webos]   fastSeek: 1
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   protocol: hls
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   partIndex: 0
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   mediaIndex: 0
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   path: /library/metadata/653
Jun 18, 2019 14:54:01.097 [11776] INFO - [ui-chrome-webos]   hasMDE: 1
Jun 18, 2019 14:54:01.098 [11776] INFO - [ui-chrome-webos] [Transcoder] Video (decision) options
Jun 18, 2019 14:54:01.098 [11776] INFO - [ui-chrome-webos] [Player] Stream codec is: ac3, selected: ac3
Jun 18, 2019 14:54:01.098 [11776] INFO - [ui-chrome-webos] [Player] Can direct stream? true (isAllowed: true)
Jun 18, 2019 14:54:01.099 [11776] INFO - [ui-chrome-webos]   X-Plex-Client-Profile-Extra: add-limitation(scope=videoCodec&scopeName=hevc&type=upperBound&name=video.width&value=3840&replace=true)+add-limitation(scope=videoCodec&scopeName=hevc&type=upperBound&name=video.height&value=2160&replace=true)+add-limitation(scope=videoCodec&scopeName=hevc&type=upperBound&name=video.bitDepth&value=10&replace=true)+append-transcode-target-codec(type=videoProfile&context=streaming&protocol=hls&videoCodec=hevc)+add-limitation(scope=videoTranscodeTarget&scopeName=hevc&scopeType=videoCodec&context=streaming&protocol=hls&type=match&name=video.colorTrc&list=bt709|bt470m|bt470bg|smpte170m|smpte240m|bt2020-10|smpte2084&isRequired=false)+add-transcode-target-audio-codec(type=videoProfile&context=streaming&protocol=hls&audioCodec=ac3&replace=true)+add-limitation(scope=videoAudioCodec&scopeName=ac3&type=upperBound&name=audio.channels&value=6&replace=true)
Jun 18, 2019 14:54:01.099 [11776] INFO - [ui-chrome-webos]   subtitles: burn
Jun 18, 2019 14:54:01.099 [11776] INFO - [ui-chrome-webos]   session: 5xsge29vxp2xzuxr63svb536
Jun 18, 2019 14:54:01.099 [11776] INFO - [ui-chrome-webos]   X-Plex-Session-Identifier: 01yj2g72ti2ro1ortc2d8pz4
Jun 18, 2019 14:54:01.100 [11776] INFO - [ui-chrome-webos]   directStreamAudio: 1
Jun 18, 2019 14:54:01.100 [11776] INFO - [ui-chrome-webos]   location: lan
Jun 18, 2019 14:54:01.100 [11776] INFO - [ui-chrome-webos]   audioBoost: 100
Jun 18, 2019 14:54:01.100 [11776] INFO - [ui-chrome-webos]   subtitleSize: 100
Jun 18, 2019 14:54:01.100 [11776] INFO - [ui-chrome-webos]   directStream: 1
Jun 18, 2019 14:54:01.101 [11776] INFO - [ui-chrome-webos]   directPlay: 0
Jun 18, 2019 14:54:01.101 [11776] INFO - [ui-chrome-webos]   fastSeek: 1
Jun 18, 2019 14:54:01.101 [11776] INFO - [ui-chrome-webos]   protocol: hls
Jun 18, 2019 14:54:01.101 [11776] INFO - [ui-chrome-webos]   partIndex: 0
Jun 18, 2019 14:54:01.101 [11776] INFO - [ui-chrome-webos]   mediaIndex: 0
Jun 18, 2019 14:54:01.101 [11776] INFO - [ui-chrome-webos]   path: /library/metadata/653
Jun 18, 2019 14:54:01.101 [11776] INFO - [ui-chrome-webos]   hasMDE: 1
Jun 18, 2019 14:54:01.102 [11776] INFO - [ui-chrome-webos] [Transcoder] Video (start) options
Jun 18, 2019 14:54:01.102 [11776] INFO - [ui-chrome-webos] [Player] Stream codec is: ac3, selected: ac3
Jun 18, 2019 14:54:01.102 [11776] INFO - [ui-chrome-webos] [Player] Can direct stream? true (isAllowed: true)
Jun 18, 2019 14:54:01.102 [11776] INFO - [ui-chrome-webos]   Direct Play: false
Jun 18, 2019 14:54:01.103 [11776] INFO - [ui-chrome-webos]   Protocol: hls
Jun 18, 2019 14:54:01.103 [11776] INFO - [ui-chrome-webos]   Player: html
Jun 18, 2019 14:54:01.103 [11776] INFO - [ui-chrome-webos] [PDE] Player decision
Jun 18, 2019 14:54:01.103 [11776] INFO - [ui-chrome-webos]   videoResolution: 2560
Jun 18, 2019 14:54:01.103 [11776] INFO - [ui-chrome-webos]   bitrate: 52294
Jun 18, 2019 14:54:01.104 [11776] INFO - [ui-chrome-webos]   useSoftSubtitles: false
Jun 18, 2019 14:54:01.104 [11776] INFO - [ui-chrome-webos]   canDirectStreamAudio: false
Jun 18, 2019 14:54:01.104 [11776] INFO - [ui-chrome-webos]   canDirectStreamVideo: false
Jun 18, 2019 14:54:01.104 [11776] INFO - [ui-chrome-webos]   canDirectPlay: false
Jun 18, 2019 14:54:01.104 [11776] INFO - [ui-chrome-webos]   canPlay: true
Jun 18, 2019 14:54:01.105 [11776] INFO - [ui-chrome-webos] [MDE] Finished analysis of 4k (mkv, hevc, truehd, 153, main 10)
Jun 18, 2019 14:54:01.105 [11776] WARN - [ui-chrome-webos] [MDE] Direct play failed; asked to always burn subtitles

especially those two lines point to a decision made by the client

Jun 18, 2019 14:54:01.099 [11776] INFO - [ui-chrome-webos]   subtitles: burn

Jun 18, 2019 14:54:01.105 [11776] WARN - [ui-chrome-webos] [MDE] Direct play failed; asked to always burn subtitles

Maybe setting the limit for errorCount on the client to 1000 would be an albeit quick & dirty temporary fix?

Jun 18, 2019 14:54:00.823 [8328] WARN - [ui-chrome-webos] [Subtitles] Request failed. statusCode:0 state:4 errorCount:4

Always-burn is definitely not an option - as @Krazeh stated - it would negate all benefits of a 4K HDR video/movie since the transcoder currently uses the h264 codec and therefore loses HDR10 metadata ā€¦

29

Have just done a test with a copy of Deadpool 2 (XML: 35810.zip (5.8 KB)).

Playing the movie from the beginning and not touching anything allowed it to play all the way through as direct play with the subtitles still playing correctly.

Playing from the beginning and immediately skipping forward 30 seconds led to it transcoding approximately 2 mins later.

Stopping playback someway into the movie and then restarting playback from that point again led to it switching from direct play to transcoding after approximately 2 minutes.

I saw similar when I tried The Martian yesterday and just left it playing from the beginning. It was quite happy to direct play, but as soon as I skipped or stopped and restarted playback it would direct play for a couple of minutes before switching to transcoding.

1 Like
30

@likeadoc Thank you for quoting me ! Iā€™m glad to see (sorry :smile:) that Iā€™m not the only one to have this problem.

As @ChuckPa said, I think that Chromecast and LGWeb OS clients have juste one common thing : the PMS.

For now, Iā€™m using Emby to avoid this problem, but as Plex, itā€™s not perfectā€¦

31

Also have this problem, extremely frustrating :frowning:

32

@ChuckPa Any update on the issue, is the Plex team working on a fix?

33

Actually , it seems it is new version of WebOS Plex app problem. I have no problem when I got my C8 at February. At First, I thought is the Plex Server problem and I try 6 previous version with no luck. Too bad we can not downgrade the WebOS Plex app and try :expressionless:

BTW the last update of WebOS Plex app have lot of change and very not user friendlyā€¦ :dizzy_face:

2 Likes
34

Same problem @ LG B7 for several weeksā€¦

35

Yep problem still there.
Funny thing I donā€™t have any issue if I turn captions off.

Also my Plex app for webOs was last updated in September 2016.

So sure this is a Server issue with some update. As it was working fine three weeks ago.

36

SRT subs donā€™t work anymore. On XPLAY no problems. Devs, we need you!

1 Like
37

Same problem here, using Synology as PMS.
I found that 1.15.1.791 was the last version wihout this problem.

1 Like
38

Hmmm maybe I should downgrade to that version, do you have an .exe file lying around for it?

39

Sorry. I only have a spk package for synology.

40

Iā€™ve found the download link:
https://downloads.plex.tv/plex-media-server-new/1.15.1.791-8bec0f76c/windows/PlexMediaServer-1.15.1.791-8bec0f76c-x86.exe

1 Like