diff options
Diffstat (limited to 'media/cast/logging')
4 files changed, 225 insertions, 143 deletions
diff --git a/media/cast/logging/raw_event_subscriber_bundle.cc b/media/cast/logging/raw_event_subscriber_bundle.cc index 6382a7c..5dc5f79 100644 --- a/media/cast/logging/raw_event_subscriber_bundle.cc +++ b/media/cast/logging/raw_event_subscriber_bundle.cc @@ -53,8 +53,7 @@ RawEventSubscriberBundle::~RawEventSubscriberBundle() { void RawEventSubscriberBundle::AddEventSubscribers(bool is_audio) { if (!receiver_offset_estimator_.get()) { - receiver_offset_estimator_.reset( - new ReceiverTimeOffsetEstimatorImpl(cast_environment_->Clock())); + receiver_offset_estimator_.reset(new ReceiverTimeOffsetEstimatorImpl); cast_environment_->Logging()->AddRawEventSubscriber( receiver_offset_estimator_.get()); } diff --git a/media/cast/logging/receiver_time_offset_estimator_impl.cc b/media/cast/logging/receiver_time_offset_estimator_impl.cc index 950b367..d511654 100644 --- a/media/cast/logging/receiver_time_offset_estimator_impl.cc +++ b/media/cast/logging/receiver_time_offset_estimator_impl.cc @@ -12,140 +12,134 @@ namespace media { namespace cast { -// This should be large enough so that we can collect all 3 events before -// the entry gets removed from the map. -const size_t kMaxEventTimesMapSize = 100; - -ReceiverTimeOffsetEstimatorImpl::ReceiverTimeOffsetEstimatorImpl( - base::TickClock* clock) - : bounded_(false), - clock_(clock), - offset_bounds_valid_(false), - last_reset_time_(clock_->NowTicks()) { +ReceiverTimeOffsetEstimatorImpl::BoundCalculator::BoundCalculator() + : has_bound_(false) {} +ReceiverTimeOffsetEstimatorImpl::BoundCalculator::~BoundCalculator() {} + +void ReceiverTimeOffsetEstimatorImpl::BoundCalculator::SetSent( + uint32 rtp, + uint32 packet_id, + bool audio, + base::TimeTicks t) { + uint64 key = (static_cast<uint64>(rtp) << 32) | (packet_id << 1) | + static_cast<uint64>(audio); + events_[key].first = t; + CheckUpdate(key); +} + +void ReceiverTimeOffsetEstimatorImpl::BoundCalculator::SetReceived( + uint32 rtp, + uint16 packet_id, + bool audio, + base::TimeTicks t) { + uint64 key = (static_cast<uint64>(rtp) << 32) | (packet_id << 1) | + static_cast<uint64>(audio); + events_[key].second = t; + CheckUpdate(key); +} + +void ReceiverTimeOffsetEstimatorImpl::BoundCalculator::UpdateBound( + base::TimeTicks sent, base::TimeTicks received) { + base::TimeDelta delta = received - sent; + if (has_bound_) { + if (delta < bound_) { + bound_ = delta; + } else { + bound_ += (delta - bound_) / kClockDriftSpeed; + } + } else { + bound_ = delta; + } + has_bound_ = true; + } + +void ReceiverTimeOffsetEstimatorImpl::BoundCalculator::CheckUpdate( + uint64 key) { + const TimeTickPair& ticks = events_[key]; + if (!ticks.first.is_null() && !ticks.second.is_null()) { + UpdateBound(ticks.first, ticks.second); + events_.erase(key); + return; + } + + if (events_.size() > kMaxEventTimesMapSize) { + EventMap::iterator i = ModMapOldest(&events_); + if (i != events_.end()) { + events_.erase(i); + } + } +} + +ReceiverTimeOffsetEstimatorImpl::ReceiverTimeOffsetEstimatorImpl() { } ReceiverTimeOffsetEstimatorImpl::~ReceiverTimeOffsetEstimatorImpl() { DCHECK(thread_checker_.CalledOnValidThread()); } + void ReceiverTimeOffsetEstimatorImpl::OnReceiveFrameEvent( const FrameEvent& frame_event) { DCHECK(thread_checker_.CalledOnValidThread()); - - if (frame_event.media_type != VIDEO_EVENT) - return; - - CastLoggingEvent event = frame_event.type; - if (event != FRAME_ENCODED && event != FRAME_ACK_SENT && - event != FRAME_ACK_RECEIVED) - return; - - EventTimesMap::iterator it = event_times_map_.find(frame_event.rtp_timestamp); - if (it == event_times_map_.end()) { - EventTimes event_times; - it = event_times_map_.insert(std::make_pair(frame_event.rtp_timestamp, - event_times)).first; - } - switch (event) { - case FRAME_ENCODED: - // Encode is supposed to happen only once. If we see duplicate event, - // throw away the entry. - if (it->second.event_a_time.is_null()) { - it->second.event_a_time = frame_event.timestamp; - } else { - event_times_map_.erase(it); - return; - } - break; + switch (frame_event.type) { case FRAME_ACK_SENT: - if (it->second.event_b_time.is_null()) { - it->second.event_b_time = frame_event.timestamp; - } else if (it->second.event_b_time != frame_event.timestamp) { - // Duplicate ack sent events are normal due to RTCP redundancy, - // but they must have the same event timestamp. - event_times_map_.erase(it); - return; - } + lower_bound_.SetSent(frame_event.rtp_timestamp, + 0, + frame_event.media_type == AUDIO_EVENT, + frame_event.timestamp); break; case FRAME_ACK_RECEIVED: - // If there are duplicate ack received events, pick the one with the - // smallest event timestamp so we can get a better bound. - if (it->second.event_c_time.is_null()) { - it->second.event_c_time = frame_event.timestamp; - } else { - it->second.event_c_time = - std::min(frame_event.timestamp, it->second.event_c_time); - } + lower_bound_.SetReceived(frame_event.rtp_timestamp, + 0, + frame_event.media_type == AUDIO_EVENT, + frame_event.timestamp); break; default: - NOTREACHED(); - } - - if (!it->second.event_a_time.is_null() && - !it->second.event_b_time.is_null() && - !it->second.event_c_time.is_null()) { - UpdateOffsetBounds(it->second); - event_times_map_.erase(it); + // Ignored + break; } - - // Keep the map size at most |kMaxEventTimesMapSize|. - if (event_times_map_.size() > kMaxEventTimesMapSize) - event_times_map_.erase(event_times_map_.begin()); } bool ReceiverTimeOffsetEstimatorImpl::GetReceiverOffsetBounds( base::TimeDelta* lower_bound, base::TimeDelta* upper_bound) { - if (!bounded_) + if (!lower_bound_.has_bound() || !upper_bound_.has_bound()) return false; - *lower_bound = prev_offset_lower_bound_; - *upper_bound = prev_offset_upper_bound_; + *lower_bound = -lower_bound_.bound(); + *upper_bound = upper_bound_.bound(); + + // Sanitize the output, we don't want the upper bound to be + // lower than the lower bound, make them the same. + if (upper_bound < lower_bound) { + lower_bound += (lower_bound - upper_bound) / 2; + upper_bound = lower_bound; + } return true; } void ReceiverTimeOffsetEstimatorImpl::OnReceivePacketEvent( const PacketEvent& packet_event) { - // Not interested in packet events. DCHECK(thread_checker_.CalledOnValidThread()); -} - -void ReceiverTimeOffsetEstimatorImpl::UpdateOffsetBounds( - const EventTimes& event) { - base::TimeDelta lower_bound = event.event_b_time - event.event_c_time; - base::TimeDelta upper_bound = event.event_b_time - event.event_a_time; - - if (offset_bounds_valid_) { - lower_bound = std::max(lower_bound, offset_lower_bound_); - upper_bound = std::min(upper_bound, offset_upper_bound_); - } - - if (lower_bound > upper_bound) { - VLOG(2) << "Got bogus offset bound values [" << lower_bound.InMilliseconds() - << ", " << upper_bound.InMilliseconds() << "]."; - return; - } - - offset_lower_bound_ = lower_bound; - offset_upper_bound_ = upper_bound; - offset_bounds_valid_ = true; - if (!bounded_ || - offset_upper_bound_ - offset_lower_bound_ < - base::TimeDelta::FromMilliseconds(20)) { - prev_offset_lower_bound_ = offset_lower_bound_; - prev_offset_upper_bound_ = offset_upper_bound_; - } - - base::TimeTicks now = clock_->NowTicks(); - if (now - last_reset_time_ > base::TimeDelta::FromSeconds(20)) { - last_reset_time_ = now; - offset_lower_bound_ = base::TimeDelta(); - offset_upper_bound_ = base::TimeDelta(); - offset_bounds_valid_ = false; + switch (packet_event.type) { + case PACKET_SENT_TO_NETWORK: + upper_bound_.SetSent(packet_event.rtp_timestamp, + packet_event.packet_id, + packet_event.media_type == AUDIO_EVENT, + packet_event.timestamp); + break; + case PACKET_RECEIVED: + upper_bound_.SetReceived(packet_event.rtp_timestamp, + packet_event.packet_id, + packet_event.media_type == AUDIO_EVENT, + packet_event.timestamp); + break; + default: + // Ignored + break; } - - bounded_ = true; } + } // namespace cast } // namespace media diff --git a/media/cast/logging/receiver_time_offset_estimator_impl.h b/media/cast/logging/receiver_time_offset_estimator_impl.h index f0abd29..768ccbd 100644 --- a/media/cast/logging/receiver_time_offset_estimator_impl.h +++ b/media/cast/logging/receiver_time_offset_estimator_impl.h @@ -5,30 +5,36 @@ #ifndef MEDIA_CAST_LOGGING_RECEIVER_TIME_OFFSET_ESTIMATOR_IMPL_H_ #define MEDIA_CAST_LOGGING_RECEIVER_TIME_OFFSET_ESTIMATOR_IMPL_H_ +#include <map> + #include "base/time/time.h" #include "base/threading/thread_checker.h" +#include "media/cast/common/mod_util.h" #include "media/cast/logging/logging_defines.h" #include "media/cast/logging/receiver_time_offset_estimator.h" -namespace base { -class TickClock; -} - namespace media { namespace cast { -// This implementation listens to three types of video events: -// 1. FRAME_ENCODED (sender side) -// 2. FRAME_ACK_SENT (receiver side) -// 3. FRAME_ACK_RECEIVED (sender side) + +// This should be large enough so that we can collect all 3 events before +// the entry gets removed from the map. +const size_t kMaxEventTimesMapSize = 500; + +// The lower, this is, the faster we adjust to clock drift. +// (But with more jitter.) +const size_t kClockDriftSpeed = 500; + + +// This implementation listens to two pair of events +// 1. FRAME_ACK_SENT / FRAME_ACK_RECEIVED (receiver->sender) +// 2. PACKET_SENT_TO_NETWORK / PACKET_RECEIVED (sender->receiver) // There is a causal relationship between these events in that these events // must happen in order. This class obtains the lower and upper bounds for -// the offset by taking the difference of timestamps (2) - (1) and (2) - (3), -// respectively. -// The bound will become better as the latency between the events decreases. +// the offset by taking the difference of timestamps. class ReceiverTimeOffsetEstimatorImpl : public ReceiverTimeOffsetEstimator { public: - ReceiverTimeOffsetEstimatorImpl(base::TickClock* clock); + ReceiverTimeOffsetEstimatorImpl(); virtual ~ReceiverTimeOffsetEstimatorImpl(); @@ -41,28 +47,47 @@ class ReceiverTimeOffsetEstimatorImpl : public ReceiverTimeOffsetEstimator { base::TimeDelta* upper_bound) OVERRIDE; private: - struct EventTimes { - base::TimeTicks event_a_time; - base::TimeTicks event_b_time; - base::TimeTicks event_c_time; + // This helper uses the difference between sent and recived event + // to calculate an upper bound on the difference between the clocks + // on the sender and receiver. Note that this difference can take + // very large positive or negative values, but the smaller value is + // always the better estimate, since a receive event cannot possibly + // happen before a send event. Note that we use this to calculate + // both upper and lower bounds by reversing the sender/receiver + // relationship. + class BoundCalculator { + public: + typedef std::pair<base::TimeTicks, base::TimeTicks> TimeTickPair; + typedef std::map<uint64, TimeTickPair> EventMap; + + BoundCalculator(); + ~BoundCalculator(); + bool has_bound() const { return has_bound_; } + base::TimeDelta bound() const { return bound_; } + + void SetSent(uint32 rtp, + uint32 packet_id, + bool audio, + base::TimeTicks t); + + void SetReceived(uint32 rtp, + uint16 packet_id, + bool audio, + base::TimeTicks t); + + private: + void UpdateBound(base::TimeTicks a, base::TimeTicks b); + void CheckUpdate(uint64 key); + + private: + EventMap events_; + bool has_bound_; + base::TimeDelta bound_; }; - typedef std::map<RtpTimestamp, EventTimes> EventTimesMap; - - void UpdateOffsetBounds(const EventTimes& event); - // Fixed size storage to store event times for recent frames. - EventTimesMap event_times_map_; - - bool bounded_; - base::TickClock* clock_; // Not owned by this class. - - bool offset_bounds_valid_; - base::TimeDelta offset_lower_bound_; - base::TimeDelta offset_upper_bound_; - base::TimeDelta prev_offset_lower_bound_; - base::TimeDelta prev_offset_upper_bound_; - base::TimeTicks last_reset_time_; + BoundCalculator upper_bound_; + BoundCalculator lower_bound_; base::ThreadChecker thread_checker_; DISALLOW_COPY_AND_ASSIGN(ReceiverTimeOffsetEstimatorImpl); diff --git a/media/cast/logging/receiver_time_offset_estimator_impl_unittest.cc b/media/cast/logging/receiver_time_offset_estimator_impl_unittest.cc index 16f0e51..c1059ae 100644 --- a/media/cast/logging/receiver_time_offset_estimator_impl_unittest.cc +++ b/media/cast/logging/receiver_time_offset_estimator_impl_unittest.cc @@ -24,8 +24,7 @@ class ReceiverTimeOffsetEstimatorImplTest : public ::testing::Test { scoped_ptr<base::TickClock>(sender_clock_).Pass(), task_runner_, task_runner_, - task_runner_)), - estimator_(cast_environment_->Clock()) { + task_runner_)) { cast_environment_->Logging()->AddRawEventSubscriber(&estimator_); } @@ -73,6 +72,13 @@ TEST_F(ReceiverTimeOffsetEstimatorImplTest, EstimateOffset) { true, 5678); + cast_environment_->Logging()->InsertPacketEvent( + sender_clock_->NowTicks(), + PACKET_SENT_TO_NETWORK, VIDEO_EVENT, + rtp_timestamp, + frame_id, + 56, 78, 1500); + EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound)); AdvanceClocks(base::TimeDelta::FromMilliseconds(10)); @@ -80,6 +86,13 @@ TEST_F(ReceiverTimeOffsetEstimatorImplTest, EstimateOffset) { receiver_clock_.NowTicks(), FRAME_ACK_SENT, VIDEO_EVENT, rtp_timestamp, frame_id); + cast_environment_->Logging()->InsertPacketEvent( + receiver_clock_.NowTicks(), + PACKET_RECEIVED, VIDEO_EVENT, + rtp_timestamp, + frame_id, + 56, 78, 1500); + EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound)); AdvanceClocks(base::TimeDelta::FromMilliseconds(30)); @@ -122,6 +135,13 @@ TEST_F(ReceiverTimeOffsetEstimatorImplTest, EventCArrivesBeforeEventB) { true, 5678); + cast_environment_->Logging()->InsertPacketEvent( + sender_clock_->NowTicks(), + PACKET_SENT_TO_NETWORK, VIDEO_EVENT, + rtp_timestamp, + frame_id, + 56, 78, 1500); + EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound)); AdvanceClocks(base::TimeDelta::FromMilliseconds(10)); @@ -134,6 +154,13 @@ TEST_F(ReceiverTimeOffsetEstimatorImplTest, EventCArrivesBeforeEventB) { EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound)); + cast_environment_->Logging()->InsertPacketEvent( + event_b_time, + PACKET_RECEIVED, VIDEO_EVENT, + rtp_timestamp, + frame_id, + 56, 78, 1500); + cast_environment_->Logging()->InsertFrameEvent( event_b_time, FRAME_ACK_SENT, VIDEO_EVENT, rtp_timestamp, frame_id); @@ -176,6 +203,13 @@ TEST_F(ReceiverTimeOffsetEstimatorImplTest, MultipleIterations) { true, 5678); + cast_environment_->Logging()->InsertPacketEvent( + sender_clock_->NowTicks(), + PACKET_SENT_TO_NETWORK, VIDEO_EVENT, + rtp_timestamp_a, + frame_id_a, + 56, 78, 1500); + AdvanceClocks(base::TimeDelta::FromMilliseconds(10)); cast_environment_->Logging()->InsertEncodedFrameEvent( sender_clock_->NowTicks(), @@ -185,11 +219,27 @@ TEST_F(ReceiverTimeOffsetEstimatorImplTest, MultipleIterations) { 1234, true, 5678); + + cast_environment_->Logging()->InsertPacketEvent( + sender_clock_->NowTicks(), + PACKET_SENT_TO_NETWORK, VIDEO_EVENT, + rtp_timestamp_b, + frame_id_b, + 56, 78, 1500); + cast_environment_->Logging()->InsertFrameEvent( receiver_clock_.NowTicks(), FRAME_ACK_SENT, VIDEO_EVENT, rtp_timestamp_a, frame_id_a); AdvanceClocks(base::TimeDelta::FromMilliseconds(20)); + + cast_environment_->Logging()->InsertPacketEvent( + receiver_clock_.NowTicks(), + PACKET_RECEIVED, VIDEO_EVENT, + rtp_timestamp_b, + frame_id_b, + 56, 78, 1500); + cast_environment_->Logging()->InsertFrameEvent( receiver_clock_.NowTicks(), FRAME_ACK_SENT, VIDEO_EVENT, rtp_timestamp_b, frame_id_b); @@ -218,7 +268,21 @@ TEST_F(ReceiverTimeOffsetEstimatorImplTest, MultipleIterations) { true, 5678); + cast_environment_->Logging()->InsertPacketEvent( + sender_clock_->NowTicks(), + PACKET_SENT_TO_NETWORK, VIDEO_EVENT, + rtp_timestamp_c, + frame_id_c, + 56, 78, 1500); + AdvanceClocks(base::TimeDelta::FromMilliseconds(3)); + cast_environment_->Logging()->InsertPacketEvent( + receiver_clock_.NowTicks(), + PACKET_RECEIVED, VIDEO_EVENT, + rtp_timestamp_c, + frame_id_c, + 56, 78, 1500); + cast_environment_->Logging()->InsertFrameEvent( receiver_clock_.NowTicks(), FRAME_ACK_SENT, VIDEO_EVENT, rtp_timestamp_c, frame_id_c); @@ -233,10 +297,10 @@ TEST_F(ReceiverTimeOffsetEstimatorImplTest, MultipleIterations) { EXPECT_TRUE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound)); int64 lower_bound_ms = lower_bound.InMilliseconds(); int64 upper_bound_ms = upper_bound.InMilliseconds(); - EXPECT_EQ(95, lower_bound_ms); - EXPECT_EQ(103, upper_bound_ms); - EXPECT_GE(true_offset_ms, lower_bound_ms); - EXPECT_LE(true_offset_ms, upper_bound_ms); + EXPECT_GT(lower_bound_ms, 90); + EXPECT_LE(lower_bound_ms, true_offset_ms); + EXPECT_LT(upper_bound_ms, 150); + EXPECT_GT(upper_bound_ms, true_offset_ms); } } // namespace cast |