[Cast] Repair receiver playout time calculations and frame skip logic.

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 44 matching lines @@
 static const int kVideoQcifWidth = 176;
 static const int kVideoQcifHeight = 144;
 
 // Since the video encoded and decoded an error will be introduced; when
 // comparing individual pixels the error can be quite large; we allow a PSNR of
 // at least |kVideoAcceptedPSNR|.
 static const double kVideoAcceptedPSNR = 38.0;
 
 // The tests are commonly implemented with |kFrameTimerMs| RunTask function;
 // a normal video is 30 fps hence the 33 ms between frames.
+//
+// TODO(miu): The errors in timing will add up significantly.  Find an
+// alternative approaches that eliminate use of this constant.
 static const int kFrameTimerMs = 33;
 
-// The packets pass through the pacer which can delay the beginning of the
-// frame by 10 ms if there is packets belonging to the previous frame being
-// retransmitted.
-// In addition, audio packets are sent in 10mS intervals in audio_encoder.cc,
-// although we send an audio frame every 33mS, which adds an extra delay.
-// A TODO was added in the code to resolve this.
-static const int kTimerErrorMs = 20;
-
 // Start the video synthetic start value to medium range value, to avoid edge
 // effects cause by encoding and quantization.
 static const int kVideoStart = 100;
 
 // The size of audio frames.  The encoder joins/breaks all inserted audio into
 // chunks of this size.
 static const int kAudioFrameDurationMs = 10;
 
