cast: Wire upp logging to be sent over RTCP between receiver and sender.

media/cast/test/end2end_unittest.cc

 // Copyright 2013 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.
 //
 // This test generate synthetic data. For audio it's a sinusoid waveform with
 // frequency kSoundFrequency and different amplitudes. For video it's a pattern
 // that is shifting by one pixel per frame, each pixels neighbors right and down
 // is this pixels value +1, since the pixel value is 8 bit it will wrap
 // frequently within the image. Visually this will create diagonally color bands
 // that moves across the screen
@@ skipping 304 matching lines @@
  protected:
   virtual ~TestReceiverVideoCallback() {}
 
  private:
   friend class base::RefCountedThreadSafe<TestReceiverVideoCallback>;
 
   int num_called_;
   std::list<ExpectedVideoFrame> expected_frame_;
 };
 
-CastLoggingConfig EnableCastLoggingConfig() {
-  CastLoggingConfig config;
+CastLoggingConfig EnableCastLoggingConfig(bool sender) {
+  CastLoggingConfig config(sender);
   config.enable_data_collection = true;
   return config;
 }
 // The actual test class, generate synthetic data for both audio and video and
 // send those through the sender and receiver and analyzes the result.
 class End2EndTest : public ::testing::Test {
  protected:
   End2EndTest()
       : task_runner_(new test::FakeTaskRunner(&testing_clock_)),
-        cast_environment_(new CastEnvironment(&testing_clock_, task_runner_,
+        cast_environment_sender_(new CastEnvironment(&testing_clock_,
             task_runner_, task_runner_, task_runner_, task_runner_,
-            task_runner_, EnableCastLoggingConfig())),
+            task_runner_, task_runner_, EnableCastLoggingConfig(true))),
+        cast_environment_receiver_(new CastEnvironment(&testing_clock_,
+            task_runner_, task_runner_, task_runner_, task_runner_,
+            task_runner_, task_runner_, EnableCastLoggingConfig(false))),
         start_time_(),
-        sender_to_receiver_(cast_environment_),
-        receiver_to_sender_(cast_environment_),
+        sender_to_receiver_(cast_environment_sender_),
+        receiver_to_sender_(cast_environment_receiver_),
         test_receiver_audio_callback_(new TestReceiverAudioCallback()),
         test_receiver_video_callback_(new TestReceiverVideoCallback()) {
     testing_clock_.Advance(
         base::TimeDelta::FromMilliseconds(kStartMillisecond));
   }
 
   void SetupConfig(transport::AudioCodec audio_codec,
                    int audio_sampling_frequency,
                    // TODO(miu): 3rd arg is meaningless?!?
                    bool external_audio_decoder,
@@ skipping 42 matching lines @@
         video_sender_config_.incoming_feedback_ssrc;
     video_receiver_config_.incoming_ssrc =
         video_sender_config_.sender_ssrc;
     video_receiver_config_.rtp_payload_type =
         video_sender_config_.rtp_payload_type;
     video_receiver_config_.use_external_decoder = false;
     video_receiver_config_.codec = video_sender_config_.codec;
   }
 
   void Create() {
-    cast_receiver_.reset(CastReceiver::CreateCastReceiver(cast_environment_,
-        audio_receiver_config_, video_receiver_config_, &receiver_to_sender_));
+    cast_receiver_.reset(CastReceiver::CreateCastReceiver(
+        cast_environment_receiver_,
+        audio_receiver_config_,
+        video_receiver_config_,
+        &receiver_to_sender_));
 
-    cast_sender_.reset(CastSender::CreateCastSender(cast_environment_,
+    cast_sender_.reset(CastSender::CreateCastSender(cast_environment_sender_,
                                                     audio_sender_config_,
                                                     video_sender_config_,
                                                     NULL,
                                                     &sender_to_receiver_));
 
     receiver_to_sender_.RegisterPacketReceiver(cast_sender_->packet_receiver());
     sender_to_receiver_.RegisterPacketReceiver(
         cast_receiver_->packet_receiver());
 
     frame_input_ = cast_sender_->frame_input();
@@ skipping 29 matching lines @@
     }
   }
 
   AudioReceiverConfig audio_receiver_config_;
   VideoReceiverConfig video_receiver_config_;
   AudioSenderConfig audio_sender_config_;
   VideoSenderConfig video_sender_config_;
 
   base::SimpleTestTickClock testing_clock_;
   scoped_refptr<test::FakeTaskRunner> task_runner_;
-  scoped_refptr<CastEnvironment> cast_environment_;
+  scoped_refptr<CastEnvironment> cast_environment_sender_;
+  scoped_refptr<CastEnvironment> cast_environment_receiver_;
   base::TimeTicks start_time_;
 
   LoopBackTransport sender_to_receiver_;
   LoopBackTransport receiver_to_sender_;
 
   scoped_ptr<CastReceiver> cast_receiver_;
   scoped_ptr<CastSender> cast_sender_;
   scoped_refptr<FrameInput> frame_input_;
   scoped_refptr<FrameReceiver> frame_receiver_;
 
@@ skipping 457 matching lines @@
     frame_receiver_->GetRawVideoFrame(
         base::Bind(&TestReceiverVideoCallback::CheckVideoFrame,
             test_receiver_video_callback_));
 
     video_start++;
   }
 
   // Basic tests.
   RunTasks(2 * kFrameTimerMs + 1);  // Empty the receiver pipeline.
   EXPECT_EQ(i, test_receiver_video_callback_->number_times_called());
-  // Logging tests.
-  LoggingImpl* logging = cast_environment_->Logging();
 
-  // Frame logging.
+  // Sender logging tests.
+  LoggingImpl* sender_log = cast_environment_sender_->Logging();
 
   // Verify that all frames and all required events were logged.
-  FrameRawMap frame_raw_log = logging->GetFrameRawData();
+  FrameRawMap frame_raw_log = sender_log->GetFrameRawData();
+
   // Every frame should have only one entry.
   EXPECT_EQ(static_cast<unsigned int>(i), frame_raw_log.size());
   FrameRawMap::const_iterator frame_it = frame_raw_log.begin();
+
   // Choose a video frame, and verify that all events were logged.
   std::vector<CastLoggingEvent> event_log = frame_it->second.type;
-  EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
-               kVideoFrameReceived)) != event_log.end());
-  EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
-               kVideoFrameSentToEncoder)) != event_log.end());
-  EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
-               kVideoFrameEncoded)) != event_log.end());
-  EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
-               kVideoRenderDelay)) != event_log.end());
+  std::vector<CastLoggingEvent>::iterator event_it;
+  event_it = std::find(event_log.begin(), event_log.end(),
+                       kVideoFrameSentToEncoder);
+  EXPECT_TRUE(event_it != event_log.end());
+  event_log.erase(event_it);
+
+  event_it = std::find(event_log.begin(), event_log.end(),
+                       kVideoFrameEncoded);
+  EXPECT_TRUE(event_it != event_log.end());
+  event_log.erase(event_it);
+
+  event_it = std::find(event_log.begin(), event_log.end(),
+                       kVideoFrameReceived);
+  EXPECT_TRUE(event_it != event_log.end());
+  event_log.erase(event_it);
+
+  event_it = std::find(event_log.begin(), event_log.end(),
+                       kVideoRenderDelay);
+  EXPECT_TRUE(event_it != event_log.end());
+  event_log.erase(event_it);
+
   // TODO(mikhal): Plumb this one through.
