Commit Graph

1724 Commits

Author SHA1 Message Date
Raja Subramanian e461e9cd79 Log skew in clock rate. (#2158)
* Log skew in clock rate.

Remember seeing sender report time stamp moving backward
across mute with replaceTrack(null). Not able to reproduce
it in JS sample app, but have seen it elsewhere.

Logging to understand it better. Wondering if the sender report
should be reset on time stamp moving backward or if we should drop
backwards moving reports.

* set threshold at 20%
2023-10-19 13:58:50 +05:30
Raja Subramanian f653efcf10 Do not update highest time on padding packet. (#2157)
* Error log of padding updating highest time to get backtrace.

* Do not update highest time on padding packet.

Padding packets use time stamp of last packet sent.
Padding packets could be sent when probing much after last packet
was sent. Updating highest time on that screws up sender report
calculations. We have ways of making sure sender reports do not
get too out-of-whack, but it logs during that repair.
That repair should be unnecessary unless the source is behaving weird
(things like publisher sending all packets at the same time, publisher
sample rate is incorrect, etc.)
2023-10-19 12:01:48 +05:30
David Colburn b290c233ea fix CreateEgress not completing (#2156) 2023-10-18 23:18:53 -07:00
David Colburn 62b057b4c1 Egress store/IO cleanup (#2152)
* egress store cleanup

* client wrapper, regenerate

* put WithClusterID back

* rename clent

* infinite loops

* client wrapper -> interface

* remove StopEgress update

* remove Update from IOClient

* avoid duplicate EgressStarted events

* update protocol
2023-10-18 14:48:51 -07:00
Raja Subramanian 7c830ea5b9 Log highest time update on padding packet. (#2154)
* Log highest time update on padding packet.

Seeing a strange case of what looks like highest time getting
updated on a padding packet. Can't see how it happens in code.
So, logging to check. Will be removing log after checking.

* log sequence number also
2023-10-19 00:53:50 +05:30
Raja Subramanian f97242c8ba Use 32-bit time stamp to get reference time stamp on a switch. (#2153)
* Use 32-bit time stamp to get reference time stamp on a switch.

With relay and dyncast and migration, it is possible that different
layers of a simulcast get out of sync in terms of extended type,
i. e. layer 0 could keep running and its timestamp could have
wrapped around and bumped the extended timestamp. But, another layer
could start and stop.

One possible solution is sending the extended timestamp across relay.

But, that breaks down during migration if publisher has started afresh.
Subscriber could still be using extended range.

So, use 32-bit timestamp to infer reference timestamp and patch it with
expected extended time stamp to derive the extended reference.

* use calculated value

* make it test friendly
2023-10-18 21:48:41 +05:30
Raja Subramanian 3e4cd3a161 Accept more range for first packet time adjustment. (#2150) 2023-10-17 23:52:14 +05:30
Raja Subramanian 11c9c56a4d Defer close of source and sink to prevent error logs. (#2149)
When a room is created via room service, when `StartSession`
runs, it sees a closed request source and returns an error
and that gets logged. It is not a real error.

Defer the sink and source close so that room creation can finish without
errors.
2023-10-17 11:37:34 +05:30
cnderrauber 53e757fd2c Fix panic on streamtracker_dd (#2147) 2023-10-17 10:37:11 +08:00
David Zhao 65934e6486 Fix ICE connection fallback (#2144)
* Fix ICE connection fallback

Short connection detection relied on iceFailedTimeout, which previously
had been misinterpreted. Since we've reduced iceFailedTimeout, it is
creating false negatives.

We'll instead use PingTimeout since clients are expected to keep the
signal connection active.

* reduce ping interval to align with total ice failure timeout
2023-10-15 14:36:12 -07:00
Raja Subramanian 70b60101f4 do the proper large negative check (#2139) 2023-10-10 11:01:49 +05:30
Raja Subramanian 31b042ddce Log larga negative gap. (#2138)
Seeing a large positive gap which I am not able to explain.
Wondering if at some other time, a large negative is happening
and the large positive is just a correction.
2023-10-09 14:32:10 +05:30
Raja Subramanian ebe1470e46 Simplify (#2137) 2023-10-07 13:15:51 +05:30
David Zhao 0931dc0300 Handle playoutDelay for Firefox (#2135)
We will need to disable playoutDelay for FF users if the developer is
assuming streams are synced.
2023-10-07 00:00:52 -07:00
Raja Subramanian 9fc276481a Increase accuracy of delay since last sender report. (#2136)
It is in 1 / 65536 seconds units. That is about 0.015 ms.
So, use microseconds to increase accuracy.
2023-10-07 12:25:47 +05:30
Raja Subramanian 2ff8fe3b78 Prevent old packets resolution. (#2134)
* Prevent old packets resolution.

With range map, we are just looking up ranges and not exactly
which packets were missing. This caused the case of old packets
being resolved after layer switch.

For example,
- Packet 10 is layer switch, range map gets reset
- Packet 11, 12, 13 are forwarded
- Packet 9 comes, it should ideally be dropped as pre-layer switch old
  packet. But, when looking up range map, it gets an offset and hence
  gets re-mapped to something before layer switch. This was probably
  okay as decoders would have had a key frame at the switch point and
  moved ahead, but incorrect technically.

Fix is to reset the start point in the range map to the switch point
and not 0. So, when packet 9 comes, range map will return "key too old"
error and that packet will be dropped as missing from cache.

* fix tests
2023-10-07 10:56:34 +05:30
David Zhao f40a97fd3e Allow playout delay even when sync stream isn't used. (#2133)
The two options should function independently. Users could still improve
video jitter by using up to 100ms of playout delay.
2023-10-06 14:51:11 -07:00
Benjamin Pracht 4253845505 Create stub for update outputs in egress service (#2132) 2023-10-05 12:00:47 -07:00
Raja Subramanian 4ea284fae0 Log potential sequence number de-sync in receiver reports. (#2128)
* Log potential sequence number de-sync in receicer reports.

Seeing some cases of a roll over being missed. That ends up
as largish range to search in an interval and reports missing packets
in the packet metadata cache.

Logging some details.

* just log in one place
2023-10-05 13:10:13 +05:30
Raja Subramanian 5aa093f65d Log time when there are too many packets. (#2127)
Ideally, can remove the nil return when there are too many packets
as we have more information with extended sequence numbers, but
logging duration first to understand what is happening better.
2023-10-05 12:02:55 +05:30
Raja Subramanian 6c49d1a160 Logging a few bits at Infow (#2126)
Seeing sequencer errors with egress (related to dummy start).
So, logging a few bits at Infow to understand them better.
2023-10-05 11:16:31 +05:30
Raja Subramanian c710ab901e Log stream start at Infow (#2125)
Seeing some sequence number adjustment where timestamp is 0.
Want to check the stream start.
2023-10-05 00:12:41 +05:30
Raja Subramanian cb0a48c12d Handle RED extended sequence number. (#2123)
When converting from RED -> Opus, if there is a loss, SFU recovers
that loss if it can using a subsequent redundant packet. That path
was not setting the extended sequence number properly.

Also, ensuring use of monotonic clock for first packet time adjustment
also.
2023-10-03 19:38:55 +05:30
Raja Subramanian 96ccf696d3 Cap expected packets to padding diff. (#2122)
* Cap expected packets to padding diff.

On the receiver, no longer using packet metadata cache to calculate
interval stats. An optimisation to get rid of packet metadata cache
on receiver side.

Because of that, padding packets in an interval could be more than
expected packets. As padding packets is just a counter, out-of-order
padding packets will make the diff look larger than expected packets
in a window. Cap the expected to 0.

NOTE: This makes it so that the count is not accurate in a window,
but that is okay occasionally. It will affect reported stats and quality
calculations, but it should be rare. For example, if 30 packets were
received in a window and 60 out-of-order padding packets were received,
it would reported as 0 packets were received. One option is to not
increment padding packets when they are out-of-order, but that will mess
up overall stats. Will make that change if we see this happen a lot.

* log unexpected padding packets
2023-10-03 12:36:19 +05:30
Raja Subramanian e6e3e2a729 sligtly easier readability (#2121) 2023-10-02 22:47:40 +05:30
Raja Subramanian 989d621c97 A small change to move out of order check before RTT calc. (#2117) 2023-10-02 11:51:46 +05:30
Raja Subramanian 180ad541fc Mark packet not handled if restart is rejected (#2115)
* Mark packet not handled if restart is rejected

* log both sn and ts on restart/rollback
2023-09-30 10:24:13 +05:30
Raja Subramanian ee3a7c01bc Log resync at Infow. (#2114)
* Log resync at Infow.

Seeing potentially large sequence number jumps on a resync.
And it seems to happen on a lot of subscribe/unsubscribe.
Logging at Infow to understand better.

Probably need to find a way to avoid resync. But, logging for now to
check if I can catch one.

* Remove resync and log large sequence number jumps
2023-09-30 08:42:46 +05:30
Raja Subramanian 39d0af4381 Start key frame requester on start. (#2111)
Sending a single PLI on connected & bound meant that the upstream
throttler may not have sent it and down stream does not have a key frame
to lock onto. Caused some e2e test failures due to limited time of
track.
2023-09-28 18:44:48 +05:30
cnderrauber 92a355e1f3 Add SyncStreams flag to Room (#2110)
* Add SyncStreams flag to Room

* Increase protocol version

* Revert version change

* Move flags to internal & solve comment
2023-09-28 15:41:44 +08:00
David Zhao 4c9d95149d Enable SVC codecs by default (#2109) 2023-09-27 21:16:13 -07:00
Raja Subramanian 789a2bd390 Log ICE candidates when closing the peer connection. (#2105)
There are cases that experience the signalling channel timeout
and disconnect and there are no logs of what the state of ICE at all.
Log ICE candidates when closing transport so that there is some
visibility in those cases.
n
2023-09-26 13:21:08 +05:30
Pingos 4f9467040e Bind() function fails when mime == "audio/red" (#2104) 2023-09-26 13:36:54 +08:00
cnderrauber 1200a960a2 Use generic type cast for IDs (#2095) 2023-09-20 17:09:24 +08:00
Raja Subramanian 281d2b674b Changing some log levels (#2094)
Logging expected WS close at Infow to understand reasons for closure.
Moving "read from ws" to Debugw as it happens when signalling closes.

Also filter out a data channel abort chunk log as it shows a bunch of
errors, but those are expected though.
2023-09-20 14:13:48 +05:30
Raja Subramanian a624e30b74 Use marshal + unmarshal to ensure unmarshallable fields are not copied. (#2092)
* Use marshal + unmarshal to ensure unmarshallable fields are not copied.

Need to ensure that config structs/fields are marshallable.

There was a use of a = b copy of struct and some of the embeded structs
had locks and copying was not good.

* update protocol

* Update deps
2023-09-20 00:23:49 +05:30
Raja Subramanian d0bfb349aa Set packet time for padding packets (#2091) 2023-09-19 19:54:54 +05:30
cnderrauber e46da0705a Add max playout delay config (#2089)
* Add max playout delay

* config sample
2023-09-19 11:30:38 +08:00
David Colburn 8a0d417a8c Participant egress (#2070)
* participant egress

* remove hasPublished when participant leaves room
2023-09-18 12:47:57 -07:00
Raja Subramanian dd2427bf05 Stop writing packets in sysnthesize on track close. (#2086) 2023-09-18 22:25:48 +05:30
Raja Subramanian e0d98eebb6 Do stats update in line. (#2085) 2023-09-18 18:42:39 +05:30
Raja Subramanian ca2f8fedab Fix out-of-range access. (#2082)
Happens when converting quality in subscibed settings to layer.
Looks like it can happen only if the provided quality is OFF.
Don't know of any client that does that. Anyhow, prevent out-of-range
access which causea a panic.
2023-09-18 10:03:22 +05:30
David Zhao 0b0431b765 Per-session TURN credentials (#2080)
Switching to using session specific TURN credentials instead of shared
credentials per Room. Also eliminates need to load Room from Redis
during TURN authentication
2023-09-17 10:08:35 -07:00
Raja Subramanian 019ad88b08 Do not force reconnect on resume if there is a pending track (#2081)
* Do not force reconnect on resume if there is a pending track

* move GetPendingTrack -> LocalParticipant
2023-09-17 14:00:09 +05:30
Raja Subramanian 97048a923c Reducing rtp stats memory consumption - part 2 (#2078)
* WIP commit

* move a struct to sender only

* Snapshot intervals

* make receiver history 4K too
2023-09-16 18:54:18 +05:30
David Zhao 340906267f Reduce ghost participant disconnect timeout (#2077)
It's been reported that "ghost" participants, those that did not terminate
cleanly, hang around the room for too long after they disappear.

Evaluating our timeouts a bit, it seems that we are really conservative
in waiting for participants to disconnect. This PR cuts down the disconnect
timeout from 50s to 20s, a 30s reduction.
2023-09-16 00:15:04 -07:00
Raja Subramanian f29887dcd0 Use bit map. (#2075)
* Use bit map.

Also, duplicate packet detection is impoetant for dropping padding
only packets at the publisher side itself. In the last PR, mentioned
that it is only for stats.

* clean up

* Update deps
2023-09-16 02:03:50 +05:30
Raja Subramanian 9c2ad54146 Clean up debug logs (#2076) 2023-09-16 01:57:34 +05:30
David Zhao 2113557842 Skip SendDataPacket logging on transport failure (#2074)
That's a sign of peer connection failure, we do not need to log these
2023-09-15 12:55:54 -07:00
Raja Subramanian 044f6cec40 Reduce packet meta data cache - part 1 (#2073)
* Reduce packet meta data cache - part 1

Packet meta data cache takes a good amount of space.
That cache is 8K entries deep and each entry is 8 bytes.
So, that takes 64KB per RTP stream.

It is mostly needed for down stream to line up with receiver reports.

So, removing cache from up stream (RTPStatsReceiver) as part 1.
Will look at optimising the down stream in part 2.

* Remove caching from RTPStatsReceiver

* clean up a bit more

* maintain history and fix test
2023-09-15 21:39:03 +05:30