+// The amount of time between frame capture on the sender and playout on the
+// receiver.
+static const int kTargetPlayoutDelayMs = 100;
+
+// The maximum amount of deviation expected in the playout times emitted by the
+// receiver.
+//
+// TODO(miu): This is a "fuzzy" way to check the timestamps.  We should be able
+// to compute exact offsets with "omnipotent" knowledge of the system.
+static const int kMaxAllowedPlayoutErrorMs = 30;
+
 std::string ConvertFromBase16String(const std::string base_16) {
   std::string compressed;
   DCHECK_EQ(base_16.size() % 2, 0u) << "Must be a multiple of 2";
   compressed.reserve(base_16.size() / 2);
 
   std::vector<uint8> v;
   if (!base::HexStringToBytes(base_16, &v)) {
     NOTREACHED();
   }
   compressed.assign(reinterpret_cast<const char*>(&v[0]), v.size());
@@ skipping 144 matching lines @@
   scoped_refptr<CastEnvironment> cast_environment_;
   scoped_ptr<test::PacketPipe> packet_pipe_;
 };
 
 // Class that verifies the audio frames coming out of the receiver.
 class TestReceiverAudioCallback
     : public base::RefCountedThreadSafe<TestReceiverAudioCallback> {
  public:
   struct ExpectedAudioFrame {
     scoped_ptr<AudioBus> audio_bus;
-    base::TimeTicks record_time;
+    base::TimeTicks playout_time;
   };
 
   TestReceiverAudioCallback() : num_called_(0) {}
 
   void SetExpectedSamplingFrequency(int expected_sampling_frequency) {
     expected_sampling_frequency_ = expected_sampling_frequency;
   }
 
   void AddExpectedResult(const AudioBus& audio_bus,
-                         const base::TimeTicks& record_time) {
+                         const base::TimeTicks& playout_time) {
     scoped_ptr<ExpectedAudioFrame> expected_audio_frame(
         new ExpectedAudioFrame());
     expected_audio_frame->audio_bus =
         AudioBus::Create(audio_bus.channels(), audio_bus.frames()).Pass();
     audio_bus.CopyTo(expected_audio_frame->audio_bus.get());
-    expected_audio_frame->record_time = record_time;
+    expected_audio_frame->playout_time = playout_time;
     expected_frames_.push_back(expected_audio_frame.release());
   }
 
   void IgnoreAudioFrame(scoped_ptr<AudioBus> audio_bus,
                         const base::TimeTicks& playout_time,
                         bool is_continuous) {
     ++num_called_;
   }
 
   void CheckAudioFrame(scoped_ptr<AudioBus> audio_bus,
@@ skipping 11 matching lines @@
     EXPECT_EQ(audio_bus->frames(), expected_audio_frame->audio_bus->frames());
     for (int ch = 0; ch < audio_bus->channels(); ++ch) {
       EXPECT_NEAR(CountZeroCrossings(
                       expected_audio_frame->audio_bus->channel(ch),
                       expected_audio_frame->audio_bus->frames()),
                   CountZeroCrossings(audio_bus->channel(ch),
                                      audio_bus->frames()),
                   1);
     }
 
-    // TODO(miu): This is a "fuzzy" way to check the timestamps.  We should be
-    // able to compute exact offsets with "omnipotent" knowledge of the system.
-    const base::TimeTicks upper_bound =
-        expected_audio_frame->record_time +
-        base::TimeDelta::FromMilliseconds(kDefaultRtpMaxDelayMs +
-                                          kTimerErrorMs);
-    EXPECT_GE(upper_bound, playout_time)
-        << "playout_time - upper_bound == "
-        << (playout_time - upper_bound).InMicroseconds() << " usec";
-
+    EXPECT_NEAR(
+        (playout_time - expected_audio_frame->playout_time).InMillisecondsF(),
+        0.0,
+        kMaxAllowedPlayoutErrorMs);
     EXPECT_TRUE(is_continuous);
   }
 
   void CheckCodedAudioFrame(
       scoped_ptr<transport::EncodedAudioFrame> audio_frame,
       const base::TimeTicks& playout_time) {
     ASSERT_TRUE(!!audio_frame);
     ASSERT_FALSE(expected_frames_.empty());
     const ExpectedAudioFrame& expected_audio_frame =
         *(expected_frames_.front());
@@ skipping 35 matching lines @@
 };
 
 // Class that verifies the video frames coming out of the receiver.
 class TestReceiverVideoCallback
     : public base::RefCountedThreadSafe<TestReceiverVideoCallback> {
  public:
   struct ExpectedVideoFrame {
     int start_value;
     int width;
     int height;
-    base::TimeTicks capture_time;
+    base::TimeTicks playout_time;
     bool should_be_continuous;
   };
 
   TestReceiverVideoCallback() : num_called_(0) {}
 
   void AddExpectedResult(int start_value,
                          int width,
                          int height,
-                         const base::TimeTicks& capture_time,
+                         const base::TimeTicks& playout_time,
                          bool should_be_continuous) {
     ExpectedVideoFrame expected_video_frame;
     expected_video_frame.start_value = start_value;
     expected_video_frame.width = width;
     expected_video_frame.height = height;
-    expected_video_frame.capture_time = capture_time;
+    expected_video_frame.playout_time = playout_time;
     expected_video_frame.should_be_continuous = should_be_continuous;
     expected_frame_.push_back(expected_video_frame);
   }
 
   void CheckVideoFrame(const scoped_refptr<media::VideoFrame>& video_frame,
-                       const base::TimeTicks& render_time,
+                       const base::TimeTicks& playout_time,
                        bool is_continuous) {
     ++num_called_;
 
     ASSERT_TRUE(!!video_frame);
     ASSERT_FALSE(expected_frame_.empty());
     ExpectedVideoFrame expected_video_frame = expected_frame_.front();
     expected_frame_.pop_front();
 
-    base::TimeDelta time_since_capture =
-        render_time - expected_video_frame.capture_time;
-    const base::TimeDelta upper_bound = base::TimeDelta::FromMilliseconds(
-        kDefaultRtpMaxDelayMs + kTimerErrorMs);
-
-    // TODO(miu): This is a "fuzzy" way to check the timestamps.  We should be
-    // able to compute exact offsets with "omnipotent" knowledge of the system.
-    EXPECT_GE(upper_bound, time_since_capture)
-        << "time_since_capture - upper_bound == "
-        << (time_since_capture - upper_bound).InMicroseconds() << " usec";
-    // TODO(miu): I broke the concept of 100 ms target delay timing on the
-    // receiver side, but the logic for computing playout time really isn't any
-    // more broken than it was.  This only affects the receiver, and is to be
-    // rectified in an soon-upcoming change.  http://crbug.com/356942
-    // EXPECT_LE(expected_video_frame.capture_time, render_time);
     EXPECT_EQ(expected_video_frame.width, video_frame->visible_rect().width());
     EXPECT_EQ(expected_video_frame.height,
               video_frame->visible_rect().height());
 
     gfx::Size size(expected_video_frame.width, expected_video_frame.height);
     scoped_refptr<media::VideoFrame> expected_I420_frame =
         media::VideoFrame::CreateFrame(
             VideoFrame::I420, size, gfx::Rect(size), size, base::TimeDelta());
     PopulateVideoFrame(expected_I420_frame, expected_video_frame.start_value);
 
     EXPECT_GE(I420PSNR(expected_I420_frame, video_frame), kVideoAcceptedPSNR);
 
+    EXPECT_NEAR(
+        (playout_time - expected_video_frame.playout_time).InMillisecondsF(),
+        0.0,
+        kMaxAllowedPlayoutErrorMs);
+
     EXPECT_EQ(expected_video_frame.should_be_continuous, is_continuous);
   }
 
   int number_times_called() const { return num_called_; }
 
  protected:
   virtual ~TestReceiverVideoCallback() {}
 
  private:
   friend class base::RefCountedThreadSafe<TestReceiverVideoCallback>;
@@ skipping 33 matching lines @@
     cast_environment_sender_->Logging()->AddRawEventSubscriber(
         &event_subscriber_sender_);
   }
 
   void Configure(transport::VideoCodec video_codec,
                  transport::AudioCodec audio_codec,
                  int audio_sampling_frequency,
                  bool external_audio_decoder,
                  int max_number_of_video_buffers_used) {
     audio_sender_config_.rtp_config.ssrc = 1;
+    audio_sender_config_.rtp_config.max_delay_ms = kTargetPlayoutDelayMs;
     audio_sender_config_.incoming_feedback_ssrc = 2;
     audio_sender_config_.rtp_config.payload_type = 96;
     audio_sender_config_.use_external_encoder = false;
     audio_sender_config_.frequency = audio_sampling_frequency;
     audio_sender_config_.channels = kAudioChannels;
     audio_sender_config_.bitrate = kDefaultAudioEncoderBitrate;
     audio_sender_config_.codec = audio_codec;
 
     audio_receiver_config_.feedback_ssrc =
         audio_sender_config_.incoming_feedback_ssrc;
     audio_receiver_config_.incoming_ssrc = audio_sender_config_.rtp_config.ssrc;
+    audio_receiver_config_.rtp_max_delay_ms = kTargetPlayoutDelayMs;
     audio_receiver_config_.rtp_payload_type =
         audio_sender_config_.rtp_config.payload_type;
     audio_receiver_config_.use_external_decoder = external_audio_decoder;
     audio_receiver_config_.frequency = audio_sender_config_.frequency;
     audio_receiver_config_.channels = kAudioChannels;
     audio_receiver_config_.codec = audio_sender_config_.codec;
 
     test_receiver_audio_callback_->SetExpectedSamplingFrequency(
         audio_receiver_config_.frequency);
 
     video_sender_config_.rtp_config.ssrc = 3;
+    video_sender_config_.rtp_config.max_delay_ms = kTargetPlayoutDelayMs;
     video_sender_config_.incoming_feedback_ssrc = 4;
     video_sender_config_.rtp_config.payload_type = 97;
     video_sender_config_.use_external_encoder = false;
     video_sender_config_.width = kVideoHdWidth;
     video_sender_config_.height = kVideoHdHeight;
     video_sender_config_.max_bitrate = 5000000;
     video_sender_config_.min_bitrate = 1000000;
     video_sender_config_.start_bitrate = 5000000;
     video_sender_config_.max_qp = 30;
     video_sender_config_.min_qp = 4;
     video_sender_config_.max_frame_rate = 30;
     video_sender_config_.max_number_of_video_buffers_used =
         max_number_of_video_buffers_used;
     video_sender_config_.codec = video_codec;
 
     video_receiver_config_.feedback_ssrc =
         video_sender_config_.incoming_feedback_ssrc;
     video_receiver_config_.incoming_ssrc = video_sender_config_.rtp_config.ssrc;
+    video_receiver_config_.rtp_max_delay_ms = kTargetPlayoutDelayMs;
     video_receiver_config_.rtp_payload_type =
         video_sender_config_.rtp_config.payload_type;
     video_receiver_config_.use_external_decoder = false;
     video_receiver_config_.codec = video_sender_config_.codec;
   }
 
   void FeedAudioFrames(int count, bool will_be_checked) {
     for (int i = 0; i < count; ++i) {
       scoped_ptr<AudioBus> audio_bus(audio_bus_factory_->NextAudioBus(
           base::TimeDelta::FromMilliseconds(kAudioFrameDurationMs)));
-      const base::TimeTicks send_time =
+      const base::TimeTicks capture_time =
           testing_clock_sender_->NowTicks() +
               i * base::TimeDelta::FromMilliseconds(kAudioFrameDurationMs);
-      if (will_be_checked)
-        test_receiver_audio_callback_->AddExpectedResult(*audio_bus, send_time);
-      audio_frame_input_->InsertAudio(audio_bus.Pass(), send_time);
+      if (will_be_checked) {
+        test_receiver_audio_callback_->AddExpectedResult(
+            *audio_bus,
+            capture_time +
+                base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs));
+      }
+      audio_frame_input_->InsertAudio(audio_bus.Pass(), capture_time);
     }
   }
 
   void FeedAudioFramesWithExpectedDelay(int count,
                                         const base::TimeDelta& delay) {
     for (int i = 0; i < count; ++i) {
       scoped_ptr<AudioBus> audio_bus(audio_bus_factory_->NextAudioBus(
           base::TimeDelta::FromMilliseconds(kAudioFrameDurationMs)));
-      const base::TimeTicks send_time =
+      const base::TimeTicks capture_time =
           testing_clock_sender_->NowTicks() +
               i * base::TimeDelta::FromMilliseconds(kAudioFrameDurationMs);
-      test_receiver_audio_callback_->AddExpectedResult(*audio_bus,
-                                                       send_time + delay);
-      audio_frame_input_->InsertAudio(audio_bus.Pass(), send_time);
+      test_receiver_audio_callback_->AddExpectedResult(
+          *audio_bus,
+          capture_time + delay +
+              base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs));
+      audio_frame_input_->InsertAudio(audio_bus.Pass(), capture_time);
     }
   }
 
   void RequestAudioFrames(int count, bool with_check) {
     for (int i = 0; i < count; ++i) {
       frame_receiver_->GetRawAudioFrame(
           base::Bind(with_check ? &TestReceiverAudioCallback::CheckAudioFrame :
                                   &TestReceiverAudioCallback::IgnoreAudioFrame,
                      test_receiver_audio_callback_));
     }
   }
 
   void Create() {
     cast_receiver_ = CastReceiver::Create(cast_environment_receiver_,
                                           audio_receiver_config_,
                                           video_receiver_config_,
                                           &receiver_to_sender_);
+
     net::IPEndPoint dummy_endpoint;
     transport_sender_.reset(new transport::CastTransportSenderImpl(
         NULL,
         testing_clock_sender_,
         dummy_endpoint,
         base::Bind(&UpdateCastTransportStatus),
         base::Bind(&End2EndTest::LogRawEvents, base::Unretained(this)),
         base::TimeDelta::FromSeconds(1),
         task_runner_,
         &sender_to_receiver_));
@@ skipping 130 matching lines @@
     const int num_audio_frames = audio_diff / kAudioFrameDurationMs;
     audio_diff -= num_audio_frames * kAudioFrameDurationMs;
 
     if (num_audio_frames > 0)
       FeedAudioFrames(1, true);
 
     test_receiver_video_callback_->AddExpectedResult(
         video_start,
         video_sender_config_.width,
         video_sender_config_.height,
-        testing_clock_sender_->NowTicks(),
+        testing_clock_sender_->NowTicks() +
+            base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs),
         true);
     SendVideoFrame(video_start, testing_clock_sender_->NowTicks());
 
     if (num_audio_frames > 0)
       RunTasks(kAudioFrameDurationMs);  // Advance clock forward.
     if (num_audio_frames > 1)
       FeedAudioFrames(num_audio_frames - 1, true);
 
     RequestAudioFrames(num_audio_frames, true);
     num_audio_frames_requested += num_audio_frames;