-  EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
-               kVideoFrameDecoded)) == event_log.end());
+  event_it = std::find(event_log.begin(), event_log.end(),
+                       kVideoFrameDecoded);
+  EXPECT_TRUE(event_it == event_log.end());
+
   // Verify that there were no other events logged with respect to this frame.
-  EXPECT_EQ(4u, event_log.size());
+  EXPECT_EQ(0u, event_log.size());
 
   // Packet logging.
   // Verify that all packet related events were logged.
-  PacketRawMap packet_raw_log = logging->GetPacketRawData();
+  PacketRawMap packet_raw_log = sender_log->GetPacketRawData();
   // Every rtp_timestamp should have only one entry.
   EXPECT_EQ(static_cast<unsigned int>(i), packet_raw_log.size());
   PacketRawMap::const_iterator packet_it = packet_raw_log.begin();
   // Choose a packet, and verify that all events were logged.
   event_log = (++(packet_it->second.packet_map.begin()))->second.type;
   EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
-               kPacketReceived)) != event_log.end());
+               kVideoPacketReceived)) != event_log.end());
   // Verify that there were no other events logged with respect to this frame.
   EXPECT_EQ(1u, event_log.size());
+
+  RunTasks(750);  // Make sure that we send a RTCP message with the log.
+
+  // Receiver logging tests.
+  LoggingImpl* receiver_log = cast_environment_receiver_->Logging();
+
+  // Verify that all frames and all required events were logged.
+  frame_raw_log = receiver_log->GetFrameRawData();
+  EXPECT_EQ(static_cast<unsigned int>(i), frame_raw_log.size());
+  frame_it = frame_raw_log.begin();
+
+  // Choose a video frame, and verify that all events were logged.
+  event_log = frame_it->second.type;
+
+  event_it = std::find(event_log.begin(), event_log.end(),
+                       kVideoFrameEncoded);

