v19 Timeshift error
#1
There is an OTA TV channel that I watch that sometimes displays a station ID logo during a movie. The movie audio keeps playing in the background but channel logo is displayed for video for a few seconds. While watching the recording, when it gets to the place where the channel logo appears, it causes Kodi to loose it's place and the timeline changes dramatically. Kodi stops the audio and the video freezes but the timeline keeps going. Other times when this station logo appears Kodi jumps back to the beginning of the recording or it exits and the player closes.

The NextPVR web client doesn't seem to have any problem playing this recording neither VLC.

My server is MX Linux, Kodi is the nightly build with kodi-pvr-nextpvr 8.2.0 on an Intel NUC running Kubuntu

Here is Kodi log.
https://paste.kodi.tv/taceyosawu.kodi
I jumped ahead to a couple minutes before this happens (around 30 Min) in the timeline.

Thanks
Reply
#2
I recently found that I only have trouble playing the recording from the TV/Recordings menu in Kodi. If I play the recording from Videos/TV Movies file location it plays through that place where the station ID logo appears.
Reply
#3
Just to clear, based on that log you don't mean Live TV timeshifting, you mean the time is shifting during playback.  Looking at the logs I think this is a player error possibly with still frames.  Does it work in Leia or in earlier v19 nightlies?

Martin
Reply
#4
(2021-02-08, 18:35)emveepee Wrote: Just to clear, based on that log you don't mean Live TV timeshifting, you mean the time is shifting during playback.  Looking at the logs I think this is a player error possibly with still frames.  Does it work in Leia or in earlier v19 nightlies?

Martin
Yes, that is correct. The time is shifting during playback.

I see this in Leia as well.

Just tried it on my Android phone (Kodi 18.9). When playback reached the place where the logo was, the timeline at the bottom reported 19:22:00. The video jumped back to a few seconds before the logo appeared, then it played through the logo normally, but the time still reported 19:22:xx and counting.  After stopping the recording, I tried again with the same results except the timeline at the bottom reported 09:xx:xx instead.

Thanks
Reply
#5
Your log was for RC1, have you tried a recent nightly?  I know @djp952 added a PR that deals with still frames.

Martin
Reply
#6
(2021-02-08, 22:21)emveepee Wrote: Your log was for RC1, have you tried a recent nightly?  I know @djp952 added a PR that deals with still frames.

Martin
The log was from a nightly from a week ago or so. I tried playing the recording again last night and it behaved the same as described in my post. The build from system info page says...

Version info:
Build: 19.0-RC1 (18.9.9.10)
Git 200210207-af9b6445fd
Compiled 2021-20-07
Reply
#7
@VCR58 did you try turning off VAAPI as I suggested on the NextPVR forum?   I don't see this as an addon issue, playback via the addon is different then through the recordings API.

If s/w decoding still fails and you can duplicate this on a supported platform like Ubuntu or Windows, I suggest you open it as a Kodi issue on github.   https://github.com/xbmc/xbmc/issues

Martin
Reply
#8
I got tagged Smile  I agree with emveepee on turning off VAAPI first, the stillframe issue was more about channels like "MusicChoice", where the video stream consists of nothing but still frames.  There what you'd get is a constant playback pause if it was a "Realtime" stream since Kodi flagged the video stream as stalled since data stopped coming in.  In the attached log, I think the stillframe noted is more due to the flush after a seek operation, not necessarily due to an actual still frame.  Switching to software decoding to see if the behavior persists would really help to isolate the problem.

Q: When recordings are played back via NextPVR are they flagged as Realtime?  That's the main behavioral difference I tend to see with playback from a PVR versus the Videos library, flagging a stream as realtime changes some of the semantics (and at times exacerbates things for ffmpeg).

edit: Scrolled down enough to see how far off the audio sync thinks it is, there may be something wrong with the timestamps in that transport stream.  ffmpeg tried REALLY HARD to seek to specific place and it's usually much better at guessing and wouldn't need like 100 seek operations to do it.  Then check out how far out of whack this gets:

2021-01-30 00:53:43.026 T:3514 WARNING <general>: ActiveAE - large audio sync error: 33951807.971796

It goes from thinking it's around 5 seconds out of sync to thinking it's more like 9 hours of of sync .... that's weird.
Reply
#9
(2021-02-09, 04:47)djp952 Wrote: I got tagged Smile  I agree with emveepee on turning off VAAPI first, the stillframe issue was more about channels like "MusicChoice", where the video stream consists of nothing but still frames.  There what you'd get is a constant playback pause if it was a "Realtime" stream since Kodi flagged the video stream as stalled since data stopped coming in.  In the attached log, I think the stillframe noted is more due to the flush after a seek operation, not necessarily due to an actual still frame.  Switching to software decoding to see if the behavior persists would really help to isolate the problem.

