Playback suddenly stops during transcoding

[Andrea3000 0]

Hi,

I have an issue while playing transcoded media from Emby running in a Docker container on linux.

I have Emby Premiere and have hardware transcoding enabled.

At some point (usually around 10 minutes from the start of the playback) the video stops. From the log I can see the following:

Quote

2022-10-09 14:48:25.742 Info Server: http/1.1 GET http://192.168.1.23:8096/emby/videos/4066/hls1/main/264.ts?PlaySessionId=8703ed5d358d457784591ba001eee111. Accept=*/*, Connection=keep-alive, Host=192.168.1.23:8096, User-Agent=AppleCoreMedia/1.0.0.19F101 (Macintosh; U; Intel Mac OS X 10_15_5; it_it), Accept-Encoding=identity, Accept-Language=it-it, Origin=http://192.168.1.23:8096, Referer=http://192.168.1.23:8096/web/index.html, X-Playback-Session-Id=0A0D2342-970C-4558-95D7-146D515ABB8D
2022-10-09 14:48:25.967 Info Server: http/1.1 Response 200 to host1. Time: 225ms. http://192.168.1.23:8096/emby/videos/4066/hls1/main/264.ts?PlaySessionId=8703ed5d358d457784591ba001eee111
2022-10-09 14:48:26.534 Info Server: http/1.1 POST http://192.168.1.23:8096/emby/Sessions/Playing/Progress?X-Emby-Client=Emby Web&X-Emby-Device-Name=Safari macOS&X-Emby-Device-Id=TW96aWxsYS81LjAgKE1hY2ludG9zaDsgSW50ZWwgTWFjIE9TIFggMTBfMTVfNSkgQXBwbGVXZWJLaXQvNjA1LjEuMTUgKEtIVE1MLCBsaWtlIEdlY2tvKSBWZXJzaW9uLzEzLjEuMSBTYWZhcmkvNjA1LjEuMTV8MTY2MTY5MDk3MTM0Mg11&X-Emby-Client-Version=4.7.8.0&reqformat=json. UserAgent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_5) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.1.1 Safari/605.1.15
2022-10-09 14:48:26.536 Debug SessionManager: OnPlaybackProgress TimeUpdate 8703ed5d358d457784591ba001eee111
2022-10-09 14:48:26.539 Info Server: http/1.1 Response 204 to host1. Time: 5ms. http://192.168.1.23:8096/emby/Sessions/Playing/Progress?X-Emby-Client=Emby Web&X-Emby-Device-Name=Safari macOS&X-Emby-Device-Id=TW96aWxsYS81LjAgKE1hY2ludG9zaDsgSW50ZWwgTWFjIE9TIFggMTBfMTVfNSkgQXBwbGVXZWJLaXQvNjA1LjEuMTUgKEtIVE1MLCBsaWtlIEdlY2tvKSBWZXJzaW9uLzEzLjEuMSBTYWZhcmkvNjA1LjEuMTV8MTY2MTY5MDk3MTM0Mg11&X-Emby-Client-Version=4.7.8.0&reqformat=json
2022-10-09 14:48:28.624 Info Server: http/1.1 GET http://192.168.1.23:8096/emby/videos/4066/hls1/main/265.ts?PlaySessionId=8703ed5d358d457784591ba001eee111. Accept=*/*, Connection=keep-alive, Host=192.168.1.23:8096, User-Agent=AppleCoreMedia/1.0.0.19F101 (Macintosh; U; Intel Mac OS X 10_15_5; it_it), Accept-Encoding=identity, Accept-Language=it-it, Origin=http://192.168.1.23:8096, Referer=http://192.168.1.23:8096/web/index.html, X-Playback-Session-Id=0A0D2342-970C-4558-95D7-146D515ABB8D
2022-10-09 14:48:28.850 Info Server: http/1.1 Response 200 to host1. Time: 226ms. http://192.168.1.23:8096/emby/videos/4066/hls1/main/265.ts?PlaySessionId=8703ed5d358d457784591ba001eee111
2022-10-09 14:48:30.102 Info Server: http/1.1 GET http://192.168.1.23:8096/emby/videos/4066/hls1/main/3624.ts?PlaySessionId=8703ed5d358d457784591ba001eee111. Accept=*/*, Connection=keep-alive, Host=192.168.1.23:8096, User-Agent=AppleCoreMedia/1.0.0.19F101 (Macintosh; U; Intel Mac OS X 10_15_5; it_it), Accept-Encoding=identity, Accept-Language=it-it, Origin=http://192.168.1.23:8096, Referer=http://192.168.1.23:8096/web/index.html, X-Playback-Session-Id=0A0D2342-970C-4558-95D7-146D515ABB8D
2022-10-09 14:48:30.104 Debug App: Returning empty segment at the end.
2022-10-09 14:48:30.106 Info Server: http/1.1 Response 200 to host1. Time: 3ms. http://192.168.1.23:8096/emby/videos/4066/hls1/main/3624.ts?PlaySessionId=8703ed5d358d457784591ba001eee111
 

 

