Episode loops after resuming

[mdsib]

Describe the bug
When I open up the app and resume an episode of a tv show, once it's over it'll keep on playing a little bit ahead of where I initially resumed it. It'll keep on doing this, getting closer and closer to starting at the end until it eventually ends. When this is happening, it shows the correct runtime and 0 seconds left. in the show. I can pause and resume it.

FWIW, I tested this just now on unstable, but it was happening on the most recent release as well.
Roku TV: C205X
Hisense model 55R6+
Software version 11.0.0 build 4193-94

To Reproduce

1. I have autoplay next episode turned off, you might need to do that.
2. Start an episode, and seek to near the end of it.
3. Quit out of the app and start it again.
4. Resume the show.
5. Instead of the show ending and kicking you back the the home page, it does the weird loop thing.

Expected behavior
It shouldn't loop.

Logs

/videos/96d8f521-10a3-8d2c-c95b-bf8f3f0b944b/hls1/main/436.ts

{"Protocol":0,"Id":"96d8f52110a38d2cc95bbf8f3f0b944b","Path":"x/y/z.mkv","EncoderPath":null,"EncoderProtocol":null,"Type":0,"Container":"mkv,webm","Size":460171424,"Name":"z","IsRemote":false,"ETag":"30f1488516d30bd4673be2a277daeb8f","RunTimeTicks":13095680000,"ReadAtNativeFramerate":false,"IgnoreDts":false,"IgnoreIndex":false,"GenPtsInput":false,"SupportsTranscoding":true,"SupportsDirectStream":true,"SupportsDirectPlay":true,"IsInfiniteStream":false,"RequiresOpening":false,"OpenToken":null,"RequiresClosing":false,"LiveStreamId":null,"BufferMs":null,"RequiresLooping":false,"SupportsProbing":true,"VideoType":0,"IsoType":null,"Video3DFormat":null,"MediaStreams":[{"Codec":"hevc","CodecTag":null,"Language":null,"ColorRange":null,"ColorSpace":"bt709","ColorTransfer":"bt709","ColorPrimaries":"bt709","DvVersionMajor":null,"DvVersionMinor":null,"DvProfile":null,"DvLevel":null,"RpuPresentFlag":null,"ElPresentFlag":null,"BlPresentFlag":null,"DvBlSignalCompatibilityId":null,"Comment":null,"TimeBase":"1/1000","CodecTimeBase":null,"Title":null,"VideoRange":"SDR","VideoRangeType":"SDR","VideoDoViTitle":null,"LocalizedUndefined":null,"LocalizedDefault":null,"LocalizedForced":null,"LocalizedExternal":null,"DisplayTitle":"1080p HEVC SDR","NalLengthSize":null,"IsInterlaced":false,"IsAVC":null,"ChannelLayout":null,"BitRate":2811134,"BitDepth":10,"RefFrames":1,"PacketLength":null,"Channels":null,"SampleRate":null,"IsDefault":true,"IsForced":false,"Height":1080,"Width":1920,"AverageFrameRate":23.976025,"RealFrameRate":23.976025,"Profile":"Main 10","Type":1,"AspectRatio":"16:9","Index":0,"Score":null,"IsExternal":false,"DeliveryMethod":null,"DeliveryUrl":null,"IsExternalUrl":null,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"Path":null,"PixelFormat":"yuv420p10le","Level":120,"IsAnamorphic":null},{"Codec":"ass","CodecTag":null,"Language":"eng","ColorRange":null,"ColorSpace":null,"ColorTransfer":null,"ColorPrimaries":null,"DvVersionMajor":null,"DvVersionMinor":null,"DvProfile":null,"DvLevel":null,"RpuPresentFlag":null,"ElPresentFlag":null,"BlPresentFlag":null,"DvBlSignalCompatibilityId":null,"Comment":null,"TimeBase":"1/1000","CodecTimeBase":null,"Title":null,"VideoRange":null,"VideoRangeType":null,"VideoDoViTitle":null,"LocalizedUndefined":"Undefined","LocalizedDefault":"Default","LocalizedForced":"Forced","LocalizedExternal":"External","DisplayTitle":"English - ASS","NalLengthSize":null,"IsInterlaced":false,"IsAVC":null,"ChannelLayout":null,"BitRate":null,"BitDepth":null,"RefFrames":null,"PacketLength":null,"Channels":null,"SampleRate":null,"IsDefault":false,"IsForced":false,"Height":null,"Width":null,"AverageFrameRate":null,"RealFrameRate":null,"Profile":null,"Type":2,"AspectRatio":null,"Index":1,"Score":null,"IsExternal":false,"DeliveryMethod":null,"DeliveryUrl":null,"IsExternalUrl":null,"IsTextSubtitleStream":true,"SupportsExternalStream":true,"Path":null,"PixelFormat":null,"Level":0,"IsAnamorphic":null},{"Codec":"ac3","CodecTag":null,"Language":null,"ColorRange":null,"ColorSpace":null,"ColorTransfer":null,"ColorPrimaries":null,"DvVersionMajor":null,"DvVersionMinor":null,"DvProfile":null,"DvLevel":null,"RpuPresentFlag":null,"ElPresentFlag":null,"BlPresentFlag":null,"DvBlSignalCompatibilityId":null,"Comment":null,"TimeBase":"1/1000","CodecTimeBase":null,"Title":null,"VideoRange":null,"VideoRangeType":null,"VideoDoViTitle":null,"LocalizedUndefined":null,"LocalizedDefault":null,"LocalizedForced":null,"LocalizedExternal":null,"DisplayTitle":"Dolby Digital - Stereo - Default","NalLengthSize":null,"IsInterlaced":false,"IsAVC":null,"ChannelLayout":"stereo","BitRate":512000,"BitDepth":null,"RefFrames":null,"PacketLength":null,"Channels":2,"SampleRate":48000,"IsDefault":true,"IsForced":false,"Height":null,"Width":null,"AverageFrameRate":null,"RealFrameRate":null,"Profile":null,"Type":0,"AspectRatio":null,"Index":2,"Score":null,"IsExternal":false,"DeliveryMethod":null,"DeliveryUrl":null,"IsExternalUrl":null,"IsTextSubtitleStream":false,"SupportsExternalStream":false,"Path":null,"PixelFormat":null,"Level":0,"IsAnamorphic":null}],"MediaAttachments":[],"Formats":[],"Bitrate":3323134,"Timestamp":null,"RequiredHttpHeaders":{},"TranscodingUrl":null,"TranscodingSubProtocol":null,"TranscodingContainer":null,"AnalyzeDurationMs":null,"DefaultAudioStreamIndex":null,"DefaultSubtitleStreamIndex":null}

