Added logging calls to FFmpegDemuxer.

media/filters/ffmpeg_demuxer.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "media/filters/ffmpeg_demuxer.h"
 
 #include <algorithm>
 #include <string>
 
 #include "base/base64.h"
 #include "base/bind.h"
 #include "base/callback.h"
 #include "base/callback_helpers.h"
 #include "base/command_line.h"
 #include "base/memory/scoped_ptr.h"
 #include "base/message_loop/message_loop.h"
 #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"
 #include "media/base/bind_to_loop.h"
 #include "media/base/decoder_buffer.h"
 #include "media/base/decrypt_config.h"
 #include "media/base/limits.h"
 #include "media/base/media_log.h"
 #include "media/base/media_switches.h"
 #include "media/base/video_decoder_config.h"
@@ skipping 466 matching lines @@
 
   base::TimeDelta max_duration;
   for (size_t i = 0; i < format_context->nb_streams; ++i) {
     AVStream* stream = format_context->streams[i];
     AVCodecContext* codec_context = stream->codec;
     AVMediaType codec_type = codec_context->codec_type;
 
     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);
       // Ensure the codec is supported. IsValidConfig() also checks that the
       // 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);
       // Ensure the codec is supported. IsValidConfig() also checks that the
       // 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;
     } else {
       continue;
     }
 
     streams_[i] = new FFmpegDemuxerStream(this, stream);
     max_duration = std::max(max_duration, streams_[i]->duration());
 
@@ skipping 36 matching lines @@
   // initializing.
   host_->SetDuration(max_duration);
   duration_known_ = (max_duration != kInfiniteDuration());
 
   int64 filesize_in_bytes = 0;
   url_protocol_.GetSize(&filesize_in_bytes);
   bitrate_ = CalculateBitrate(format_context, max_duration, filesize_in_bytes);
   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);
 }
 
 void FFmpegDemuxer::OnSeekFrameDone(const PipelineStatusCB& cb, int result) {
   DCHECK(message_loop_->BelongsToCurrentThread());
   CHECK(pending_seek_);
   pending_seek_ = false;
 
   if (!blocking_thread_.IsRunning()) {
     cb.Run(PIPELINE_ERROR_ABORT);
@@ skipping 185 matching lines @@
   }
   for (size_t i = 0; i < buffered.size(); ++i)
     host_->AddBufferedTimeRange(buffered.start(i), buffered.end(i));
 }
 
 void FFmpegDemuxer::OnDataSourceError() {
   host_->OnDemuxerError(PIPELINE_ERROR_READ);
 }
 
 }  // namespace media