[mikhal1, 2014/01/14 19:57:18]

check for not end

[pwestin, 2014/01/17 23:46:17]

Done.

+
+  event_it = std::find(event_log.begin(), event_log.end(),
+                       kVideoRenderDelay);
+
+  EXPECT_TRUE(event_it != event_log.end());
+  EXPECT_EQ(2u, event_log.size());
 }
 
 // TODO(mikhal): Crashes on the bots. Re-enable. http://crbug.com/329563
 #if defined(OS_WIN)
 #define MAYBE_AudioLogging DISABLED_AudioLogging
 #else
 #define MAYBE_AudioLogging AudioLogging
 #endif
 // Audio test without packet loss; This test is targeted at testing the logging
 // aspects of the end2end, but is basically equivalent to LoopNoLossPcm16.
@@ skipping 39 matching lines @@
           base::Bind(&TestReceiverAudioCallback::CheckPcmAudioFrame,
               test_receiver_audio_callback_));
     }
   }
 
   // Basic tests.
   RunTasks(2 * kFrameTimerMs + 1);  // Empty the receiver pipeline.
   //EXPECT_EQ(i - 1, test_receiver_audio_callback_->number_times_called());
   EXPECT_EQ(i - 1, test_receiver_audio_callback_->number_times_called());
   // Logging tests.
-  LoggingImpl* logging = cast_environment_->Logging();
+  LoggingImpl* sender_log = cast_environment_sender_->Logging();
   // Verify that all frames and all required events were logged.
-  FrameRawMap frame_raw_log = logging->GetFrameRawData();
+  FrameRawMap frame_raw_log = sender_log->GetFrameRawData();
   // TODO(mikhal): Results are wrong. Need to resolve passing/calculation of
   // rtp_timestamp for audio for this to work.
   // Should have logged both audio and video. Every frame should have only one
   // entry.
   //EXPECT_EQ(static_cast<unsigned int>(i - 1), frame_raw_log.size());
   FrameRawMap::const_iterator frame_it = frame_raw_log.begin();
   // Choose a video frame, and verify that all events were logged.
   std::vector<CastLoggingEvent> event_log = frame_it->second.type;
   EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
                kAudioFrameReceived)) != event_log.end());
   EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
                kAudioFrameEncoded)) != event_log.end());
   // EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
   //              kAudioPlayoutDelay)) != event_log.end());
   // TODO(mikhal): Plumb this one through.
   EXPECT_TRUE((std::find(event_log.begin(), event_log.end(),
                kAudioFrameDecoded)) == event_log.end());
   // Verify that there were no other events logged with respect to this frame.
   EXPECT_EQ(2u, event_log.size());
 }
 
 
 // TODO(pwestin): Add repeatable packet loss test.
 // TODO(pwestin): Add test for misaligned send get calls.
 // TODO(pwestin): Add more tests that does not resample.
 // TODO(pwestin): Add test when we have starvation for our RunTask.
 
 }  // namespace cast
 }  // namespace media