/usr/bin/ffmpeg -analyzeduration 200M -ss 00:21:48.000 -f matroska,webm -autorotate 0 -i file:"x/y/z.mkv" -map_metadata -1 -map_chapters -1 -threads 8 -map 0:0 -map 0:2 -map -0:s -codec:v:0 libx264 -preset superfast -crf 23 -maxrate 9370447 -bufsize 18740894 -profile:v:0 high -level 41 -x264opts:0 subme=0:me_range=4:rc_lookahead=10:me=dia:no_chroma_me:8x8dct=0:partitions=none -force_key_frames:0 "expr:gte(t,1308+n_forced*3)" -sc_threshold:v:0 0 -vf "setparams=color_primaries=bt709:color_trc=bt709:colorspace=bt709,scale=trunc(min(max(iw\,ih*a)\,min(1920\,1080*a))/2)*2:trunc(min(max(iw/a\,ih)\,min(1920/a\,1080))/2)*2,format=yuv420p" -codec:a:0 copy -copyts -avoid_negative_ts disabled -max_muxing_queue_size 2048 -f hls -max_delay 5000000 -hls_time 3 -hls_segment_type mpegts -start_number 436 -hls_segment_filename "/dev/shm/1595/jellyfin/transcodes/66d16627689cb47948ec167cb39b72f7%d.ts" -hls_playlist_type vod -hls_list_size 0 -y "/dev/shm/1595/jellyfin/transcodes/66d16627689cb47948ec167cb39b72f7.m3u8"