@@ skipping 84 matching lines @@
     if (num_audio_frames > 0)
       FeedAudioFramesWithExpectedDelay(1, expected_delay);
 
     // Frame will be rendered with 100mS delay, as the transmission is delayed.
     // The receiver at this point cannot be synced to the sender's clock, as no
     // packets, and specifically no RTCP packets were sent.
     test_receiver_video_callback_->AddExpectedResult(
         video_start,
         video_sender_config_.width,
         video_sender_config_.height,
-        initial_send_time + expected_delay,
+        initial_send_time + expected_delay +
+            base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs),
         true);
     SendVideoFrame(video_start, testing_clock_sender_->NowTicks());
 
     if (num_audio_frames > 0)
       RunTasks(kAudioFrameDurationMs);  // Advance clock forward.
     if (num_audio_frames > 1)
       FeedAudioFramesWithExpectedDelay(num_audio_frames - 1, expected_delay);
 
     RunTasks(kFrameTimerMs - kAudioFrameDurationMs);
     audio_diff += kFrameTimerMs;
     video_start++;
   }
 
   RunTasks(test_delay_ms);
   sender_to_receiver_.SetSendPackets(true);
 
   int num_audio_frames_requested = 0;
   for (int j = 0; j < 10; ++j) {
     const int num_audio_frames = audio_diff / kAudioFrameDurationMs;
     audio_diff -= num_audio_frames * kAudioFrameDurationMs;
 
     if (num_audio_frames > 0)
       FeedAudioFrames(1, true);
 
     test_receiver_video_callback_->AddExpectedResult(
         video_start,
         video_sender_config_.width,
         video_sender_config_.height,
-        testing_clock_sender_->NowTicks(),
+        testing_clock_sender_->NowTicks() +
+            base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs),
         true);
     SendVideoFrame(video_start, testing_clock_sender_->NowTicks());
 
     if (num_audio_frames > 0)
       RunTasks(kAudioFrameDurationMs);  // Advance clock forward.
     if (num_audio_frames > 1)
       FeedAudioFrames(num_audio_frames - 1, true);
 
     RequestAudioFrames(num_audio_frames, true);
     num_audio_frames_requested += num_audio_frames;
