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