Added logging calls to FFmpegDemuxer.

media/filters/ffmpeg_demuxer.cc

Index: media/filters/ffmpeg_demuxer.cc
diff --git a/media/filters/ffmpeg_demuxer.cc b/media/filters/ffmpeg_demuxer.cc
index 70c55963f1c9700c2c090f89a0e270bde58e07c1..d3727c45d8855a6567fdcc5c4862c4943619d7b6 100644
--- a/media/filters/ffmpeg_demuxer.cc
+++ b/media/filters/ffmpeg_demuxer.cc
@@ -17,6 +17,7 @@
 #include "base/metrics/sparse_histogram.h"
 #include "base/stl_util.h"
 #include "base/strings/string_util.h"
+#include "base/strings/stringprintf.h"
 #include "base/task_runner_util.h"
 #include "base/time/time.h"
 #include "media/base/audio_decoder_config.h"
@@ -503,6 +504,14 @@ void FFmpegDemuxer::OnFindStreamInfoDone(const PipelineStatusCB& status_cb,
     if (codec_type == AVMEDIA_TYPE_AUDIO) {
       if (found_audio_stream)
         continue;
+
+      // Logging
+      std::string codec_name = codec_context->codec_name;

[scherkus (not reviewing), 2013/08/02 21:53:48]

if you're putting the logging here, then we should move all of this down to
where you're logging found_audio/video_stream below and use the
Audio/VideoDecoderCofnigs

for example ... we'll log the wrong thing here if there are multiple audio/video
tracks where we don't support the first tracks (notice on line 526 where if we
don't accept the config we don't set found_audio_stream to true)

also some of these are duplicated (e.g., sample rate == samples per second)

[Ty Overby, 2013/08/02 23:04:27]

Done.

+      media_log_->SetProperty("audio_codec_name", codec_name);
+      media_log_->SetProperty("audio_sample_rate", codec_context->sample_rate);
+      media_log_->SetProperty("audio_channels", codec_context->channels);
+
+
       // Log the codec detected, whether it is supported or not.
       UMA_HISTOGRAM_SPARSE_SLOWLY("Media.DetectedAudioCodec",
                                   codec_context->codec_id);
@@ -510,12 +519,33 @@ void FFmpegDemuxer::OnFindStreamInfoDone(const PipelineStatusCB& status_cb,
       // channel layout and sample format are valid.
       AudioDecoderConfig audio_config;
       AVStreamToAudioDecoderConfig(stream, &audio_config, false);
+
+      media_log_->SetProperty("audio_samples_per_second",
+                              audio_config.samples_per_second());
+
       if (!audio_config.IsValidConfig())
         continue;
       found_audio_stream = true;
     } else if (codec_type == AVMEDIA_TYPE_VIDEO) {
       if (found_video_stream)
         continue;
+
+      // Logging
+      std::string codec_name = avcodec_get_name(codec_context->codec_id);
+      media_log_->SetProperty("video_codec_name", codec_name);
+      media_log_->SetProperty("width", codec_context->width);
+      media_log_->SetProperty("height", codec_context->height);
+      media_log_->SetProperty("coded_width", codec_context->coded_width);
+      media_log_->SetProperty("coded_height", codec_context->coded_height);
+      media_log_->SetProperty("ticks_per_frame",

[scherkus (not reviewing), 2013/08/02 21:53:48]

I wouldn't bother logging this one

[Ty Overby, 2013/08/02 23:04:27]

Done.

+                              codec_context->ticks_per_frame);
+
+      std::string base_time = "";
+      base::SStringPrintf(&base_time, "%d/%d",

[scherkus (not reviewing), 2013/08/02 21:53:48]

you can use StringPrintf() (no leading S) and pass that result directly into the
log call on the next line

[Ty Overby, 2013/08/02 23:04:27]

Done.

+                          codec_context->time_base.num,
+                          codec_context->time_base.den);
+      media_log_->SetProperty("time_base", base_time);

[scherkus (not reviewing), 2013/08/02 21:53:48]

this might not end up being very useful information ... we'll see :)

[Ty Overby, 2013/08/02 23:04:27]

Ok, well it's easy to add/remove if it proves useful.  FPS is defined in terms
of this fraction.

+
       // Log the codec detected, whether it is supported or not.
       UMA_HISTOGRAM_SPARSE_SLOWLY("Media.DetectedVideoCodec",
                                   codec_context->codec_id);
@@ -523,6 +553,13 @@ void FFmpegDemuxer::OnFindStreamInfoDone(const PipelineStatusCB& status_cb,
       // frame size and visible size are valid.
       VideoDecoderConfig video_config;
       AVStreamToVideoDecoderConfig(stream, &video_config, false);
+
+      media_log_->SetProperty("video_decoder_config",

[scherkus (not reviewing), 2013/08/02 21:53:48]

don't bother logging -- it'll duplicates other stuff you're logging

[Ty Overby, 2013/08/02 23:04:27]

Done.

+                              video_config.AsHumanReadableString());
+      media_log_->SetProperty("pixel_format", video_config.FormatName());

[scherkus (not reviewing), 2013/08/02 21:53:48]

nit: s/pixel_format/video_format/

[Ty Overby, 2013/08/02 23:04:27]

Done.

+      media_log_->SetProperty("video_is_encrypted",
+                              video_config.is_encrypted());
+
       if (!video_config.IsValidConfig())
         continue;
       found_video_stream = true;
@@ -579,6 +616,13 @@ void FFmpegDemuxer::OnFindStreamInfoDone(const PipelineStatusCB& status_cb,
   if (bitrate_ > 0)
     data_source_->SetBitrate(bitrate_);
 
+  media_log_->SetProperty("found_audio_stream", found_audio_stream);
+  media_log_->SetProperty("found_video_stream", found_video_stream);
+  media_log_->SetProperty("max_duration", max_duration.InMillisecondsF());

[scherkus (not reviewing), 2013/08/02 21:53:48]

nit: I'd use InSecondsF

[Ty Overby, 2013/08/02 23:04:27]

Done.

+  media_log_->SetProperty("start_time", start_time_.InMillisecondsF());
+  media_log_->SetProperty("filesize_in_bytes",(int) filesize_in_bytes);

[scherkus (not reviewing), 2013/08/02 21:53:48]

this will need to be converted to a string due to 32-bit limitations

(yep, we've seen people play videos larger than 2^31-1 bytes and complain that
media-internals reports a negative number...)

[Ty Overby, 2013/08/02 23:04:27]

Oh wow.  

Done.

+  media_log_->SetProperty("bitrate", bitrate_);
+
   status_cb.Run(PIPELINE_OK);
 }