Some subtitles not showing, which used to

[pwhodges 1519]

I guess this is related to the recent Roku firmware update.

I have some files with subs in which are described as tx3g in Handbrake and are not visible in MKVToolnix.  They used to display in the Emby/Roku app, but now no longer do.  The dropdown to select them is there, so Emby is seeing them - it calls them MOV_TXT - and they are selected.

I have the setting to burn-in SSA subtitles set, because the Roku doesn't handle those well, but I guess this doesn't affect these subs.  I suppose I could force transcoding in the Emby server by setting a low quality, but that's not what I want to do in general - I've not yet checked if that would work, though (currently I have subtitle extraction enabled in the server).

Does this require a change from Roku, or can the Emby app do something about it?

Paul

[Luke 36991]

Hi there, can we please look at an example? Thanks.

[pwhodges 1519]

I rotated the log then started playing the test file I've kept.  Server log attached (is there a Roku log?).  The subs did not show, though they were selected in the Roku client.  They do show in other clients, such as web and Android.

Only this type of subtitles have this problem.  There was no ffmpeg log.

Paul

embyserver.txt

Edited July 8, 2020 by pwhodges

[speechles 1917]

 

2020-07-08 23:01:27.835 Info HttpServer: SocketException: http://192.168.1.66:8096/emby/Videos/2422882/stream.mp4?static=true&mediaSourceId=1bccf42264b690b7d5dbfb79bb07fbaf&api_key=52588378e7bc421d85fec16f15ab2425

There was an error reading the stream and those subtitles aren't delivered during fallback. We may need to improve that part of the equation.

 

Here is the full section that is interesting...

