No more subtitles in the web UI

[Marin 20]

Hi,

 

I'm using emby server 3.0.5882.0 on Centos 7 (up to date). Since the last Emby update, subtitles do not work anymore when media are played from the web browser. This happens both in Windows (Edge / Firefox), Windows Phone 10 (Edge) and Linux (latest Firefox on Fedora 23). This was working fine before the update.

 

All my files are MKV files with embedded subs (no external files). Subs are detected by Emby and by the transcoder. The web UI shows controls to select the subs or turn them off, but triggering them does not change anything.

 

Did someone else notice the same problem ?

 

The transcoder log is attached.

 

Thanks!

Log

[Luke 42077]

There's a fix for Edge/IE for the next release, although I'm not aware of any issues in Firefox. I'll take a look but I know I've tested that recently. Thanks.

[Marin 20]

Hi,

 

Yes, I was aware of issues with Edge. I also tested with the new web app: did not work either.

As all my metadata is stored in NFO files, I just removed the whole server package and flushed the whole /var/lib/emby-server directory. I'll reinstall the server from scratch and see what happens.

 

Thanks.

Edited March 17, 2016 by Marin

[Luke 42077]

In the new tv web app everything is fine for me with Edge, no problem found there.

[Marin 20]

I have some news.

 

ffmpeg reports a subtitle extraction failure:

016-03-17 21:40:35.3639 Info HttpServer: HTTP GET http://nice-vsrv-emby-00.core.nice.cloud.olivarim.com:8096/emby/videos/a0d71c8644509c0018656cf024278c0d/hls1/main/931.ts?DeviceId=745ca1ce79be082d4f97fc508257bb212acc38f6&MediaSourceId=a0d71c8644509c0018656cf024278c0d&VideoCodec=h264&AudioCodec=aac&AudioStreamIndex=2&VideoBitrate=31613472&AudioBitrate=320000&MaxAudioChannels=6&Level=41&Profile=high&PlaySessionId=cd84b86e15de47fda29754155ce2b4c5&api_key=18f46e77214f4e4f8e39ebd38bd2f0c6&CopyTimestamps=false. UserAgent: Mozilla/5.0 (Windows Phone 10.0; Android 4.2.1; NOKIA; Lumia 930) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2486.0 Mobile Safari/537.36 Edge/13.10586
2016-03-17 21:40:35.3703 Info HttpServer: HTTP Response 200 to 10.16.5.67. Time: 6ms. http://nice-vsrv-emby-00.core.nice.cloud.olivarim.com:8096/emby/videos/a0d71c8644509c0018656cf024278c0d/hls1/main/931.ts?DeviceId=745ca1ce79be082d4f97fc508257bb212acc38f6&MediaSourceId=a0d71c8644509c0018656cf024278c0d&VideoCodec=h264&AudioCodec=aac&AudioStreamIndex=2&VideoBitrate=31613472&AudioBitrate=320000&MaxAudioChannels=6&Level=41&Profile=high&PlaySessionId=cd84b86e15de47fda29754155ce2b4c5&api_key=18f46e77214f4e4f8e39ebd38bd2f0c6&CopyTimestamps=false
2016-03-17 21:40:35.8241 Info HttpServer: HTTP POST http://nice-vsrv-emby-00.core.nice.cloud.olivarim.com:8096/emby/Sessions/Playing/Stopped. UserAgent: Mozilla/5.0 (Windows Phone 10.0; Android 4.2.1; NOKIA; Lumia 930) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2486.0 Mobile Safari/537.36 Edge/13.10586
2016-03-17 21:40:36.3012 Info App: Killing ffmpeg process for /var/lib/emby-server/transcoding-temp/ae3972ccce7979d0d3b6b904917ed7c3.m3u8
2016-03-17 21:40:36.4065 Info App: FFMpeg exited with code 0
2016-03-17 21:40:36.4065 Info App: Deleting partial stream file(s) /var/lib/emby-server/transcoding-temp/ae3972ccce7979d0d3b6b904917ed7c3.m3u8
2016-03-17 21:40:36.4108 Info HttpServer: HTTP Response 204 to 10.16.5.67. Time: 587ms. http://nice-vsrv-emby-00.core.nice.cloud.olivarim.com:8096/emby/Sessions/Playing/Stopped
2016-03-17 21:40:36.4500 Info HttpServer: HTTP GET http://nice-vsrv-emby-00.core.nice.cloud.olivarim.com:8096/web/. UserAgent: Mozilla/5.0 (Windows Phone 10.0; Android 4.2.1; NOKIA; Lumia 930) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2486.0 Mobile Safari/537.36 Edge/13.10586
2016-03-17 21:40:55.4467 Info SubtitleEncoder: Killing ffmpeg subtitle extraction process
2016-03-17 21:40:55.4982 Info SubtitleEncoder: Deleting extracted subtitle due to failure: /var/lib/emby-server/data/subtitles/d/dadaed41-0075-a362-b4c6-513c62fcbe99.srt
2016-03-17 21:40:55.4993 Error SubtitleEncoder: ffmpeg subtitle extraction failed for file:"/opt/library/movies/Mendes, Sam/American Beauty (1999)/American Beauty - Sam Mendes, 1999 - 1080p - en-US, fr-FR ST en, fr.mkv" to /var/lib/emby-server/data/subtitles/d/dadaed41-0075-a362-b4c6-513c62fcbe99.srt

