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 "media/cast/logging/stats_event_subscriber.h"
6 
7 #include <stddef.h>
8 #include <stdint.h>
9 
10 #include <memory>
11 #include <utility>
12 
13 #include "base/memory/ref_counted.h"
14 #include "base/rand_util.h"
15 #include "base/test/simple_test_tick_clock.h"
16 #include "base/time/tick_clock.h"
17 #include "base/values.h"
18 #include "media/base/fake_single_thread_task_runner.h"
19 #include "media/cast/cast_environment.h"
20 #include "media/cast/logging/logging_defines.h"
21 #include "media/cast/test/fake_receiver_time_offset_estimator.h"
22 #include "testing/gtest/include/gtest/gtest.h"
23 
24 namespace {
25 const int kReceiverOffsetSecs = 100;
26 }
27 
28 namespace media {
29 namespace cast {
30 
31 class StatsEventSubscriberTest : public ::testing::Test {
32  protected:
StatsEventSubscriberTest()33   StatsEventSubscriberTest()
34       : task_runner_(new FakeSingleThreadTaskRunner(&sender_clock_)),
35         cast_environment_(new CastEnvironment(&sender_clock_,
36                                               task_runner_,
37                                               task_runner_,
38                                               task_runner_)),
39         fake_offset_estimator_(
40             base::TimeDelta::FromSeconds(kReceiverOffsetSecs)) {
41     receiver_clock_.Advance(base::TimeDelta::FromSeconds(kReceiverOffsetSecs));
42     cast_environment_->logger()->Subscribe(&fake_offset_estimator_);
43   }
44 
~StatsEventSubscriberTest()45   ~StatsEventSubscriberTest() override {
46     if (subscriber_.get())
47       cast_environment_->logger()->Unsubscribe(subscriber_.get());
48     cast_environment_->logger()->Unsubscribe(&fake_offset_estimator_);
49   }
50 
AdvanceClocks(base::TimeDelta delta)51   void AdvanceClocks(base::TimeDelta delta) {
52     task_runner_->Sleep(delta);
53     receiver_clock_.Advance(delta);
54   }
55 
Init(EventMediaType event_media_type)56   void Init(EventMediaType event_media_type) {
57     DCHECK(!subscriber_.get());
58     subscriber_.reset(new StatsEventSubscriber(
59         event_media_type, cast_environment_->Clock(), &fake_offset_estimator_));
60     cast_environment_->logger()->Subscribe(subscriber_.get());
61   }
62 
63   base::SimpleTestTickClock sender_clock_;
64   base::SimpleTestTickClock receiver_clock_;
65   scoped_refptr<FakeSingleThreadTaskRunner> task_runner_;
66   scoped_refptr<CastEnvironment> cast_environment_;
67   test::FakeReceiverTimeOffsetEstimator fake_offset_estimator_;
68   std::unique_ptr<StatsEventSubscriber> subscriber_;
69 };
70 
TEST_F(StatsEventSubscriberTest,CaptureEncode)71 TEST_F(StatsEventSubscriberTest, CaptureEncode) {
72   Init(VIDEO_EVENT);
73 
74   RtpTimeTicks rtp_timestamp;
75   FrameId frame_id = FrameId::first();
76   int extra_frames = 50;
77   // Only the first |extra_frames| frames logged will be taken into account
78   // when computing dropped frames.
79   int num_frames = StatsEventSubscriber::kMaxFrameInfoMapSize + 50;
80   int dropped_frames = 0;
81   base::TimeTicks start_time = sender_clock_.NowTicks();
82   // Drop half the frames during the encode step.
83   for (int i = 0; i < num_frames; i++) {
84     std::unique_ptr<FrameEvent> capture_begin_event(new FrameEvent());
85     capture_begin_event->timestamp = sender_clock_.NowTicks();
86     capture_begin_event->type = FRAME_CAPTURE_BEGIN;
87     capture_begin_event->media_type = VIDEO_EVENT;
88     capture_begin_event->rtp_timestamp = rtp_timestamp;
89     cast_environment_->logger()->DispatchFrameEvent(
90         std::move(capture_begin_event));
91 
92     AdvanceClocks(base::TimeDelta::FromMicroseconds(10));
93     std::unique_ptr<FrameEvent> capture_end_event(new FrameEvent());
94     capture_end_event->timestamp = sender_clock_.NowTicks();
95     capture_end_event->type = FRAME_CAPTURE_END;
96     capture_end_event->media_type = VIDEO_EVENT;
97     capture_end_event->rtp_timestamp = rtp_timestamp;
98     cast_environment_->logger()->DispatchFrameEvent(
99         std::move(capture_end_event));
100 
101     if (i % 2 == 0) {
102       AdvanceClocks(base::TimeDelta::FromMicroseconds(10));
103       std::unique_ptr<FrameEvent> encode_event(new FrameEvent());
104       encode_event->timestamp = sender_clock_.NowTicks();
105       encode_event->type = FRAME_ENCODED;
106       encode_event->media_type = VIDEO_EVENT;
107       encode_event->rtp_timestamp = rtp_timestamp;
108       encode_event->frame_id = frame_id;
109       encode_event->size = 1024;
110       encode_event->key_frame = true;
111       encode_event->target_bitrate = 5678;
112       encode_event->encoder_cpu_utilization = 9.10;
113       encode_event->idealized_bitrate_utilization = 11.12;
114       cast_environment_->logger()->DispatchFrameEvent(std::move(encode_event));
115     } else if (i < extra_frames) {
116       dropped_frames++;
117     }
118     AdvanceClocks(base::TimeDelta::FromMicroseconds(34567));
119     rtp_timestamp += RtpTimeDelta::FromTicks(90);
120     frame_id++;
121   }
122 
123   base::TimeTicks end_time = sender_clock_.NowTicks();
124 
125   StatsEventSubscriber::StatsMap stats_map;
126   subscriber_->GetStatsInternal(&stats_map);
127 
128   auto it = stats_map.find(StatsEventSubscriber::CAPTURE_FPS);
129   ASSERT_TRUE(it != stats_map.end());
130 
131   base::TimeDelta duration = end_time - start_time;
132   EXPECT_DOUBLE_EQ(
133       it->second,
134       static_cast<double>(num_frames) / duration.InMillisecondsF() * 1000);
135 
136   it = stats_map.find(StatsEventSubscriber::NUM_FRAMES_CAPTURED);
137   ASSERT_TRUE(it != stats_map.end());
138 
139   EXPECT_DOUBLE_EQ(it->second, static_cast<double>(num_frames));
140 
141   it = stats_map.find(StatsEventSubscriber::NUM_FRAMES_DROPPED_BY_ENCODER);
142   ASSERT_TRUE(it != stats_map.end());
143 
144   EXPECT_DOUBLE_EQ(it->second, static_cast<double>(dropped_frames));
145 
146   it = stats_map.find(StatsEventSubscriber::AVG_CAPTURE_LATENCY_MS);
147   ASSERT_TRUE(it != stats_map.end());
148 
149   EXPECT_DOUBLE_EQ(it->second, static_cast<double>(0.01));
150 }
151 
TEST_F(StatsEventSubscriberTest,Encode)152 TEST_F(StatsEventSubscriberTest, Encode) {
153   Init(VIDEO_EVENT);
154 
155   RtpTimeTicks rtp_timestamp;
156   FrameId frame_id = FrameId::first();
157   int num_frames = 10;
158   base::TimeTicks start_time = sender_clock_.NowTicks();
159   AdvanceClocks(base::TimeDelta::FromMicroseconds(35678));
160   base::TimeTicks first_event_time = sender_clock_.NowTicks();
161   base::TimeTicks last_event_time;
162   int total_size = 0;
163   for (int i = 0; i < num_frames; i++) {
164     int size = 1000 + base::RandInt(-100, 100);
165     total_size += size;
166     std::unique_ptr<FrameEvent> encode_event(new FrameEvent());
167     encode_event->timestamp = sender_clock_.NowTicks();
168     encode_event->type = FRAME_ENCODED;
169     encode_event->media_type = VIDEO_EVENT;
170     encode_event->rtp_timestamp = rtp_timestamp;
171     encode_event->frame_id = frame_id;
172     encode_event->size = size;
173     encode_event->key_frame = true;
174     encode_event->target_bitrate = 5678;
175     encode_event->encoder_cpu_utilization = 9.10;
176     encode_event->idealized_bitrate_utilization = 11.12;
177     cast_environment_->logger()->DispatchFrameEvent(std::move(encode_event));
178     last_event_time = sender_clock_.NowTicks();
179 
180     AdvanceClocks(base::TimeDelta::FromMicroseconds(35678));
181     rtp_timestamp += RtpTimeDelta::FromTicks(90);
182     frame_id++;
183   }
184 
185   base::TimeTicks end_time = sender_clock_.NowTicks();
186 
187   StatsEventSubscriber::StatsMap stats_map;
188   subscriber_->GetStatsInternal(&stats_map);
189 
190   auto it = stats_map.find(StatsEventSubscriber::ENCODE_FPS);
191   ASSERT_TRUE(it != stats_map.end());
192 
193   base::TimeDelta duration = end_time - start_time;
194   EXPECT_DOUBLE_EQ(
195       it->second,
196       static_cast<double>(num_frames) / duration.InMillisecondsF() * 1000);
197 
198   it = stats_map.find(StatsEventSubscriber::ENCODE_KBPS);
199   ASSERT_TRUE(it != stats_map.end());
200 
201   EXPECT_DOUBLE_EQ(it->second,
202               static_cast<double>(total_size) / duration.InMillisecondsF() * 8);
203 
204   it = stats_map.find(StatsEventSubscriber::FIRST_EVENT_TIME_MS);
205   ASSERT_TRUE(it != stats_map.end());
206 
207   EXPECT_DOUBLE_EQ(
208       it->second,
209       (first_event_time - base::TimeTicks::UnixEpoch()).InMillisecondsF());
210 
211   it = stats_map.find(StatsEventSubscriber::LAST_EVENT_TIME_MS);
212   ASSERT_TRUE(it != stats_map.end());
213 
214   EXPECT_DOUBLE_EQ(
215       it->second,
216       (last_event_time - base::TimeTicks::UnixEpoch()).InMillisecondsF());
217 }
218 
TEST_F(StatsEventSubscriberTest,Decode)219 TEST_F(StatsEventSubscriberTest, Decode) {
220   Init(VIDEO_EVENT);
221 
222   RtpTimeTicks rtp_timestamp;
223   FrameId frame_id = FrameId::first();
224   int num_frames = 10;
225   base::TimeTicks start_time = sender_clock_.NowTicks();
226   for (int i = 0; i < num_frames; i++) {
227     std::unique_ptr<FrameEvent> decode_event(new FrameEvent());
228     decode_event->timestamp = receiver_clock_.NowTicks();
229     decode_event->type = FRAME_DECODED;
230     decode_event->media_type = VIDEO_EVENT;
231     decode_event->rtp_timestamp = rtp_timestamp;
232     decode_event->frame_id = frame_id;
233     cast_environment_->logger()->DispatchFrameEvent(std::move(decode_event));
234 
235     AdvanceClocks(base::TimeDelta::FromMicroseconds(36789));
236     rtp_timestamp += RtpTimeDelta::FromTicks(90);
237     frame_id++;
238   }
239 
240   base::TimeTicks end_time = sender_clock_.NowTicks();
241 
242   StatsEventSubscriber::StatsMap stats_map;
243   subscriber_->GetStatsInternal(&stats_map);
244 
245   auto it = stats_map.find(StatsEventSubscriber::DECODE_FPS);
246   ASSERT_TRUE(it != stats_map.end());
247 
248   base::TimeDelta duration = end_time - start_time;
249   EXPECT_DOUBLE_EQ(
250       it->second,
251       static_cast<double>(num_frames) / duration.InMillisecondsF() * 1000);
252 }
253 
TEST_F(StatsEventSubscriberTest,PlayoutDelay)254 TEST_F(StatsEventSubscriberTest, PlayoutDelay) {
255   Init(VIDEO_EVENT);
256 
257   RtpTimeTicks rtp_timestamp;
258   FrameId frame_id = FrameId::first();
259   int num_frames = 10;
260   int late_frames = 0;
261   for (int i = 0, delay_ms = -50; i < num_frames; i++, delay_ms += 10) {
262     base::TimeDelta delay = base::TimeDelta::FromMilliseconds(delay_ms);
263     if (delay_ms > 0)
264       late_frames++;
265     std::unique_ptr<FrameEvent> playout_event(new FrameEvent());
266     playout_event->timestamp = receiver_clock_.NowTicks();
267     playout_event->type = FRAME_PLAYOUT;
268     playout_event->media_type = VIDEO_EVENT;
269     playout_event->rtp_timestamp = rtp_timestamp;
270     playout_event->frame_id = frame_id;
271     playout_event->delay_delta = delay;
272     cast_environment_->logger()->DispatchFrameEvent(std::move(playout_event));
273 
274     AdvanceClocks(base::TimeDelta::FromMicroseconds(37890));
275     rtp_timestamp += RtpTimeDelta::FromTicks(90);
276     frame_id++;
277   }
278 
279   StatsEventSubscriber::StatsMap stats_map;
280   subscriber_->GetStatsInternal(&stats_map);
281 
282   auto it = stats_map.find(StatsEventSubscriber::NUM_FRAMES_LATE);
283   ASSERT_TRUE(it != stats_map.end());
284 
285   EXPECT_DOUBLE_EQ(it->second, late_frames);
286 }
287 
TEST_F(StatsEventSubscriberTest,E2ELatency)288 TEST_F(StatsEventSubscriberTest, E2ELatency) {
289   Init(VIDEO_EVENT);
290 
291   RtpTimeTicks rtp_timestamp;
292   FrameId frame_id = FrameId::first();
293   int num_frames = 10;
294   base::TimeDelta total_latency;
295   for (int i = 0; i < num_frames; i++) {
296     std::unique_ptr<FrameEvent> capture_begin_event(new FrameEvent());
297     capture_begin_event->timestamp = sender_clock_.NowTicks();
298     capture_begin_event->type = FRAME_CAPTURE_BEGIN;
299     capture_begin_event->media_type = VIDEO_EVENT;
300     capture_begin_event->rtp_timestamp = rtp_timestamp;
301     cast_environment_->logger()->DispatchFrameEvent(
302         std::move(capture_begin_event));
303 
304     int latency_micros = 100000 + base::RandInt(-5000, 50000);
305     base::TimeDelta latency = base::TimeDelta::FromMicroseconds(latency_micros);
306     AdvanceClocks(latency);
307 
308     int delay_micros = base::RandInt(-50000, 50000);
309     base::TimeDelta delay = base::TimeDelta::FromMilliseconds(delay_micros);
310     total_latency += latency;
311 
312     std::unique_ptr<FrameEvent> playout_event(new FrameEvent());
313     playout_event->timestamp = receiver_clock_.NowTicks();
314     playout_event->type = FRAME_PLAYOUT;
315     playout_event->media_type = VIDEO_EVENT;
316     playout_event->rtp_timestamp = rtp_timestamp;
317     playout_event->frame_id = frame_id;
318     playout_event->delay_delta = delay;
319     cast_environment_->logger()->DispatchFrameEvent(std::move(playout_event));
320 
321     rtp_timestamp += RtpTimeDelta::FromTicks(90);
322     frame_id++;
323   }
324 
325   StatsEventSubscriber::StatsMap stats_map;
326   subscriber_->GetStatsInternal(&stats_map);
327 
328   auto it = stats_map.find(StatsEventSubscriber::AVG_E2E_LATENCY_MS);
329   ASSERT_TRUE(it != stats_map.end());
330 
331   EXPECT_DOUBLE_EQ(
332       it->second, total_latency.InMillisecondsF() / num_frames);
333 }
334 
TEST_F(StatsEventSubscriberTest,Packets)335 TEST_F(StatsEventSubscriberTest, Packets) {
336   Init(VIDEO_EVENT);
337 
338   RtpTimeTicks rtp_timestamp;
339   int num_packets = 10;
340   int num_latency_recorded_packets = 0;
341   base::TimeTicks start_time = sender_clock_.NowTicks();
342   int total_size = 0;
343   int retransmit_total_size = 0;
344   base::TimeDelta total_network_latency;
345   base::TimeDelta total_queueing_latency;
346   base::TimeDelta total_packet_latency;
347   int num_packets_transmitted = 0;
348   int num_packets_received = 0;
349   int num_packets_retransmitted = 0;
350   int num_packets_rtx_rejected = 0;
351 
352   base::TimeTicks sender_encoded_time = sender_clock_.NowTicks();
353   base::TimeTicks receiver_encoded_time = receiver_clock_.NowTicks();
354   std::unique_ptr<FrameEvent> encode_event(new FrameEvent());
355   encode_event->timestamp = sender_encoded_time;
356   encode_event->type = FRAME_ENCODED;
357   encode_event->media_type = VIDEO_EVENT;
358   encode_event->rtp_timestamp = rtp_timestamp;
359   encode_event->frame_id = FrameId::first();
360   cast_environment_->logger()->DispatchFrameEvent(std::move(encode_event));
361 
362   // Every 2nd packet will be retransmitted once.
363   // Every 4th packet will be retransmitted twice.
364   // Every 8th packet will be retransmitted 3 times + 1 rejected retransmission.
365   for (int i = 0; i < num_packets; i++) {
366     int size = 1000 + base::RandInt(-100, 100);
367     total_size += size;
368 
369     std::unique_ptr<PacketEvent> send_event(new PacketEvent());
370     send_event->timestamp = sender_clock_.NowTicks();
371     send_event->type = PACKET_SENT_TO_NETWORK;
372     send_event->media_type = VIDEO_EVENT;
373     send_event->rtp_timestamp = rtp_timestamp;
374     send_event->frame_id = FrameId::first();
375     send_event->packet_id = i;
376     send_event->max_packet_id = num_packets - 1;
377     send_event->size = size;
378     cast_environment_->logger()->DispatchPacketEvent(std::move(send_event));
379 
380     num_packets_transmitted++;
381     total_queueing_latency += sender_clock_.NowTicks() - sender_encoded_time;
382 
383     int latency_micros = 20000 + base::RandInt(-10000, 10000);
384     base::TimeDelta latency = base::TimeDelta::FromMicroseconds(latency_micros);
385     // Latency is only recorded for packets that aren't retransmitted.
386     if (i % 2 != 0) {
387       total_network_latency += latency;
388       total_packet_latency +=
389           receiver_clock_.NowTicks() - receiver_encoded_time + latency;
390       num_latency_recorded_packets++;
391     }
392 
393     AdvanceClocks(latency);
394 
395     base::TimeTicks received_time = receiver_clock_.NowTicks();
396 
397     // Retransmission 1.
398     AdvanceClocks(base::TimeDelta::FromMicroseconds(12345));
399     if (i % 2 == 0) {
400       std::unique_ptr<PacketEvent> retransmit_event(new PacketEvent());
401       retransmit_event->timestamp = receiver_clock_.NowTicks();
402       retransmit_event->type = PACKET_RETRANSMITTED;
403       retransmit_event->media_type = VIDEO_EVENT;
404       retransmit_event->rtp_timestamp = rtp_timestamp;
405       retransmit_event->frame_id = FrameId::first();
406       retransmit_event->packet_id = i;
407       retransmit_event->max_packet_id = num_packets - 1;
408       retransmit_event->size = size;
409       cast_environment_->logger()->DispatchPacketEvent(
410           std::move(retransmit_event));
411 
412       retransmit_total_size += size;
413       num_packets_transmitted++;
414       num_packets_retransmitted++;
415     }
416 
417     // Retransmission 2.
418     AdvanceClocks(base::TimeDelta::FromMicroseconds(13456));
419     if (i % 4 == 0) {
420       std::unique_ptr<PacketEvent> retransmit_event(new PacketEvent());
421       retransmit_event->timestamp = receiver_clock_.NowTicks();
422       retransmit_event->type = PACKET_RETRANSMITTED;
423       retransmit_event->media_type = VIDEO_EVENT;
424       retransmit_event->rtp_timestamp = rtp_timestamp;
425       retransmit_event->frame_id = FrameId::first();
426       retransmit_event->packet_id = i;
427       retransmit_event->max_packet_id = num_packets - 1;
428       retransmit_event->size = size;
429       cast_environment_->logger()->DispatchPacketEvent(
430           std::move(retransmit_event));
431 
432       retransmit_total_size += size;
433       num_packets_transmitted++;
434       num_packets_retransmitted++;
435     }
436 
437     // Retransmission 3.
438     AdvanceClocks(base::TimeDelta::FromMicroseconds(14567));
439     if (i % 8 == 0) {
440       std::unique_ptr<PacketEvent> retransmit_event(new PacketEvent());
441       retransmit_event->timestamp = receiver_clock_.NowTicks();
442       retransmit_event->type = PACKET_RETRANSMITTED;
443       retransmit_event->media_type = VIDEO_EVENT;
444       retransmit_event->rtp_timestamp = rtp_timestamp;
445       retransmit_event->frame_id = FrameId::first();
446       retransmit_event->packet_id = i;
447       retransmit_event->max_packet_id = num_packets - 1;
448       retransmit_event->size = size;
449       cast_environment_->logger()->DispatchPacketEvent(
450           std::move(retransmit_event));
451 
452       std::unique_ptr<PacketEvent> reject_event(new PacketEvent());
453       reject_event->timestamp = receiver_clock_.NowTicks();
454       reject_event->type = PACKET_RTX_REJECTED;
455       reject_event->media_type = VIDEO_EVENT;
456       reject_event->rtp_timestamp = rtp_timestamp;
457       reject_event->frame_id = FrameId::first();
458       reject_event->packet_id = i;
459       reject_event->max_packet_id = num_packets - 1;
460       reject_event->size = size;
461       cast_environment_->logger()->DispatchPacketEvent(std::move(reject_event));
462 
463       retransmit_total_size += size;
464       num_packets_transmitted++;
465       num_packets_retransmitted++;
466       num_packets_rtx_rejected++;
467     }
468 
469     std::unique_ptr<PacketEvent> receive_event(new PacketEvent());
470     receive_event->timestamp = received_time;
471     receive_event->type = PACKET_RECEIVED;
472     receive_event->media_type = VIDEO_EVENT;
473     receive_event->rtp_timestamp = rtp_timestamp;
474     receive_event->frame_id = FrameId::first();
475     receive_event->packet_id = i;
476     receive_event->max_packet_id = num_packets - 1;
477     receive_event->size = size;
478     cast_environment_->logger()->DispatchPacketEvent(std::move(receive_event));
479 
480     num_packets_received++;
481   }
482 
483   base::TimeTicks end_time = sender_clock_.NowTicks();
484   base::TimeDelta duration = end_time - start_time;
485 
486   StatsEventSubscriber::StatsMap stats_map;
487   subscriber_->GetStatsInternal(&stats_map);
488 
489   // Measure AVG_NETWORK_LATENCY_MS, TRANSMISSION_KBPS, RETRANSMISSION_KBPS.
490   auto it = stats_map.find(StatsEventSubscriber::AVG_NETWORK_LATENCY_MS);
491   ASSERT_TRUE(it != stats_map.end());
492 
493   EXPECT_DOUBLE_EQ(
494       it->second,
495       total_network_latency.InMillisecondsF() / num_latency_recorded_packets);
496 
497   it = stats_map.find(StatsEventSubscriber::AVG_QUEUEING_LATENCY_MS);
498   ASSERT_TRUE(it != stats_map.end());
499 
500   EXPECT_DOUBLE_EQ(
501       it->second,
502       total_queueing_latency.InMillisecondsF() / num_packets);
503 
504   it = stats_map.find(StatsEventSubscriber::AVG_PACKET_LATENCY_MS);
505   ASSERT_TRUE(it != stats_map.end());
506 
507   EXPECT_DOUBLE_EQ(
508       it->second,
509       total_packet_latency.InMillisecondsF() / num_latency_recorded_packets);
510 
511   it = stats_map.find(StatsEventSubscriber::TRANSMISSION_KBPS);
512   ASSERT_TRUE(it != stats_map.end());
513 
514   EXPECT_DOUBLE_EQ(it->second,
515               static_cast<double>(total_size) / duration.InMillisecondsF() * 8);
516 
517   it = stats_map.find(StatsEventSubscriber::RETRANSMISSION_KBPS);
518   ASSERT_TRUE(it != stats_map.end());
519 
520   EXPECT_DOUBLE_EQ(it->second,
521               static_cast<double>(retransmit_total_size) /
522                   duration.InMillisecondsF() * 8);
523 
524   it = stats_map.find(StatsEventSubscriber::NUM_PACKETS_SENT);
525   ASSERT_TRUE(it != stats_map.end());
526 
527   EXPECT_DOUBLE_EQ(it->second, static_cast<double>(num_packets));
528 
529   it = stats_map.find(StatsEventSubscriber::NUM_PACKETS_RECEIVED);
530   ASSERT_TRUE(it != stats_map.end());
531 
532   EXPECT_DOUBLE_EQ(it->second, static_cast<double>(num_packets_received));
533 
534   it = stats_map.find(StatsEventSubscriber::NUM_PACKETS_RETRANSMITTED);
535   ASSERT_TRUE(it != stats_map.end());
536 
537   EXPECT_DOUBLE_EQ(it->second, static_cast<double>(num_packets_retransmitted));
538 
539   it = stats_map.find(StatsEventSubscriber::NUM_PACKETS_RTX_REJECTED);
540   ASSERT_TRUE(it != stats_map.end());
541 
542   EXPECT_DOUBLE_EQ(it->second, static_cast<double>(num_packets_rtx_rejected));
543 }
544 
CheckHistogramHasValue(base::ListValue * values,const std::string & bucket,int expected_count)545 bool CheckHistogramHasValue(base::ListValue* values,
546                             const std::string& bucket, int expected_count) {
547   for (size_t i = 0; i < values->GetSize(); ++i) {
548     const base::DictionaryValue* dict = NULL;
549     values->GetDictionary(i, &dict);
550     if (!dict->HasKey(bucket))
551       continue;
552     int bucket_count = 0;
553     if (!dict->GetInteger(bucket, &bucket_count))
554       return false;
555     return bucket_count == expected_count;
556   }
557   return false;
558 }
559 
TEST_F(StatsEventSubscriberTest,Histograms)560 TEST_F(StatsEventSubscriberTest, Histograms) {
561   Init(VIDEO_EVENT);
562   AdvanceClocks(base::TimeDelta::FromMilliseconds(123));
563 
564   RtpTimeTicks rtp_timestamp = RtpTimeTicks().Expand(UINT32_C(123));
565   FrameId frame_id = FrameId::first();
566 
567   // 10 Frames with capture latency in the bucket of "10-14"ms.
568   // 10 Frames with encode time in the bucket of "15-19"ms.
569   for (int i = 0; i < 10; ++i) {
570     ++frame_id;
571     rtp_timestamp += RtpTimeDelta::FromTicks(1);
572 
573     std::unique_ptr<FrameEvent> capture_begin_event(new FrameEvent());
574     capture_begin_event->timestamp = sender_clock_.NowTicks();
575     capture_begin_event->type = FRAME_CAPTURE_BEGIN;
576     capture_begin_event->media_type = VIDEO_EVENT;
577     capture_begin_event->rtp_timestamp = rtp_timestamp;
578     cast_environment_->logger()->DispatchFrameEvent(
579         std::move(capture_begin_event));
580 
581     AdvanceClocks(base::TimeDelta::FromMilliseconds(10));
582     std::unique_ptr<FrameEvent> capture_end_event(new FrameEvent());
583     capture_end_event->timestamp = sender_clock_.NowTicks();
584     capture_end_event->type = FRAME_CAPTURE_END;
585     capture_end_event->media_type = VIDEO_EVENT;
586     capture_end_event->rtp_timestamp = rtp_timestamp;
587     cast_environment_->logger()->DispatchFrameEvent(
588         std::move(capture_end_event));
589 
590     AdvanceClocks(base::TimeDelta::FromMilliseconds(15));
591     std::unique_ptr<FrameEvent> encode_event(new FrameEvent());
592     encode_event->timestamp = sender_clock_.NowTicks();
593     encode_event->type = FRAME_ENCODED;
594     encode_event->media_type = VIDEO_EVENT;
595     encode_event->rtp_timestamp = rtp_timestamp;
596     encode_event->frame_id = frame_id;
597     encode_event->size = 1024;
598     encode_event->key_frame = true;
599     encode_event->target_bitrate = 5678;
600     encode_event->encoder_cpu_utilization = 9.10;
601     encode_event->idealized_bitrate_utilization = 11.12;
602     cast_environment_->logger()->DispatchFrameEvent(std::move(encode_event));
603   }
604 
605   // Send 3 packets for the last frame.
606   // Queueing latencies are 100ms, 200ms and 300ms.
607   for (int i = 0; i < 3; ++i) {
608     AdvanceClocks(base::TimeDelta::FromMilliseconds(100));
609     std::unique_ptr<PacketEvent> send_event(new PacketEvent());
610     send_event->timestamp = sender_clock_.NowTicks();
611     send_event->type = PACKET_SENT_TO_NETWORK;
612     send_event->media_type = VIDEO_EVENT;
613     send_event->rtp_timestamp = rtp_timestamp;
614     send_event->frame_id = FrameId::first();
615     send_event->packet_id = i;
616     send_event->max_packet_id = 2;
617     send_event->size = 123;
618     cast_environment_->logger()->DispatchPacketEvent(std::move(send_event));
619   }
620 
621   // Receive 3 packets for the last frame.
622   // Network latencies are 100ms, 200ms and 300ms.
623   // Packet latencies are 400ms.
624   AdvanceClocks(base::TimeDelta::FromMilliseconds(100));
625   for (int i = 0; i < 3; ++i) {
626     std::unique_ptr<PacketEvent> receive_event(new PacketEvent());
627     receive_event->timestamp = receiver_clock_.NowTicks();
628     receive_event->type = PACKET_RECEIVED;
629     receive_event->media_type = VIDEO_EVENT;
630     receive_event->rtp_timestamp = rtp_timestamp;
631     receive_event->frame_id = FrameId::first();
632     receive_event->packet_id = i;
633     receive_event->max_packet_id = 2;
634     receive_event->size = 123;
635     cast_environment_->logger()->DispatchPacketEvent(std::move(receive_event));
636   }
637 
638   std::unique_ptr<FrameEvent> playout_event(new FrameEvent());
639   playout_event->timestamp = receiver_clock_.NowTicks();
640   playout_event->type = FRAME_PLAYOUT;
641   playout_event->media_type = VIDEO_EVENT;
642   playout_event->rtp_timestamp = rtp_timestamp;
643   playout_event->frame_id = frame_id;
644   playout_event->delay_delta = base::TimeDelta::FromMilliseconds(100);
645   cast_environment_->logger()->DispatchFrameEvent(std::move(playout_event));
646 
647   StatsEventSubscriber::SimpleHistogram* histogram;
648   std::unique_ptr<base::ListValue> values;
649 
650   histogram = subscriber_->GetHistogramForTesting(
651       StatsEventSubscriber::CAPTURE_LATENCY_MS_HISTO);
652   ASSERT_TRUE(histogram);
653   values = histogram->GetHistogram();
654   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "10-14", 10));
655 
656   histogram = subscriber_->GetHistogramForTesting(
657       StatsEventSubscriber::ENCODE_TIME_MS_HISTO);
658   ASSERT_TRUE(histogram);
659   values = histogram->GetHistogram();
660   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "15-19", 10));
661 
662   histogram = subscriber_->GetHistogramForTesting(
663       StatsEventSubscriber::QUEUEING_LATENCY_MS_HISTO);
664   ASSERT_TRUE(histogram);
665   values = histogram->GetHistogram();
666   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "100-119", 1));
667   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "200-219", 1));
668   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "300-319", 1));
669 
670   histogram = subscriber_->GetHistogramForTesting(
671       StatsEventSubscriber::NETWORK_LATENCY_MS_HISTO);
672   ASSERT_TRUE(histogram);
673   values = histogram->GetHistogram();
674   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "100-119", 1));
675   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "200-219", 1));
676   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "300-319", 1));
677 
678   histogram = subscriber_->GetHistogramForTesting(
679       StatsEventSubscriber::PACKET_LATENCY_MS_HISTO);
680   ASSERT_TRUE(histogram);
681   values = histogram->GetHistogram();
682   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "400-419", 3));
683 
684   histogram = subscriber_->GetHistogramForTesting(
685       StatsEventSubscriber::LATE_FRAME_MS_HISTO);
686   ASSERT_TRUE(histogram);
687   values = histogram->GetHistogram();
688   EXPECT_TRUE(CheckHistogramHasValue(values.get(), "100-119", 1));
689 }
690 
691 }  // namespace cast
692 }  // namespace media
693