Roku autoplay next episode has suddenly stopped working

[Jdmoody1980 1]

A few days ago, auto play next episode went bonkers. Sometimes it advances, but rarely played more than 2 in a row. They are the same episodes I have played for years at night while sleeping. All of the sudden they stop with 2 seconds remaining. If you hit the right arrow on the remote it advances with no issues, otherwise it just sits with a blank black screen, and 2 seconds remaining. 

[ebr 14913]

Hi there, let's look at an example. Please attach the information requested in how to report a media playback issue. Thanks!

Also, confirm that you don't have the "Still watching prompt" enabled in the app settings.

[daryl362 0]

I'm able to corroborate, this just started happening to me this week as well. It has been intermittent but I can specifically point to the episode "The Return" on my logs concluding at 22:07 as an instance where it happened.

embyserver-63802771200.txt

ffmpeg-transcode-c8f4483d-862d-48b4-ae7e-e171eadced71_1.txt

 

Edited October 31, 2022 by daryl362

[rotational467 31]

My wife started seeing this last week, need to confirm but I believe it's working correctly again on a 3800X stick after updating to 11.5 build 4235 and Emby app 4.0.69.

[ebr 14913]

1 hour ago, rotational467 said:

need to confirm but I believe it's working correctly again on a 3800X stick after updating to 11.5 build 4235

@Jdmoody1980 can you see if there is a firmware update for your device?

[rotational467 31]

My wife reports this is still happening, and I seem to have reproduced it earlier today (unable to get logs right now).  Here's what happened:

Server 4.7.9.0 on ubuntu 20.04

Roku OS 11.5.4235, emby app 4.0.69

Open app -> TV shows -> Pick show -> Pick season -> Pick episode (note: episode was in-progress, resumed from where left off)

Playback stops on black screen with 3 seconds remaining.  No UI popups or anything.

Use on-screen controls to manually advance to next episode.

Next 4-5 episodes autoplay correctly.

Between her and I, we've now seen this behavior randomly on different shows and on different Roku devices (but all running same versions), all on local network with emby.  It seems to have "just started" out of nowhere a few weeks ago, (Emby server 4.7.8.0, Roku app 4.0.67, Roku OS 11.0.whatever it was) and didn't coincide with any Roku OS or app update or emby server update.  Everything had been on their respective versions for some time when it started, and the problem persists on latest release versions.  There doesn't seem to be any consistency as to when it occurs - except it seems to happen to her way more than me of course, to make sure I get in maximum trouble 

[speechles 1917]

Hmm...

    ' hang at end detection
    if m.player.state = "buffering"

We do have this in the app. When directstreaming/transcoding sometimes HLS can get confused about runtime length when the audio is direct streamed and the video is converted. But as you see our current hang at end detection works when the client requests extra packets which do not really exist when using HLS. It only prevents a hang if the player starts buffering. It should never hang anytime else.

This means you must be Direct Playing and it hangs?? We have never seen this happen before.

Can you share a screen shot of what the Stats-for-Nerds shows when enabled in the Roku app? Also, If any ffmpeg log is created for that same session can you share that too.

 

Edited November 9, 2022 by speechles

[rotational467 31]

Hey @speechles, I'll try to do some controlled tests + log gathering later today.  Tired of wife aggro

We've seen this regardless of playback method (note this is always local media) - direct playback, H.265 -> H.264, and transcodes due to subs.  So far I can't find any common thread except for the client being a Roku device.

I did catch another instance late last night, I had left a show running in my office and came back to find it was stopped at 2 seconds remaining with the network's title card on screen, so it doesn't seem to be only on black.  On the server side, the Dashboard indicated the session was active but the timer wasn't running.  User Sessions (via emby diag plugin) also showed the transcode active (H.265 to H.264 and PGS sub overlay) and the timer not progressing.  It was super late though and I just had to shut everything down, no time for troubleshooting.

[ebr 14913]

3 minutes ago, rotational467 said:

I did catch another instance late last night, I had left a show running in my office and came back to find it was stopped at 2 seconds remaining with the network's title card on screen, so it doesn't seem to be only on black.  On the server side, the Dashboard indicated the session was active but the timer wasn't running.  User Sessions (via emby diag plugin) also showed the transcode active (H.265 to H.264 and PGS sub overlay) and the timer not progressing.  It was super late though and I just had to shut everything down, no time for troubleshooting.

Hi. There should have been an ffmpeg log from that.  Can you find it?

[rotational467 31]

@ebrlet me get fresh logs today.  I forgot that the last episode that tried to start last night ended up failing with the same behavior I've seen discussed on here as an issue with "range requests" (also why I gave up and turned everything off and went to bed!).  I've included that log since I've got it, but I can't be sure which ffmpeg log is the right one for the stalled playback at end and don't want to send anyone down any rabbit holes.

ffmpeg-transcode-a36126b5-fd7e-44de-afc3-149c3959db33_1.txt

Edited November 9, 2022 by rotational467

[speechles 1917]