2020-07-08 23:01:08.798 Info SessionManager: Playback start reported by app Roku SG 4.0.7 playing s00e99 A Mug's Game - tx3g subs . Started at 0 ms
2020-07-08 23:01:08.799 Info HttpServer: HTTP Response 204 to 192.168.1.11. Time: 3ms. http://192.168.1.66:8096/emby/Sessions/Playing
2020-07-08 23:01:08.830 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/Videos/2422882/stream.mp4?static=true&mediaSourceId=1bccf42264b690b7d5dbfb79bb07fbaf. Host=192.168.1.66:8096, Range=bytes=145698972-, User-Agent=Roku/DVP-9.30 (509.30E04172A), Accept=*/*
2020-07-08 23:01:09.071 Info HttpServer: HTTP Response 206 to 192.168.1.11. Time: 241ms. http://192.168.1.66:8096/emby/Videos/2422882/stream.mp4?static=true&mediaSourceId=1bccf42264b690b7d5dbfb79bb07fbaf
2020-07-08 23:01:09.233 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/Videos/2422882/stream.mp4?static=true&mediaSourceId=1bccf42264b690b7d5dbfb79bb07fbaf. Host=192.168.1.66:8096, User-Agent=Roku/DVP-9.30 (509.30E04172A), Accept=*/*
2020-07-08 23:01:13.161 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/Videos/2422882/index.bif?width=320&mediaSourceId=1bccf42264b690b7d5dbfb79bb07fbaf. Connection=close, Host=192.168.1.66:8096, User-Agent=Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:01:13.162 Info HttpServer: HTTP Response 200 to 192.168.1.11. Time: 2ms. http://192.168.1.66:8096/emby/Videos/2422882/index.bif?width=320&mediaSourceId=1bccf42264b690b7d5dbfb79bb07fbaf
2020-07-08 23:01:13.273 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/Sessions?deviceId=c4eb6879-73b0-5b60-a338-fdfa7a98ab72. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:01:13.274 Info HttpServer: HTTP Response 200 to 192.168.1.11. Time: 1ms. http://192.168.1.66:8096/emby/Sessions?deviceId=c4eb6879-73b0-5b60-a338-fdfa7a98ab72
2020-07-08 23:01:14.150 Info HttpServer: HTTP POST http://192.168.1.66:8096/emby/Sessions/Playing/Progress. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:01:14.156 Info HttpServer: HTTP Response 204 to 192.168.1.11. Time: 6ms. http://192.168.1.66:8096/emby/Sessions/Playing/Progress
2020-07-08 23:01:24.312 Info HttpServer: HTTP POST http://192.168.1.66:8096/emby/Sessions/Playing/Progress. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:01:24.314 Info HttpServer: HTTP Response 204 to 192.168.1.11. Time: 1ms. http://192.168.1.66:8096/emby/Sessions/Playing/Progress
2020-07-08 23:01:27.835 Info HttpServer: SocketException: http://192.168.1.66:8096/emby/Videos/2422882/stream.mp4?static=true&mediaSourceId=1bccf42264b690b7d5dbfb79bb07fbaf&api_key=52588378e7bc421d85fec16f15ab2425
2020-07-08 23:01:27.835 Info HttpServer: HTTP Response 200 to 192.168.1.11. Time: 19114ms. http://192.168.1.66:8096/emby/Videos/2422882/stream.mp4?static=true&mediaSourceId=1bccf42264b690b7d5dbfb79bb07fbaf
2020-07-08 23:01:34.987 Info HttpServer: HTTP POST http://192.168.1.66:8096/emby/Sessions/Playing/Progress. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:01:34.990 Info HttpServer: HTTP Response 204 to 192.168.1.11. Time: 4ms. http://192.168.1.66:8096/emby/Sessions/Playing/Progress
2020-07-08 23:01:36.321 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/system/info/public. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; MSAppHost/3.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36 Edge/18.19041
2020-07-08 23:01:36.321 Info HttpServer: HTTP Response 200 to 192.168.1.74. Time: 1ms. http://192.168.1.66:8096/emby/system/info/public
2020-07-08 23:01:36.326 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/System/Info. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; MSAppHost/3.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36 Edge/18.19041
2020-07-08 23:01:36.327 Info HttpServer: HTTP Response 200 to 192.168.1.74. Time: 1ms. http://192.168.1.66:8096/emby/System/Info
2020-07-08 23:01:36.333 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/DisplayPreferences/usersettings?userId=f4d38bae52fe46b984c0d459c777ea31&client=emby. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; MSAppHost/3.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36 Edge/18.19041
2020-07-08 23:01:36.336 Info HttpServer: HTTP Response 200 to 192.168.1.74. Time: 2ms. http://192.168.1.66:8096/emby/DisplayPreferences/usersettings?userId=f4d38bae52fe46b984c0d459c777ea31&client=emby
2020-07-08 23:01:36.385 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/Sync/Items/Ready?TargetId=08giYVaKg3Yf9YUrSNdZiqriFAeRvLnlnASsjw6vSw0. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; MSAppHost/3.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36 Edge/18.19041
2020-07-08 23:01:36.387 Info HttpServer: HTTP Response 200 to 192.168.1.74. Time: 1ms. http://192.168.1.66:8096/emby/Sync/Items/Ready?TargetId=08giYVaKg3Yf9YUrSNdZiqriFAeRvLnlnASsjw6vSw0
2020-07-08 23:01:36.390 Info HttpServer: HTTP POST http://192.168.1.66:8096/emby/Sync/Data. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; MSAppHost/3.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36 Edge/18.19041
2020-07-08 23:01:36.391 Info HttpServer: HTTP Response 200 to 192.168.1.74. Time: 1ms. http://192.168.1.66:8096/emby/Sync/Data
2020-07-08 23:01:36.577 Info HttpServer: HTTP GET http://emby.cassland.org:8096/emby/system/info/public. UserAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; MSAppHost/3.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.102 Safari/537.36 Edge/18.19041
2020-07-08 23:01:36.577 Info HttpServer: HTTP Response 200 to 2a02:8010:f01e::74. Time: 0ms. http://emby.cassland.org:8096/emby/system/info/public
2020-07-08 23:01:45.262 Info HttpServer: HTTP POST http://192.168.1.66:8096/emby/Sessions/Playing/Progress. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:01:45.290 Info HttpServer: HTTP Response 204 to 192.168.1.11. Time: 28ms. http://192.168.1.66:8096/emby/Sessions/Playing/Progress
2020-07-08 23:01:56.121 Info HttpServer: HTTP POST http://192.168.1.66:8096/emby/Sessions/Playing/Progress. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:01:56.125 Info HttpServer: HTTP Response 204 to 192.168.1.11. Time: 4ms. http://192.168.1.66:8096/emby/Sessions/Playing/Progress
2020-07-08 23:02:04.553 Info HttpServer: HTTP Response 200 to 192.168.1.11. Time: 55320ms. http://192.168.1.66:8096/emby/Videos/2422882/stream.mp4?static=true&mediaSourceId=1bccf42264b690b7d5dbfb79bb07fbaf
2020-07-08 23:02:07.713 Info HttpServer: HTTP POST http://192.168.1.66:8096/emby/Sessions/Playing/Progress. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:02:07.718 Info HttpServer: HTTP Response 204 to 192.168.1.11. Time: 6ms. http://192.168.1.66:8096/emby/Sessions/Playing/Progress
2020-07-08 23:02:07.792 Info HttpServer: HTTP POST http://192.168.1.66:8096/emby/Sessions/Playing/Stopped. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:02:07.793 Info SessionManager: Playback stopped reported by app Roku SG 4.0.7 playing s00e99 A Mug's Game - tx3g subs . Stopped at 54000 ms

