src/media/cast/logging/encoding_event_subscriber_unittest.cc

   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/encoding_event_subscriber.h"
  11 #include "media/cast/logging/logging_defines.h"
  12 #include "media/cast/test/fake_single_thread_task_runner.h"
  13 #include "testing/gtest/include/gtest/gtest.h"
  14
  15 using media::cast::proto::AggregatedFrameEvent;
  16 using media::cast::proto::AggregatedPacketEvent;
  17 using media::cast::proto::BasePacketEvent;
  18
  19 namespace media {
  20 namespace cast {
  21
  22 class EncodingEventSubscriberTest : public ::testing::Test {
  23  protected:
  24   EncodingEventSubscriberTest()
  25       : testing_clock_(new base::SimpleTestTickClock()),
  26         task_runner_(new test::FakeSingleThreadTaskRunner(testing_clock_)),
  27         cast_environment_(new CastEnvironment(
  28             scoped_ptr<base::TickClock>(testing_clock_).Pass(),
  29             task_runner_,
  30             task_runner_,
  31             task_runner_,
  32             task_runner_,
  33             task_runner_,
  34             task_runner_,
  35             GetLoggingConfigWithRawEventsAndStatsEnabled())) {}
  36
  37   void Init(EventMediaType event_media_type) {
  38     DCHECK(!event_subscriber_);
  39     event_subscriber_.reset(new EncodingEventSubscriber(event_media_type, 10));
  40     cast_environment_->Logging()->AddRawEventSubscriber(
  41         event_subscriber_.get());
  42   }
  43
  44   virtual ~EncodingEventSubscriberTest() {
  45     if (event_subscriber_) {
  46       cast_environment_->Logging()->RemoveRawEventSubscriber(
  47           event_subscriber_.get());
  48     }
  49   }
  50
  51   base::SimpleTestTickClock* testing_clock_;  // Owned by CastEnvironment.
  52   scoped_refptr<test::FakeSingleThreadTaskRunner> task_runner_;
  53   scoped_refptr<CastEnvironment> cast_environment_;
  54   scoped_ptr<EncodingEventSubscriber> event_subscriber_;
  55 };
  56
  57 TEST_F(EncodingEventSubscriberTest, FrameEventTruncating) {
  58   Init(VIDEO_EVENT);
  59
  60   base::TimeTicks now(testing_clock_->NowTicks());
  61
  62   // Entry with RTP timestamp 0 should get dropped.
  63   for (int i = 0; i < 11; i++) {
  64     cast_environment_->Logging()->InsertFrameEvent(now,
  65                                                    kVideoFrameCaptured,
  66                                                    i * 100,
  67                                                    /*frame_id*/ 0);
  68     cast_environment_->Logging()->InsertFrameEvent(now,
  69                                                    kVideoFrameDecoded,
  70                                                    i * 100,
  71                                                    /*frame_id*/ 0);
  72   }
  73
  74   FrameEventMap frame_events;
  75   event_subscriber_->GetFrameEventsAndReset(&frame_events);
  76
  77   ASSERT_EQ(10u, frame_events.size());
  78   EXPECT_EQ(100u, frame_events.begin()->first);
  79   EXPECT_EQ(1000u, frame_events.rbegin()->first);
  80 }
  81
  82 TEST_F(EncodingEventSubscriberTest, PacketEventTruncating) {
  83   Init(AUDIO_EVENT);
  84
  85   base::TimeTicks now(testing_clock_->NowTicks());
  86
  87   // Entry with RTP timestamp 0 should get dropped.
  88   for (int i = 0; i < 11; i++) {
  89     cast_environment_->Logging()->InsertPacketEvent(now,
  90                                                     kAudioPacketReceived,
  91                                                     /*rtp_timestamp*/ i * 100,
  92                                                     /*frame_id*/ 0,
  93                                                     /*packet_id*/ i,
  94                                                     /*max_packet_id*/ 10,
  95                                                     /*size*/ 123);
  96   }
  97
  98   PacketEventMap packet_events;
  99   event_subscriber_->GetPacketEventsAndReset(&packet_events);
 100
 101   ASSERT_EQ(10u, packet_events.size());
 102   EXPECT_EQ(100u, packet_events.begin()->first);
 103   EXPECT_EQ(1000u, packet_events.rbegin()->first);
 104 }
 105
 106 TEST_F(EncodingEventSubscriberTest, EventFiltering) {
 107   Init(VIDEO_EVENT);
 108
 109   base::TimeTicks now(testing_clock_->NowTicks());
 110   RtpTimestamp rtp_timestamp = 100;
 111   cast_environment_->Logging()->InsertFrameEvent(now,
 112                                                  kVideoFrameDecoded,
 113                                                  rtp_timestamp,
 114                                                  /*frame_id*/ 0);
 115
 116   // This is an AUDIO_EVENT and shouldn't be processed by the subscriber.
 117   cast_environment_->Logging()->InsertFrameEvent(now,
 118                                                  kAudioFrameDecoded,
 119                                                  rtp_timestamp,
 120                                                  /*frame_id*/ 0);
 121
 122   FrameEventMap frame_events;
 123   event_subscriber_->GetFrameEventsAndReset(&frame_events);
 124
 125   FrameEventMap::iterator frame_it = frame_events.find(rtp_timestamp);
 126   ASSERT_TRUE(frame_it != frame_events.end());
 127
 128   linked_ptr<AggregatedFrameEvent> frame_event = frame_it->second;
 129
 130   ASSERT_EQ(1, frame_event->event_type_size());
 131   EXPECT_EQ(media::cast::proto::VIDEO_FRAME_DECODED,
 132             frame_event->event_type(0));
 133
 134   PacketEventMap packet_events;
 135   event_subscriber_->GetPacketEventsAndReset(&packet_events);
 136   EXPECT_TRUE(packet_events.empty());
 137 }
 138
 139 TEST_F(EncodingEventSubscriberTest, FrameEvent) {
 140   Init(VIDEO_EVENT);
 141   base::TimeTicks now(testing_clock_->NowTicks());
 142   RtpTimestamp rtp_timestamp = 100;
 143   cast_environment_->Logging()->InsertFrameEvent(now, kVideoFrameDecoded,
 144                                                  rtp_timestamp,
 145                                                  /*frame_id*/ 0);
 146
 147   FrameEventMap frame_events;
 148   event_subscriber_->GetFrameEventsAndReset(&frame_events);
 149
 150   ASSERT_EQ(1u, frame_events.size());
 151
 152   FrameEventMap::iterator it = frame_events.find(rtp_timestamp);
 153   ASSERT_TRUE(it != frame_events.end());
 154
 155   linked_ptr<AggregatedFrameEvent> event = it->second;
 156
 157   EXPECT_EQ(rtp_timestamp, event->rtp_timestamp());
 158
 159   ASSERT_EQ(1, event->event_type_size());
 160   EXPECT_EQ(media::cast::proto::VIDEO_FRAME_DECODED, event->event_type(0));
 161   ASSERT_EQ(1, event->event_timestamp_micros_size());
 162   EXPECT_EQ(now.ToInternalValue(), event->event_timestamp_micros(0));
 163
 164   EXPECT_EQ(0, event->encoded_frame_size());
 165   EXPECT_EQ(0, event->delay_millis());
 166
 167   event_subscriber_->GetFrameEventsAndReset(&frame_events);
 168   EXPECT_TRUE(frame_events.empty());
 169 }
 170
 171 TEST_F(EncodingEventSubscriberTest, FrameEventDelay) {
 172   Init(AUDIO_EVENT);
 173   base::TimeTicks now(testing_clock_->NowTicks());
 174   RtpTimestamp rtp_timestamp = 100;
 175   int delay_ms = 100;
 176   cast_environment_->Logging()->InsertFrameEventWithDelay(
 177       now, kAudioPlayoutDelay, rtp_timestamp,
 178       /*frame_id*/ 0, base::TimeDelta::FromMilliseconds(delay_ms));
 179
 180   FrameEventMap frame_events;
 181   event_subscriber_->GetFrameEventsAndReset(&frame_events);
 182
 183   ASSERT_EQ(1u, frame_events.size());
 184
 185   FrameEventMap::iterator it = frame_events.find(rtp_timestamp);
 186   ASSERT_TRUE(it != frame_events.end());
 187
 188   linked_ptr<AggregatedFrameEvent> event = it->second;
 189
 190   EXPECT_EQ(rtp_timestamp, event->rtp_timestamp());
 191
 192   ASSERT_EQ(1, event->event_type_size());
 193   EXPECT_EQ(media::cast::proto::AUDIO_PLAYOUT_DELAY, event->event_type(0));
 194   ASSERT_EQ(1, event->event_timestamp_micros_size());
 195   EXPECT_EQ(now.ToInternalValue(), event->event_timestamp_micros(0));
 196
 197   EXPECT_EQ(0, event->encoded_frame_size());
 198   EXPECT_EQ(100, event->delay_millis());
 199 }
 200
 201 TEST_F(EncodingEventSubscriberTest, FrameEventSize) {
 202   Init(VIDEO_EVENT);
 203   base::TimeTicks now(testing_clock_->NowTicks());
 204   RtpTimestamp rtp_timestamp = 100;
 205   int size = 123;
 206   cast_environment_->Logging()->InsertFrameEventWithSize(
 207       now, kVideoFrameEncoded, rtp_timestamp,
 208       /*frame_id*/ 0, size);
 209
 210   FrameEventMap frame_events;
 211   event_subscriber_->GetFrameEventsAndReset(&frame_events);
 212
 213   ASSERT_EQ(1u, frame_events.size());
 214
 215   FrameEventMap::iterator it = frame_events.find(rtp_timestamp);
 216   ASSERT_TRUE(it != frame_events.end());
 217
 218   linked_ptr<AggregatedFrameEvent> event = it->second;
 219
 220   EXPECT_EQ(rtp_timestamp, event->rtp_timestamp());
 221
 222   ASSERT_EQ(1, event->event_type_size());
 223   EXPECT_EQ(media::cast::proto::VIDEO_FRAME_ENCODED, event->event_type(0));
 224   ASSERT_EQ(1, event->event_timestamp_micros_size());
 225   EXPECT_EQ(now.ToInternalValue(), event->event_timestamp_micros(0));
 226
 227   EXPECT_EQ(size, event->encoded_frame_size());
 228   EXPECT_EQ(0, event->delay_millis());
 229 }
 230
 231 TEST_F(EncodingEventSubscriberTest, MultipleFrameEvents) {
 232   Init(AUDIO_EVENT);
 233   RtpTimestamp rtp_timestamp1 = 100;
 234   RtpTimestamp rtp_timestamp2 = 200;
 235   base::TimeTicks now1(testing_clock_->NowTicks());
 236   cast_environment_->Logging()->InsertFrameEventWithDelay(
 237       now1, kAudioPlayoutDelay, rtp_timestamp1,
 238       /*frame_id*/ 0, /*delay*/ base::TimeDelta::FromMilliseconds(100));
 239
 240   testing_clock_->Advance(base::TimeDelta::FromMilliseconds(20));
 241   base::TimeTicks now2(testing_clock_->NowTicks());
 242   cast_environment_->Logging()->InsertFrameEventWithSize(
 243       now2, kAudioFrameEncoded, rtp_timestamp2,
 244       /*frame_id*/ 0, /*size*/ 123);
 245
 246   testing_clock_->Advance(base::TimeDelta::FromMilliseconds(20));
 247   base::TimeTicks now3(testing_clock_->NowTicks());
 248   cast_environment_->Logging()->InsertFrameEvent(
 249       now3, kAudioFrameDecoded, rtp_timestamp1, /*frame_id*/ 0);
 250
 251   FrameEventMap frame_events;
 252   event_subscriber_->GetFrameEventsAndReset(&frame_events);
 253
 254   ASSERT_EQ(2u, frame_events.size());
 255
 256   FrameEventMap::iterator it = frame_events.find(100);
 257   ASSERT_TRUE(it != frame_events.end());
 258
 259   linked_ptr<AggregatedFrameEvent> event = it->second;
 260
 261   EXPECT_EQ(rtp_timestamp1, event->rtp_timestamp());
 262
 263   ASSERT_EQ(2, event->event_type_size());
 264   EXPECT_EQ(media::cast::proto::AUDIO_PLAYOUT_DELAY, event->event_type(0));
 265   EXPECT_EQ(media::cast::proto::AUDIO_FRAME_DECODED, event->event_type(1));
 266
 267   ASSERT_EQ(2, event->event_timestamp_micros_size());
 268   EXPECT_EQ(now1.ToInternalValue(), event->event_timestamp_micros(0));
 269   EXPECT_EQ(now3.ToInternalValue(), event->event_timestamp_micros(1));
 270
 271   it = frame_events.find(200);
 272   ASSERT_TRUE(it != frame_events.end());
 273
 274   event = it->second;
 275
 276   EXPECT_EQ(rtp_timestamp2, event->rtp_timestamp());
 277
 278   ASSERT_EQ(1, event->event_type_size());
 279   EXPECT_EQ(media::cast::proto::AUDIO_FRAME_ENCODED, event->event_type(0));
 280
 281   ASSERT_EQ(1, event->event_timestamp_micros_size());
 282   EXPECT_EQ(now2.ToInternalValue(), event->event_timestamp_micros(0));
 283 }
 284
 285 TEST_F(EncodingEventSubscriberTest, PacketEvent) {
 286   Init(AUDIO_EVENT);
 287   base::TimeTicks now(testing_clock_->NowTicks());
 288   RtpTimestamp rtp_timestamp = 100;
 289   int packet_id = 2;
 290   int size = 100;
 291   cast_environment_->Logging()->InsertPacketEvent(
 292       now, kAudioPacketReceived, rtp_timestamp, /*frame_id*/ 0, packet_id,
 293       /*max_packet_id*/ 10, size);
 294
 295   PacketEventMap packet_events;
 296   event_subscriber_->GetPacketEventsAndReset(&packet_events);
 297
 298   ASSERT_EQ(1u, packet_events.size());
 299
 300   PacketEventMap::iterator it = packet_events.find(rtp_timestamp);
 301   ASSERT_TRUE(it != packet_events.end());
 302
 303   linked_ptr<AggregatedPacketEvent> event = it->second;
 304
 305   EXPECT_EQ(rtp_timestamp, event->rtp_timestamp());
 306
 307   ASSERT_EQ(1, event->base_packet_event_size());
 308   const BasePacketEvent& base_event = event->base_packet_event(0);
 309   EXPECT_EQ(packet_id, base_event.packet_id());
 310   ASSERT_EQ(1, base_event.event_type_size());
 311   EXPECT_EQ(media::cast::proto::AUDIO_PACKET_RECEIVED,
 312             base_event.event_type(0));
 313   ASSERT_EQ(1, base_event.event_timestamp_micros_size());
 314   EXPECT_EQ(now.ToInternalValue(), base_event.event_timestamp_micros(0));
 315
 316   event_subscriber_->GetPacketEventsAndReset(&packet_events);
 317   EXPECT_TRUE(packet_events.empty());
 318 }
 319
 320 TEST_F(EncodingEventSubscriberTest, MultiplePacketEventsForPacket) {
 321   Init(OTHER_EVENT);
 322   base::TimeTicks now1(testing_clock_->NowTicks());
 323   RtpTimestamp rtp_timestamp = 100;
 324   int packet_id = 2;
 325   int size = 100;
 326   cast_environment_->Logging()->InsertPacketEvent(
 327       now1, kPacketSentToPacer, rtp_timestamp, /*frame_id*/ 0, packet_id,
 328       /*max_packet_id*/ 10, size);
 329
 330   testing_clock_->Advance(base::TimeDelta::FromMilliseconds(20));
 331   base::TimeTicks now2(testing_clock_->NowTicks());
 332   cast_environment_->Logging()->InsertPacketEvent(
 333       now2, kPacketSentToNetwork, rtp_timestamp, /*frame_id*/ 0, packet_id,
 334       /*max_packet_id*/ 10, size);
 335
 336   PacketEventMap packet_events;
 337   event_subscriber_->GetPacketEventsAndReset(&packet_events);
 338
 339   ASSERT_EQ(1u, packet_events.size());
 340
 341   PacketEventMap::iterator it = packet_events.find(rtp_timestamp);
 342   ASSERT_TRUE(it != packet_events.end());
 343
 344   linked_ptr<AggregatedPacketEvent> event = it->second;
 345
 346   EXPECT_EQ(rtp_timestamp, event->rtp_timestamp());
 347
 348   ASSERT_EQ(1, event->base_packet_event_size());
 349   const BasePacketEvent& base_event = event->base_packet_event(0);
 350   EXPECT_EQ(packet_id, base_event.packet_id());
 351   ASSERT_EQ(2, base_event.event_type_size());
 352   EXPECT_EQ(media::cast::proto::PACKET_SENT_TO_PACER, base_event.event_type(0));
 353   EXPECT_EQ(media::cast::proto::PACKET_SENT_TO_NETWORK,
 354             base_event.event_type(1));
 355   ASSERT_EQ(2, base_event.event_timestamp_micros_size());
 356   EXPECT_EQ(now1.ToInternalValue(), base_event.event_timestamp_micros(0));
 357   EXPECT_EQ(now2.ToInternalValue(), base_event.event_timestamp_micros(1));
 358 }
 359
 360 TEST_F(EncodingEventSubscriberTest, MultiplePacketEventsForFrame) {
 361   Init(OTHER_EVENT);
 362   base::TimeTicks now1(testing_clock_->NowTicks());
 363   RtpTimestamp rtp_timestamp = 100;
 364   int packet_id_1 = 2;
 365   int packet_id_2 = 3;
 366   int size = 100;
 367   cast_environment_->Logging()->InsertPacketEvent(
 368       now1, kPacketSentToPacer, rtp_timestamp, /*frame_id*/ 0, packet_id_1,
 369       /*max_packet_id*/ 10, size);
 370
 371   testing_clock_->Advance(base::TimeDelta::FromMilliseconds(20));
 372   base::TimeTicks now2(testing_clock_->NowTicks());
 373   cast_environment_->Logging()->InsertPacketEvent(
 374       now2, kPacketRetransmitted, rtp_timestamp, /*frame_id*/ 0, packet_id_2,
 375       /*max_packet_id*/ 10, size);
 376
 377   PacketEventMap packet_events;
 378   event_subscriber_->GetPacketEventsAndReset(&packet_events);
 379
 380   ASSERT_EQ(1u, packet_events.size());
 381
 382   PacketEventMap::iterator it = packet_events.find(rtp_timestamp);
 383   ASSERT_TRUE(it != packet_events.end());
 384
 385   linked_ptr<AggregatedPacketEvent> event = it->second;
 386
 387   EXPECT_EQ(rtp_timestamp, event->rtp_timestamp());
 388
 389   ASSERT_EQ(2, event->base_packet_event_size());
 390   const BasePacketEvent& base_event = event->base_packet_event(0);
 391   EXPECT_EQ(packet_id_1, base_event.packet_id());
 392   ASSERT_EQ(1, base_event.event_type_size());
 393   EXPECT_EQ(media::cast::proto::PACKET_SENT_TO_PACER, base_event.event_type(0));
 394   ASSERT_EQ(1, base_event.event_timestamp_micros_size());
 395   EXPECT_EQ(now1.ToInternalValue(), base_event.event_timestamp_micros(0));
 396
 397   const BasePacketEvent& base_event_2 = event->base_packet_event(1);
 398   EXPECT_EQ(packet_id_2, base_event_2.packet_id());
 399   ASSERT_EQ(1, base_event_2.event_type_size());
 400   EXPECT_EQ(media::cast::proto::PACKET_RETRANSMITTED,
 401             base_event_2.event_type(0));
 402   ASSERT_EQ(1, base_event_2.event_timestamp_micros_size());
 403   EXPECT_EQ(now2.ToInternalValue(), base_event_2.event_timestamp_micros(0));
 404 }
 405
 406 TEST_F(EncodingEventSubscriberTest, MultiplePacketEvents) {
 407   Init(OTHER_EVENT);
 408   base::TimeTicks now1(testing_clock_->NowTicks());
 409   RtpTimestamp rtp_timestamp_1 = 100;
 410   RtpTimestamp rtp_timestamp_2 = 200;
 411   int packet_id_1 = 2;
 412   int packet_id_2 = 3;
 413   int size = 100;
 414   cast_environment_->Logging()->InsertPacketEvent(
 415       now1, kPacketSentToPacer, rtp_timestamp_1, /*frame_id*/ 0, packet_id_1,
 416       /*max_packet_id*/ 10, size);
 417
 418   testing_clock_->Advance(base::TimeDelta::FromMilliseconds(20));
 419   base::TimeTicks now2(testing_clock_->NowTicks());
 420   cast_environment_->Logging()->InsertPacketEvent(
 421       now2, kPacketRetransmitted, rtp_timestamp_2, /*frame_id*/ 0, packet_id_2,
 422       /*max_packet_id*/ 10, size);
 423
 424   PacketEventMap packet_events;
 425   event_subscriber_->GetPacketEventsAndReset(&packet_events);
 426
 427   ASSERT_EQ(2u, packet_events.size());
 428
 429   PacketEventMap::iterator it = packet_events.find(rtp_timestamp_1);
 430   ASSERT_TRUE(it != packet_events.end());
 431
 432   linked_ptr<AggregatedPacketEvent> event = it->second;
 433
 434   EXPECT_EQ(rtp_timestamp_1, event->rtp_timestamp());
 435
 436   ASSERT_EQ(1, event->base_packet_event_size());
 437   const BasePacketEvent& base_event = event->base_packet_event(0);
 438   EXPECT_EQ(packet_id_1, base_event.packet_id());
 439   ASSERT_EQ(1, base_event.event_type_size());
 440   EXPECT_EQ(media::cast::proto::PACKET_SENT_TO_PACER, base_event.event_type(0));
 441   ASSERT_EQ(1, base_event.event_timestamp_micros_size());
 442   EXPECT_EQ(now1.ToInternalValue(), base_event.event_timestamp_micros(0));
 443
 444   it = packet_events.find(rtp_timestamp_2);
 445   ASSERT_TRUE(it != packet_events.end());
 446
 447   event = it->second;
 448
 449   EXPECT_EQ(rtp_timestamp_2, event->rtp_timestamp());
 450
 451   ASSERT_EQ(1, event->base_packet_event_size());
 452   const BasePacketEvent& base_event_2 = event->base_packet_event(0);
 453   EXPECT_EQ(packet_id_2, base_event_2.packet_id());
 454   ASSERT_EQ(1, base_event_2.event_type_size());
 455   EXPECT_EQ(media::cast::proto::PACKET_RETRANSMITTED,
 456             base_event_2.event_type(0));
 457   ASSERT_EQ(1, base_event_2.event_timestamp_micros_size());
 458   EXPECT_EQ(now2.ToInternalValue(), base_event_2.event_timestamp_micros(0));
 459 }
 460
 461 }  // namespace cast
 462 }  // namespace media