Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Drifttracer making adjustments on tvOS receiver which seem excessive #2477

Closed
oviano opened this issue Oct 5, 2022 · 11 comments
Closed

Drifttracer making adjustments on tvOS receiver which seem excessive #2477

oviano opened this issue Oct 5, 2022 · 11 comments
Labels
Type: Question Questions or things that require clarification

Comments

@oviano
Copy link
Contributor

oviano commented Oct 5, 2022

The result is that packets are being released slightly too slowly by SRT, resulting in both the audio and video buffers on the player (I am referring to a buffer that the packets are placed in after extracting them from SRT and before decoding) is being exhausted.

To give an idea of the time period, if I start with a buffer representing around 100ms of data, this gets depleted to zero over a period of perhaps an hour. I also tried disabling the RTT part of the drift calculation, but this made no difference (as expected, as this is happening over the LAN so RTT is neglible).

Both sender and receiver running latest SRT with ENABLE_STDCXX_SYNC=1. Sender is Windows 11 Pro. Latency is 120ms, over a LAN connection.

When I run the same receiver code on macOS, I don't get the same issue. If I disable the drifttracer on tvOS, things seem better but presumably the SRT buffer will grow smaller over time?

I don't know if the clock drift on tvOS is excessive/wrong, or not, but I'm struggling to reconcile three things:

  • server is doing a live encode, generating packets with a certain PTS and sending them over SRT as they are created
  • receiver is receiving this data, but the drift tracer is delaying the release of these packets from SRT due to "clock drift"
  • this means that when the video player tries to playback according to PTS, using steady_clock for scheduling, it doesn't get the packets quickly enough

Is the solution that am I supposed to playback at a slower speed than indicated by the PTS in order to adjust to SRT's drift adjustment?

Attached is the drift tracer csv, covering around 15 minutes or so when the drift reached about 30ms.

drift_trace_09_18_49.345666.csv

@oviano oviano added the Type: Question Questions or things that require clarification label Oct 5, 2022
@ethouris
Copy link
Collaborator

ethouris commented Oct 5, 2022

To give you an idea as to how this drift is calculated:

With the arrival of the first data packet there's a lock of the base arrival time: BT. The timestamp in the packets - OTD - is a relative time towards the connection start time on the sender side, so it will always have a >0 value in the first data packet. So BT = NOW - OTD(0). The NOW time is then for this packet its ETS ( ETS = NOW(0)). For any other packet ETS(n) = BT + OTD(n).

That's not exactly precise because OTD is a 32-bit time that overflows kinda one per 2.5 minutes so at the overflow detection there's a "segment" added, so for v overflow we have BTS(v) = BT + S*v and therefore ETS(n) = BTS + OTD. Effective play time is then calculated as PTS = ETS + Latency + Drift (initially 0).

The key part is this ETS value (expected arrival time), which in ideal conditions should be ETS(n) = NOW(n), that is, should be equal to the time when the packet has arrived. If this differs, this difference is added to the array of values that will over time get the average of it. This will be then used as a "drift" value.

