diff options
| -rw-r--r-- | remoting/client/jni/chromoting_jni_instance.cc | 12 | ||||
| -rw-r--r-- | remoting/client/jni/chromoting_jni_instance.h | 4 | ||||
| -rw-r--r-- | remoting/client/plugin/pepper_video_renderer_3d.cc | 32 | ||||
| -rw-r--r-- | remoting/client/plugin/pepper_video_renderer_3d.h | 16 | ||||
| -rw-r--r-- | remoting/client/software_video_renderer.cc | 27 | ||||
| -rw-r--r-- | remoting/client/software_video_renderer.h | 9 | ||||
| -rw-r--r-- | remoting/protocol/client_event_dispatcher.cc | 8 | ||||
| -rw-r--r-- | remoting/protocol/performance_tracker.cc | 89 | ||||
| -rw-r--r-- | remoting/protocol/performance_tracker.h | 29 |
9 files changed, 111 insertions, 115 deletions
diff --git a/remoting/client/jni/chromoting_jni_instance.cc b/remoting/client/jni/chromoting_jni_instance.cc index ba7672b..b12364e 100644 --- a/remoting/client/jni/chromoting_jni_instance.cc +++ b/remoting/client/jni/chromoting_jni_instance.cc @@ -292,18 +292,6 @@ void ChromotingJniInstance::SendClientMessage(const std::string& type, client_->host_stub()->DeliverClientMessage(extension_message); } -void ChromotingJniInstance::RecordPaintTime(int64 paint_time_ms) { - if (!jni_runtime_->network_task_runner()->BelongsToCurrentThread()) { - jni_runtime_->network_task_runner()->PostTask( - FROM_HERE, base::Bind(&ChromotingJniInstance::RecordPaintTime, this, - paint_time_ms)); - return; - } - - if (stats_logging_enabled_) - perf_tracker_->RecordPaintTime(paint_time_ms); -} - void ChromotingJniInstance::OnConnectionState( protocol::ConnectionToHost::State state, protocol::ErrorCode error) { diff --git a/remoting/client/jni/chromoting_jni_instance.h b/remoting/client/jni/chromoting_jni_instance.h index d87aed9..6ec4e40 100644 --- a/remoting/client/jni/chromoting_jni_instance.h +++ b/remoting/client/jni/chromoting_jni_instance.h @@ -93,10 +93,6 @@ class ChromotingJniInstance void SendClientMessage(const std::string& type, const std::string& data); - // Records paint time for statistics logging, if enabled. May be called from - // any thread. - void RecordPaintTime(int64 paint_time_ms); - // ClientUserInterface implementation. void OnConnectionState(protocol::ConnectionToHost::State state, protocol::ErrorCode error) override; diff --git a/remoting/client/plugin/pepper_video_renderer_3d.cc b/remoting/client/plugin/pepper_video_renderer_3d.cc index 83985d4..4d518b6 100644 --- a/remoting/client/plugin/pepper_video_renderer_3d.cc +++ b/remoting/client/plugin/pepper_video_renderer_3d.cc @@ -54,11 +54,6 @@ class PepperVideoRenderer3D::Picture { PP_VideoPicture picture_; }; -PepperVideoRenderer3D::FrameDecodeTimestamp::FrameDecodeTimestamp( - uint32_t frame_id, - base::TimeTicks decode_started_time) - : frame_id(frame_id), decode_started_time(decode_started_time) {} - PepperVideoRenderer3D::PepperVideoRenderer3D() : callback_factory_(this) {} PepperVideoRenderer3D::~PepperVideoRenderer3D() { @@ -265,14 +260,10 @@ void PepperVideoRenderer3D::DecodeNextPacket() { if (!initialization_finished_ || decode_pending_ || pending_packets_.empty()) return; - ++latest_frame_id_; - frame_decode_timestamps_.push_back( - FrameDecodeTimestamp(latest_frame_id_, base::TimeTicks::Now())); - const VideoPacket* packet = pending_packets_.front()->packet(); int32_t result = video_decoder_.Decode( - latest_frame_id_, packet->data().size(), packet->data().data(), + packet->frame_id(), packet->data().size(), packet->data().data(), callback_factory_.NewCallback(&PepperVideoRenderer3D::OnDecodeDone)); CHECK_EQ(result, PP_OK_COMPLETIONPENDING); decode_pending_ = true; @@ -317,21 +308,7 @@ void PepperVideoRenderer3D::OnPictureReady(int32_t result, return; } - CHECK(!frame_decode_timestamps_.empty()); - const FrameDecodeTimestamp& frame_timer = frame_decode_timestamps_.front(); - - if (picture.decode_id != frame_timer.frame_id) { - LOG(ERROR) - << "Received a video packet that didn't contain a complete frame."; - event_handler_->OnVideoDecodeError(); - return; - } - - base::TimeDelta decode_time = - base::TimeTicks::Now() - frame_timer.decode_started_time; - perf_tracker_->RecordDecodeTime(decode_time.InMilliseconds()); - - frame_decode_timestamps_.pop_front(); + perf_tracker_->OnFrameDecoded(picture.decode_id); next_picture_.reset(new Picture(&video_decoder_, picture)); @@ -348,7 +325,6 @@ void PepperVideoRenderer3D::PaintIfNeeded() { current_picture_ = next_picture_.Pass(); force_repaint_ = false; - latest_paint_started_time_ = base::TimeTicks::Now(); const PP_VideoPicture& picture = current_picture_->picture(); PP_Resource graphics_3d = graphics_.pp_resource(); @@ -409,9 +385,7 @@ void PepperVideoRenderer3D::OnPaintDone(int32_t result) { CHECK_EQ(result, PP_OK) << "Graphics3D::SwapBuffers() failed"; paint_pending_ = false; - base::TimeDelta paint_time = - base::TimeTicks::Now() - latest_paint_started_time_; - perf_tracker_->RecordPaintTime(paint_time.InMilliseconds()); + perf_tracker_->OnFramePainted(current_picture_->picture().decode_id); PaintIfNeeded(); } diff --git a/remoting/client/plugin/pepper_video_renderer_3d.h b/remoting/client/plugin/pepper_video_renderer_3d.h index a624a87..2c229b6 100644 --- a/remoting/client/plugin/pepper_video_renderer_3d.h +++ b/remoting/client/plugin/pepper_video_renderer_3d.h @@ -11,7 +11,6 @@ #include "base/basictypes.h" #include "base/callback.h" #include "base/memory/scoped_ptr.h" -#include "base/time/time.h" #include "ppapi/cpp/graphics_3d.h" #include "ppapi/cpp/instance_handle.h" #include "ppapi/cpp/video_decoder.h" @@ -53,13 +52,6 @@ class PepperVideoRenderer3D : public PepperVideoRenderer, class PendingPacket; class Picture; - struct FrameDecodeTimestamp { - FrameDecodeTimestamp(uint32_t frame_id, - base::TimeTicks decode_started_time); - uint32_t frame_id; - base::TimeTicks decode_started_time; - }; - // Callback for pp::VideoDecoder::Initialize(). void OnInitialized(int32_t result); @@ -113,15 +105,10 @@ class PepperVideoRenderer3D : public PepperVideoRenderer, bool get_picture_pending_ = false; bool paint_pending_ = false; - uint32_t latest_frame_id_ = 0; - // Queue of packets that that have been received, but haven't been passed to // the decoder yet. std::deque<PendingPacket*> pending_packets_; - // Timestamps for all frames currently being processed by the decoder. - std::deque<FrameDecodeTimestamp> frame_decode_timestamps_; - // The current picture shown on the screen or being rendered. Must be deleted // before |video_decoder_|. scoped_ptr<Picture> current_picture_; @@ -134,9 +121,6 @@ class PepperVideoRenderer3D : public PepperVideoRenderer, // Set to true if the screen has been resized and needs to be repainted. bool force_repaint_ = false; - // Time the last paint operation was started. - base::TimeTicks latest_paint_started_time_; - // The texture type for which |shader_program| was initialized. Can be either // 0, GL_TEXTURE_2D, GL_TEXTURE_RECTANGLE_ARB or GL_TEXTURE_EXTERNAL_OES. 0 // indicates that |shader_program_| hasn't been intialized. diff --git a/remoting/client/software_video_renderer.cc b/remoting/client/software_video_renderer.cc index b52db3eac..8172369 100644 --- a/remoting/client/software_video_renderer.cc +++ b/remoting/client/software_video_renderer.cc @@ -149,25 +149,23 @@ void SoftwareVideoRenderer::ProcessVideoPacket(scoped_ptr<VideoPacket> packet, consumer_->AllocateFrame(source_size_); frame->set_dpi(source_dpi_); + int32_t frame_id = packet->frame_id(); base::PostTaskAndReplyWithResult( decode_task_runner_.get(), FROM_HERE, base::Bind(&DoDecodeFrame, decoder_.get(), base::Passed(&packet), base::Passed(&frame)), base::Bind(&SoftwareVideoRenderer::RenderFrame, - weak_factory_.GetWeakPtr(), base::TimeTicks::Now(), - done_runner.Release())); + weak_factory_.GetWeakPtr(), frame_id, done_runner.Release())); } void SoftwareVideoRenderer::RenderFrame( - base::TimeTicks decode_start_time, + int32_t frame_id, const base::Closure& done, scoped_ptr<webrtc::DesktopFrame> frame) { DCHECK(thread_checker_.CalledOnValidThread()); - if (perf_tracker_) { - perf_tracker_->RecordDecodeTime( - (base::TimeTicks::Now() - decode_start_time).InMilliseconds()); - } + if (perf_tracker_) + perf_tracker_->OnFrameDecoded(frame_id); if (!frame) { if (!done.is_null()) @@ -175,20 +173,17 @@ void SoftwareVideoRenderer::RenderFrame( return; } - consumer_->DrawFrame( - frame.Pass(), - base::Bind(&SoftwareVideoRenderer::OnFrameRendered, - weak_factory_.GetWeakPtr(), base::TimeTicks::Now(), done)); + consumer_->DrawFrame(frame.Pass(), + base::Bind(&SoftwareVideoRenderer::OnFrameRendered, + weak_factory_.GetWeakPtr(), frame_id, done)); } -void SoftwareVideoRenderer::OnFrameRendered(base::TimeTicks paint_start_time, +void SoftwareVideoRenderer::OnFrameRendered(int32_t frame_id, const base::Closure& done) { DCHECK(thread_checker_.CalledOnValidThread()); - if (perf_tracker_) { - perf_tracker_->RecordPaintTime( - (base::TimeTicks::Now() - paint_start_time).InMilliseconds()); - } + if (perf_tracker_) + perf_tracker_->OnFramePainted(frame_id); if (!done.is_null()) done.Run(); diff --git a/remoting/client/software_video_renderer.h b/remoting/client/software_video_renderer.h index 318a3d8..5158e9d 100644 --- a/remoting/client/software_video_renderer.h +++ b/remoting/client/software_video_renderer.h @@ -55,11 +55,10 @@ class SoftwareVideoRenderer : public VideoRenderer, const base::Closure& done) override; private: - void RenderFrame(base::TimeTicks decode_start_time, - const base::Closure& done, - scoped_ptr<webrtc::DesktopFrame> frame); - void OnFrameRendered(base::TimeTicks paint_start_time, - const base::Closure& done); + void RenderFrame(int32_t frame_id, + const base::Closure& done, + scoped_ptr<webrtc::DesktopFrame> frame); + void OnFrameRendered(int32_t frame_id, const base::Closure& done); scoped_refptr<base::SingleThreadTaskRunner> decode_task_runner_; FrameConsumer* consumer_; diff --git a/remoting/protocol/client_event_dispatcher.cc b/remoting/protocol/client_event_dispatcher.cc index 4f1e51e..9329227 100644 --- a/remoting/protocol/client_event_dispatcher.cc +++ b/remoting/protocol/client_event_dispatcher.cc @@ -25,7 +25,7 @@ void ClientEventDispatcher::InjectKeyEvent(const KeyEvent& event) { DCHECK(event.has_usb_keycode()); DCHECK(event.has_pressed()); EventMessage message; - message.set_timestamp(base::Time::Now().ToInternalValue()); + message.set_timestamp(base::TimeTicks::Now().ToInternalValue()); message.mutable_key_event()->CopyFrom(event); writer()->Write(SerializeAndFrameMessage(message), base::Closure()); } @@ -33,21 +33,21 @@ void ClientEventDispatcher::InjectKeyEvent(const KeyEvent& event) { void ClientEventDispatcher::InjectTextEvent(const TextEvent& event) { DCHECK(event.has_text()); EventMessage message; - message.set_timestamp(base::Time::Now().ToInternalValue()); + message.set_timestamp(base::TimeTicks::Now().ToInternalValue()); message.mutable_text_event()->CopyFrom(event); writer()->Write(SerializeAndFrameMessage(message), base::Closure()); } void ClientEventDispatcher::InjectMouseEvent(const MouseEvent& event) { EventMessage message; - message.set_timestamp(base::Time::Now().ToInternalValue()); + message.set_timestamp(base::TimeTicks::Now().ToInternalValue()); message.mutable_mouse_event()->CopyFrom(event); writer()->Write(SerializeAndFrameMessage(message), base::Closure()); } void ClientEventDispatcher::InjectTouchEvent(const TouchEvent& event) { EventMessage message; - message.set_timestamp(base::Time::Now().ToInternalValue()); + message.set_timestamp(base::TimeTicks::Now().ToInternalValue()); message.mutable_touch_event()->CopyFrom(event); writer()->Write(SerializeAndFrameMessage(message), base::Closure()); } diff --git a/remoting/protocol/performance_tracker.cc b/remoting/protocol/performance_tracker.cc index 283e59b..3ee1a4a 100644 --- a/remoting/protocol/performance_tracker.cc +++ b/remoting/protocol/performance_tracker.cc @@ -118,27 +118,29 @@ void PerformanceTracker::RecordVideoPacketStats(const VideoPacket& packet) { // Record this received packet, even if it is empty. video_packet_rate_.Record(1); - // Record the RTT, even for empty packets, otherwise input events that - // do not cause an on-screen change can give very large, bogus RTTs. - if (packet.has_latest_event_timestamp() && - packet.latest_event_timestamp() > latest_input_event_timestamp_) { - latest_input_event_timestamp_ = packet.latest_event_timestamp(); - - base::TimeDelta round_trip_latency = - base::Time::Now() - - base::Time::FromInternalValue(packet.latest_event_timestamp()); - - round_trip_ms_.Record(round_trip_latency.InMilliseconds()); - - uma_custom_times_updater_.Run( - kRoundTripLatencyHistogram, round_trip_latency.InMilliseconds(), - kLatencyHistogramMinMs, kLatencyHistogramMaxMs, - kLatencyHistogramBuckets); + 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 packet is empty, there are no other stats to update. - if (!packet.data().size()) + 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()); @@ -188,18 +190,55 @@ void PerformanceTracker::RecordVideoPacketStats(const VideoPacket& packet) { } } -void PerformanceTracker::RecordDecodeTime(double value) { - video_decode_ms_.Record(value); +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, value, kVideoActionsHistogramsMinMs, - kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); + kVideoDecodeLatencyHistogram, delay.InMilliseconds(), + kVideoActionsHistogramsMinMs, kVideoActionsHistogramsMaxMs, + kVideoActionsHistogramsBuckets); } -void PerformanceTracker::RecordPaintTime(double value) { - video_paint_ms_.Record(value); +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( - kVideoPaintLatencyHistogram, value, kVideoActionsHistogramsMinMs, - kVideoActionsHistogramsMaxMs, kVideoActionsHistogramsBuckets); + kRoundTripLatencyHistogram, round_trip_latency.InMilliseconds(), + kLatencyHistogramMinMs, kLatencyHistogramMaxMs, kLatencyHistogramBuckets); } void PerformanceTracker::UploadRateStatsToUma() { diff --git a/remoting/protocol/performance_tracker.h b/remoting/protocol/performance_tracker.h index f1d9aa0..fefb169 100644 --- a/remoting/protocol/performance_tracker.h +++ b/remoting/protocol/performance_tracker.h @@ -5,6 +5,8 @@ #ifndef REMOTING_PROTOCOL_PERFORMANCE_TRACKER_H_ #define REMOTING_PROTOCOL_PERFORMANCE_TRACKER_H_ +#include <map> + #include "base/callback.h" #include "base/timer/timer.h" #include "remoting/base/rate_counter.h" @@ -53,8 +55,12 @@ class PerformanceTracker { // Record stats for a video-packet. void RecordVideoPacketStats(const VideoPacket& packet); - void RecordDecodeTime(double value); - void RecordPaintTime(double value); + // Helpers to track decode and paint time. If the render drops some frames + // before they are painted then OnFramePainted() records paint time when the + // following frame is rendered. OnFramePainted() may be called multiple times, + // in which case all calls after the first one are ignored. + void OnFrameDecoded(int32_t frame_id); + void OnFramePainted(int32_t frame_id); // Sets callbacks in ChromotingInstance to update a UMA custom counts, custom // times or enum histogram. @@ -66,6 +72,18 @@ class PerformanceTracker { void OnPauseStateChanged(bool paused); private: + struct FrameTimestamps { + // Set to null for frames that were not sent after a fresh input event. + base::TimeTicks latest_event_timestamp; + + base::TimeTicks time_received; + base::TimeTicks time_decoded; + }; + typedef std::map<int32_t, FrameTimestamps> FramesTimestampsMap; + + // Helper to record input roundtrip latency after a frame has been painted. + void RecordRoundTripLatency(const FrameTimestamps& timestamps); + // Updates frame-rate, packet-rate and bandwidth UMA statistics. void UploadRateStatsToUma(); @@ -97,8 +115,11 @@ class PerformanceTracker { UpdateUmaCustomHistogramCallback uma_custom_times_updater_; UpdateUmaEnumHistogramCallback uma_enum_histogram_updater_; - // The latest input timestamp that a VideoPacket was seen annotated with. - int64_t latest_input_event_timestamp_ = 0; + // The latest event timestamp that a VideoPacket was seen annotated with. + base::TimeTicks latest_event_timestamp_; + + // Stores timestamps for the frames that are currently being processed. + FramesTimestampsMap frame_timestamps_; bool is_paused_ = false; |