As you can see from the elements I have highlighted in bold, the segments that were being served were increasing up to 265.ts, at which point, instead of continuing with 266.ts, a request is done for 3624.ts that doesn't exist.

I have attached the full server log and transcode log. As you can see from the transcode log, the transcoding (with throttling enabled) got up to the segment 305.ts so there was plenty of buffer ahead of the current playback position.

This happens with all the clients I tried so far (LG WebOS TV and MacOS Safari)

Do you know why this happens and how to fix it?

 

embyserver.txt ffmpeg-transcode-25c3b5ff-9b01-4ae2-bc88-41053ea6a7ef_1.txt

Edited October 9, 2022 by Andrea3000

[Abobader 3470]

Hello Andrea3000,

** This is an auto reply **

Please wait for someone from staff support or our members to reply to you.

It's recommended to provide more info, as it explain in this thread:

Thank you.

Emby Team

[Andrea3000 0]

I just tried again with the same movie to inspect and save a copy of the playlist .m3u8 file before it gets removed. This time it happened earlier in the movie, between segment 102 and 103 (therefore I can exclude a corrupted media).

This is the extract from the log

Quote

2022-10-09 21:07:53.432 Info Server: http/1.1 GET http://192.168.1.23:8096/emby/videos/4066/hls1/main/101.ts?PlaySessionId=7c029710b98b46e9a313bc78c0fa9511. Accept=*/*, Connection=keep-alive, Host=192.168.1.23:8096, User-Agent=AppleCoreMedia/1.0.0.19F101 (Macintosh; U; Intel Mac OS X 10_15_5; it_it), Accept-Encoding=identity, Accept-Language=it-it, Origin=http://192.168.1.23:8096, Referer=http://192.168.1.23:8096/web/index.html, X-Playback-Session-Id=D7994757-C463-47E3-A1BE-F81652898B68
2022-10-09 21:07:53.652 Info Server: http/1.1 Response 200 to host1. Time: 220ms. http://192.168.1.23:8096/emby/videos/4066/hls1/main/101.ts?PlaySessionId=7c029710b98b46e9a313bc78c0fa9511
2022-10-09 21:07:55.271 Debug Server: http/1.1 GET http://192.168.1.23:8096/emby/Sessions?deviceId=TW96aWxsYS81LjAgKE1hY2ludG9zaDsgSW50ZWwgTWFjIE9TIFggMTBfMTVfNSkgQXBwbGVXZWJLaXQvNjA1LjEuMTUgKEtIVE1MLCBsaWtlIEdlY2tvKSBWZXJzaW9uLzEzLjEuMSBTYWZhcmkvNjA1LjEuMTV8MTY2MTY5MDk3MTM0Mg11&X-Emby-Client=Emby Web&X-Emby-Device-Name=Safari macOS&X-Emby-Device-Id=TW96aWxsYS81LjAgKE1hY2ludG9zaDsgSW50ZWwgTWFjIE9TIFggMTBfMTVfNSkgQXBwbGVXZWJLaXQvNjA1LjEuMTUgKEtIVE1MLCBsaWtlIEdlY2tvKSBWZXJzaW9uLzEzLjEuMSBTYWZhcmkvNjA1LjEuMTV8MTY2MTY5MDk3MTM0Mg11&X-Emby-Client-Version=4.7.8.0. UserAgent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_5) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.1.1 Safari/605.1.15
2022-10-09 21:07:55.272 Debug Server: http/1.1 Response 200 to host1. Time: 2ms. http://192.168.1.23:8096/emby/Sessions?deviceId=TW96aWxsYS81LjAgKE1hY2ludG9zaDsgSW50ZWwgTWFjIE9TIFggMTBfMTVfNSkgQXBwbGVXZWJLaXQvNjA1LjEuMTUgKEtIVE1MLCBsaWtlIEdlY2tvKSBWZXJzaW9uLzEzLjEuMSBTYWZhcmkvNjA1LjEuMTV8MTY2MTY5MDk3MTM0Mg11&X-Emby-Client=Emby Web&X-Emby-Device-Name=Safari macOS&X-Emby-Device-Id=TW96aWxsYS81LjAgKE1hY2ludG9zaDsgSW50ZWwgTWFjIE9TIFggMTBfMTVfNSkgQXBwbGVXZWJLaXQvNjA1LjEuMTUgKEtIVE1MLCBsaWtlIEdlY2tvKSBWZXJzaW9uLzEzLjEuMSBTYWZhcmkvNjA1LjEuMTV8MTY2MTY5MDk3MTM0Mg11&X-Emby-Client-Version=4.7.8.0
2022-10-09 21:07:56.789 Info Server: http/1.1 GET http://192.168.1.23:8096/emby/videos/4066/hls1/main/102.ts?PlaySessionId=7c029710b98b46e9a313bc78c0fa9511. Accept=*/*, Connection=keep-alive, Host=192.168.1.23:8096, User-Agent=AppleCoreMedia/1.0.0.19F101 (Macintosh; U; Intel Mac OS X 10_15_5; it_it), Accept-Encoding=identity, Accept-Language=it-it, Origin=http://192.168.1.23:8096, Referer=http://192.168.1.23:8096/web/index.html, X-Playback-Session-Id=D7994757-C463-47E3-A1BE-F81652898B68
2022-10-09 21:07:56.999 Info Server: http/1.1 Response 200 to host1. Time: 210ms. http://192.168.1.23:8096/emby/videos/4066/hls1/main/102.ts?PlaySessionId=7c029710b98b46e9a313bc78c0fa9511
2022-10-09 21:07:58.535 Info Server: http/1.1 GET http://192.168.1.23:8096/emby/videos/4066/hls1/main/3624.ts?PlaySessionId=7c029710b98b46e9a313bc78c0fa9511. Accept=*/*, Connection=keep-alive, Host=192.168.1.23:8096, User-Agent=AppleCoreMedia/1.0.0.19F101 (Macintosh; U; Intel Mac OS X 10_15_5; it_it), Accept-Encoding=identity, Accept-Language=it-it, Origin=http://192.168.1.23:8096, Referer=http://192.168.1.23:8096/web/index.html, X-Playback-Session-Id=D7994757-C463-47E3-A1BE-F81652898B68
2022-10-09 21:07:58.535 Debug App: Returning empty segment at the end.
2022-10-09 21:07:58.535 Info Server: http/1.1 Response 200 to host1. Time: 1ms. http://192.168.1.23:8096/emby/videos/4066/hls1/main/3624.ts?PlaySessionId=7c029710b98b46e9a313bc78c0fa9511

 