The idea is that it should detect how much the subsequent values from NOW(n) diverge from ETS(n) values. The current debug logging provides a log with "RECEIVED DATA" phrase that should display the values of ETS and PTS (unfortunately "now" isn't added, though it should be in some logs nearby - the problem is that this time is displayed in the current monotonic clock base and it differs to the log time base). In some next logs there should be also displayed a delay between PTS and the actual play time (time when the packet is given up to the application).

One of the factors that may strongly influence this distance between ETS and NOW is that the network delay may be small initially (when taking the value for BT), but increases drastically once a burst of packets is being sent - and this phenomenon is even more significant in LAN than in any wider network. I have observed this phenomenon when testing in LAN, and likely that's why RTT is taken into account when calculating the drift - so that the extra delay detected between NOW and ETS is blamed on the network and not on the actual time speed difference.

Might be though that the reason is different, and on Windows it may be as well due to some internal delays that do not deliver packets fast enough, and this may change in time, and in both directions. The best way would be to trace how the ETS - NOW distance shapes in time and then how this composes with the PTS from the particular stream (actually the only sense making procedure would be to pick up these values from the last packet delivering the video frame confronted with the PTS from that frame - in a usual SRT transmission MPEG-TS packets are aligned with UDP packets so these last packets are usually packets that have the PID for video and are shorter than 1316 bytes).

Anyway, if you have ideally equal clocks on both sender and receiver machines, this drift might diverge in the beginning a bit, but then it should remain stable during transmission, and it should come only from the network. The problem is that the packet arrival time (NOW) is the only source of information as to how the clock on the sender side may work, and this may potentially be burdened with some other "dirty" factors of not always determinable source.

@maxsharabayko
Copy link
Collaborator

maxsharabayko commented Oct 5, 2022

@ethouris The drift tracer algorithm is described here and here.

@oviano
RTT is quite stable.
newplot (1)

There is obviously a clock drift of ~5ms/minute.
newplot

From the data it looks like the drift should be successfully compensated.

Could you please also collect msRcvBuf statistics to analyze the RCV buffer fullness?

@oviano
Copy link
Contributor Author

oviano commented Oct 5, 2022

Thankyou @ethouris for the detailed explanation and @maxsharabayko for the interpretation.

Would 5ms per minute be in the normal ballpark? It sounds quite a lot, I guess for a 50fps source a duplicated/dropped frame by the player every four minutes to compensate.

If for any reason it was incorrectly compensating how would that manifest itself - as the msRcvBuf becoming progressively smaller or larger than the configured latency?

@maxsharabayko
Copy link
Collaborator

maxsharabayko commented Oct 5, 2022

The msRcvBuf is expected to stay at the same level (~SRTO_RCVLATENCY) if the drift compensation is performed appropriately and given the network delay remains the same. If it is, then likely the player/demuxer has to adjust the playback speed to compensate for the drift in PTS.

@oviano
Copy link
Contributor Author

oviano commented Oct 5, 2022

Ok thank you.

Am I correct in saying that the current drift value is not currently exposed by the API?

I already have code that slows down or speeds up either the audio or video streams for a short period of time in order to maintain AV sync.

It would seem logical that when the drift changes, I could apply the same algorithm but to both audio and video streams at once.

@ethouris
Copy link
Collaborator

ethouris commented Oct 6, 2022

The drift isn't. The API provides you only with the expected delivery time, but this is already dependent on the drift compensation value. And I don't think this will help the application anyhow.

I was thinking that maybe somehow the timestamp information from the stream can be fed back to SRT in order to help it adjust the time pace better. But this is also tricky - what we expect from the live stream is that the video is being played with the same speed as it is being recorded. But if clocks on the recorded and the player machines run in slightly different speeds, then even the timestamps in the stream are along with the recorder's clock speed and will have to be adjusted on the player.

@oviano
Copy link
Contributor Author

oviano commented Oct 6, 2022

From what I can see, when the drift jumps, this directly translates to an equivalent jump in the amount of buffered packets in my player. That is, in the example above as the drift value increases, meaning packets spend longer in the SRT buffer, my own buffers decrease by the same amount.

So my thinking was that if I was able to track the drift, I could just factor that into my playback speed.

I'm currently experimenting with adding usClockDrift to the SRT STATS, if I find it proves useful I'll submit a PR.

However, I guess the aspect of this that I find a bit confusing is that if the clock is slightly different on tvOS receiver vs Windows sender, that necessitates clock drift adjustment, I would think that this would also be slowing down playback anyway because the same steady clock is used for playback? That's why I was wondering if the clock drift was even correct. To help with this, I am also adding code to log the msRcvBuf with the other drift tracer CSV data, to see if this sheds any light.

@maxsharabayko
Copy link
Collaborator

Using RTT, msRcvBuf and your local clock on the receiver you could estimate roughly the drift. Or extend the API and expose the TSBPD adjustment value as you do.

@oviano
Copy link
Contributor Author

oviano commented Oct 6, 2022

A couple of (optional!) PRs relating to this discussion.

#2481
#2480

@oviano
Copy link
Contributor Author

oviano commented Oct 6, 2022

Adding updated drift trace log for completeness.

drift_trace_17_42_44.247643.csv

@oviano
Copy link
Contributor Author

oviano commented Oct 9, 2022

So I'm closing this issue now as it looks like the drifttracer is working as expected. It was just a bigger drift than I was expecting.

@oviano oviano closed this as completed Oct 9, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Type: Question Questions or things that require clarification
Projects
None yet
Development

No branches or pull requests

3 participants