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// Simulate end to end streaming.
6//
7// Input:
8// --source=
9//   WebM used as the source of video and audio frames.
10// --output=
11//   File path to writing out the raw event log of the simulation session.
12// --sim-id=
13//   Unique simulation ID.
14// --target-delay-ms=
15//   Target playout delay to configure (integer number of milliseconds).
16//   Optional; default is 400.
17//
18// Output:
19// - Raw event log of the simulation session tagged with the unique test ID,
20//   written out to the specified file path.
21
22#include "base/at_exit.h"
23#include "base/base_paths.h"
24#include "base/command_line.h"
25#include "base/files/file_path.h"
26#include "base/files/file_util.h"
27#include "base/files/memory_mapped_file.h"
28#include "base/files/scoped_file.h"
29#include "base/json/json_writer.h"
30#include "base/logging.h"
31#include "base/path_service.h"
32#include "base/strings/string_number_conversions.h"
33#include "base/test/simple_test_tick_clock.h"
34#include "base/thread_task_runner_handle.h"
35#include "base/time/tick_clock.h"
36#include "base/values.h"
37#include "media/base/audio_bus.h"
38#include "media/base/media.h"
39#include "media/base/video_frame.h"
40#include "media/cast/cast_config.h"
41#include "media/cast/cast_environment.h"
42#include "media/cast/cast_receiver.h"
43#include "media/cast/cast_sender.h"
44#include "media/cast/logging/encoding_event_subscriber.h"
45#include "media/cast/logging/log_serializer.h"
46#include "media/cast/logging/logging_defines.h"
47#include "media/cast/logging/proto/raw_events.pb.h"
48#include "media/cast/logging/raw_event_subscriber_bundle.h"
49#include "media/cast/logging/simple_event_subscriber.h"
50#include "media/cast/net/cast_transport_config.h"
51#include "media/cast/net/cast_transport_defines.h"
52#include "media/cast/net/cast_transport_sender.h"
53#include "media/cast/net/cast_transport_sender_impl.h"
54#include "media/cast/test/fake_media_source.h"
55#include "media/cast/test/fake_single_thread_task_runner.h"
56#include "media/cast/test/loopback_transport.h"
57#include "media/cast/test/proto/network_simulation_model.pb.h"
58#include "media/cast/test/skewed_tick_clock.h"
59#include "media/cast/test/utility/audio_utility.h"
60#include "media/cast/test/utility/default_config.h"
61#include "media/cast/test/utility/test_util.h"
62#include "media/cast/test/utility/udp_proxy.h"
63#include "media/cast/test/utility/video_utility.h"
64
65using media::cast::proto::IPPModel;
66using media::cast::proto::NetworkSimulationModel;
67using media::cast::proto::NetworkSimulationModelType;
68
69namespace media {
70namespace cast {
71namespace {
72const char kSourcePath[] = "source";
73const char kModelPath[] = "model";
74const char kOutputPath[] = "output";
75const char kSimulationId[] = "sim-id";
76const char kLibDir[] = "lib-dir";
77const char kTargetDelay[] = "target-delay-ms";
78
79base::TimeDelta GetTargetPlayoutDelay() {
80  const std::string delay_str =
81      CommandLine::ForCurrentProcess()->GetSwitchValueASCII(kTargetDelay);
82  if (delay_str.empty())
83    return base::TimeDelta::FromMilliseconds(400);
84  int delay_ms;
85  CHECK(base::StringToInt(delay_str, &delay_ms));
86  CHECK_GT(delay_ms, 0);
87  return base::TimeDelta::FromMilliseconds(delay_ms);
88}
89
90void UpdateCastTransportStatus(CastTransportStatus status) {
91  LOG(INFO) << "Cast transport status: " << status;
92}
93
94void AudioInitializationStatus(CastInitializationStatus status) {
95  LOG(INFO) << "Audio status: " << status;
96}
97
98void VideoInitializationStatus(CastInitializationStatus status) {
99  LOG(INFO) << "Video status: " << status;
100}
101
102void LogTransportEvents(const scoped_refptr<CastEnvironment>& env,
103                        const std::vector<PacketEvent>& packet_events,
104                        const std::vector<FrameEvent>& frame_events) {
105  for (std::vector<media::cast::PacketEvent>::const_iterator it =
106           packet_events.begin();
107       it != packet_events.end();
108       ++it) {
109    env->Logging()->InsertPacketEvent(it->timestamp,
110                                      it->type,
111                                      it->media_type,
112                                      it->rtp_timestamp,
113                                      it->frame_id,
114                                      it->packet_id,
115                                      it->max_packet_id,
116                                      it->size);
117  }
118  for (std::vector<media::cast::FrameEvent>::const_iterator it =
119           frame_events.begin();
120       it != frame_events.end();
121       ++it) {
122    if (it->type == FRAME_PLAYOUT) {
123      env->Logging()->InsertFrameEventWithDelay(
124          it->timestamp,
125          it->type,
126          it->media_type,
127          it->rtp_timestamp,
128          it->frame_id,
129          it->delay_delta);
130    } else {
131      env->Logging()->InsertFrameEvent(
132          it->timestamp,
133          it->type,
134          it->media_type,
135          it->rtp_timestamp,
136          it->frame_id);
137    }
138  }
139}
140
141void GotVideoFrame(
142    int* counter,
143    CastReceiver* cast_receiver,
144    const scoped_refptr<media::VideoFrame>& video_frame,
145    const base::TimeTicks& render_time,
146    bool continuous) {
147  ++*counter;
148  cast_receiver->RequestDecodedVideoFrame(
149      base::Bind(&GotVideoFrame, counter, cast_receiver));
150}
151
152void GotAudioFrame(
153    int* counter,
154    CastReceiver* cast_receiver,
155    scoped_ptr<AudioBus> audio_bus,
156    const base::TimeTicks& playout_time,
157    bool is_continuous) {
158  ++*counter;
159  cast_receiver->RequestDecodedAudioFrame(
160      base::Bind(&GotAudioFrame, counter, cast_receiver));
161}
162
163// Serialize |frame_events| and |packet_events| and append to the file
164// located at |output_path|.
165void AppendLogToFile(media::cast::proto::LogMetadata* metadata,
166                     const media::cast::FrameEventList& frame_events,
167                     const media::cast::PacketEventList& packet_events,
168                     const base::FilePath& output_path) {
169  media::cast::proto::GeneralDescription* gen_desc =
170      metadata->mutable_general_description();
171  gen_desc->set_product("Cast Simulator");
172  gen_desc->set_product_version("0.1");
173
174  scoped_ptr<char[]> serialized_log(new char[media::cast::kMaxSerializedBytes]);
175  int output_bytes;
176  bool success = media::cast::SerializeEvents(*metadata,
177                                              frame_events,
178                                              packet_events,
179                                              true,
180                                              media::cast::kMaxSerializedBytes,
181                                              serialized_log.get(),
182                                              &output_bytes);
183
184  if (!success) {
185    LOG(ERROR) << "Failed to serialize log.";
186    return;
187  }
188
189  if (AppendToFile(output_path, serialized_log.get(), output_bytes) == -1) {
190    LOG(ERROR) << "Failed to append to log.";
191  }
192}
193
194// Run simulation once.
195//
196// |output_path| is the path to write serialized log.
197// |extra_data| is extra tagging information to write to log.
198void RunSimulation(const base::FilePath& source_path,
199                   const base::FilePath& output_path,
200                   const std::string& extra_data,
201                   const NetworkSimulationModel& model) {
202  // Fake clock. Make sure start time is non zero.
203  base::SimpleTestTickClock testing_clock;
204  testing_clock.Advance(base::TimeDelta::FromSeconds(1));
205
206  // Task runner.
207  scoped_refptr<test::FakeSingleThreadTaskRunner> task_runner =
208      new test::FakeSingleThreadTaskRunner(&testing_clock);
209  base::ThreadTaskRunnerHandle task_runner_handle(task_runner);
210
211  // CastEnvironments.
212  scoped_refptr<CastEnvironment> sender_env =
213      new CastEnvironment(
214          scoped_ptr<base::TickClock>(
215              new test::SkewedTickClock(&testing_clock)).Pass(),
216          task_runner,
217          task_runner,
218          task_runner);
219  scoped_refptr<CastEnvironment> receiver_env =
220      new CastEnvironment(
221          scoped_ptr<base::TickClock>(
222              new test::SkewedTickClock(&testing_clock)).Pass(),
223          task_runner,
224          task_runner,
225          task_runner);
226
227  // Event subscriber. Store at most 1 hour of events.
228  EncodingEventSubscriber audio_event_subscriber(AUDIO_EVENT,
229                                                 100 * 60 * 60);
230  EncodingEventSubscriber video_event_subscriber(VIDEO_EVENT,
231                                                 30 * 60 * 60);
232  sender_env->Logging()->AddRawEventSubscriber(&audio_event_subscriber);
233  sender_env->Logging()->AddRawEventSubscriber(&video_event_subscriber);
234
235  // Audio sender config.
236  AudioSenderConfig audio_sender_config = GetDefaultAudioSenderConfig();
237  audio_sender_config.max_playout_delay = GetTargetPlayoutDelay();
238
239  // Audio receiver config.
240  FrameReceiverConfig audio_receiver_config =
241      GetDefaultAudioReceiverConfig();
242  audio_receiver_config.rtp_max_delay_ms =
243      audio_sender_config.max_playout_delay.InMilliseconds();
244
245  // Video sender config.
246  VideoSenderConfig video_sender_config = GetDefaultVideoSenderConfig();
247  video_sender_config.max_bitrate = 2500000;
248  video_sender_config.min_bitrate = 2000000;
249  video_sender_config.start_bitrate = 2000000;
250  video_sender_config.max_playout_delay = GetTargetPlayoutDelay();
251
252  // Video receiver config.
253  FrameReceiverConfig video_receiver_config =
254      GetDefaultVideoReceiverConfig();
255  video_receiver_config.rtp_max_delay_ms =
256      video_sender_config.max_playout_delay.InMilliseconds();
257
258  // Loopback transport.
259  LoopBackTransport receiver_to_sender(receiver_env);
260  LoopBackTransport sender_to_receiver(sender_env);
261
262  // Cast receiver.
263  scoped_ptr<CastReceiver> cast_receiver(
264      CastReceiver::Create(receiver_env,
265                           audio_receiver_config,
266                           video_receiver_config,
267                           &receiver_to_sender));
268
269  // Cast sender and transport sender.
270  scoped_ptr<CastTransportSender> transport_sender(
271      new CastTransportSenderImpl(
272          NULL,
273          &testing_clock,
274          net::IPEndPoint(),
275          make_scoped_ptr(new base::DictionaryValue),
276          base::Bind(&UpdateCastTransportStatus),
277          base::Bind(&LogTransportEvents, sender_env),
278          base::TimeDelta::FromSeconds(1),
279          task_runner,
280          &sender_to_receiver));
281  scoped_ptr<CastSender> cast_sender(
282      CastSender::Create(sender_env, transport_sender.get()));
283
284  // Build packet pipe.
285  if (model.type() != media::cast::proto::INTERRUPTED_POISSON_PROCESS) {
286    LOG(ERROR) << "Unknown model type " << model.type() << ".";
287    return;
288  }
289
290  const IPPModel& ipp_model = model.ipp();
291
292  std::vector<double> average_rates(ipp_model.average_rate_size());
293  std::copy(ipp_model.average_rate().begin(), ipp_model.average_rate().end(),
294      average_rates.begin());
295  test::InterruptedPoissonProcess ipp(average_rates,
296      ipp_model.coef_burstiness(), ipp_model.coef_variance(), 0);
297
298  // Connect sender to receiver. This initializes the pipe.
299  receiver_to_sender.Initialize(
300      ipp.NewBuffer(128 * 1024).Pass(),
301      transport_sender->PacketReceiverForTesting(),
302      task_runner, &testing_clock);
303  sender_to_receiver.Initialize(
304      ipp.NewBuffer(128 * 1024).Pass(),
305      cast_receiver->packet_receiver(), task_runner,
306      &testing_clock);
307
308  // Start receiver.
309  int audio_frame_count = 0;
310  int video_frame_count = 0;
311  cast_receiver->RequestDecodedVideoFrame(
312      base::Bind(&GotVideoFrame, &video_frame_count, cast_receiver.get()));
313  cast_receiver->RequestDecodedAudioFrame(
314      base::Bind(&GotAudioFrame, &audio_frame_count, cast_receiver.get()));
315
316  FakeMediaSource media_source(task_runner,
317                               &testing_clock,
318                               video_sender_config);
319
320  // Initializing audio and video senders.
321  cast_sender->InitializeAudio(audio_sender_config,
322                               base::Bind(&AudioInitializationStatus));
323  cast_sender->InitializeVideo(media_source.get_video_config(),
324                               base::Bind(&VideoInitializationStatus),
325                               CreateDefaultVideoEncodeAcceleratorCallback(),
326                               CreateDefaultVideoEncodeMemoryCallback());
327  task_runner->RunTasks();
328
329  // Start sending.
330  if (!source_path.empty()) {
331    // 0 means using the FPS from the file.
332    media_source.SetSourceFile(source_path, 0);
333  }
334  media_source.Start(cast_sender->audio_frame_input(),
335                     cast_sender->video_frame_input());
336
337  // Run for 3 minutes.
338  base::TimeDelta elapsed_time;
339  while (elapsed_time.InMinutes() < 3) {
340    // Each step is 100us.
341    base::TimeDelta step = base::TimeDelta::FromMicroseconds(100);
342    task_runner->Sleep(step);
343    elapsed_time += step;
344  }
345
346  // Get event logs for audio and video.
347  media::cast::proto::LogMetadata audio_metadata, video_metadata;
348  media::cast::FrameEventList audio_frame_events, video_frame_events;
349  media::cast::PacketEventList audio_packet_events, video_packet_events;
350  audio_metadata.set_extra_data(extra_data);
351  video_metadata.set_extra_data(extra_data);
352  audio_event_subscriber.GetEventsAndReset(
353      &audio_metadata, &audio_frame_events, &audio_packet_events);
354  video_event_subscriber.GetEventsAndReset(
355      &video_metadata, &video_frame_events, &video_packet_events);
356
357  // Print simulation results.
358
359  // Compute and print statistics for video:
360  //
361  // * Total video frames captured.
362  // * Total video frames encoded.
363  // * Total video frames dropped.
364  // * Total video frames received late.
365  // * Average target bitrate.
366  // * Average encoded bitrate.
367  int total_video_frames = 0;
368  int encoded_video_frames = 0;
369  int dropped_video_frames = 0;
370  int late_video_frames = 0;
371  int64 total_delay_of_late_frames_ms = 0;
372  int64 encoded_size = 0;
373  int64 target_bitrate = 0;
374  for (size_t i = 0; i < video_frame_events.size(); ++i) {
375    const media::cast::proto::AggregatedFrameEvent& event =
376        *video_frame_events[i];
377    ++total_video_frames;
378    if (event.has_encoded_frame_size()) {
379      ++encoded_video_frames;
380      encoded_size += event.encoded_frame_size();
381      target_bitrate += event.target_bitrate();
382    } else {
383      ++dropped_video_frames;
384    }
385    if (event.has_delay_millis() && event.delay_millis() < 0) {
386      ++late_video_frames;
387      total_delay_of_late_frames_ms += -event.delay_millis();
388    }
389  }
390
391  double avg_encoded_bitrate =
392      !encoded_video_frames ? 0 :
393      8.0 * encoded_size * video_sender_config.max_frame_rate /
394      encoded_video_frames / 1000;
395  double avg_target_bitrate =
396      !encoded_video_frames ? 0 : target_bitrate / encoded_video_frames / 1000;
397
398  LOG(INFO) << "Configured target playout delay (ms): "
399            << video_receiver_config.rtp_max_delay_ms;
400  LOG(INFO) << "Audio frame count: " << audio_frame_count;
401  LOG(INFO) << "Total video frames: " << total_video_frames;
402  LOG(INFO) << "Dropped video frames " << dropped_video_frames;
403  LOG(INFO) << "Late video frames: " << late_video_frames
404            << " (average lateness: "
405            << (late_video_frames > 0 ?
406                    static_cast<double>(total_delay_of_late_frames_ms) /
407                        late_video_frames :
408                    0)
409            << " ms)";
410  LOG(INFO) << "Average encoded bitrate (kbps): " << avg_encoded_bitrate;
411  LOG(INFO) << "Average target bitrate (kbps): " << avg_target_bitrate;
412  LOG(INFO) << "Writing log: " << output_path.value();
413
414  // Truncate file and then write serialized log.
415  {
416    base::ScopedFILE file(base::OpenFile(output_path, "wb"));
417    if (!file.get()) {
418      LOG(INFO) << "Cannot write to log.";
419      return;
420    }
421  }
422  AppendLogToFile(&video_metadata, video_frame_events, video_packet_events,
423                  output_path);
424  AppendLogToFile(&audio_metadata, audio_frame_events, audio_packet_events,
425                  output_path);
426}
427
428NetworkSimulationModel DefaultModel() {
429  NetworkSimulationModel model;
430  model.set_type(cast::proto::INTERRUPTED_POISSON_PROCESS);
431  IPPModel* ipp = model.mutable_ipp();
432  ipp->set_coef_burstiness(0.609);
433  ipp->set_coef_variance(4.1);
434
435  ipp->add_average_rate(0.609);
436  ipp->add_average_rate(0.495);
437  ipp->add_average_rate(0.561);
438  ipp->add_average_rate(0.458);
439  ipp->add_average_rate(0.538);
440  ipp->add_average_rate(0.513);
441  ipp->add_average_rate(0.585);
442  ipp->add_average_rate(0.592);
443  ipp->add_average_rate(0.658);
444  ipp->add_average_rate(0.556);
445  ipp->add_average_rate(0.371);
446  ipp->add_average_rate(0.595);
447  ipp->add_average_rate(0.490);
448  ipp->add_average_rate(0.980);
449  ipp->add_average_rate(0.781);
450  ipp->add_average_rate(0.463);
451
452  return model;
453}
454
455bool IsModelValid(const NetworkSimulationModel& model) {
456  if (!model.has_type())
457    return false;
458  NetworkSimulationModelType type = model.type();
459  if (type == media::cast::proto::INTERRUPTED_POISSON_PROCESS) {
460    if (!model.has_ipp())
461      return false;
462    const IPPModel& ipp = model.ipp();
463    if (ipp.coef_burstiness() <= 0.0 || ipp.coef_variance() <= 0.0)
464      return false;
465    if (ipp.average_rate_size() == 0)
466      return false;
467    for (int i = 0; i < ipp.average_rate_size(); i++) {
468      if (ipp.average_rate(i) <= 0.0)
469        return false;
470    }
471  }
472
473  return true;
474}
475
476NetworkSimulationModel LoadModel(const base::FilePath& model_path) {
477  if (model_path.empty()) {
478    LOG(ERROR) << "Model path not set.";
479    return DefaultModel();
480  }
481  std::string model_str;
482  if (!base::ReadFileToString(model_path, &model_str)) {
483    LOG(ERROR) << "Failed to read model file.";
484    return DefaultModel();
485  }
486
487  NetworkSimulationModel model;
488  if (!model.ParseFromString(model_str)) {
489    LOG(ERROR) << "Failed to parse model.";
490    return DefaultModel();
491  }
492  if (!IsModelValid(model)) {
493    LOG(ERROR) << "Invalid model.";
494    return DefaultModel();
495  }
496
497  return model;
498}
499
500}  // namespace
501}  // namespace cast
502}  // namespace media
503
504int main(int argc, char** argv) {
505  base::AtExitManager at_exit;
506  CommandLine::Init(argc, argv);
507  InitLogging(logging::LoggingSettings());
508
509  const CommandLine* cmd = CommandLine::ForCurrentProcess();
510  base::FilePath media_path = cmd->GetSwitchValuePath(media::cast::kLibDir);
511  if (media_path.empty()) {
512    if (!PathService::Get(base::DIR_MODULE, &media_path)) {
513      LOG(ERROR) << "Failed to load FFmpeg.";
514      return 1;
515    }
516  }
517
518  if (!media::InitializeMediaLibrary(media_path)) {
519    LOG(ERROR) << "Failed to initialize FFmpeg.";
520    return 1;
521  }
522
523  base::FilePath source_path = cmd->GetSwitchValuePath(
524      media::cast::kSourcePath);
525  base::FilePath output_path = cmd->GetSwitchValuePath(
526      media::cast::kOutputPath);
527  if (output_path.empty()) {
528    base::GetTempDir(&output_path);
529    output_path = output_path.AppendASCII("sim-events.gz");
530  }
531  std::string sim_id = cmd->GetSwitchValueASCII(media::cast::kSimulationId);
532
533  NetworkSimulationModel model = media::cast::LoadModel(
534      cmd->GetSwitchValuePath(media::cast::kModelPath));
535
536  base::DictionaryValue values;
537  values.SetBoolean("sim", true);
538  values.SetString("sim-id", sim_id);
539
540  std::string extra_data;
541  base::JSONWriter::Write(&values, &extra_data);
542
543  // Run.
544  media::cast::RunSimulation(source_path, output_path, extra_data, model);
545  return 0;
546}
547