ffmpeg version 4.4.2 Copyright (c) 2000-2021 the FFmpeg developers
  built with gcc 11.3.0 (Gentoo Hardened 11.3.0 p4)
  configuration: --prefix=/usr --libdir=/usr/lib64 --shlibdir=/usr/lib64 --docdir=/usr/share/doc/ffmpeg-4.4.2/html --mandir=/usr/share/man --enable-shared --cc=x86_64-pc-linux-gnu-gcc --cxx=x86_64-pc-linux-gnu-g++ --ar=x86_64-pc-linux-gnu-ar --nm=x86_64-pc-linux-gnu-nm --strip=x86_64-pc-linux-gnu-strip --ranlib=x86_64-pc-linux-gnu-ranlib --pkg-config=x86_64-pc-linux-gnu-pkg-config --optflags='-O3 -pipe -march=native -mindirect-branch=thunk' --extra-libs= --disable-static --enable-avfilter --enable-avresample --disable-stripping --disable-optimizations --disable-libcelt --enable-nonfree --disable-indev=v4l2 --disable-outdev=v4l2 --disable-indev=alsa --disable-indev=oss --disable-indev=jack --disable-indev=sndio --disable-outdev=alsa --disable-outdev=oss --disable-outdev=sndio --enable-bzlib --disable-runtime-cpudetect --disable-debug --disable-gcrypt --enable-gnutls --disable-gmp --enable-gpl --disable-hardcoded-tables --enable-iconv --disable-libxml2 --disable-lzma --enable-network --disable-opencl --enable-openssl --enable-postproc --disable-libsmbclient --disable-ffplay --disable-sdl2 --disable-vaapi --disable-vdpau --disable-vulkan --disable-xlib --disable-libxcb --disable-libxcb-shm --disable-libxcb-xfixes --enable-zlib --disable-libcdio --disable-libiec61883 --disable-libdc1394 --disable-libcaca --disable-openal --disable-opengl --disable-libv4l2 --disable-libpulse --disable-libdrm --disable-libjack --disable-libopencore-amrwb --disable-libopencore-amrnb --disable-libcodec2 --enable-libdav1d --disable-libfdk-aac --disable-libopenjpeg --enable-libbluray --disable-libgme --disable-libgsm --disable-libaribb24 --disable-mmal --disable-libmodplug --disable-libopus --disable-libilbc --disable-librtmp --disable-libssh --disable-libspeex --disable-libsrt --disable-librsvg --disable-ffnvcodec --enable-libvorbis --disable-libvpx --disable-libzvbi --disable-appkit --disable-libbs2b --enable-chromaprint --disable-cuda-llvm --disable-libflite --disable-frei0r --disable-libvmaf --disable-libfribidi --disable-fontconfig --disable-ladspa --enable-libass --disable-libtesseract --disable-lv2 --disable-libfreetype --disable-libvidstab --disable-librubberband --disable-libzmq --disable-libzimg --disable-libsoxr --enable-pthreads --disable-amf --disable-libvo-amrwbenc --disable-libkvazaar --disable-libaom --enable-libmp3lame --disable-libopenh264 --disable-librav1e --disable-libsnappy --disable-libsvtav1 --disable-libtheora --disable-libtwolame --disable-libwebp --enable-libx264 --enable-libx265 --disable-libxvid --disable-gnutls --disable-armv5te --disable-armv6 --disable-armv6t2 --disable-neon --disable-vfp --disable-vfpv3 --disable-armv8 --disable-mipsdsp --disable-mipsdspr2 --disable-mipsfpu --disable-altivec --disable-vsx --disable-power8 --disable-amd3dnow --disable-amd3dnowext --disable-fma4 --disable-xop --enable-pic --cpu=host --disable-doc --disable-htmlpages --enable-manpages
  libavutil      56. 70.100 / 56. 70.100
  libavcodec     58.134.100 / 58.134.100
  libavformat    58. 76.100 / 58. 76.100
  libavdevice    58. 13.100 / 58. 13.100
  libavfilter     7.110.100 /  7.110.100
  libavresample   4.  0.  0 /  4.  0.  0
  libswscale      5.  9.100 /  5.  9.100
  libswresample   3.  9.100 /  3.  9.100
  libpostproc    55.  9.100 / 55.  9.100
