diff options
author | mikhal@chromium.org <mikhal@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2014-02-06 17:36:28 +0000 |
---|---|---|
committer | mikhal@chromium.org <mikhal@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98> | 2014-02-06 17:36:28 +0000 |
commit | cadee27a321b98a7d75b52683addaff5a1d1dbf6 (patch) | |
tree | 61d35b7b64150a766ede0e2747779debfc0ed0f9 /media | |
parent | a771d1d10ff8f70f97b25d054251f7ff2e3eb613 (diff) | |
download | chromium_src-cadee27a321b98a7d75b52683addaff5a1d1dbf6.zip chromium_src-cadee27a321b98a7d75b52683addaff5a1d1dbf6.tar.gz chromium_src-cadee27a321b98a7d75b52683addaff5a1d1dbf6.tar.bz2 |
Cast:Updating Logging stats
Modify stats to hold more "native values" such as min, max,
count and sum.
This will allow the user to get more basic
information, while still be able to compute higher level
stats, such as frame rate and bit rate.
BUG=327949
Review URL: https://codereview.chromium.org/130423007
git-svn-id: svn://svn.chromium.org/chrome/trunk/src@249423 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'media')
-rw-r--r-- | media/cast/audio_receiver/audio_receiver.cc | 2 | ||||
-rw-r--r-- | media/cast/logging/logging_defines.cc | 32 | ||||
-rw-r--r-- | media/cast/logging/logging_defines.h | 48 | ||||
-rw-r--r-- | media/cast/logging/logging_impl.cc | 133 | ||||
-rw-r--r-- | media/cast/logging/logging_impl.h | 26 | ||||
-rw-r--r-- | media/cast/logging/logging_stats.cc | 112 | ||||
-rw-r--r-- | media/cast/logging/logging_stats.h | 12 | ||||
-rw-r--r-- | media/cast/logging/logging_unittest.cc | 137 | ||||
-rw-r--r-- | media/cast/video_receiver/video_receiver.cc | 2 | ||||
-rw-r--r-- | media/cast/video_sender/video_sender.cc | 2 |
10 files changed, 228 insertions, 278 deletions
diff --git a/media/cast/audio_receiver/audio_receiver.cc b/media/cast/audio_receiver/audio_receiver.cc index e7043c9..8c64e2f 100644 --- a/media/cast/audio_receiver/audio_receiver.cc +++ b/media/cast/audio_receiver/audio_receiver.cc @@ -403,7 +403,7 @@ void AudioReceiver::IncomingPacket(scoped_ptr<Packet> packet) { void AudioReceiver::CastFeedback(const RtcpCastMessage& cast_message) { RtcpReceiverLogMessage receiver_log; AudioRtcpRawMap audio_logs = - cast_environment_->Logging()->GetAudioRtcpRawData(); + cast_environment_->Logging()->GetAndResetAudioRtcpRawData(); while (!audio_logs.empty()) { AudioRtcpRawMap::iterator it = audio_logs.begin(); diff --git a/media/cast/logging/logging_defines.cc b/media/cast/logging/logging_defines.cc index 8766680..0eb57bf 100644 --- a/media/cast/logging/logging_defines.cc +++ b/media/cast/logging/logging_defines.cc @@ -88,13 +88,18 @@ std::string CastLoggingToString(CastLoggingEvent event) { } } -FrameEvent::FrameEvent() {} +FrameEvent::FrameEvent() + : frame_id(0u), + size(0u) {} FrameEvent::~FrameEvent() {} -BasePacketInfo::BasePacketInfo() {} +BasePacketInfo::BasePacketInfo() + : size(0u) {} BasePacketInfo::~BasePacketInfo() {} -PacketEvent::PacketEvent() {} +PacketEvent::PacketEvent() + : frame_id(0u), + max_packet_id(0) {} PacketEvent::~PacketEvent() {} GenericEvent::GenericEvent() {} @@ -104,12 +109,23 @@ ReceiverRtcpEvent::ReceiverRtcpEvent() {} ReceiverRtcpEvent::~ReceiverRtcpEvent() {} FrameLogStats::FrameLogStats() - : framerate_fps(0), - bitrate_kbps(0), - max_delay_ms(0), - min_delay_ms(0), - avg_delay_ms(0) {} + : event_counter(0), + sum_size(0) {} FrameLogStats::~FrameLogStats() {} +PacketLogStats::PacketLogStats() + : event_counter(0), + sum_size(0) {} + +PacketLogStats::~PacketLogStats() {} + +GenericLogStats::GenericLogStats() + : event_counter(0), + sum(0), + sum_squared(0), + min(0), + max(0) {} + +GenericLogStats::~GenericLogStats() {} } // namespace cast } // namespace media diff --git a/media/cast/logging/logging_defines.h b/media/cast/logging/logging_defines.h index f23aeb1..057f869 100644 --- a/media/cast/logging/logging_defines.h +++ b/media/cast/logging/logging_defines.h @@ -9,13 +9,12 @@ #include <string> #include <vector> -#include "base/memory/linked_ptr.h" #include "base/time/time.h" namespace media { namespace cast { -static const uint32 kFrameIdUnknown = 0xFFFF; +static const uint32 kFrameIdUnknown = 0xFFFFFFFF; struct CastLoggingConfig { CastLoggingConfig(bool sender); @@ -76,9 +75,11 @@ struct FrameEvent { ~FrameEvent(); uint32 frame_id; - size_t size; // Encoded size only. + // Size is set only for kAudioFrameEncoded and kVideoFrameEncoded. + size_t size; std::vector<base::TimeTicks> timestamp; std::vector<CastLoggingEvent> type; + // Delay is only set for kAudioPlayoutDelay and kVideoRenderDelay. base::TimeDelta delay_delta; // Render/playout delay. }; @@ -109,15 +110,40 @@ struct GenericEvent { std::vector<base::TimeTicks> timestamp; }; +// Generic statistics given the raw data. More specific data (e.g. frame rate +// and bit rate) can be computed given the basic metrics. +// Some of the metrics will only be set when applicable, e.g. delay and size. struct FrameLogStats { FrameLogStats(); ~FrameLogStats(); + base::TimeTicks first_event_time; + base::TimeTicks last_event_time; + int event_counter; + size_t sum_size; + base::TimeDelta min_delay; + base::TimeDelta max_delay; + base::TimeDelta sum_delay; +}; + +struct PacketLogStats { + PacketLogStats(); + ~PacketLogStats(); + base::TimeTicks first_event_time; + base::TimeTicks last_event_time; + int event_counter; + size_t sum_size; +}; - double framerate_fps; - double bitrate_kbps; - int max_delay_ms; - int min_delay_ms; - int avg_delay_ms; +struct GenericLogStats { + GenericLogStats(); + ~GenericLogStats(); + base::TimeTicks first_event_time; + base::TimeTicks last_event_time; + int event_counter; + int sum; + uint64 sum_squared; + int min; + int max; }; struct ReceiverRtcpEvent { @@ -138,9 +164,9 @@ typedef std::map<CastLoggingEvent, GenericEvent> GenericRawMap; typedef std::multimap<uint32, ReceiverRtcpEvent> AudioRtcpRawMap; typedef std::multimap<uint32, ReceiverRtcpEvent> VideoRtcpRawMap; -typedef std::map<CastLoggingEvent, linked_ptr<FrameLogStats > > FrameStatsMap; -typedef std::map<CastLoggingEvent, double> PacketStatsMap; -typedef std::map<CastLoggingEvent, double> GenericStatsMap; +typedef std::map<CastLoggingEvent, FrameLogStats> FrameStatsMap; +typedef std::map<CastLoggingEvent, PacketLogStats> PacketStatsMap; +typedef std::map<CastLoggingEvent, GenericLogStats> GenericStatsMap; } // namespace cast } // namespace media diff --git a/media/cast/logging/logging_impl.cc b/media/cast/logging/logging_impl.cc index 7b5ff4b..8f339ce 100644 --- a/media/cast/logging/logging_impl.cc +++ b/media/cast/logging/logging_impl.cc @@ -55,9 +55,9 @@ void LoggingImpl::InsertFrameEventWithSize(const base::TimeTicks& time_of_event, } if (config_.enable_uma_stats) { if (event == kAudioFrameEncoded) - UMA_HISTOGRAM_COUNTS("Cast.AudioFrameEncoded", frame_size); + UMA_HISTOGRAM_COUNTS("Cast.AudioFrameEncodedSize", frame_size); else if (event == kVideoFrameEncoded) { - UMA_HISTOGRAM_COUNTS("Cast.VideoFrameEncoded", frame_size); + UMA_HISTOGRAM_COUNTS("Cast.VideoFrameEncodedSize", frame_size); } } @@ -169,7 +169,7 @@ void LoggingImpl::InsertGenericUmaEvent(CastLoggingEvent event, int value) { UMA_HISTOGRAM_COUNTS("Cast.RttMs", value); break; case kPacketLoss: - UMA_HISTOGRAM_COUNTS("Cast.PacketLoss", value); + UMA_HISTOGRAM_COUNTS("Cast.PacketLossFraction", value); break; case kJitterMs: UMA_HISTOGRAM_COUNTS("Cast.JitterMs", value); @@ -184,149 +184,44 @@ void LoggingImpl::InsertGenericUmaEvent(CastLoggingEvent event, int value) { } // should just get the entire class, would be much easier. -FrameRawMap LoggingImpl::GetFrameRawData() { +FrameRawMap LoggingImpl::GetFrameRawData() const { DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread()); return raw_.GetFrameData(); } -PacketRawMap LoggingImpl::GetPacketRawData() { +PacketRawMap LoggingImpl::GetPacketRawData() const { DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread()); return raw_.GetPacketData(); } -GenericRawMap LoggingImpl::GetGenericRawData() { +GenericRawMap LoggingImpl::GetGenericRawData() const { DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread()); return raw_.GetGenericData(); } -AudioRtcpRawMap LoggingImpl::GetAudioRtcpRawData() { +AudioRtcpRawMap LoggingImpl::GetAndResetAudioRtcpRawData() { DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread()); return raw_.GetAndResetAudioRtcpData(); } -VideoRtcpRawMap LoggingImpl::GetVideoRtcpRawData() { +VideoRtcpRawMap LoggingImpl::GetAndResetVideoRtcpRawData() { DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread()); return raw_.GetAndResetVideoRtcpData(); } -const FrameStatsMap* LoggingImpl::GetFrameStatsData( - const base::TimeTicks& now) { +FrameStatsMap LoggingImpl::GetFrameStatsData() const { DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread()); - // Get stats data. - const FrameStatsMap* stats = stats_.GetFrameStatsData(now); - if (config_.enable_uma_stats) { - FrameStatsMap::const_iterator it; - for (it = stats->begin(); it != stats->end(); ++it) { - // Check for an active event. - // The default frame event implies frame rate. - if (it->second->framerate_fps > 0) { - switch (it->first) { - case kAudioFrameReceived: - UMA_HISTOGRAM_COUNTS("Cast.Stats.AudioFrameReceived", - it->second->framerate_fps); - break; - case kAudioFrameCaptured: - UMA_HISTOGRAM_COUNTS("Cast.Stats.AudioFrameCaptured", - it->second->framerate_fps); - break; - case kAudioFrameEncoded: - UMA_HISTOGRAM_COUNTS("Cast.Stats.AudioFrameEncoded", - it->second->framerate_fps); - break; - case kVideoFrameCaptured: - UMA_HISTOGRAM_COUNTS("Cast.Stats.VideoFrameCaptured", - it->second->framerate_fps); - break; - case kVideoFrameReceived: - UMA_HISTOGRAM_COUNTS("Cast.Stats.VideoFrameReceived", - it->second->framerate_fps); - break; - case kVideoFrameSentToEncoder: - UMA_HISTOGRAM_COUNTS("Cast.Stats.VideoFrameSentToEncoder", - it->second->framerate_fps); - break; - case kVideoFrameEncoded: - UMA_HISTOGRAM_COUNTS("Cast.Stats.VideoFrameEncoded", - it->second->framerate_fps); - break; - case kVideoFrameDecoded: - UMA_HISTOGRAM_COUNTS("Cast.Stats.VideoFrameDecoded", - it->second->framerate_fps); - break; - default: - // No-op - break; - } - } else { - // All active frame events trigger frame rate computation. - continue; - } - // Bit rate should only be provided following encoding for either audio - // or video. - if (it->first == kVideoFrameEncoded) { - UMA_HISTOGRAM_COUNTS("Cast.Stats.VideoBitrateKbps", - it->second->framerate_fps); - } else if (it->first == kAudioFrameEncoded) { - UMA_HISTOGRAM_COUNTS("Cast.Stats.AudioBitrateKbps", - it->second->framerate_fps); - } - // Delay events. - if (it->first == kAudioPlayoutDelay) { - UMA_HISTOGRAM_COUNTS("Cast.Stats.AudioPlayoutDelayAvg", - it->second->avg_delay_ms); - UMA_HISTOGRAM_COUNTS("Cast.Stats.AudioPlayoutDelayMin", - it->second->min_delay_ms); - UMA_HISTOGRAM_COUNTS("Cast.Stats.AudioPlayoutDelayMax", - it->second->max_delay_ms); - } else if (it->first == kVideoRenderDelay) { - UMA_HISTOGRAM_COUNTS("Cast.Stats.VideoPlayoutDelayAvg", - it->second->avg_delay_ms); - UMA_HISTOGRAM_COUNTS("Cast.Stats.VideoPlayoutDelayMin", - it->second->min_delay_ms); - UMA_HISTOGRAM_COUNTS("Cast.Stats.VideoPlayoutDelayMax", - it->second->max_delay_ms); - } - } - } - return stats; + return stats_.GetFrameStatsData(); } -const PacketStatsMap* LoggingImpl::GetPacketStatsData( - const base::TimeTicks& now) { +PacketStatsMap LoggingImpl::GetPacketStatsData() const { DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread()); - // Get stats data. - const PacketStatsMap* stats = stats_.GetPacketStatsData(now); - if (config_.enable_uma_stats) { - PacketStatsMap::const_iterator it; - for (it = stats->begin(); it != stats->end(); ++it) { - switch (it->first) { - case kPacketSentToPacer: - UMA_HISTOGRAM_COUNTS("Cast.Stats.PacketSentToPacer", it->second); - break; - case kPacketSentToNetwork: - UMA_HISTOGRAM_COUNTS("Cast.Stats.PacketSentToNetwork", it->second); - break; - case kPacketRetransmitted: - UMA_HISTOGRAM_COUNTS("Cast.Stats.PacketRetransmited", it->second); - break; - case kDuplicatePacketReceived: - UMA_HISTOGRAM_COUNTS("Cast.Stats.DuplicatePacketReceived", - it->second); - break; - default: - // No-op. - break; - } - } - } - return stats; + return stats_.GetPacketStatsData(); } -const GenericStatsMap* LoggingImpl::GetGenericStatsData() { +GenericStatsMap LoggingImpl::GetGenericStatsData() const { DCHECK(main_thread_proxy_->RunsTasksOnCurrentThread()); - // Get stats data. - const GenericStatsMap* stats = stats_.GetGenericStatsData(); - return stats; + return stats_.GetGenericStatsData(); } void LoggingImpl::ResetRaw() { diff --git a/media/cast/logging/logging_impl.h b/media/cast/logging/logging_impl.h index a0e1ed9..3105199 100644 --- a/media/cast/logging/logging_impl.h +++ b/media/cast/logging/logging_impl.h @@ -62,18 +62,20 @@ class LoggingImpl : public base::NonThreadSafe { int value); // Get raw data. - FrameRawMap GetFrameRawData(); - PacketRawMap GetPacketRawData(); - GenericRawMap GetGenericRawData(); - AudioRtcpRawMap GetAudioRtcpRawData(); - VideoRtcpRawMap GetVideoRtcpRawData(); - - // Get stats only (computed when called). Triggers UMA stats when enabled. - const FrameStatsMap* GetFrameStatsData(const base::TimeTicks& now); - const PacketStatsMap* GetPacketStatsData(const base::TimeTicks& now); - const GenericStatsMap* GetGenericStatsData(); - - // Reset raw logging data. + FrameRawMap GetFrameRawData() const; + PacketRawMap GetPacketRawData() const; + GenericRawMap GetGenericRawData() const; + + // Get the RTCP data and reset the data. + AudioRtcpRawMap GetAndResetAudioRtcpRawData(); + VideoRtcpRawMap GetAndResetVideoRtcpRawData(); + + // Get stats only. + FrameStatsMap GetFrameStatsData() const; + PacketStatsMap GetPacketStatsData() const; + GenericStatsMap GetGenericStatsData() const; + + // Reset raw logging data (this does not reset the RTCP raw data). void ResetRaw(); // Reset stats logging data. void ResetStats(); diff --git a/media/cast/logging/logging_stats.cc b/media/cast/logging/logging_stats.cc index 2cdabcc..e9e6d72 100644 --- a/media/cast/logging/logging_stats.cc +++ b/media/cast/logging/logging_stats.cc @@ -2,20 +2,18 @@ // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. -#include "base/memory/linked_ptr.h" -#include "base/memory/scoped_ptr.h" #include "media/cast/logging/logging_stats.h" +#include "base/logging.h" +#include "base/memory/scoped_ptr.h" + namespace media { namespace cast { LoggingStats::LoggingStats() : frame_stats_(), packet_stats_(), - generic_stats_(), - start_time_() { - memset(counts_, 0, sizeof(counts_)); - memset(start_time_, 0, sizeof(start_time_)); + generic_stats_() { } LoggingStats::~LoggingStats() {} @@ -24,7 +22,6 @@ void LoggingStats::Reset() { frame_stats_.clear(); packet_stats_.clear(); generic_stats_.clear(); - memset(counts_, 0, sizeof(counts_)); } void LoggingStats::InsertFrameEvent(const base::TimeTicks& time_of_event, @@ -44,7 +41,7 @@ void LoggingStats::InsertFrameEventWithSize( // Update size. FrameStatsMap::iterator it = frame_stats_.find(event); DCHECK(it != frame_stats_.end()); - it->second->bitrate_kbps += frame_size; + it->second.sum_size += frame_size; } void LoggingStats::InsertFrameEventWithDelay( @@ -57,14 +54,11 @@ void LoggingStats::InsertFrameEventWithDelay( // Update size. FrameStatsMap::iterator it = frame_stats_.find(event); DCHECK(it != frame_stats_.end()); - // Using the average delay as a counter, will divide by the counter when - // triggered. - it->second->avg_delay_ms += delay.InMilliseconds(); - if (delay.InMilliseconds() > it->second->max_delay_ms) - it->second->max_delay_ms = delay.InMilliseconds(); - if ((delay.InMilliseconds() < it->second->min_delay_ms) || - (counts_[event] == 1) ) - it->second->min_delay_ms = delay.InMilliseconds(); + it->second.sum_delay += delay; + if (delay > it->second.max_delay || it->second.event_counter == 1) + it->second.max_delay = delay; + if (delay < it->second.min_delay || it->second.event_counter == 1) + it->second.min_delay = delay; } void LoggingStats::InsertBaseFrameEvent(const base::TimeTicks& time_of_event, @@ -75,12 +69,15 @@ void LoggingStats::InsertBaseFrameEvent(const base::TimeTicks& time_of_event, FrameStatsMap::iterator it = frame_stats_.find(event); if (it == frame_stats_.end()) { // New event. - start_time_[event] = time_of_event; - linked_ptr<FrameLogStats> stats(new FrameLogStats()); + FrameLogStats stats; + stats.first_event_time = time_of_event; + stats.last_event_time = time_of_event; + stats.event_counter = 1; frame_stats_.insert(std::make_pair(event, stats)); + } else { + it->second.last_event_time = time_of_event; + ++(it->second.event_counter); } - - ++counts_[event]; } void LoggingStats::InsertPacketEvent(const base::TimeTicks& time_of_event, @@ -94,13 +91,17 @@ void LoggingStats::InsertPacketEvent(const base::TimeTicks& time_of_event, PacketStatsMap::iterator it = packet_stats_.find(event); if (it == packet_stats_.end()) { // New event. - start_time_[event] = time_of_event; - packet_stats_.insert(std::make_pair(event, size)); + PacketLogStats stats; + stats.first_event_time = time_of_event; + stats.last_event_time = time_of_event; + stats.sum_size = size; + stats.event_counter = 1; + packet_stats_.insert(std::make_pair(event, stats)); } else { - // Add to existing. - it->second += size; + // Add to an existing event. + it->second.sum_size += size; + ++(it->second.event_counter); } - ++counts_[event]; } void LoggingStats::InsertGenericEvent(const base::TimeTicks& time_of_event, @@ -109,50 +110,39 @@ void LoggingStats::InsertGenericEvent(const base::TimeTicks& time_of_event, GenericStatsMap::iterator it = generic_stats_.find(event); if (it == generic_stats_.end()) { // New event. - start_time_[event] = time_of_event; - generic_stats_.insert(std::make_pair(event, value)); + GenericLogStats stats; + stats.first_event_time = time_of_event; + stats.last_event_time = time_of_event; + stats.sum = value; + stats.sum_squared = value * value; + stats.min = value; + stats.max = value; + stats.event_counter = 1; + generic_stats_.insert(std::make_pair(event, stats)); } else { - // Add to existing (will be used to compute average). - it->second += value; + // Add to existing event. + it->second.sum += value; + it->second.sum_squared += value * value; + ++(it->second.event_counter); + it->second.last_event_time = time_of_event; + if (it->second.min > value) { + it->second.min = value; + } else if (it->second.max < value) { + it->second.max = value; + } } - ++counts_[event]; } -const FrameStatsMap* LoggingStats::GetFrameStatsData( - const base::TimeTicks& now) { - // Compute framerate and bitrate (when available). - FrameStatsMap::iterator it; - for (it = frame_stats_.begin(); it != frame_stats_.end(); ++it) { - base::TimeDelta time_diff = now - start_time_[it->first]; - it->second->framerate_fps = counts_[it->first] / time_diff.InSecondsF(); - if (it->second->bitrate_kbps > 0) { - it->second->bitrate_kbps = (8 / 1000) * it->second->bitrate_kbps / - time_diff.InSecondsF(); - } - if (it->second->avg_delay_ms > 0) - it->second->avg_delay_ms /= counts_[it->first]; - } - return &frame_stats_; +FrameStatsMap LoggingStats::GetFrameStatsData() const { + return frame_stats_; } -const PacketStatsMap* LoggingStats::GetPacketStatsData( - const base::TimeTicks& now) { - PacketStatsMap::iterator it; - for (it = packet_stats_.begin(); it != packet_stats_.end(); ++it) { - if (counts_[it->first] == 0) continue; - base::TimeDelta time_diff = now - start_time_[it->first]; - it->second = (8 / 1000) * it->second / time_diff.InSecondsF(); - } - return &packet_stats_; +PacketStatsMap LoggingStats::GetPacketStatsData() const { + return packet_stats_; } -const GenericStatsMap* LoggingStats::GetGenericStatsData() { - // Compute averages. - GenericStatsMap::iterator it; - for (it = generic_stats_.begin(); it != generic_stats_.end(); ++it) { - it->second /= counts_[ it->first]; - } - return &generic_stats_; +GenericStatsMap LoggingStats::GetGenericStatsData() const { + return generic_stats_; } } // namespace cast diff --git a/media/cast/logging/logging_stats.h b/media/cast/logging/logging_stats.h index 4421ecd..eb5745e 100644 --- a/media/cast/logging/logging_stats.h +++ b/media/cast/logging/logging_stats.h @@ -47,13 +47,11 @@ class LoggingStats { void InsertGenericEvent(const base::TimeTicks& time_of_event, CastLoggingEvent event, int value); - // Get log stats: some of the values, such as frame rate and bit rates are - // computed at the time of the call. - const FrameStatsMap* GetFrameStatsData(const base::TimeTicks& now); + FrameStatsMap GetFrameStatsData() const; - const PacketStatsMap* GetPacketStatsData(const base::TimeTicks& now); + PacketStatsMap GetPacketStatsData() const; - const GenericStatsMap* GetGenericStatsData(); + GenericStatsMap GetGenericStatsData() const; private: void InsertBaseFrameEvent(const base::TimeTicks& time_of_event, @@ -64,10 +62,6 @@ class LoggingStats { FrameStatsMap frame_stats_; PacketStatsMap packet_stats_; GenericStatsMap generic_stats_; - // Every event has an individual start time - base::TimeTicks start_time_[kNumOfLoggingEvents]; - // Keep track of event counts. - int counts_[kNumOfLoggingEvents]; DISALLOW_COPY_AND_ASSIGN(LoggingStats); }; diff --git a/media/cast/logging/logging_unittest.cc b/media/cast/logging/logging_unittest.cc index c07571b..256eaf1 100644 --- a/media/cast/logging/logging_unittest.cc +++ b/media/cast/logging/logging_unittest.cc @@ -42,6 +42,8 @@ class TestLogging : public ::testing::Test { scoped_refptr<test::FakeSingleThreadTaskRunner> task_runner_; scoped_ptr<LoggingImpl> logging_; base::SimpleTestTickClock testing_clock_; + + DISALLOW_COPY_AND_ASSIGN(TestLogging); }; TEST_F(TestLogging, BasicFrameLogging) { @@ -49,31 +51,35 @@ TEST_F(TestLogging, BasicFrameLogging) { base::TimeDelta time_interval = testing_clock_.NowTicks() - start_time; uint32 rtp_timestamp = 0; uint32 frame_id = 0; + base::TimeTicks now; do { - logging_->InsertFrameEvent(testing_clock_.NowTicks(), - kAudioFrameCaptured, rtp_timestamp, frame_id); + now = testing_clock_.NowTicks(); + logging_->InsertFrameEvent(now, kAudioFrameCaptured, rtp_timestamp, + frame_id); testing_clock_.Advance( base::TimeDelta::FromMilliseconds(kFrameIntervalMs)); rtp_timestamp += kFrameIntervalMs * 90; ++frame_id; - time_interval = testing_clock_.NowTicks() - start_time; + time_interval = now - start_time; } while (time_interval.InSeconds() < kIntervalTime1S); + base::TimeTicks end_time = now; // Get logging data. FrameRawMap frame_map = logging_->GetFrameRawData(); // Size of map should be equal to the number of frames logged. EXPECT_EQ(frame_id, frame_map.size()); // Verify stats. - const FrameStatsMap* frame_stats = - logging_->GetFrameStatsData(testing_clock_.NowTicks()); + FrameStatsMap frame_stats = logging_->GetFrameStatsData(); // Size of stats equals the number of events. - EXPECT_EQ(1u, frame_stats->size()); - FrameStatsMap::const_iterator it = frame_stats->find(kAudioFrameCaptured); - EXPECT_TRUE(it != frame_stats->end()); - EXPECT_NEAR(30.3, it->second->framerate_fps, 0.1); - EXPECT_EQ(0, it->second->bitrate_kbps); - EXPECT_EQ(0, it->second->max_delay_ms); - EXPECT_EQ(0, it->second->min_delay_ms); - EXPECT_EQ(0, it->second->avg_delay_ms); + EXPECT_EQ(1u, frame_stats.size()); + FrameStatsMap::const_iterator it = frame_stats.find(kAudioFrameCaptured); + EXPECT_TRUE(it != frame_stats.end()); + EXPECT_EQ(0, it->second.max_delay.InMilliseconds()); + EXPECT_EQ(0, it->second.min_delay.InMilliseconds()); + EXPECT_EQ(start_time, it->second.first_event_time); + EXPECT_EQ(end_time, it->second.last_event_time); + EXPECT_EQ(0u, it->second.sum_size); + // Number of events is equal to the number of frames. + EXPECT_EQ(static_cast<int>(frame_id), it->second.event_counter); } TEST_F(TestLogging, FrameLoggingWithSize) { @@ -84,9 +90,11 @@ TEST_F(TestLogging, FrameLoggingWithSize) { base::TimeDelta time_interval = testing_clock_.NowTicks() - start_time; uint32 rtp_timestamp = 0; uint32 frame_id = 0; + size_t sum_size = 0; do { int size = kBaseFrameSizeBytes + base::RandInt(-kRandomSizeInterval, kRandomSizeInterval); + sum_size += static_cast<size_t>(size); logging_->InsertFrameEventWithSize(testing_clock_.NowTicks(), kAudioFrameCaptured, rtp_timestamp, frame_id, size); testing_clock_.Advance( @@ -100,18 +108,15 @@ TEST_F(TestLogging, FrameLoggingWithSize) { // Size of map should be equal to the number of frames logged. EXPECT_EQ(frame_id, frame_map.size()); // Verify stats. - const FrameStatsMap* frame_stats = - logging_->GetFrameStatsData(testing_clock_.NowTicks()); + FrameStatsMap frame_stats = logging_->GetFrameStatsData(); // Size of stats equals the number of events. - EXPECT_EQ(1u, frame_stats->size()); - FrameStatsMap::const_iterator it = frame_stats->find(kAudioFrameCaptured); - EXPECT_TRUE(it != frame_stats->end()); - EXPECT_NEAR(30.3, it->second->framerate_fps, 0.1); - EXPECT_NEAR(8 * kBaseFrameSizeBytes / (kFrameIntervalMs * 1000), - it->second->bitrate_kbps, kRandomSizeInterval); - EXPECT_EQ(0, it->second->max_delay_ms); - EXPECT_EQ(0, it->second->min_delay_ms); - EXPECT_EQ(0, it->second->avg_delay_ms); + EXPECT_EQ(1u, frame_stats.size()); + FrameStatsMap::const_iterator it = frame_stats.find(kAudioFrameCaptured); + EXPECT_TRUE(it != frame_stats.end()); + EXPECT_EQ(0, it->second.max_delay.InMilliseconds()); + EXPECT_EQ(0, it->second.min_delay.InMilliseconds()); + EXPECT_EQ(0, it->second.sum_delay.InMilliseconds()); + EXPECT_EQ(sum_size, it->second.sum_size); } TEST_F(TestLogging, FrameLoggingWithDelay) { @@ -139,18 +144,15 @@ TEST_F(TestLogging, FrameLoggingWithDelay) { // Size of map should be equal to the number of frames logged. EXPECT_EQ(frame_id, frame_map.size()); // Verify stats. - const FrameStatsMap* frame_stats = - logging_->GetFrameStatsData(testing_clock_.NowTicks()); + FrameStatsMap frame_stats = logging_->GetFrameStatsData(); // Size of stats equals the number of events. - EXPECT_EQ(1u, frame_stats->size()); - FrameStatsMap::const_iterator it = frame_stats->find(kAudioFrameCaptured); - EXPECT_TRUE(it != frame_stats->end()); - EXPECT_NEAR(30.3, it->second->framerate_fps, 0.1); - EXPECT_EQ(0, it->second->bitrate_kbps); - EXPECT_GE(kPlayoutDelayMs + kRandomSizeInterval, it->second->max_delay_ms); - EXPECT_LE(kPlayoutDelayMs - kRandomSizeInterval, it->second->min_delay_ms); - EXPECT_NEAR(kPlayoutDelayMs, it->second->avg_delay_ms, - 0.2 * kRandomSizeInterval); + EXPECT_EQ(1u, frame_stats.size()); + FrameStatsMap::const_iterator it = frame_stats.find(kAudioFrameCaptured); + EXPECT_TRUE(it != frame_stats.end()); + EXPECT_GE(kPlayoutDelayMs + kRandomSizeInterval, + it->second.max_delay.InMilliseconds()); + EXPECT_LE(kPlayoutDelayMs - kRandomSizeInterval, + it->second.min_delay.InMilliseconds()); } TEST_F(TestLogging, MultipleEventFrameLogging) { @@ -210,37 +212,54 @@ TEST_F(TestLogging, PacketLogging) { // Size of map should be equal to the number of frames logged. EXPECT_EQ(frame_id, raw_map.size()); // Verify stats. - const PacketStatsMap* stats_map = - logging_->GetPacketStatsData(testing_clock_.NowTicks()); + PacketStatsMap stats_map = logging_->GetPacketStatsData(); // Size of stats equals the number of events. - EXPECT_EQ(1u, stats_map->size()); - PacketStatsMap::const_iterator it = stats_map->find(kPacketSentToPacer); - EXPECT_TRUE(it != stats_map->end()); - // We only store the bitrate as a packet statistic. - EXPECT_NEAR(8 * kNumPacketsPerFrame * kBaseSize / (kFrameIntervalMs * 1000), - it->second, kSizeInterval); + EXPECT_EQ(1u, stats_map.size()); + PacketStatsMap::const_iterator it = stats_map.find(kPacketSentToPacer); + EXPECT_TRUE(it != stats_map.end()); } TEST_F(TestLogging, GenericLogging) { // Insert multiple generic types. - const size_t kNumRuns = 1000; + const size_t kNumRuns = 20;//1000; const int kBaseValue = 20; + int sum_value_rtt = 0; + int sum_value_pl = 0; + int sum_value_jitter = 0; + uint64 sumsq_value_rtt = 0; + uint64 sumsq_value_pl = 0; + uint64 sumsq_value_jitter = 0; + int min_value, max_value; for (size_t i = 0; i < kNumRuns; ++i) { int value = kBaseValue + base::RandInt(-5, 5); + sum_value_rtt += value; + sumsq_value_rtt += value * value; logging_->InsertGenericEvent(testing_clock_.NowTicks(), kRttMs, value); if (i % 2) { logging_->InsertGenericEvent(testing_clock_.NowTicks(), kPacketLoss, value); + sum_value_pl += value; + sumsq_value_pl += value * value; } if (!(i % 4)) { logging_->InsertGenericEvent(testing_clock_.NowTicks(), kJitterMs, value); + sum_value_jitter += value; + sumsq_value_jitter += value * value; + } + if (i == 0) { + min_value = value; + max_value = value; + } else if (min_value > value) { + min_value = value; + } else if (max_value < value) { + max_value = value; } } GenericRawMap raw_map = logging_->GetGenericRawData(); - const GenericStatsMap* stats_map = logging_->GetGenericStatsData(); + GenericStatsMap stats_map = logging_->GetGenericStatsData(); // Size of generic map = number of different events. EXPECT_EQ(3u, raw_map.size()); - EXPECT_EQ(3u, stats_map->size()); + EXPECT_EQ(3u, stats_map.size()); // Raw events - size of internal map = number of calls. GenericRawMap::iterator rit = raw_map.find(kRttMs); EXPECT_EQ(kNumRuns, rit->second.value.size()); @@ -251,13 +270,21 @@ TEST_F(TestLogging, GenericLogging) { rit = raw_map.find(kJitterMs); EXPECT_EQ(kNumRuns / 4, rit->second.value.size()); EXPECT_EQ(kNumRuns / 4, rit->second.timestamp.size()); - // Stats - one value per event. - GenericStatsMap::const_iterator sit = stats_map->find(kRttMs); - EXPECT_NEAR(kBaseValue, sit->second, 2.5); - sit = stats_map->find(kPacketLoss); - EXPECT_NEAR(kBaseValue, sit->second, 2.5); - sit = stats_map->find(kJitterMs); - EXPECT_NEAR(kBaseValue, sit->second, 2.5); + // Stats - one value per all events. + GenericStatsMap::const_iterator sit = stats_map.find(kRttMs); + EXPECT_EQ(sum_value_rtt, sit->second.sum); + EXPECT_EQ(sumsq_value_rtt, sit->second.sum_squared); + EXPECT_LE(min_value, sit->second.min); + EXPECT_GE(max_value, sit->second.max); + sit = stats_map.find(kPacketLoss); + EXPECT_EQ(sum_value_pl, sit->second.sum); + EXPECT_EQ(sumsq_value_pl, sit->second.sum_squared); + EXPECT_LE(min_value, sit->second.min); + EXPECT_GE(max_value, sit->second.max); + sit = stats_map.find(kJitterMs); + EXPECT_EQ(sumsq_value_jitter, sit->second.sum_squared); + EXPECT_LE(min_value, sit->second.min); + EXPECT_GE(max_value, sit->second.max); } TEST_F(TestLogging, RtcpMultipleEventFrameLogging) { @@ -291,10 +318,10 @@ TEST_F(TestLogging, RtcpMultipleEventFrameLogging) { EXPECT_EQ(frame_id, frame_map.size()); // Multiple events captured per frame. - AudioRtcpRawMap audio_rtcp = logging_->GetAudioRtcpRawData(); + AudioRtcpRawMap audio_rtcp = logging_->GetAndResetAudioRtcpRawData(); EXPECT_EQ(0u, audio_rtcp.size()); - VideoRtcpRawMap video_rtcp = logging_->GetVideoRtcpRawData(); + VideoRtcpRawMap video_rtcp = logging_->GetAndResetVideoRtcpRawData(); EXPECT_EQ((frame_id + 1) / 2, video_rtcp.size()); } diff --git a/media/cast/video_receiver/video_receiver.cc b/media/cast/video_receiver/video_receiver.cc index cdaaf38..21a3067 100644 --- a/media/cast/video_receiver/video_receiver.cc +++ b/media/cast/video_receiver/video_receiver.cc @@ -423,7 +423,7 @@ void VideoReceiver::CastFeedback(const RtcpCastMessage& cast_message) { RtcpReceiverLogMessage receiver_log; VideoRtcpRawMap video_logs = - cast_environment_->Logging()->GetVideoRtcpRawData(); + cast_environment_->Logging()->GetAndResetVideoRtcpRawData(); while (!video_logs.empty()) { // TODO(hclam): Avoid calling begin() within a loop. diff --git a/media/cast/video_sender/video_sender.cc b/media/cast/video_sender/video_sender.cc index bcffd0e..7eba267 100644 --- a/media/cast/video_sender/video_sender.cc +++ b/media/cast/video_sender/video_sender.cc @@ -221,7 +221,7 @@ void VideoSender::SendRtcpReport() { transport::RtcpSenderLogMessage sender_log_message; VideoRtcpRawMap video_logs = - cast_environment_->Logging()->GetVideoRtcpRawData(); + cast_environment_->Logging()->GetAndResetVideoRtcpRawData(); while (!video_logs.empty()) { // TODO(hclam): Avoid calling begin() within a loop. |