Collapse most spammy output of webrtc_perf_tests with PrintResultList

webrtc/call/call_perf_tests.cc

 /*
  *  Copyright (c) 2013 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 <limits>
 #include <memory>
-#include <sstream>
 #include <string>
 
 #include "testing/gtest/include/gtest/gtest.h"
 
 #include "webrtc/base/checks.h"
 #include "webrtc/base/constructormagic.h"
 #include "webrtc/base/thread_annotations.h"
 #include "webrtc/call.h"
 #include "webrtc/call/transport_adapter.h"
 #include "webrtc/config.h"
@@ skipping 68 matching lines @@
     {
       rtc::CritScope lock(&crit_);
       if (receive_stream_)
         stats = receive_stream_->GetStats();
     }
     if (stats.sync_offset_ms == std::numeric_limits<int>::max())
       return;
 
     int64_t now_ms = clock_->TimeInMilliseconds();
 
-    std::stringstream ss;
-    ss << stats.sync_offset_ms;
-    webrtc::test::PrintResult("stream_offset",
-                              "",
-                              "synchronization",
-                              ss.str(),
-                              "ms",
-                              false);
+    sync_offset_ms_list_.push_back(stats.sync_offset_ms);
     int64_t time_since_creation = now_ms - creation_time_ms_;
     // During the first couple of seconds audio and video can falsely be
     // estimated as being synchronized. We don't want to trigger on those.
     if (time_since_creation < kStartupTimeMs)
       return;
     if (std::abs(stats.sync_offset_ms) < kInSyncThresholdMs) {
       if (first_time_in_sync_ == -1) {
         first_time_in_sync_ = now_ms;
         webrtc::test::PrintResult("sync_convergence_time",
                                   "",
                                   "synchronization",
                                   time_since_creation,
                                   "ms",
                                   false);
       }
       if (time_since_creation > kMinRunTimeMs)
         observation_complete_.Set();
     }
   }
 
   void set_receive_stream(VideoReceiveStream* receive_stream) {
     rtc::CritScope lock(&crit_);
     receive_stream_ = receive_stream;
   }
 
+  void PrintResults() {
+    test::PrintResultList("stream_offset", "", "synchronization",
+                          test::ValuesToString(sync_offset_ms_list_), "ms",
+                          false);
+  }
+
  private:
   Clock* const clock_;
   const int64_t creation_time_ms_;
   int64_t first_time_in_sync_;
   rtc::CriticalSection crit_;
   VideoReceiveStream* receive_stream_ GUARDED_BY(crit_);
+  std::vector<int> sync_offset_ms_list_;
 };
 
 void CallPerfTest::TestAudioVideoSync(FecMode fec,
                                       CreateOrder create_first,
                                       float video_ntp_speed,
                                       float video_rtp_speed,
                                       float audio_rtp_speed) {
   const char* kSyncGroup = "av_sync";
   const uint32_t kAudioSendSsrc = 1234;
   const uint32_t kAudioRecvSsrc = 5678;
@@ skipping 141 matching lines @@
 
   voe_base->DeleteChannel(send_channel_id);
   voe_base->DeleteChannel(recv_channel_id);
   voe_base->Release();
   voe_codec->Release();
 
   DestroyCalls();
 
   VoiceEngine::Delete(voice_engine);
 
+  observer.PrintResults();
   EXPECT_EQ(1, metrics::NumSamples("WebRTC.Video.AVSyncOffsetInMs"));
 }
 
 TEST_F(CallPerfTest, PlaysOutAudioAndVideoInSyncWithVideoNtpDrift) {
   TestAudioVideoSync(FecMode::kOff, CreateOrder::kAudioFirst,
                      DriftingClock::PercentsFaster(10.0f),
                      DriftingClock::kNoDrift, DriftingClock::kNoDrift);
 }
 
 TEST_F(CallPerfTest, PlaysOutAudioAndVideoInSyncWithAudioFasterThanVideoDrift) {
@@ skipping 67 matching lines @@
       EXPECT_TRUE(iter != capture_time_list_.end());
 
       // The real capture time has been wrapped to uint32_t before converted
       // to rtp timestamp in the sender side. So here we convert the estimated
       // capture time to a uint32_t 90k timestamp also for comparing.
       uint32_t estimated_capture_timestamp =
           90 * static_cast<uint32_t>(video_frame.ntp_time_ms());
       uint32_t real_capture_timestamp = iter->second;
       int time_offset_ms = real_capture_timestamp - estimated_capture_timestamp;
       time_offset_ms = time_offset_ms / 90;
-      std::stringstream ss;
-      ss << time_offset_ms;
+      time_offset_ms_list_.push_back(time_offset_ms);
 
-      webrtc::test::PrintResult(
-          "capture_ntp_time", "", "real - estimated", ss.str(), "ms", true);
       EXPECT_TRUE(std::abs(time_offset_ms) < threshold_ms_);
     }
 
     Action OnSendRtp(const uint8_t* packet, size_t length) override {
       rtc::CritScope lock(&crit_);
       RTPHeader header;
       EXPECT_TRUE(parser_->Parse(packet, length, &header));
 
       if (!rtp_start_timestamp_set_) {
         // Calculate the rtp timestamp offset in order to calculate the real
@@ skipping 22 matching lines @@
         VideoEncoderConfig* encoder_config) override {
       (*receive_configs)[0].renderer = this;
       // Enable the receiver side rtt calculation.
       (*receive_configs)[0].rtp.rtcp_xr.receiver_reference_time_report = true;
     }
 
     void PerformTest() override {
       EXPECT_TRUE(Wait()) << "Timed out while waiting for "
                              "estimated capture NTP time to be "
                              "within bounds.";
+      test::PrintResultList("capture_ntp_time", "", "real - estimated",
+                            test::ValuesToString(time_offset_ms_list_), "ms",
+                            true);
     }
 
     rtc::CriticalSection crit_;
     const FakeNetworkPipe::Config net_config_;
     Clock* const clock_;
     int threshold_ms_;
     int start_time_ms_;
     int run_time_ms_;
     int64_t creation_time_ms_;
     test::FrameGeneratorCapturer* capturer_;
     bool rtp_start_timestamp_set_;
     uint32_t rtp_start_timestamp_;
     typedef std::map<uint32_t, uint32_t> FrameCaptureTimeList;
     FrameCaptureTimeList capture_time_list_ GUARDED_BY(&crit_);
+    std::vector<int> time_offset_ms_list_;
   } test(net_config, threshold_ms, start_time_ms, run_time_ms);
 
   RunBaseTest(&test);
 }
 
 TEST_F(CallPerfTest, CaptureNtpTimeWithNetworkDelay) {
   FakeNetworkPipe::Config net_config;
   net_config.queue_delay_ms = 100;
   // TODO(wu): lower the threshold as the calculation/estimatation becomes more
   // accurate.
@@ skipping 75 matching lines @@
 
    private:
     // TODO(holmer): Run this with a timer instead of once per packet.
     Action OnSendRtp(const uint8_t* packet, size_t length) override {
       VideoSendStream::Stats stats = send_stream_->GetStats();
       if (stats.substreams.size() > 0) {
         RTC_DCHECK_EQ(1u, stats.substreams.size());
         int bitrate_kbps =
             stats.substreams.begin()->second.total_bitrate_bps / 1000;
         if (bitrate_kbps > 0) {
-          test::PrintResult(
-              "bitrate_stats_",
-              (pad_to_min_bitrate_ ? "min_transmit_bitrate"
-                                   : "without_min_transmit_bitrate"),
-              "bitrate_kbps",
-              static_cast<size_t>(bitrate_kbps),
-              "kbps",
-              false);
+          bitrate_kbps_list.push_back(bitrate_kbps);
           if (pad_to_min_bitrate_) {
             if (bitrate_kbps > kMinAcceptableTransmitBitrate &&
                 bitrate_kbps < kMaxAcceptableTransmitBitrate) {
               ++num_bitrate_observations_in_range_;
             }
           } else {
             // Expect bitrate stats to roughly match the max encode bitrate.
             if (bitrate_kbps > (kMaxEncodeBitrateKbps -
                                 kAcceptableBitrateErrorMargin / 2) &&
                 bitrate_kbps < (kMaxEncodeBitrateKbps +
@@ skipping 21 matching lines @@
         VideoEncoderConfig* encoder_config) override {
       if (pad_to_min_bitrate_) {
         encoder_config->min_transmit_bitrate_bps = kMinTransmitBitrateBps;
       } else {
         RTC_DCHECK_EQ(0, encoder_config->min_transmit_bitrate_bps);
       }
     }
 
     void PerformTest() override {
       EXPECT_TRUE(Wait()) << "Timeout while waiting for send-bitrate stats.";
+      test::PrintResultList(
+          "bitrate_stats_",
+          (pad_to_min_bitrate_ ? "min_transmit_bitrate"
+                               : "without_min_transmit_bitrate"),
+          "bitrate_kbps", test::ValuesToString(bitrate_kbps_list), "kbps",
+          false);
     }
 
     VideoSendStream* send_stream_;
     const bool pad_to_min_bitrate_;
     int num_bitrate_observations_in_range_;
+    std::vector<size_t> bitrate_kbps_list;
   } test(pad_to_min_bitrate);
 
   fake_encoder_.SetMaxBitrate(kMaxEncodeBitrateKbps);
   RunBaseTest(&test);
 }
 
 TEST_F(CallPerfTest, PadsToMinTransmitBitrate) { TestMinTransmitBitrate(true); }
 
 TEST_F(CallPerfTest, NoPadWithoutMinTransmitBitrate) {
   TestMinTransmitBitrate(false);
@@ skipping 83 matching lines @@
     int encoder_inits_;
     uint32_t last_set_bitrate_;
     VideoSendStream* send_stream_;
     VideoEncoderConfig encoder_config_;
   } test;
 
   RunBaseTest(&test);
 }
 
 }  // namespace webrtc