It looks like an error happens in the stream and it starts transcoding and that stops the subtitles? Does that sound like what is happening? I can only go off the logs to try to guess the cause.

2020-07-08 23:02:07.800 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/Sessions?deviceId=c4eb6879-73b0-5b60-a338-fdfa7a98ab72. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:02:07.801 Info HttpServer: HTTP Response 200 to 192.168.1.11. Time: 1ms. http://192.168.1.66:8096/emby/Sessions?deviceId=c4eb6879-73b0-5b60-a338-fdfa7a98ab72
2020-07-08 23:02:08.556 Info HttpServer: HTTP GET http://192.168.1.66:8096/emby/Users/13f5e6dfe73248e7a18e47e0b4796950/Items/2422882?fields=Overview. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:02:08.561 Info HttpServer: HTTP Response 200 to 192.168.1.11. Time: 5ms. http://192.168.1.66:8096/emby/Users/13f5e6dfe73248e7a18e47e0b4796950/Items/2422882?fields=Overview
2020-07-08 23:02:08.836 Info HttpServer: HTTP POST http://192.168.1.66:8096/emby/Items/2422882/PlaybackInfo?UserId=13f5e6dfe73248e7a18e47e0b4796950&isplayback=false&maxstreamingbitrate=10000001&starttimeticks=00000000. UserAgent: Roku/DVP-9.30 (509.30E04172A)
2020-07-08 23:02:08.965 Info MediaInfoService: User policy for Home. EnablePlaybackRemuxing: True EnableVideoPlaybackTranscoding: True EnableAudioPlaybackTranscoding: True
2020-07-08 23:02:08.965 Info MediaInfoService: RemoteClientBitrateLimit: 4000000, RemoteIp: 192.168.1.11, IsInLocalNetwork: True
2020-07-08 23:02:08.966 Info MediaInfoService: RemoteClientBitrateLimit: 4000000, RemoteIp: 192.168.1.11, IsInLocalNetwork: True
2020-07-08 23:02:08.966 Info MediaInfoService: RemoteClientBitrateLimit: 4000000, RemoteIp: 192.168.1.11, IsInLocalNetwork: True
2020-07-08 23:02:08.966 Info HttpServer: HTTP Response 200 to 192.168.1.11. Time: 130ms. http://192.168.1.66:8096/emby/Items/2422882/PlaybackInfo?UserId=13f5e6dfe73248e7a18e47e0b4796950&isplayback=false&maxstreamingbitrate=10000001&starttimeticks=00000000

Then the fallback above occurs.

Edited July 8, 2020 by speechles

[pwhodges 1519]

Well, as I said, no ffmpeg log was present - I thought that meant no transcoding or remuxing was happening.  I'm pretty sure this failure of these particular subtitles has started since the recent troublesome Roku FW update.

Paul

(PS: FYI, the machine with IP ending in 74 is my desktop, which simply had Emby web open on it.)

[Luke 36991]

Are you still able to reproduce this?

[pwhodges 1519]

Yes, the problem remains with the latest server and Roku betas.  Log attached (last item played, no ffmpeg log).

Paul

embyserver.txt

[Luke 36991]

Can you supply a copy of the media info from the web app for this file? thanks.

[pwhodges 1519]

Download link sent by PM in case that helps.

Paul

Edited July 24, 2020 by pwhodges

[Luke 36991]

Can you send the video to @speechles as well. Thanks.

[pwhodges 1519]

Done.

Paul