@@ skipping 15 matching lines @@
 // This tests a network glitch lasting for 10 video frames.
 // Flaky. See crbug.com/351596.
 TEST_F(End2EndTest, DISABLED_GlitchWith3Buffers) {
   Configure(transport::kVp8, transport::kOpus, kDefaultAudioSamplingRate,
             false, 3);
   video_sender_config_.rtp_config.max_delay_ms = 67;
   video_receiver_config_.rtp_max_delay_ms = 67;
   Create();
 
   int video_start = kVideoStart;
-  base::TimeTicks send_time;
+  base::TimeTicks capture_time;
   // Frames will rendered on completion until the render time stabilizes, i.e.
   // we got enough data.
   const int frames_before_glitch = 20;
   for (int i = 0; i < frames_before_glitch; ++i) {
-    send_time = testing_clock_sender_->NowTicks();
-    SendVideoFrame(video_start, send_time);
+    capture_time = testing_clock_sender_->NowTicks();
+    SendVideoFrame(video_start, capture_time);
     test_receiver_video_callback_->AddExpectedResult(
         video_start,
         video_sender_config_.width,
         video_sender_config_.height,
-        send_time,
+        capture_time + base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs),
         true);
     frame_receiver_->GetRawVideoFrame(
         base::Bind(&TestReceiverVideoCallback::CheckVideoFrame,
                    test_receiver_video_callback_));
     RunTasks(kFrameTimerMs);
     video_start++;
   }
 
   // Introduce a glitch lasting for 10 frames.
   sender_to_receiver_.SetSendPackets(false);
   for (int i = 0; i < 10; ++i) {
-    send_time = testing_clock_sender_->NowTicks();
+    capture_time = testing_clock_sender_->NowTicks();
     // First 3 will be sent and lost.
-    SendVideoFrame(video_start, send_time);
+    SendVideoFrame(video_start, capture_time);
     RunTasks(kFrameTimerMs);
     video_start++;
   }
   sender_to_receiver_.SetSendPackets(true);
   RunTasks(100);