Even in this case it is trying to access the segment 3624.ts.

For completeness, this is an extract of the playlist file that shows no reference to segment 3624.ts

Quote

874A5D_100.ts
#EXTINF:3.003011,
874A5D_101.ts
#EXTINF:3.003000,
874A5D_102.ts
#EXTINF:3.003000,
874A5D_103.ts
#EXTINF:3.003000,
874A5D_104.ts
#EXTINF:3.003000,
874A5D_105.ts
#EXTINF:3.003000,

 

I have attached the logs and the playlist.

 

embyserver-2.txt ffmpeg-transcode-d7195f65-3e3e-48e5-8c05-92eeedd4b496_1.txt 874A5D.m3u8

[Andrea3000 0]

How can I debug this further?

As you can see from the logs, I have debug logging already enabled but this doesn’t seem to show where the issue is coming from.

 

Do you have any idea of what’s going on?

[Andrea3000 0]

I tried with Jellyfin and the playback went smoothly until the end.

I have done a quick calculation:

1) The movie duration is 03:01:12.55

2) The duration of each .ts segmet is 3.003s

3) Segment 3624.ts would correspond to 03:01:22.87 which is even past the end of the movie

I'm not quite sure what's happening, it's almost as if the client is trying to seek to end of movie (even past that actually)

 

I also tried with another movie and it also stopped at around 10 minutes of playback (around 22:01 local time). Logs are attached.

ffmpeg-transcode-0d37377d-f61e-4791-be2c-2a8dacbc0520_1.txt embyserver-3.txt