Input #0, matroska,webm, from 'x/y/z.mkv':
  Metadata:
    CREATION_TIME   : 2017-11-19T03:59:45Z
    ENCODER         : Lavf57.7.2
  Duration: 00:21:49.57, start: 0.000000, bitrate: 2811 kb/s
  Stream #0:0: Video: hevc (Main 10), yuv420p10le(tv, bt709), 1920x1080 [SAR 1:1 DAR 16:9], 23.98 fps, 23.98 tbr, 1k tbn, 25 tbc (default)
    Metadata:
      BPS             : 2297137
      BPS-eng         : 2297137
      DURATION        : 00:21:49.517000000
      DURATION-eng    : 00:21:49.517000000
      NUMBER_OF_FRAMES: 31397
      NUMBER_OF_FRAMES-eng: 31397
      NUMBER_OF_BYTES : 376017650
      NUMBER_OF_BYTES-eng: 376017650
      _STATISTICS_WRITING_APP: mkvmerge v18.0.0 ('Apricity') 64-bit
      _STATISTICS_WRITING_APP-eng: mkvmerge v18.0.0 ('Apricity') 64-bit
      _STATISTICS_WRITING_DATE_UTC: 2017-12-25 04:16:35
      _STATISTICS_WRITING_DATE_UTC-eng: 2017-12-25 04:16:35
      _STATISTICS_TAGS: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
  Stream #0:1(eng): Subtitle: ass
    Metadata:
      BPS             : 154
      BPS-eng         : 154
      DURATION        : 00:21:04.544000000
      DURATION-eng    : 00:21:04.544000000
      NUMBER_OF_FRAMES: 447
      NUMBER_OF_FRAMES-eng: 447
      NUMBER_OF_BYTES : 24369
      NUMBER_OF_BYTES-eng: 24369
      _STATISTICS_WRITING_APP: mkvmerge v18.0.0 ('Apricity') 64-bit
      _STATISTICS_WRITING_APP-eng: mkvmerge v18.0.0 ('Apricity') 64-bit
      _STATISTICS_WRITING_DATE_UTC: 2017-12-25 04:16:35
      _STATISTICS_WRITING_DATE_UTC-eng: 2017-12-25 04:16:35
      _STATISTICS_TAGS: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
  Stream #0:2: Audio: ac3, 48000 Hz, stereo, fltp, 512 kb/s (default)
    Metadata:
      BPS             : 512000
      BPS-eng         : 512000
      DURATION        : 00:21:49.568000000
      DURATION-eng    : 00:21:49.568000000
      NUMBER_OF_FRAMES: 40924
      NUMBER_OF_FRAMES-eng: 40924
      NUMBER_OF_BYTES : 83812352
      NUMBER_OF_BYTES-eng: 83812352
      _STATISTICS_WRITING_APP: mkvmerge v18.0.0 ('Apricity') 64-bit
      _STATISTICS_WRITING_APP-eng: mkvmerge v18.0.0 ('Apricity') 64-bit
      _STATISTICS_WRITING_DATE_UTC: 2017-12-25 04:16:35
      _STATISTICS_WRITING_DATE_UTC-eng: 2017-12-25 04:16:35
      _STATISTICS_TAGS: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
      _STATISTICS_TAGS-eng: BPS DURATION NUMBER_OF_FRAMES NUMBER_OF_BYTES
