Home | History | Annotate | Download | only in logging
      1 // Copyright 2014 The Chromium Authors. All rights reserved.
      2 // Use of this source code is governed by a BSD-style license that can be
      3 // found in the LICENSE file.
      4 
      5 #include "base/memory/ref_counted.h"
      6 #include "base/memory/scoped_ptr.h"
      7 #include "base/test/simple_test_tick_clock.h"
      8 #include "base/time/tick_clock.h"
      9 #include "media/cast/cast_environment.h"
     10 #include "media/cast/logging/logging_defines.h"
     11 #include "media/cast/logging/receiver_time_offset_estimator_impl.h"
     12 #include "media/cast/test/fake_single_thread_task_runner.h"
     13 #include "testing/gtest/include/gtest/gtest.h"
     14 
     15 namespace media {
     16 namespace cast {
     17 
     18 class ReceiverTimeOffsetEstimatorImplTest : public ::testing::Test {
     19  protected:
     20   ReceiverTimeOffsetEstimatorImplTest()
     21       : sender_clock_(new base::SimpleTestTickClock()),
     22         task_runner_(new test::FakeSingleThreadTaskRunner(sender_clock_)),
     23         cast_environment_(new CastEnvironment(
     24             scoped_ptr<base::TickClock>(sender_clock_).Pass(),
     25             task_runner_,
     26             task_runner_,
     27             task_runner_)) {
     28     cast_environment_->Logging()->AddRawEventSubscriber(&estimator_);
     29   }
     30 
     31   virtual ~ReceiverTimeOffsetEstimatorImplTest() {
     32     cast_environment_->Logging()->RemoveRawEventSubscriber(&estimator_);
     33   }
     34 
     35   void AdvanceClocks(base::TimeDelta time) {
     36     sender_clock_->Advance(time);
     37     receiver_clock_.Advance(time);
     38   }
     39 
     40   base::SimpleTestTickClock* sender_clock_;  // Owned by CastEnvironment.
     41   scoped_refptr<test::FakeSingleThreadTaskRunner> task_runner_;
     42   scoped_refptr<CastEnvironment> cast_environment_;
     43   base::SimpleTestTickClock receiver_clock_;
     44   ReceiverTimeOffsetEstimatorImpl estimator_;
     45 };
     46 
     47 // Suppose the true offset is 100ms.
     48 // Event A occurred at sender time 20ms.
     49 // Event B occurred at receiver time 130ms. (sender time 30ms)
     50 // Event C occurred at sender time 60ms.
     51 // Then the bound after all 3 events have arrived is [130-60=70, 130-20=110].
     52 TEST_F(ReceiverTimeOffsetEstimatorImplTest, EstimateOffset) {
     53   int64 true_offset_ms = 100;
     54   receiver_clock_.Advance(base::TimeDelta::FromMilliseconds(true_offset_ms));
     55 
     56   base::TimeDelta lower_bound;
     57   base::TimeDelta upper_bound;
     58 
     59   EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound));
     60 
     61   RtpTimestamp rtp_timestamp = 0;
     62   uint32 frame_id = 0;
     63 
     64   AdvanceClocks(base::TimeDelta::FromMilliseconds(20));
     65 
     66   cast_environment_->Logging()->InsertEncodedFrameEvent(
     67       sender_clock_->NowTicks(),
     68       FRAME_ENCODED, VIDEO_EVENT,
     69       rtp_timestamp,
     70       frame_id,
     71       1234,
     72       true,
     73       5678);
     74 
     75   cast_environment_->Logging()->InsertPacketEvent(
     76       sender_clock_->NowTicks(),
     77       PACKET_SENT_TO_NETWORK, VIDEO_EVENT,
     78       rtp_timestamp,
     79       frame_id,
     80       56, 78, 1500);
     81 
     82   EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound));
     83 
     84   AdvanceClocks(base::TimeDelta::FromMilliseconds(10));
     85   cast_environment_->Logging()->InsertFrameEvent(
     86       receiver_clock_.NowTicks(), FRAME_ACK_SENT, VIDEO_EVENT,
     87       rtp_timestamp, frame_id);
     88 
     89   cast_environment_->Logging()->InsertPacketEvent(
     90       receiver_clock_.NowTicks(),
     91       PACKET_RECEIVED, VIDEO_EVENT,
     92       rtp_timestamp,
     93       frame_id,
     94       56, 78, 1500);
     95 
     96   EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound));
     97 
     98   AdvanceClocks(base::TimeDelta::FromMilliseconds(30));
     99   cast_environment_->Logging()->InsertFrameEvent(
    100       sender_clock_->NowTicks(), FRAME_ACK_RECEIVED, VIDEO_EVENT,
    101       rtp_timestamp, frame_id);
    102 
    103   EXPECT_TRUE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound));
    104 
    105   int64 lower_bound_ms = lower_bound.InMilliseconds();
    106   int64 upper_bound_ms = upper_bound.InMilliseconds();
    107   EXPECT_EQ(70, lower_bound_ms);
    108   EXPECT_EQ(110, upper_bound_ms);
    109   EXPECT_GE(true_offset_ms, lower_bound_ms);
    110   EXPECT_LE(true_offset_ms, upper_bound_ms);
    111 }
    112 
    113 // Same scenario as above, but event C arrives before event B. It doens't mean
    114 // event C occurred before event B.
    115 TEST_F(ReceiverTimeOffsetEstimatorImplTest, EventCArrivesBeforeEventB) {
    116   int64 true_offset_ms = 100;
    117   receiver_clock_.Advance(base::TimeDelta::FromMilliseconds(true_offset_ms));
    118 
    119   base::TimeDelta lower_bound;
    120   base::TimeDelta upper_bound;
    121 
    122   EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound));
    123 
    124   RtpTimestamp rtp_timestamp = 0;
    125   uint32 frame_id = 0;
    126 
    127   AdvanceClocks(base::TimeDelta::FromMilliseconds(20));
    128 
    129   cast_environment_->Logging()->InsertEncodedFrameEvent(
    130       sender_clock_->NowTicks(),
    131       FRAME_ENCODED, VIDEO_EVENT,
    132       rtp_timestamp,
    133       frame_id,
    134       1234,
    135       true,
    136       5678);
    137 
    138   cast_environment_->Logging()->InsertPacketEvent(
    139       sender_clock_->NowTicks(),
    140       PACKET_SENT_TO_NETWORK, VIDEO_EVENT,
    141       rtp_timestamp,
    142       frame_id,
    143       56, 78, 1500);
    144 
    145   EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound));
    146 
    147   AdvanceClocks(base::TimeDelta::FromMilliseconds(10));
    148   base::TimeTicks event_b_time = receiver_clock_.NowTicks();
    149   AdvanceClocks(base::TimeDelta::FromMilliseconds(30));
    150   base::TimeTicks event_c_time = sender_clock_->NowTicks();
    151 
    152   cast_environment_->Logging()->InsertFrameEvent(
    153       event_c_time, FRAME_ACK_RECEIVED, VIDEO_EVENT, rtp_timestamp, frame_id);
    154 
    155   EXPECT_FALSE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound));
    156 
    157   cast_environment_->Logging()->InsertPacketEvent(
    158       event_b_time,
    159       PACKET_RECEIVED, VIDEO_EVENT,
    160       rtp_timestamp,
    161       frame_id,
    162       56, 78, 1500);
    163 
    164   cast_environment_->Logging()->InsertFrameEvent(
    165       event_b_time, FRAME_ACK_SENT, VIDEO_EVENT, rtp_timestamp, frame_id);
    166 
    167   EXPECT_TRUE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound));
    168 
    169   int64 lower_bound_ms = lower_bound.InMilliseconds();
    170   int64 upper_bound_ms = upper_bound.InMilliseconds();
    171   EXPECT_EQ(70, lower_bound_ms);
    172   EXPECT_EQ(110, upper_bound_ms);
    173   EXPECT_GE(true_offset_ms, lower_bound_ms);
    174   EXPECT_LE(true_offset_ms, upper_bound_ms);
    175 }
    176 
    177 TEST_F(ReceiverTimeOffsetEstimatorImplTest, MultipleIterations) {
    178   int64 true_offset_ms = 100;
    179   receiver_clock_.Advance(base::TimeDelta::FromMilliseconds(true_offset_ms));
    180 
    181   base::TimeDelta lower_bound;
    182   base::TimeDelta upper_bound;
    183 
    184   RtpTimestamp rtp_timestamp_a = 0;
    185   int frame_id_a = 0;
    186   RtpTimestamp rtp_timestamp_b = 90;
    187   int frame_id_b = 1;
    188   RtpTimestamp rtp_timestamp_c = 180;
    189   int frame_id_c = 2;
    190 
    191   // Frame 1 times: [20, 30+100, 60]
    192   // Frame 2 times: [30, 50+100, 55]
    193   // Frame 3 times: [77, 80+100, 110]
    194   // Bound should end up at [95, 103]
    195   // Events times in chronological order: 20, 30 x2, 50, 55, 60, 77, 80, 110
    196   AdvanceClocks(base::TimeDelta::FromMilliseconds(20));
    197   cast_environment_->Logging()->InsertEncodedFrameEvent(
    198       sender_clock_->NowTicks(),
    199       FRAME_ENCODED, VIDEO_EVENT,
    200       rtp_timestamp_a,
    201       frame_id_a,
    202       1234,
    203       true,
    204       5678);
    205 
    206   cast_environment_->Logging()->InsertPacketEvent(
    207       sender_clock_->NowTicks(),
    208       PACKET_SENT_TO_NETWORK, VIDEO_EVENT,
    209       rtp_timestamp_a,
    210       frame_id_a,
    211       56, 78, 1500);
    212 
    213   AdvanceClocks(base::TimeDelta::FromMilliseconds(10));
    214   cast_environment_->Logging()->InsertEncodedFrameEvent(
    215       sender_clock_->NowTicks(),
    216       FRAME_ENCODED, VIDEO_EVENT,
    217       rtp_timestamp_b,
    218       frame_id_b,
    219       1234,
    220       true,
    221       5678);
    222 
    223   cast_environment_->Logging()->InsertPacketEvent(
    224       sender_clock_->NowTicks(),
    225       PACKET_SENT_TO_NETWORK, VIDEO_EVENT,
    226       rtp_timestamp_b,
    227       frame_id_b,
    228       56, 78, 1500);
    229 
    230   cast_environment_->Logging()->InsertFrameEvent(
    231       receiver_clock_.NowTicks(), FRAME_ACK_SENT, VIDEO_EVENT,
    232       rtp_timestamp_a, frame_id_a);
    233 
    234   AdvanceClocks(base::TimeDelta::FromMilliseconds(20));
    235 
    236   cast_environment_->Logging()->InsertPacketEvent(
    237       receiver_clock_.NowTicks(),
    238       PACKET_RECEIVED, VIDEO_EVENT,
    239       rtp_timestamp_b,
    240       frame_id_b,
    241       56, 78, 1500);
    242 
    243   cast_environment_->Logging()->InsertFrameEvent(
    244       receiver_clock_.NowTicks(), FRAME_ACK_SENT, VIDEO_EVENT,
    245       rtp_timestamp_b, frame_id_b);
    246 
    247   AdvanceClocks(base::TimeDelta::FromMilliseconds(5));
    248   cast_environment_->Logging()->InsertFrameEvent(sender_clock_->NowTicks(),
    249                                                  FRAME_ACK_RECEIVED,
    250                                                  VIDEO_EVENT,
    251                                                  rtp_timestamp_b,
    252                                                  frame_id_b);
    253 
    254   AdvanceClocks(base::TimeDelta::FromMilliseconds(5));
    255   cast_environment_->Logging()->InsertFrameEvent(sender_clock_->NowTicks(),
    256                                                  FRAME_ACK_RECEIVED,
    257                                                  VIDEO_EVENT,
    258                                                  rtp_timestamp_a,
    259                                                  frame_id_a);
    260 
    261   AdvanceClocks(base::TimeDelta::FromMilliseconds(17));
    262   cast_environment_->Logging()->InsertEncodedFrameEvent(
    263       sender_clock_->NowTicks(),
    264       FRAME_ENCODED, VIDEO_EVENT,
    265       rtp_timestamp_c,
    266       frame_id_c,
    267       1234,
    268       true,
    269       5678);
    270 
    271   cast_environment_->Logging()->InsertPacketEvent(
    272       sender_clock_->NowTicks(),
    273       PACKET_SENT_TO_NETWORK, VIDEO_EVENT,
    274       rtp_timestamp_c,
    275       frame_id_c,
    276       56, 78, 1500);
    277 
    278   AdvanceClocks(base::TimeDelta::FromMilliseconds(3));
    279   cast_environment_->Logging()->InsertPacketEvent(
    280       receiver_clock_.NowTicks(),
    281       PACKET_RECEIVED, VIDEO_EVENT,
    282       rtp_timestamp_c,
    283       frame_id_c,
    284       56, 78, 1500);
    285 
    286   cast_environment_->Logging()->InsertFrameEvent(
    287       receiver_clock_.NowTicks(), FRAME_ACK_SENT, VIDEO_EVENT,
    288       rtp_timestamp_c, frame_id_c);
    289 
    290   AdvanceClocks(base::TimeDelta::FromMilliseconds(30));
    291   cast_environment_->Logging()->InsertFrameEvent(sender_clock_->NowTicks(),
    292                                                  FRAME_ACK_RECEIVED,
    293                                                  VIDEO_EVENT,
    294                                                  rtp_timestamp_c,
    295                                                  frame_id_c);
    296 
    297   EXPECT_TRUE(estimator_.GetReceiverOffsetBounds(&lower_bound, &upper_bound));
    298   int64 lower_bound_ms = lower_bound.InMilliseconds();
    299   int64 upper_bound_ms = upper_bound.InMilliseconds();
    300   EXPECT_GT(lower_bound_ms, 90);
    301   EXPECT_LE(lower_bound_ms, true_offset_ms);
    302   EXPECT_LT(upper_bound_ms, 150);
    303   EXPECT_GT(upper_bound_ms, true_offset_ms);
    304 }
    305 
    306 }  // namespace cast
    307 }  // namespace media
    308