Some shows stuck in reset loop when trying to skip forward

Some shows exhibit this bug only when played on either of my TiVo stream 4Ks where the recording starts to play and plays fine if left alone but if you try to fast forward or jump forward the image and audio will jump forward but then the audio gets way out of sync or the image and play bar cursor jumps back to the starting couple seconds of the video. Playing the affected show on iOS or Apple TV devices plays them as normal so it doesn’t seem to be a server issue. Also if I start the show playing from my iPhone and choose for it to play on the TiVo stream from there the TiVo stream plays it fine.

Sorta hard to describe but put a video link below. Any thoughts or information that would help debug the issue?

Can you try finding that recording on the web UI and select Fix Video Timestamps

Performed timestamp fix as requested from the web UI. Pertinent section of the logs afterwards below. Issue still occurring as before. Anything else I can do or provide to help?

2020/09/29 19:00:03.673274 [IDX] Generating video index for job 1601423990-83

2020/09/29 19:41:46.578884 [MTS] Rewriting MPEG-TS timestamps for file-4211: Good Morning America S2020E312 2020-09-29-0659.mpg

2020/09/29 19:44:38.538724 [MTS] Statistics for "Good Morning America S2020E312 2020-09-29-0659.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=0 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=true saw_pmt=true highest_pts=7440.449189

2020/09/29 19:44:38.548670 [MTS] Finished video index generation for file-4211 in 171s

For additional information this has been occurring most mornings on this same recording for Good Morning America.

Any improvement in playback after fixing timestamp?

Can you grab the player logs via http://x:57000/log using the IP of the TiVo right after the issue occurs

No there wasn’t a discernible difference in the issue after the timestamp repair. Logs from the TiVo below.

@tmm1 this is still occurring at least everyday if not on multiple shows per day. The bulk of the offending shows are from my antenna on ABC network but I’ve seen it happen on other networks too. It happens on both my TiVo stream 4Ks and nowhere else in my house (iPads, iPhones, Apple TV’s).

What can I do to help y’all get this fixed? I put the TiVo logs from a recent occurrence. the common theme I see on my logs when this does occur vs when it doesn’t is the increasing dropped count after I try to seek and it resets to the start of the video and the audio gets out of sync. When I jump forward on other shows that work correctly the dropped count is always zero after the jump forward commands.

[ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:32.165 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:32.171 24557 24557 V mpv : seeking by 30.0 from 216.26999999999998
06-14 23:25:32.172 24557 24557 V mpv : command: seek 30.0
06-14 23:25:32.200 24557 24587 V mpv : event: seek
06-14 23:25:32.200 24557 24557 V PlayerActivity: state SEEKING_FORWARD -> SEEKING_FORWARD
06-14 23:25:32.305 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:32.310 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:32.374 24557 24557 V mpv : seeking by 30.0 from 246.26999999999998
06-14 23:25:32.374 24557 24557 V mpv : command: seek 30.0
06-14 23:25:32.374 24557 24557 V PlayerActivity: state SEEKING_FORWARD -> SEEKING_FORWARD
06-14 23:25:32.421 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:32.428 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:32.515 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:32.521 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:32.565 24557 24557 V mpv : seeking by 30.0 from 246.26999999999998
06-14 23:25:32.565 24557 24557 V mpv : command: seek 30.0
06-14 23:25:32.566 24557 24587 V mpv : [lavf] queuing seek to 336.270000
06-14 23:25:32.566 24557 24587 V mpv : [lavf] cached range 0: 57.327633 <-> 63.066700 (bof=0, eof=0)
06-14 23:25:32.566 24557 24587 V mpv : [lavf] cached range 1: 17.220900 <-> 32.456800 (bof=0, eof=0)
06-14 23:25:32.567 24557 24557 V PlayerActivity: state SEEKING_FORWARD -> SEEKING_FORWARD
06-14 23:25:32.624 24557 24587 V mpv : event: seek
06-14 23:25:32.669 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:32.675 24557 24557 V mpvstats: AV: 336.270 A-V: 0.000 Dropped: 0 Cache: 0.000s + 0KB
06-14 23:25:32.677 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:32.780 24557 24557 V mpv : seeking by 30.0 from 336.27
06-14 23:25:32.780 24557 24557 V mpv : command: seek 30.0
06-14 23:25:32.781 24557 24557 V PlayerActivity: state SEEKING_FORWARD -> SEEKING_FORWARD
06-14 23:25:32.914 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:32.921 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:32.925 24557 24587 V mpv : [lavf] queuing seek to 366.270000 (cascade)
06-14 23:25:32.925 24557 24587 V mpv : [lavf] cached range 0: 57.327633 <-> 63.066700 (bof=0, eof=0)
06-14 23:25:32.925 24557 24587 V mpv : [lavf] cached range 1: 17.220900 <-> 32.456800 (bof=0, eof=0)
06-14 23:25:32.988 24557 24587 V mpv : event: seek
06-14 23:25:32.988 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:32.999 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:33.212 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:33.225 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:33.231 24557 24587 V mpv : [lavf] seek done
06-14 23:25:33.231 24557 24587 V mpv : [lavf] execute seek (to 366.342800 flags 4)
06-14 23:25:33.232 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:33.235 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:33.331 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:33.338 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:33.408 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:33.416 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:33.619 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:33.625 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:33.713 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:33.722 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:33.852 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:33.856 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:33.945 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:33.949 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:34.118 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:34.123 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:34.217 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:34.223 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:34.394 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:34.399 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:34.510 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:34.517 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:34.601 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:34.611 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:34.787 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:34.800 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:35.060 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:35.066 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:35.210 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:35.220 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:35.392 24557 24587 D mpv : [ffmpeg] tcp: Starting connection attempt to 192.168.1.145 port 8089
06-14 23:25:35.400 24557 24587 D mpv : [ffmpeg] tcp: Successfully connected to 192.168.1.145 port 8089
06-14 23:25:35.402 24557 24587 V mpv : [lavf] seek done
06-14 23:25:35.473 24557 24587 V mpv : [vd] Decoder format: 1920x1080 mediacodec auto/auto/auto/auto/auto CL=unknown (auto 0.000000/0.000000/0.000000)
06-14 23:25:35.482 24557 24587 V mpv : [cplayer] first video frame after restart shown
06-14 23:25:35.484 24557 24587 V mpv : event: playback-restart
06-14 23:25:35.484 24557 24587 V mpv : [cplayer] playback restart complete @ 0.000000
06-14 23:25:35.484 24557 24557 V PlayerActivity: state SEEKING_FORWARD -> PLAYING
06-14 23:25:35.675 24557 24557 V mpvstats: AV: 0.233 A-V: 0.000 Dropped: 0 Cache: 2.169s + 0KB
06-14 23:25:38.785 24557 24557 V mpvstats: AV: 3.135 A-V: 0.000 Dropped: 2 Cache: 32.232s + 0KB
06-14 23:25:38.888 24557 24557 V mpvstats: AV: 3.269 A-V: 0.000 Dropped: 4 Cache: 33.267s + 0KB
06-14 23:25:40.032 24557 24557 V mpvstats: AV: 4.336 A-V: 0.000 Dropped: 27 Cache: 40.307s + 0KB
06-14 23:25:41.155 24557 24557 V mpvstats: AV: 5.470 A-V: 0.000 Dropped: 50 Cache: 40.240s + 0KB
06-14 23:25:41.580 24557 31447 V ApiServer: REQUEST: GET /log
06-14 23:25:41.885 24557 24557 V mpvstats: AV: 6.137 A-V: 0.000 Dropped: 56 Cache: 40.173s + 0KB
06-14 23:25:42.310 24557 24557 V mpvstats: AV: 6.437 A-V: 0.000 Dropped: 56 Cache: 40.140s + 0KB
06-14 23:25:44.904 24557 24557 V mpvstats: AV: 9.473 A-V: 0.000 Dropped: 56 Cache: 39.907s + 0KB
06-14 23:25:47.944 24557 24557 V mpvstats: AV: 12.441 A-V: 0.000 Dropped: 56 Cache: 39.706s + 0KB
06-14 23:25:49.092 24557 31466 V ApiServer: REQUEST: GET /log

I think I’ve found the solution to this at least for now. Based on some other threads about choppy playback on TS4k that recommended changing the decoder to software from hardware selection under advanced settings; I tried that and the problem on this specific ABC recording immediately went away.

I made the same change on my other TS4k and got the same resolution.

I’m going to keep an eye out to see if this resolves my problem long term but this looks promising.

1 Like

I also have this issue but have not tried the software decoder. Still, it seems like if several of us have the problem AND it's the default transcoder, there must be a bug somewhere. I've submitted logs a couple of times when it happened but I neglected to follow up via email afterward. I will do so next time I see it.

One of the most interesting things is that when the skip fails like this, if I go back and just use regular fast-forward, it will sometimes let you past that point, but if you try to skip again it will bump wayyy back to wherever the initial loop issue happened.