Stream mapping:
  Stream #0:0 -> #0:0 (hevc (native) -> h264 (libx264))
  Stream #0:2 -> #0:1 (copy)
Press [q] to stop, [?] for help
[libx264 @ 0x5557e95d7980] using SAR=1/1
[libx264 @ 0x5557e95d7980] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX FMA3 BMI2 AVX2
[libx264 @ 0x5557e95d7980] profile Main, level 4.1, 4:2:0, 8-bit
[libx264 @ 0x5557e95d7980] 264 - core 164 - H.264/MPEG-4 AVC codec - Copyleft 2003-2022 - http://www.videolan.org/x264.html - options: cabac=1 ref=1 deblock=1:0:0 analyse=0x1:0 me=dia subme=0 psy=1 psy_rd=1.00:0.00 mixed_ref=0 me_range=4 chroma_me=0 trellis=0 8x8dct=0 cqm=0 deadzone=21,11 fast_pskip=1 chroma_qp_offset=0 threads=8 lookahead_threads=1 sliced_threads=0 nr=0 decimate=1 interlaced=0 bluray_compat=0 constrained_intra=0 bframes=3 b_pyramid=2 b_adapt=1 b_bias=0 direct=1 weightb=1 open_gop=0 weightp=1 keyint=250 keyint_min=23 scenecut=0 intra_refresh=0 rc_lookahead=10 rc=crf mbtree=0 crf=23.0 qcomp=0.60 qpmin=0 qpmax=69 qpstep=4 vbv_maxrate=9370 vbv_bufsize=18740 crf_max=0.0 nal_hrd=none filler=0 ip_ratio=1.40 pb_ratio=1.30 aq=1:1.00
Output #0, hls, to '/dev/shm/1595/jellyfin/transcodes/66d16627689cb47948ec167cb39b72f7.m3u8':
  Metadata:
    encoder         : Lavf58.76.100
  Stream #0:0: Video: h264, yuv420p(tv, bt709, progressive), 1920x1080 [SAR 1:1 DAR 16:9], q=2-31, 23.98 fps, 90k tbn (default)
    Metadata:
      encoder         : Lavc58.134.100 libx264
    Side data:
      cpb: bitrate max/min/avg: 9370000/0/0 buffer size: 18740000 vbv_delay: N/A
  Stream #0:1: Audio: ac3, 48000 Hz, stereo, fltp, 512 kb/s (default)
frame=    1 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A speed=   0x    
[hls @ 0x5557e95d44c0] Opening '/dev/shm/1595/jellyfin/transcodes/66d16627689cb47948ec167cb39b72f7436.ts' for writing
frame=   36 fps=0.0 q=-1.0 Lsize=N/A time=00:00:00.54 bitrate=N/A speed=0.929x    
video:571kB audio:128kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: unknown
[libx264 @ 0x5557e95d7980] frame I:1     Avg QP:17.46  size: 96986
[libx264 @ 0x5557e95d7980] frame P:10    Avg QP:19.18  size: 31088
[libx264 @ 0x5557e95d7980] frame B:25    Avg QP:20.91  size:  7029
[libx264 @ 0x5557e95d7980] consecutive B-frames:  5.6%  5.6%  0.0% 88.9%
[libx264 @ 0x5557e95d7980] mb I  I16..4: 24.1%  0.0% 75.9%
[libx264 @ 0x5557e95d7980] mb P  I16..4: 17.5%  0.0%  0.0%  P16..4: 58.6%  0.0%  0.0%  0.0%  0.0%    skip:24.0%
[libx264 @ 0x5557e95d7980] mb B  I16..4:  1.4%  0.0%  0.0%  B16..8: 20.6%  0.0%  0.0%  direct: 8.8%  skip:69.2%  L0:31.6% L1:59.3% BI: 9.0%
[libx264 @ 0x5557e95d7980] coded y,uvDC,uvAC intra: 40.2% 55.7% 18.3% inter: 8.5% 15.2% 0.1%
[libx264 @ 0x5557e95d7980] i16 v,h,dc,p: 38% 28% 10% 24%
[libx264 @ 0x5557e95d7980] i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 26% 29%  8%  8%  6%  4%  7%  4%  8%
[libx264 @ 0x5557e95d7980] i8c dc,h,v,p: 35% 27% 27% 11%
[libx264 @ 0x5557e95d7980] Weighted P-Frames: Y:0.0% UV:0.0%
[libx264 @ 0x5557e95d7980] kb/s:3109.35