Q: When recordings are played back via NextPVR are they flagged as Realtime?  That's the main behavioral difference I tend to see with playback from a PVR versus the Videos library, flagging a stream as realtime changes some of the semantics (and at times exacerbates things for ffmpeg).

edit: Scrolled down enough to see how far off the audio sync thinks it is, there may be something wrong with the timestamps in that transport stream.  ffmpeg tried REALLY HARD to seek to specific place and it's usually much better at guessing and wouldn't need like 100 seek operations to do it.  Then check out how far out of whack this gets:

2021-01-30 00:53:43.026 T:3514 WARNING <general>: ActiveAE - large audio sync error: 33951807.971796

It goes from thinking it's around 5 seconds out of sync to thinking it's more like 9 hours of of sync .... that's weird.

Yes, I agree it is weird. I tried Martin's suggestion about turning off HW VAAPI and it did not help. Also, when I checked again there was the same issue playing from either Videos or Recordings. So I'm convinced it isn't a PVR issue as well.

I decided to go back to Windows 10 on this NUC and install the latest nightly and see if there is any improvement playing the recording. I found it had no trouble at all playing the recording. Tried it several times and never saw the timeline go wacky like it did before with Kubuntu.

I guess I stick with Windows 10 client and see if this issue crops up again. I did save the Kubuntu hard drive image just in case.

Thanks guys

Edit: I spoke too soon. It happened again with Windows 10. I guess I'll need to open up a Github issue.
Reply
#10
(2021-02-09, 05:25)VCR58 Wrote:
(2021-02-09, 04:47)djp952 Wrote: I got tagged Smile  I agree with emveepee on turning off VAAPI first, the stillframe issue was more about channels like "MusicChoice", where the video stream consists of nothing but still frames.  There what you'd get is a constant playback pause if it was a "Realtime" stream since Kodi flagged the video stream as stalled since data stopped coming in.  In the attached log, I think the stillframe noted is more due to the flush after a seek operation, not necessarily due to an actual still frame.  Switching to software decoding to see if the behavior persists would really help to isolate the problem.

Q: When recordings are played back via NextPVR are they flagged as Realtime?  That's the main behavioral difference I tend to see with playback from a PVR versus the Videos library, flagging a stream as realtime changes some of the semantics (and at times exacerbates things for ffmpeg).

edit: Scrolled down enough to see how far off the audio sync thinks it is, there may be something wrong with the timestamps in that transport stream.  ffmpeg tried REALLY HARD to seek to specific place and it's usually much better at guessing and wouldn't need like 100 seek operations to do it.  Then check out how far out of whack this gets:

2021-01-30 00:53:43.026 T:3514 WARNING <general>: ActiveAE - large audio sync error: 33951807.971796

It goes from thinking it's around 5 seconds out of sync to thinking it's more like 9 hours of of sync .... that's weird.

Yes, I agree it is weird. I tried Martin's suggestion about turning off HW VAAPI and it did not help. Also, when I checked again there was the same issue playing from either Videos or Recordings. So I'm convinced it isn't a PVR issue as well.

I decided to go back to Windows 10 on this NUC and install the latest nightly and see if there is any improvement playing the recording. I found it had no trouble at all playing the recording. Tried it several times and never saw the timeline go wacky like it did before with Kubuntu.

I guess I stick with Windows 10 client and see if this issue crops up again. I did save the Kubuntu hard drive image just in case.

Thanks guys

Edit: I spoke too soon. It happened again with Windows 10. I guess I'll need to open up a Github issue.

Can you share the .ts recording file?  Happy to spend some time on it to help see what's what with it.  I happen to own Eraser on DVD, I think it would count as acceptable use.  My copy isn't 720p, though.
Reply
#11
(2021-02-09, 06:27)djp952 Wrote:
(2021-02-09, 05:25)VCR58 Wrote:
(2021-02-09, 04:47)djp952 Wrote: I got tagged Smile  I agree with emveepee on turning off VAAPI first, the stillframe issue was more about channels like "MusicChoice", where the video stream consists of nothing but still frames.  There what you'd get is a constant playback pause if it was a "Realtime" stream since Kodi flagged the video stream as stalled since data stopped coming in.  In the attached log, I think the stillframe noted is more due to the flush after a seek operation, not necessarily due to an actual still frame.  Switching to software decoding to see if the behavior persists would really help to isolate the problem.