23:38:06.397 subtitle input filter: decoding size 1920x1080
23:38:06.397 Auto-inserting subfeed filter
23:38:06.397 Auto-inserting graphicsub2video filter
23:38:06.397 Impossible to convert between the formats supported by the filter 'hwupload@f4' and the filter 'auto_scale_0'
23:38:06.398 Error reinitializing filters!
23:38:06.398 Failed to inject frame into filter network: Function not implemented
23:38:06.398 Error while processing the decoded data for stream #0:2
23:38:06.400 [aac @ 0x1e8da00] Qavg: 21704.059
23:38:06.400 [aac @ 0x1e8da00] 2 frames left in the queue on closing
23:38:06.405 Conversion failed!

It is something having to do with the subtitles and the inability to scale them.

 

 

[rotational467 31]

@ebr @speechles

OK, I just restarted Emby and was able to reproduce it:

Open app -> TV Shows -> Show -> Season -> Episode

Episode plays normally (skip intro is used), currently playback is frozen with 3 seconds remaining.  Note that both server and client believe media is in a playing state - emby screenshot attached, and roku on-screen control offers pause, not play.  Stats for Nerds only shows the same transcoding information as the server screenshot.

Transcoding was finished with a good 15+ minutes remaining in the episode.  I've  been collecting info and writing this post for a good 10 minutes since it froze, with no change in any of the above, and the embyserver log is continuing to print the following messages (I assume it's why the server thinks it's still playing):

2022-11-09 16:48:15.517 Info Server: http/1.1 GET http://192.168.2.5:8096/emby/videos/3345/hls1/main/424.ts?PlaySessionId=119eaf126c19472284d5e63327bb3e7b. Accept=*/*, Host=192.168.2.5:8096, User-Agent=Roku/DVP-11.5 (11.5.0.4235-55), CMCD-Session=st=v,pr=0,sf=h,sid="PL01-e9fa83d470a8b099",cid="3778721911", CMCD-Object=ot=av,br=12321,tb=12321,d=651, CMCD-Request=mtp=111500,su,bl=2700,nor="424.ts%3FPlaySessionId%3D119eaf126c19472284d5e63327bb3e7b"
2022-11-09 16:48:15.518 Info Server: http/1.1 Response 200 to host2. Time: 1ms. http://192.168.2.5:8096/emby/videos/3345/hls1/main/424.ts?PlaySessionId=119eaf126c19472284d5e63327bb3e7b

 

ffmpeg-transcode-446dc579-2421-419f-9d4e-a23854fcb8d3_1.txt embyserver.txt

[rotational467 31]

Possibly interesting or not - after the Roku screensaver kicked in, Emby is aware the device is idle but thinks the media is playing, which I assume should be an impossible state.

The thumbnail also changed to a still from that episode, and the transcoding position is displaying differently as well.

[ebr 14913]

Okay, I don't believe this actually has anything to do with auto play of episodes.  It is simply a playback issue with these items.

@softworkz

[softworkz 3335]

What these two screenshots tell is that playback has proceeded to the end, but the client hasn't reported playback to be stopped.

The ffmpeg log seems to correspond to the image from the same post. It shows a completed transcode of the whole file from start to end without error.

I don't know the circumstances of how it came to the second screenshot, but what it tells is that playback has reached the end of the file (again, without the client having reported playback stop) but here another transcode run has happened which started somewhere between 5-10% before the end and has run (completed) to the end.

[ebr 14913]

8 hours ago, softworkz said:

playback has reached the end of the file

Not quite.  It looks like the player has hung a few seconds from the end.  Could this be the range requests issue the user mentioned above?

[softworkz 3335]

2 minutes ago, ebr said:

It looks like the player has hung a few seconds from the end.

How do you come to the conclusion? The position is shown as 21:12 which is exactly the end position.

[rotational467 31]

I will attempt to reproduce again today with debug logging enabled and using different media files.

[softworkz 3335]

Not needed. I'm seeing the issue.

[ebr 14913]

3 hours ago, softworkz said:

How do you come to the conclusion?

Based on the user reports in this thread.  

3 hours ago, softworkz said:

Not needed. I'm seeing the issue.

So you have found a problem?

[softworkz 3335]

The server has sent a playlist to the client with one more segment than was actually produced. In those cases, the server sends an empty (200) response for that last non-existing segment. This had usually been working so far, but in this case, the Roku seems to be not satisfied with the empty response and keeps desperately trying to download that segment.

[pwhodges 1530]

Is this the business I reported where the video stream was shorter than the audio or subtitle stream?

Paul

[softworkz 3335]

8 hours ago, pwhodges said:

Is this the business I reported where the video stream was shorter than the audio or subtitle stream?

No, this is different. There server calculates the segment count by dividing by 3.000s and the actual segments output are 3.003s long due to the video time base.

[softworkz 3335]

On 11/10/2022 at 6:30 PM, ebr said:

On 11/10/2022 at 3:19 PM, softworkz said:

Not needed. I'm seeing the issue.

So you have found a problem?

The next beta will serve a special mpegts segment with null packets instead of "nothing" (zero length response). Hopefully this will satisfy the Roku.

[softworkz 3335]

On 11/18/2022 at 7:21 AM, softworkz said:

The next beta will serve a special mpegts segment with null packets instead of "nothing" (zero length response). Hopefully this will satisfy the Roku.

I'm sorry. It's not in the new beta. @Luke will have to explain why.