High-latency player connections can cause "fighting"

[tari]

I've observed this behavior when working on Kodi/XBMC support, and I suspect #52 is related since the symptom ("it actually does manage to pause the video, but the madVR user will start it immediately again") is the same.

My implementation of control of Kodi involves connecting over HTTP, making a request and waiting for a response. Due to how the API is designed, most actions require two round-trips (a state query to get a necessary parameter value, then the actual command/query). As I've implemented it now, every query opens a new HTTP connection. The upshot of all this is that operations on a Kodi player tend to have high latency.

Where things start going wrong is when another user in the room performs an action on playback state (play, pause, seek). A state change arrives from the server and a command is dispatched to the player, but a preceding status check will usually complete first. This causes a conflicting state to be reported, and latency effects tend to make the player cycle between playing and paused states.

(Performing blocking RPCs might be an easy fix but would tend to bog down the reactor a lot, so it's not a good solution.)

Representative debug output:

[11:17:07] client/server << {"State": {"ignoringOnTheFly": {"server": 1}, "playstate": {"paused": true, "position": 2
6.0, "setBy": "None", "doSeek": null}, "ping": {"serverRtt": 0.1529710292816162, "clientLatencyCalculation": 1441646227.429288, "latencyCalculation": 1441646227.505084}}}
[11:17:07] <None> paused
[11:17:07] client/server >> {"State": {"ignoringOnTheFly": {"server": 1}, "ping": {"clientRtt": 0.1514420509338379, "clientLatencyCalculation": 1441646227.581642, "latencyCalculation": 1441646227.505084}, "playstate": {"paused": false, "position": 27.008032083511353}}}
[11:17:07] client/server << {"State": {"ignoringOnTheFly": {"server": 1}, "playstate": {"paused": false, "position":
27.082831205780106, "setBy": "None", "doSeek": null}, "ping": {"serverRtt": 0.1451740264892578, "clientLatencyCalculation": 1441646227.581754, "latencyCalculation": 1441646227.65037}}}
[11:17:07] <None> unpaused
[11:17:07] client/server >> {"State": {"ignoringOnTheFly": {"server": 1}, "ping": {"clientRtt": 0.14456892013549805,
"clientLatencyCalculation": 1441646227.727131, "latencyCalculation": 1441646227.65037}, "playstate": {"paused": false, "position": 27.05450201034546}}}
[11:17:07] client/server >> {"Set": {"ready": {"isReady": false, "manuallyInitiated": false}}}
[11:17:07] client/server >> {"State": {"ignoringOnTheFly": {"client": 1}, "ping": {"clientRtt": 0.14456892013549805, "clientLatencyCalculation": 1441646227.773196}, "playstate": {"paused": true, "position": 27.0}}}

---

I believe enforced ordering of commands would solve this problem, which could be done by passing a cookie (perhaps just a timestamp) to most player queries. If on callback (for example to client.updatePlayerStatus) a cookie is older than the newest state-change command, the result is ignored.

For example, under normal operation:

1. player.askForStatus with cookie 0
2. askForStatus completes, passing cookie 0 back to client.updatePlayerStatus
3. askForStatus with cookie 1
4. ...

High-latency with commands. Player is playing initially:

1.askForStatus(cookie=1) begins a status request.
2. setPaused(True) begins player state change request. Client notes that all cookies <= 1 are stale.
3. askForStatus(1) completes, calls updatePlayerStatus(cookie=1). Client recognizes stale cookie and ignores status.
4. askForStatus(cookie=2). This cookie is fresh.
5. Player changes state to paused.
6. askForStatus(2) completes, returning paused state. updatePlayerStatus notes state change.

---

I implemented something like this in my player interface and it seemed to help, but it's much cleaner (and benefits all other players) to implement this ordering cooperatively between the client and player modules.

[Et0h]

My understanding is that in some cases the problem is not a "preceding status check", unless I am misunderstanding your use of the term.

The problem I have encountered, e.g. in relation to the MPC-HC pause/unpause issue, is that in some cases players will respond with old information to all status checks made in the time between when it has been told to make a state change and when that state change has actually been made.

If we have a layer between the existing Syncplay code (which expects everything to be instant) and the media player (which is sometimes laggy) which assume the state has changed as anticipated, then this could also be use to "lie" about media player position in the event a player takes too long to respond (following the system currently used for VLC).

We have to be careful to make sure that this system properly handles managed rooms and pause/unpause to toggle ready state. We also have to take account of the fact that in some cases two people unpause at the same time and in that case the second person may actually pause, so one has to have a timeout for any assumption that the player is just being laggy.

Because the quirks of each player may be different (e.g. some may always process a command before responding) it may be best for it to be solved on a per-player basis, or at least to allow for thresholds and behaviour of any intermediate layer to be varied on a per-player basis.

[tari]

Okay, so the complication to my proposal appears to be that players might require delay beyond just "this status was requested after the most recent command." I think in most cases this could be handled by making the "cookie" into a timestamp.

---

Consider a hypothetical player that may require up to 10ms after sending a play/pause command before the returned status reflects that command. requestStatus is shorthand for the client starting a status request, and reportStatus is the player module calling back on completion.

Under ideal conditions, the timestamp is unimportant:

1. requestStatus(time=0)
2. reportStatus(time=0), client accepts new state

With latency and possible reordering:

1. requestStatus(time=0)
2. setPlaying(False), time=6
3. reportStatus(time=0), report is ignored because it is older than most recent command
4. requestStatus(time=8)
5. reportStatus(time=8), report is ignored because it started less than 10ms after the most recent command
6. requestStatus(time=16)
7. reportStatus(time=16), client accepts new state

---

I think this approach handles both situations cleanly, and the player latency (10ms in the above example) could be exposed as an option, allowing users to try to handle particularly slow players, at the cost of some speed in syncplay responding to changes. The actual latency of a player could easily vary between machines or networks, so exposing that as an option makes sense to me.

[Et0h]

This is an issue to be dealt with on a per-player basis.