Q: When recordings are played back via NextPVR are they flagged as Realtime?  That's the main behavioral difference I tend to see with playback from a PVR versus the Videos library, flagging a stream as realtime changes some of the semantics (and at times exacerbates things for ffmpeg).

edit: Scrolled down enough to see how far off the audio sync thinks it is, there may be something wrong with the timestamps in that transport stream.  ffmpeg tried REALLY HARD to seek to specific place and it's usually much better at guessing and wouldn't need like 100 seek operations to do it.  Then check out how far out of whack this gets:

2021-01-30 00:53:43.026 T:3514 WARNING <general>: ActiveAE - large audio sync error: 33951807.971796

It goes from thinking it's around 5 seconds out of sync to thinking it's more like 9 hours of of sync .... that's weird.

Yes, I agree it is weird. I tried Martin's suggestion about turning off HW VAAPI and it did not help. Also, when I checked again there was the same issue playing from either Videos or Recordings. So I'm convinced it isn't a PVR issue as well.

I decided to go back to Windows 10 on this NUC and install the latest nightly and see if there is any improvement playing the recording. I found it had no trouble at all playing the recording. Tried it several times and never saw the timeline go wacky like it did before with Kubuntu.

I guess I stick with Windows 10 client and see if this issue crops up again. I did save the Kubuntu hard drive image just in case.

Thanks guys

Edit: I spoke too soon. It happened again with Windows 10. I guess I'll need to open up a Github issue.

Can you share the .ts recording file?  Happy to spend some time on it to help see what's what with it.  I happen to own Eraser on DVD, I think it would count as acceptable use.  My copy isn't 720p, though.

Sure. I made a snippet of the TV recording that includes the part where the station ID occurs. It is about 100 MB. I shared this on the NextPVR forum as well.
Reply
#12
@djp952 if there is anything I can help you with let me know.  Because this is a a localhost install it is using the file system not http for streaming,  /mnt/sda1/TV Movies/Eraser (1996)/Eraser.(1996).ts , so Kodi would be using file system calls for all the seeks times etc.

Martin
Reply
#13
Hi @VCR58.  I registered for the NextPVR forum and searched your posts but I only found content consisting of zipped log files.  I apologize if I'm being obtuse, but can you point me to where I can find the actual recorded .TS file?

Based on the commentary to date, I'm expecting to find that this is an ffmpeg concern as opposed to a Kodi concern, but I would definitely like to be able to reproduce your issue on my system(s) and see if there is anything I am able to do to help you out.
Reply
#14
I had a copy so I PM'd you a link. 

Martin
Reply
#15
Thank you Martin, and I apologize for the delay in my response.  The problem appears to be happening because the stream's Program Clock Reference (PCR) drops to zero at around 1:08 into the sample .ts video, which is where KWKB inserts the mentioned (and really intrusive! WTH?) video frames.  While I did not replicate the exact concern on Windows (under Leia or Matrix) -- playback did continue -- the stream time reported by Kodi sometimes jumped to more than 9 minutes in on a stream that is under 6 minutes in length.  For me, this was also accompanied by a "large audio sync error" of around 40 seconds in the Kodi log.  Note that this was done via the Kodi "Videos" library as opposed to a PVR addon. The playback semantics are a bit different when videos are played this way.

I think the broadcaster is primarily at fault here, any insertion(s) into the video stream should preserve continuity, but contacting them about it may or may not bear any fruit.  Personally, I'd still try to go that route first; the evidence does point a finger at this being the culprit.

Beyond that it's hard to say what might be able to be done in Kodi.  My guess here is that Kodi could be made to be more tolerant of this condition, but that may be a tall mountain to climb given my experiences to date.  The underlying cause may also be in ffmpeg itself; when viewing in VLC I noted that the VLC UI will reset itself when this content occurs as if it were something new, and reset itself again when the proper PCRs become available, again as if it were something new.  If there is a way for ffmpeg to communicate to Kodi that there has been an abrupt and unexpected stream change when the PCR gets jacked up, maybe that could work?

In my opinion the transport stream is at fault here and KWKB needs to fix it.  Short of that, I'd open an Issue for Kodi on GitHub with a "[VideoPlayer]" tag re-describing the problem and linking to the sample .ts file.  Resolution is unlikely to be a PVR-specific concern so I would recommend authoring it as a more generic "Videos" issue.  It can be replicated outside of a PVR addon.  That helps more than you may think Smile
Reply



Logout Mark Read Team Forum Stats Members Help
Timeshift error0
This forum uses Lukasz Tkacz MyBB addons.