Yet, permissions are correct:

[marin@nice-vsrv-emby-00 subtitles]$ pwd && ll
/var/lib/emby-server/data/subtitles
total 0
drwxr-xr-x. 2 emby emby  6 17 mars  21:42 1
drwxr-xr-x. 2 emby emby 53 17 mars  21:32 4
drwxr-xr-x. 2 emby emby 53 17 mars  21:32 7
drwxr-xr-x. 2 emby emby 53 17 mars  21:32 c
drwxr-xr-x. 2 emby emby  6 17 mars  21:40 d

I also noticed that the srt file was present (with correct content) in the d/ directory during playback. No subs were shown, though.

 

The full log file is attached. There are lots of error about expired tokens and service errors... Do you have a link to the rpm of the previous version ? I'd like to test it to see if that's a regression.

 

Thanks!

server.txt

Edited March 17, 2016 by Marin

[Luke 42077]

was there a subtitle extraction log? it might not necessarily be a failure but we might have just killed it because it was taking too long. if i had to guess, that might be what's really going on here. we extract internal text-based subtitles on the fly and send them down to the browser as plain text. on some systems, this extraction process can take longer than expected, leading the user to think that subtitles are not working. We only do this once and then the output result is cached on the server for the next use. We won't have to do this forever because chrome and edge have on their roadmap support for internal track switching. but for now it's still the best way.

[Marin 20]

Hi,

 

Yes, there was one. It is attached.

Subs are extracted, as I can see them in the data directory during playback (extracted file is valid). Yet the subtitles are not cached and are deleted by the server, as the server log shows.

I'll make some other tests this evening to see whether subs do appear after some time, but I don't think they will. I'll post full log files afterwoods.

 

Thanks again,

 

Marin.

Edited March 18, 2016 by Marin

[Luke 42077]

It's deleting them because the server thinks the extraction failed - either because it took too long, or ffmpeg exited with an error code.

[Marin 20]

Hi again,

 

I ran two tests on two distinct files. Both files are MKV with embedded SRT subs. The first file is a SD DVD rip, whereas the second one is a 1080p BD Rip. mkvinfo and ffprobe output is attached. My browser is Firefox 45.0 on Fedora 23.

 

The first file played fine and subtitles worked. I played the file from the beginning and even seeked to a random point: subs worked in both cases. However, the server log contains many errors.

 

The second file played fine but without subs. I played the 3 first minutes of the file, never jumped to a random position, but never seen a subtitle.

 

Server, transcode and ffmpeg-subextract logs are attached for both files.

 

This may be related to the issue you were talking about, but I do not understand why it only appears now: those files were playing fine before recent updates. The machine has far more power than needed to play HD movies and I did not change anything except updating Emby.

 

Thanks for your time,

 

Marin.

file1-ffmpeg-subextract.txt

file1-ffmpeg-subextract2.txt

file1-ffprobe.txt

file1-mkvinfo.txt

file1-server.txt

file1-transcode.txt

file1-transcode2.txt

file2-ffmpeg-subextract1.txt

file2-ffmpeg-subextract2.txt

file2-ffprobe.txt

file2-mkvinfo.txt

file2-server.txt

file2-transcode.txt

Edited March 18, 2016 by Marin

[Luke 42077]

We have also updated ffmpeg in recent releases. Sometimes subtitle extraction takes a little bit of time, even on fast machines. That's why external text-based subtitles are always the most efficient.

 

When you see the log line

Killing ffmpeg subtitle extraction process

That's when you know it took too long. What i'm going to do for the next release is increase the kill timeout from two minutes to three, or more. I know what you're thinking, by then you will have given up and stopped the video. But at least if the extraction does succeed, then it will be re-used the next time you play the same title.

 

What I'd also like to do in the future is introduce a scheduled task that can pre-extract these prior to playback.

[Luke 42077]

One interesting thing I notice in your log is two simultaneous extractions for different subtitle streams on the same video:

2016-03-18 20:38:57.1257 Error SubtitleEncoder: ffmpeg subtitle extraction failed for file:"/opt/library/movies/Mendes, Sam/American Beauty (1999)/American Beauty - Sam Mendes, 1999 - 1080p - en-US, fr-FR ST en, fr.mkv" to /var/lib/emby-server/data/subtitles/1/1da11a24-311b-de53-e468-bbf4dcb04a15.srt
2016-03-18 20:38:57.1257 Error SubtitleEncoder: ffmpeg subtitle extraction failed for file:"/opt/library/movies/Mendes, Sam/American Beauty (1999)/American Beauty - Sam Mendes, 1999 - 1080p - en-US, fr-FR ST en, fr.mkv" to /var/lib/emby-server/data/subtitles/d/dadaed41-0075-a362-b4c6-513c62fcbe99.srt

That could definitely hurt extraction performance. What we do with subtitles is we give the video player the urls they can use to download the subtitles in text format. It looks like Firefox is downloading them immediately whether the subtitles are selected or not. I did some testing in Chrome, and it doesn't download them until they're needed, which is more efficient obviously.