-  send_time = testing_clock_sender_->NowTicks();
+  capture_time = testing_clock_sender_->NowTicks();
 
   // Frame 1 should be acked by now and we should have an opening to send 4.
-  SendVideoFrame(video_start, send_time);
+  SendVideoFrame(video_start, capture_time);
   RunTasks(kFrameTimerMs);
 
   // Frames 1-3 are old frames by now, and therefore should be decoded, but
   // not rendered. The next frame we expect to render is frame #4.
-  test_receiver_video_callback_->AddExpectedResult(video_start,
-                                                   video_sender_config_.width,
-                                                   video_sender_config_.height,
-                                                   send_time,
-                                                   true);
+  test_receiver_video_callback_->AddExpectedResult(
+      video_start,
+      video_sender_config_.width,
+      video_sender_config_.height,
+      capture_time + base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs),
+      true);
 
   frame_receiver_->GetRawVideoFrame(
       base::Bind(&TestReceiverVideoCallback::CheckVideoFrame,
                  test_receiver_video_callback_));
 
   RunTasks(2 * kFrameTimerMs + 1);  // Empty the receiver pipeline.
   EXPECT_EQ(frames_before_glitch + 1,
             test_receiver_video_callback_->number_times_called());
 }
 
 // Disabled due to flakiness and crashiness.  http://crbug.com/360951
 TEST_F(End2EndTest, DISABLED_DropEveryOtherFrame3Buffers) {
   Configure(transport::kVp8, transport::kOpus, kDefaultAudioSamplingRate, false,
             3);
   video_sender_config_.rtp_config.max_delay_ms = 67;
   video_receiver_config_.rtp_max_delay_ms = 67;
   Create();
   sender_to_receiver_.DropAllPacketsBelongingToOddFrames();
 
   int video_start = kVideoStart;
-  base::TimeTicks send_time;
+  base::TimeTicks capture_time;
 
   int i = 0;
   for (; i < 20; ++i) {
-    send_time = testing_clock_sender_->NowTicks();
-    SendVideoFrame(video_start, send_time);
+    capture_time = testing_clock_sender_->NowTicks();
+    SendVideoFrame(video_start, capture_time);
 
     if (i % 2 == 0) {
       test_receiver_video_callback_->AddExpectedResult(
           video_start,
           video_sender_config_.width,
           video_sender_config_.height,
-          send_time,
+          capture_time +
+              base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs),
           i == 0);
 
       // GetRawVideoFrame will not return the frame until we are close in
       // time before we should render the frame.
       frame_receiver_->GetRawVideoFrame(
           base::Bind(&TestReceiverVideoCallback::CheckVideoFrame,
                      test_receiver_video_callback_));
     }
     RunTasks(kFrameTimerMs);
     video_start++;
@@ skipping 13 matching lines @@
 
   video_receiver_config_.aes_iv_mask =
       video_sender_config_.rtp_config.aes_iv_mask;
   video_receiver_config_.aes_key =
       video_sender_config_.rtp_config.aes_key;
 
   Create();
 
   int frames_counter = 0;
   for (; frames_counter < 3; ++frames_counter) {
-    const base::TimeTicks send_time = testing_clock_sender_->NowTicks();
-    SendVideoFrame(frames_counter, send_time);
+    const base::TimeTicks capture_time = testing_clock_sender_->NowTicks();
+    SendVideoFrame(frames_counter, capture_time);
 
     test_receiver_video_callback_->AddExpectedResult(
         frames_counter,
         video_sender_config_.width,
         video_sender_config_.height,
-        send_time,
+        capture_time + base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs),
         true);
 
     RunTasks(kFrameTimerMs);
 
     frame_receiver_->GetRawVideoFrame(
         base::Bind(&TestReceiverVideoCallback::CheckVideoFrame,
                    test_receiver_video_callback_));
   }
   RunTasks(2 * kFrameTimerMs + 1);  // Empty the pipeline.
   EXPECT_EQ(frames_counter,
@@ skipping 29 matching lines @@
 
 // Video test without packet loss - tests the logging aspects of the end2end,
 // but is basically equivalent to LoopNoLossPcm16.
 TEST_F(End2EndTest, VideoLogging) {
   Configure(transport::kVp8, transport::kPcm16, 32000, false, 1);
   Create();
 
   int video_start = kVideoStart;
   const int num_frames = 5;
   for (int i = 0; i < num_frames; ++i) {
-    base::TimeTicks send_time = testing_clock_sender_->NowTicks();
+    base::TimeTicks capture_time = testing_clock_sender_->NowTicks();
     test_receiver_video_callback_->AddExpectedResult(
         video_start,
         video_sender_config_.width,
         video_sender_config_.height,
-        send_time,
+        capture_time + base::TimeDelta::FromMilliseconds(kTargetPlayoutDelayMs),
         true);
 
-    SendVideoFrame(video_start, send_time);
+    SendVideoFrame(video_start, capture_time);
     RunTasks(kFrameTimerMs);
 
     frame_receiver_->GetRawVideoFrame(
         base::Bind(&TestReceiverVideoCallback::CheckVideoFrame,
                    test_receiver_video_callback_));
 
     video_start++;
   }
 
   // Basic tests.
@@ skipping 189 matching lines @@
   EXPECT_EQ(1000, received_counter);
 }
 
 // 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