Additional context
I've tried it on two series and they both do this to some extent.

[candry7731]

I can NOT Duplicate this issue with the unstable branch.

[mdsib]

Could you apply this patch and let me know what the position is when resuming the episode? I'm just grasping at straws, but I did notice that this is always 0 for me, even in the middle of an episode.

diff --git a/components/JFVideo.brs b/components/JFVideo.brs
index 6816344..f66d853 100644
--- a/components/JFVideo.brs
+++ b/components/JFVideo.brs
@@ -59,6 +59,7 @@ end sub
 ' Report playback to server
 sub ReportPlayback(state = "update" as string)
 
+    print "report playback with state "; state; "and position "; m.top.position
     if m.top.position = invalid then return
 
     params = {

EDIT: Nevermind, I don't think that's it. It looks like it only happens for certain videos.

[pinovecs]

I have experienced it occasionally with select shows. In my case it would loop the last 5-10 seconds. I believe its something to do with the encoding of the video and not the Roku application itself, although it doesn't happen when running on a PC.

[fice-t]

I can reproduce this on v1.6.6 with "autoplay next episode" the default (on). In this case, the "Next Episode" button counts down to 0 and remains displayed ("Next Episode 0") when the loop is playing.

[cewert]

I can reproduce this on v1.6.6 with "autoplay next episode" the default (on). In this case, the "Next Episode" button counts down to 0 and remains displayed ("Next Episode 0") when the loop is playing.

I was able to reproduce this v1.6.6. Countdown for next episode reaches 0, the button stays visible, and the video jumped backwards in time (randomly?). I watched till the end again to see if it would fix itself but it continued to jump backwards in time once it reached the end of the show.

The file was an AVI file so the issue seems to be with transcoded files. AVI xvid AC3 -> TS H264 AAC (stereo)

EDIT: I'm using QSV for hardware accel if that matters:

Stream #0:0 -> #0:0 (mpeg4 (native) -> h264 (h264_qsv))
Stream #0:1 -> #0:1 (ac3 (native) -> aac (libfdk_aac))

[cewert]

@fice-t Can you tell me more about the video that was causing the loop (container, video codec, audio codec)? Was it transcoding?

@mdsib Are you still seeing this on the latest stable version of the app, v1.6.6? If so, are the files similar to the one in the OP, HEVC SDR?

[cewert]

I think this may be caused by playing video files with codecs the device doesn't fully support.

In my case, the only videos doing the loop were AVI MPEG4 videos with AC3 audio. I had playback.mpeg4 turned on (the default), so the files were being transcoded anyway because of the container and audio codec but the video codec remained. I haven't been able to reproduce the issue after disabling playback.mpeg4. The files still transcode but I haven't seen the loop yet.

@fice-t @mdsib Can you guys try disabling all the user settings that attempt to play files the device may not support and see if you can reproduce this issue? These are the settings:

• playback.mpeg4
• playback.mpeg2
• playback.av1
• playback.tryDirect.h264ProfileLevel
• playback.tryDirect.hvecProfileLevel

[mdsib]

@cewert Unfortunately, my Roku TV has died. I can't reproduce anything till that's fixed. Which may be never.

From what I remember, the issue seemed to be related to a race condition between marking the episode as completed and playing the next episode. That's why each loop would be closer to the end - it was the periodic watch time update's latest update before the end of the episode. But that doesn't explain why it was happening when autoplay was off.

[cewert]

This may be fixed by #1941. Please reopen if this is still an issue on the latest version (v2.1.5+)