// Copyright 2015 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. #include "remoting/protocol/performance_tracker.h" #include "remoting/proto/video.pb.h" namespace { // We take the last 10 latency numbers and report the average. const int kLatencySampleSize = 10; // UMA histogram names. const char kRoundTripLatencyHistogram[] = "Chromoting.Video.RoundTripLatency"; const char kVideoCaptureLatencyHistogram[] = "Chromoting.Video.CaptureLatency"; const char kVideoEncodeLatencyHistogram[] = "Chromoting.Video.EncodeLatency"; const char kVideoDecodeLatencyHistogram[] = "Chromoting.Video.DecodeLatency"; const char kVideoPaintLatencyHistogram[] = "Chromoting.Video.PaintLatency"; const char kVideoFrameRateHistogram[] = "Chromoting.Video.FrameRate"; const char kVideoPacketRateHistogram[] = "Chromoting.Video.PacketRate"; const char kVideoBandwidthHistogram[] = "Chromoting.Video.Bandwidth"; const char kCapturePendingLatencyHistogram[] = "Chromoting.Video.CapturePendingLatency"; const char kCaptureOverheadHistogram[] = "Chromoting.Video.CaptureOverhead"; const char kEncodePendingLatencyHistogram[] = "Chromoting.Video.EncodePendingLatency"; const char kSendPendingLatencyHistogram[] = "Chromoting.Video.SendPendingLatency"; const char kNetworkLatencyHistogram[] = "Chromoting.Video.NetworkLatency"; // Custom count and custom time histograms are log-scaled by default. This // results in fine-grained buckets at lower values and wider-ranged buckets // closer to the maximum. // The values defined for each histogram below are based on the 99th percentile // numbers for the corresponding metric over a recent 28-day period. // Values above the maximum defined for a histogram end up in the max-bucket. // If the minimum for a UMA histogram is set to be < 1, it is implicitly // normalized to 1. // See $/src/base/metrics/histogram.h for more details. // Video-specific metrics are stored in a custom times histogram. const int kVideoActionsHistogramsMinMs = 1; const int kVideoActionsHistogramsMaxMs = 250; const int kVideoActionsHistogramsBuckets = 50; // Round-trip latency values are stored in a custom times histogram. const int kLatencyHistogramMinMs = 1; const int kLatencyHistogramMaxMs = 20000; const int kLatencyHistogramBuckets = 50; // Bandwidth statistics are stored in a custom counts histogram. const int kBandwidthHistogramMinBps = 0; const int kBandwidthHistogramMaxBps = 10 * 1000 * 1000; const int kBandwidthHistogramBuckets = 100; // Frame rate is stored in a custom enum histogram, because we we want to record // the frequency of each discrete value, rather than using log-scaled buckets. // We don't expect video frame rate to be greater than 40fps. Setting a maximum // of 100fps will leave some room for future improvements, and account for any // bursts of packets. Enum histograms expect samples to be less than the // boundary value, so set to 101. const int kMaxFramesPerSec = 101; void UpdateUmaEnumHistogramStub(const std::string& histogram_name, int64_t value, int histogram_max) {} void UpdateUmaCustomHistogramStub(const std::string& histogram_name, int64_t value, int histogram_min, int histogram_max, int histogram_buckets) {} } // namespace namespace remoting { namespace protocol { PerformanceTracker::FrameTimestamps::FrameTimestamps() {} PerformanceTracker::FrameTimestamps::~FrameTimestamps() {} PerformanceTracker::PerformanceTracker() : video_bandwidth_(base::TimeDelta::FromSeconds(kStatsUpdatePeriodSeconds)), video_frame_rate_( base::TimeDelta::FromSeconds(kStatsUpdatePeriodSeconds)), video_packet_rate_( base::TimeDelta::FromSeconds(kStatsUpdatePeriodSeconds)), video_capture_ms_(kLatencySampleSize), video_encode_ms_(kLatencySampleSize), video_decode_ms_(kLatencySampleSize), video_paint_ms_(kLatencySampleSize), round_trip_ms_(kLatencySampleSize) { uma_custom_counts_updater_ = base::Bind(&UpdateUmaCustomHistogramStub); uma_custom_times_updater_ = base::Bind(&UpdateUmaCustomHistogramStub); uma_enum_histogram_updater_ = base::Bind(&UpdateUmaEnumHistogramStub); } PerformanceTracker::~PerformanceTracker() {} void PerformanceTracker::SetUpdateUmaCallbacks( UpdateUmaCustomHistogramCallback update_uma_custom_counts_callback, UpdateUmaCustomHistogramCallback update_uma_custom_times_callback, UpdateUmaEnumHistogramCallback update_uma_enum_histogram_callback) { DCHECK(!update_uma_custom_counts_callback.is_null()); DCHECK(!update_uma_custom_times_callback.is_null()); DCHECK(!update_uma_enum_histogram_callback.is_null()); uma_custom_counts_updater_ = update_uma_custom_counts_callback; uma_custom_times_updater_ = update_uma_custom_times_callback; uma_enum_histogram_updater_ = update_uma_enum_histogram_callback; } void PerformanceTracker::RecordVideoPacketStats(const VideoPacket& packet) { if (!is_paused_ && !upload_uma_stats_timer_.IsRunning()) { upload_uma_stats_timer_.Start( FROM_HERE, base::TimeDelta::FromSeconds(kStatsUpdatePeriodSeconds), base::Bind(&PerformanceTracker::UploadRateStatsToUma, base::Unretained(this))); } // Record this received packet, even if it is empty. video_packet_rate_.Record(1); FrameTimestamps timestamps; timestamps.time_received = base::TimeTicks::Now(); if (packet.has_latest_event_timestamp()) { base::TimeTicks timestamp = base::TimeTicks::FromInternalValue(packet.latest_event_timestamp()); // Only use latest_event_timestamp field if it has changed from the // previous frame. if (timestamp > latest_event_timestamp_) { timestamps.latest_event_timestamp = timestamp; latest_event_timestamp_ = timestamp; } } // If the host didn't specify any of the latency fields then set // |total_host_latency| to Max, to indicate that the latency is unknown. timestamps.total_host_latency = base::TimeDelta::Max(); if (packet.has_capture_time_ms() && packet.has_encode_time_ms() && packet.has_capture_pending_time_ms() && packet.has_capture_overhead_time_ms() && packet.has_encode_pending_time_ms() && packet.has_send_pending_time_ms()) { timestamps.total_host_latency = base::TimeDelta::FromMilliseconds( packet.capture_time_ms() + packet.encode_time_ms() + packet.capture_pending_time_ms() + packet.capture_overhead_time_ms() + packet.encode_pending_time_ms() + packet.send_pending_time_ms()); } // If the packet is empty, there are no other stats to update. if (!packet.data().size()) { // Record the RTT, even for empty packets, otherwise input events that // do not cause an on-screen change can give very large, bogus RTTs. RecordRoundTripLatency(timestamps); return; } DCHECK(packet.has_frame_id()); frame_timestamps_[packet.frame_id()] = timestamps; video_frame_rate_.Record(1); video_bandwidth_.Record(packet.data().size()); if (packet.has_capture_time_ms()) { video_capture_ms_.Record(packet.capture_time_ms()); uma_custom_times_updater_.Run( kVideoCaptureLatencyHistogram, packet.capture_time_ms(), kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); } if (packet.has_encode_time_ms()) { video_encode_ms_.Record(packet.encode_time_ms()); uma_custom_times_updater_.Run( kVideoEncodeLatencyHistogram, packet.encode_time_ms(), kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); } if (packet.has_capture_pending_time_ms()) { uma_custom_times_updater_.Run( kCapturePendingLatencyHistogram, packet.capture_pending_time_ms(), kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); } if (packet.has_capture_overhead_time_ms()) { uma_custom_times_updater_.Run( kCaptureOverheadHistogram, packet.capture_overhead_time_ms(), kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); } if (packet.has_encode_pending_time_ms()) { uma_custom_times_updater_.Run( kEncodePendingLatencyHistogram, packet.encode_pending_time_ms(), kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); } if (packet.has_send_pending_time_ms()) { uma_custom_times_updater_.Run( kSendPendingLatencyHistogram, packet.send_pending_time_ms(), kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); } } void PerformanceTracker::OnFrameDecoded(int32_t frame_id) { FramesTimestampsMap::iterator it = frame_timestamps_.find(frame_id); DCHECK(it != frame_timestamps_.end()); it->second.time_decoded = base::TimeTicks::Now(); base::TimeDelta delay = it->second.time_decoded - it->second.time_received; video_decode_ms_.Record(delay.InMilliseconds()); uma_custom_times_updater_.Run( kVideoDecodeLatencyHistogram, delay.InMilliseconds(), kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); } void PerformanceTracker::OnFramePainted(int32_t frame_id) { base::TimeTicks now = base::TimeTicks::Now(); while (!frame_timestamps_.empty() && frame_timestamps_.begin()->first <= frame_id) { FrameTimestamps& timestamps = frame_timestamps_.begin()->second; // time_decoded may be null if OnFrameDecoded() was never called, e.g. if // the frame was dropped or decoding has failed. if (!timestamps.time_decoded.is_null()) { base::TimeDelta delay = now - timestamps.time_decoded; video_paint_ms_.Record(delay.InMilliseconds()); uma_custom_times_updater_.Run( kVideoPaintLatencyHistogram, delay.InMilliseconds(), kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); } RecordRoundTripLatency(timestamps); frame_timestamps_.erase(frame_timestamps_.begin()); } } void PerformanceTracker::RecordRoundTripLatency( const FrameTimestamps& timestamps) { if (timestamps.latest_event_timestamp.is_null()) return; base::TimeTicks now = base::TimeTicks::Now(); base::TimeDelta round_trip_latency = now - timestamps.latest_event_timestamp; round_trip_ms_.Record(round_trip_latency.InMilliseconds()); uma_custom_times_updater_.Run( kRoundTripLatencyHistogram, round_trip_latency.InMilliseconds(), kLatencyHistogramMinMs, kLatencyHistogramMaxMs, kLatencyHistogramBuckets); if (!timestamps.total_host_latency.is_max()) { // Calculate total processing time on host and client. base::TimeDelta total_processing_latency = timestamps.total_host_latency + (now - timestamps.time_received); base::TimeDelta network_latency = round_trip_latency - total_processing_latency; uma_custom_times_updater_.Run( kNetworkLatencyHistogram, network_latency.InMilliseconds(), kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); } } void PerformanceTracker::UploadRateStatsToUma() { uma_enum_histogram_updater_.Run(kVideoFrameRateHistogram, video_frame_rate(), kMaxFramesPerSec); uma_enum_histogram_updater_.Run(kVideoPacketRateHistogram, video_packet_rate(), kMaxFramesPerSec); uma_custom_counts_updater_.Run( kVideoBandwidthHistogram, video_bandwidth(), kBandwidthHistogramMinBps, kBandwidthHistogramMaxBps, kBandwidthHistogramBuckets); } void PerformanceTracker::OnPauseStateChanged(bool paused) { is_paused_ = paused; if (is_paused_) { // Pause the UMA timer when the video is paused. It will be unpaused in // RecordVideoPacketStats() when a new frame is received. upload_uma_stats_timer_.Stop(); } } } // namespace protocol } // namespace remoting