timeshift: fix ff,rew,skip+,skip-

[ksooo]

For me, this changes fixes all timeshift issues with ff,rew,skip+,skip- (the well-known "allways skips to start of buffer bug").

Not quite sure why not subtracting pkt_pts from "now" fixes things, but it does. Any opinions/explanation?

Are the values of pkt->pkt_pts as returned now the real culprit? Don't know.

[nmaclean]

This seems much better now!

[perexg]

Could you provide "timeshift" logs from tvh with and without this patch ? Just to check...

[ksooo]

@perexg will do that tomorrow. For debugging, I've locally added much more logging to "timeshift", especially to _timeshift_skip() in timeshift/timeshift_reader.c which clearly shows that without the patch every(!) course search in that function (looking for the right timeshift file) failed, compared to the patched behavior, where every coarse search and every fine search (looking for the correct iframe) succeeds, despite from skip tries before start of buffer / behind end of buffer which now returns start/end of buffer as expected.

[ksooo]

Here we go...

Test scenario:
0) Tune, stay live for about 2 mins

1. skip+ => should be a nop, because already live
2. skip-
3. skip-
4. skip+

Patch to enhance timeshift logging, esp. in _timeshift_skip(): http://paste.ubuntu.com/8619382/
Annotated log for unpatched test scenario: http://paste.ubuntu.com/8619358/
Annotated log for patched test scenario: http://paste.ubuntu.com/8619375/

[Jalle19]

@ksooo would it make anything easier if the addon makes sure that it never tries to seek past the beginning of the buffer?

[ksooo]

@Jalle19 No. :-) If tvh behaves as it should to... and with my patch it does (at least that's my impression).

[Jalle19]

Okay, then I won't commit that (was just testing it locally).

[perexg]

OK, Looking to code and trying to understand what it does. And it seems (not 100% sure) that it's a client fault. Why client uses absolute skip+ and skip- requests ? The client is alwas behind the server. The absolute requests should be used for absolute goto skips, not for prev/rev etc....

I think that the req_time is wrong, because client expects something which is "past" for the server.

[Jalle19]

XBMC sends time in milliseconds since the subscription started when it wants to do a seek request. It then expects the server to respond with the PTS to skip to. I think the API was designed with VDR in mind.

[perexg]

Yes, but the issue is that the time seems to be in past when tvh tries to process it, because the 0 (starting) time is a bit different for client/server.. I would like to see full timeshift debug/trace for skip+ and skip- requests (with unpatched tvh).

And I think that client should really send the relative requests (just remove "absolute" field from the subscriptionSeek / subscriptionSkip requests and calculate delta's internally in the client - if it's possible to determine the absolute position when request was invoked in xbmc).

EDIT: It should apply for small time differences - the larger should be handled fine. (EDIT2: fine witth the absolute requests).

[ksooo]

@Jalle19 could you provide the logs perexg requested? I'm really very busy today with other things and will not be able to work on this issue today (and the next days).

[Jalle19]

@ksooo sure, I can provide the logs.

@perexg in the addon we don't know if the user seeked forward or backward so we can't send the relative time in seconds to tvheadend. When I said the client sends the time in milliseconds I didn't mean it as the time of day, I meant that if you've watched a channel for 5 minutes it will send the value 300 000 to the backend (300 * 1000), thus I don't think the time difference between the client and server should matter.

[ksooo]

@Jalle19 addon knows whether skip is forward or backward, at least PVR API implies so:
bool SeekTime(int time,bool backward,double *startpts)
Or does xbmc not provide the accurate value?

[Jalle19]

@ksooo actually not, looks can be deceiving. The boolean in this case indiciates whether the backend should skip to the I-frame before or after the specified position. See https://github.com/xbmc/xbmc/blob/master/xbmc/pvr/addons/PVRClient.h#L420. I admit I haven't actually checked what it's set to, could be that the documentation is wrong as well.

[Jalle19]

@perexg the addon is not aware of the current PTS at the time of the seek request. XBMC sends a pointer to the SeekTime() method which is supposed to be filled with the actual PTS after seek. See https://github.com/xbmc/xbmc/blob/master/xbmc/cores/dvdplayer/DVDPlayer.cpp#L2269-L2278

[ksooo]

@perexg yes, imho the culprit is, that in unpatched tvh, req_time is to small due to a to large value of pkt->pkt_pts.

timeshift.c:
ts->pts_delta = getmonoclock() - ts_rescale(pkt->pkt_pts, 1000000);
timeshift/timeshift_reader.c:
skip->time = [basically the time value passed from xbmc via htsp]
skip_time = ts_rescale(skip->time, 1000000);
skip_time += (skip->type == SMT_SKIP_ABS_TIME) ? ts->pts_delta : last_time;
req_time = skip_time;

For me, the question is, whether the math subtracting pkt->pkt_pts from "now" (getmonoclock()) is correct and the value of pkt->pkt_pts is wrong (way to large) or whether math is wrong. My patch assumes math is wrong.

Furthermore, I think, the time value passed by xbmc is okay and contains exactly the value @Jalle19 described earlier (start of subscription == 0 + x milliseconds => passed by the addon as nanoseconds to tvh via htsp "subscriptionSeek" method).

EDIT: time is passed to tvh in microsecs, not nanosecs.

[Jalle19]

It is passed a microseconds to tvheadend, not nanoseconds.

[Jalle19]

Exactly, milli -> micro -> nano.

[perexg]

@ksooo : I don't think that the "getmonoclock() - ts_rescale(pkt->pkt_pts, 1000000);" is wrong. It just takes the presentation time of the first packet (scalled from 90kHz to 1MHz) and subsctracts it from the actual clocks. So the "zero" time is exactly defined and tvh expects to have the absolute time relative to pts start.

The question is, why the first difference (pkt->pkt_pts) is so big.. For timeshift, the tsfix is applied, so pkt->pkt_pts should start around 0. Hmmm: here is it (log from tsfix):

deliver: pts = 320361496
pkt_pts = 320361496
deliver: pts = 320365096
deliver: pts = 320368696
deliver: pts = 320372296
deliver: pts = 10800
deliver: pts = 3600
deliver: pts = 320375896
deliver: pts = 7200
deliver: pts = 320379496
deliver: pts = 21600

The low values are correct, the high are suspicious..

[perexg]

And the winner is:

deliver: pts = 341907496, TELETEXT

So we should take the original offset from audio/video streams.

[perexg]

OK, I commited these two patches (both of them should fix this issue):

6106b71
82b17a7

EDIT: After tests, please, close this pull request.

[Jalle19]

Will try ASAP when I get home.

[nurtext]

Will also try when I'm at home (running XBMC 13.2 Gotham, pvr.tvh 0.9.3 and Tvheadend Git build from yesterday on Synology DS213j [marvel-armada370 hard-float])

[Nuesel]

I compiled tvheaded (git clone 6106b71) and tvh.pvr 0.9.3 (current version in the Gotham branch). I'm using XBMC 13.2 Gotham.
It works definitely much better than before. The only issue, I have found so far, is that I sometimes have trouble to skip to the end of the timeshift buffer. Could also be XBMC related.
I skip several times in 30 seconds steps, but XBMC stops seeking before reaching the buffer end. If will try again, I often have success, so I can see the live show.

[ksooo]

@perexg: Works like a charm now.

[nurtext]

@perexg Works fine for me too. Thanks in advance! Frakkin' TELETEXT 😄