Inconsistent PlaybackPositionTicks

[Protected 86]

I wasn't done writing this...

Edited September 19, 2024 by Protected

[Protected 86]

I'm trying to use TimeUpdate events to track in my plugin whether playback is progressing smoothly (within tolerance). I'm seeing a lot of stuff like this:

2024-09-19 20:15:43.103 Debug SessionManager: OnPlaybackProgress TimeUpdate ce40841ce33243a391938e3cc7420b6c
2024-09-19 20:15:43.103 Info Party: >> Progress event from 8d39e2a8347e9c369b028de8661f8d76 (TimeUpdate)
2024-09-19 20:15:43.103 Info Party: Host updated position to 9833163950 at 638623701431038814

So far so good.

2024-09-19 20:15:49.623 Info Party: >> Progress event from 8d39e2a8347e9c369b028de8661f8d76 (TimeUpdate)
2024-09-19 20:15:49.623 Info Party: Host updated position to 9843163950 at 638623701496237077

Not so good anymore. As you can see, more than 6 seconds have passed, but Emby is telling my plugin that we're only (exactly?) one second after the previous event. The video didn't pause or hitch. There was no log entry for SessionManager receiving a playback progress. Was this simulated? Why?

2024-09-19 20:15:53.153 Debug SessionManager: OnPlaybackProgress TimeUpdate ce40841ce33243a391938e3cc7420b6c
2024-09-19 20:15:53.154 Info Party: >> Progress event from 8d39e2a8347e9c369b028de8661f8d76 (TimeUpdate)
2024-09-19 20:15:53.154 Info Party: Host updated position to 9933608330 at 638623701531543820

Just over ten seconds after the first instance of the event, the sessionmanager logs the event for the second time and my handler is invoked for the third time. This time, the position carried by the event jumps to a non-exact offset of the previous ones, and if you do the math it's just over ten seconds after the first event - matching the logger clock with a high degree of accuracy.

What happened in the second call? Can I detect and discard those?

[Protected 86]

I suppose this is the obvious way to filter out the updates with incorrect tick reports:

    if (e.EventName == ProgressEvent.TimeUpdate && (e.PlaybackPositionTicks - attendee.PositionTicks) % 10000000 == 0)
    {
        //Discard bogus updates
        return;
    }

Due to the high resolution of "ticks" it seems effectively impossible that a real update will happen an exact amount of seconds after the previous update. Even if it does happen, discarding a real but extremely rare update won't be much of a problem.

Using only the updates that pass this check, I seem to be getting excellent sync. I'll be running some tests with real users soon.

Edited September 19, 2024 by Protected

[Luke 42077]

Hi, apps are told to send progress reports every 10 seconds. In between those reports, the server will automatically increment the time each second.

This is the first I've heard of such a discrepancy though.

[Protected 86]

Maybe others aren't doing anything with the ticks reported by the timeupdate event?

I understand the basic idea, but you can't tell the timer to call back every second and add exactly one second to the progress ticks on each callback since it's not guaranteed that the callback will run on time, especially if the CPU is busy. Even if the (host) application reports on time, that's still nine opportunities for the estimation to fail before the next report (especially since any discrepancies will compound). I looked it up just now and there are mechanisms in newer versions of .net like Stopwatch and PeriodicTimer designed to improve the (apparently notorious) inaccuracy of System.Threading.Timer, but even then I don't think that's necessary.

Instead I recommend you use the same method I used in my plugin (almost done with that!) When you get a real progress update (UPDATE_TICKS) save in the session the current time or the time of the update in ticks with as much accuracy as possible (UPDATE_TIME). Whenever you need to call the event, estimate/update the progress ticks using UPDATE_TICKS + (CURRENT_TIME - UPDATE_TIME). Unless the video player is paused of course.

 

Edited September 23, 2024 by Protected

[Luke 42077]

Quote

 

Maybe others aren't doing anything with the ticks reported by the timeupdate event?

The server dashboard is displaying it.

Quote

I understand the basic idea, but you can't tell the timer to call back every second and add exactly one second to the progress ticks on each callback since it's not guaranteed that the callback will run on time, especially if the CPU is busy.

Right, this is adjusted for.