Report timing frames info in GetStats.

webrtc/modules/video_coding/generic_decoder.cc

 /*
  *  Copyright (c) 2012 The WebRTC project authors. All Rights Reserved.
  *
  *  Use of this source code is governed by a BSD-style license
  *  that can be found in the LICENSE file in the root of the source
  *  tree. An additional intellectual property rights grant can be found
  *  in the file PATENTS.  All contributing project authors may
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
+#include <algorithm>
+
 #include "webrtc/base/checks.h"
 #include "webrtc/base/logging.h"
 #include "webrtc/base/timeutils.h"
 #include "webrtc/base/trace_event.h"
 #include "webrtc/modules/video_coding/include/video_coding.h"
 #include "webrtc/modules/video_coding/generic_decoder.h"
 #include "webrtc/modules/video_coding/internal_defines.h"
 #include "webrtc/system_wrappers/include/clock.h"
 
 namespace webrtc {
@@ skipping 62 matching lines @@
   const int64_t now_ms = _clock->TimeInMilliseconds();
   if (!decode_time_ms) {
     decode_time_ms =
         rtc::Optional<int32_t>(now_ms - frameInfo->decodeStartTimeMs);
   }
   _timing->StopDecodeTimer(decodedImage.timestamp(), *decode_time_ms, now_ms,
                            frameInfo->renderTimeMs);
 
   // Report timing information.
   if (frameInfo->timing.is_timing_frame) {
+    int64_t capture_time_ms = decodedImage.ntp_time_ms() - ntp_offset_;

[hbos, 2017/06/27 14:08:31]

What does |capture_time_ms| imply if |decodedImage.ntp_time_ms()| is negative /
clock not estimated yet?

[ilnik, 2017/06/27 15:23:56]

ntp_time_ms() is -1 if sender clock is not estimated. Otherwise it's capture
time in ntp format in receiver clock. 

     // Convert remote timestamps to local time from ntp timestamps.
     frameInfo->timing.encode_start_ms -= ntp_offset_;
     frameInfo->timing.encode_finish_ms -= ntp_offset_;
     frameInfo->timing.packetization_finish_ms -= ntp_offset_;
     frameInfo->timing.pacer_exit_ms -= ntp_offset_;
     frameInfo->timing.network_timestamp_ms -= ntp_offset_;
     frameInfo->timing.network2_timestamp_ms -= ntp_offset_;
-    // TODO(ilnik): Report timing information here.
-    // Capture time: decodedImage.ntp_time_ms() - ntp_offset
-    // Encode start: frameInfo->timing.encode_start_ms
-    // Encode finish: frameInfo->timing.encode_finish_ms
-    // Packetization done: frameInfo->timing.packetization_finish_ms
-    // Pacer exit: frameInfo->timing.pacer_exit_ms
-    // Network timestamp: frameInfo->timing.network_timestamp_ms
-    // Network2 timestamp: frameInfo->timing.network2_timestamp_ms
-    // Receive start: frameInfo->timing.receive_start_ms
-    // Receive finish: frameInfo->timing.receive_finish_ms
-    // Decode start: frameInfo->decodeStartTimeMs
-    // Decode finish: now_ms
-    // Render time: frameInfo->renderTimeMs
+
+    int64_t sender_delta_ms = 0;
+    if (decodedImage.ntp_time_ms() < 0) {
+      // Sender clock is not estimated yet. Make sure that sender times are all
+      // negative to indicate that. Yet they still should be relatively correct.

[hbos, 2017/06/27 14:08:31]

Can you document the meaning of negative values in VideoSendTiming or use a bool
to indicate is_clock_estimated.

[ilnik, 2017/06/27 15:23:56]

Done.

+      sender_delta_ms =
+          std::max({capture_time_ms, frameInfo->timing.encode_start_ms,
+                    frameInfo->timing.encode_finish_ms,
+                    frameInfo->timing.packetization_finish_ms,
+                    frameInfo->timing.pacer_exit_ms,
+                    frameInfo->timing.network_timestamp_ms,
+                    frameInfo->timing.network2_timestamp_ms}) +
+          1;
+    }
+
+    TimingFrameInfo timing_frame_info;
+
+    timing_frame_info.capture_time_ms = capture_time_ms - sender_delta_ms;
+    timing_frame_info.encode_start_ms =
+        frameInfo->timing.encode_start_ms - sender_delta_ms;
+    timing_frame_info.encode_finish_ms =
+        frameInfo->timing.encode_finish_ms - sender_delta_ms;
+    timing_frame_info.packetization_finish_ms =
+        frameInfo->timing.packetization_finish_ms - sender_delta_ms;
+    timing_frame_info.pacer_exit_ms =
+        frameInfo->timing.pacer_exit_ms - sender_delta_ms;
+    timing_frame_info.network_timestamp_ms =
+        frameInfo->timing.network_timestamp_ms - sender_delta_ms;
+    timing_frame_info.network2_timestamp_ms =
+        frameInfo->timing.network2_timestamp_ms - sender_delta_ms;
+    timing_frame_info.receive_start_ms = frameInfo->timing.receive_start_ms;
+    timing_frame_info.receive_finish_ms = frameInfo->timing.receive_finish_ms;
+    timing_frame_info.decode_start_ms = frameInfo->decodeStartTimeMs;
+    timing_frame_info.decode_finish_ms = now_ms;
+    timing_frame_info.render_time_ms = frameInfo->renderTimeMs;
+    timing_frame_info.rtp_timestamp = decodedImage.timestamp();
+
+    _timing->SetTimingFrameInfo(timing_frame_info);
   }
 
   decodedImage.set_timestamp_us(
       frameInfo->renderTimeMs * rtc::kNumMicrosecsPerMillisec);
   decodedImage.set_rotation(frameInfo->rotation);
   _receiveCallback->FrameToRender(decodedImage, qp, frameInfo->content_type);
 }
 
 int32_t VCMDecodedFrameCallback::ReceivedDecodedReferenceFrame(
     const uint64_t pictureId) {
@@ skipping 99 matching lines @@
 
 bool VCMGenericDecoder::External() const {
   return _isExternal;
 }
 
 bool VCMGenericDecoder::PrefersLateDecoding() const {
   return _decoder->PrefersLateDecoding();
 }
 
 }  // namespace webrtc