Logged information from BufferedDataSource including

content/renderer/media/buffered_data_source.cc

 // Copyright 2013 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 "content/renderer/media/buffered_data_source.h"
 
 #include "base/bind.h"
 #include "base/callback_helpers.h"
 #include "base/message_loop/message_loop_proxy.h"
 #include "media/base/media_log.h"
@@ skipping 126 matching lines @@
 void BufferedDataSource::Initialize(
     const GURL& url,
     BufferedResourceLoader::CORSMode cors_mode,
     const InitializeCB& init_cb) {
   DCHECK(render_loop_->BelongsToCurrentThread());
   DCHECK(!init_cb.is_null());
   DCHECK(!loader_.get());
   url_ = url;
   cors_mode_ = cors_mode;
 
-  init_cb_ = init_cb;
+  init_cb_ = CreateInitializeCB(media_log_, init_cb);
 
   if (url_.SchemeIs(kHttpScheme) || url_.SchemeIs(kHttpsScheme)) {
     // Do an unbounded range request starting at the beginning.  If the server
     // responds with 200 instead of 206 we'll fall back into a streaming mode.
     loader_.reset(CreateResourceLoader(0, kPositionNotSpecified));
   } else {
     // For all other protocols, assume they support range request. We fetch
     // the full range of the resource to obtain the instance size because
     // we won't be served HTTP headers.
     loader_.reset(CreateResourceLoader(kPositionNotSpecified,
                                        kPositionNotSpecified));
     assume_fully_buffered_ = true;
   }
 
   loader_->Start(
       base::Bind(&BufferedDataSource::StartCallback, weak_this_),
       base::Bind(&BufferedDataSource::LoadingStateChangedCallback, weak_this_),
       base::Bind(&BufferedDataSource::ProgressCallback, weak_this_),
       frame_);
 }
 
+// TODO(tyoverby): remove this typedef
+typedef base::Callback<void(bool)> InitializeCB;

[Ty Overby, 2013/08/20 23:06:38]

scherkus@: How do I get rid of this line?  I threw it in there because without
it, the code that I wrote won't compile, but existing code (see line 140 in this
file) worked just fine from the typedef included from buffered_data_source.h

+
+// The reason that we need to stitch this into the normal callback
+// is because the methods that are called require Initialize() to be called
+// before they can be called.
+static void OnInit(const scoped_refptr<media::MediaLog>& media_log,
+                   BufferedDataSource* data_source,
+                   const InitializeCB& init_cb,
+                   bool success) {
+  media_log->SetBooleanProperty("single_origin",
+                                data_source->HasSingleOrigin());
+  media_log->SetBooleanProperty("pass_cors_access_check",
+                                data_source->DidPassCORSAccessCheck());
+
+  init_cb.Run(success);
+}
+
+InitializeCB BufferedDataSource::CreateInitializeCB(
+    const scoped_refptr<media::MediaLog>& media_log,
+    const InitializeCB& init_cb) {
+
+  return base::Bind(&OnInit, media_log, this, init_cb);
+}
+
 void BufferedDataSource::SetPreload(Preload preload) {
   DCHECK(render_loop_->BelongsToCurrentThread());
   preload_ = preload;
 }
 
 bool BufferedDataSource::HasSingleOrigin() {
   DCHECK(render_loop_->BelongsToCurrentThread());
   DCHECK(init_cb_.is_null() && loader_.get())
       << "Initialize() must complete before calling HasSingleOrigin()";

[scherkus (not reviewing), 2013/08/21 20:31:12]

if you're worried about the DCHECKs() for logging purposes you can get around it
one of two ways:
  1) call loader_->HasSingleOrigin() yourself
  2) copy init_cb_ locally inside StartCallback() and clear init_cb_, then call
HasSingleOrigin()

[Ty Overby, 2013/08/21 22:19:52]

Option 1 worked

Done.

   return loader_->HasSingleOrigin();
 }
 
 bool BufferedDataSource::DidPassCORSAccessCheck() const {
   return loader_.get() && loader_->DidPassCORSAccessCheck();
 }
 
 void BufferedDataSource::Abort() {
   DCHECK(render_loop_->BelongsToCurrentThread());
   {
@@ skipping 176 matching lines @@
   // All responses must be successful. Resources that are assumed to be fully
   // buffered must have a known content length.
   bool success = status == BufferedResourceLoader::kOk &&
       (!assume_fully_buffered_ ||
        loader_->instance_size() != kPositionNotSpecified);
 
   if (success) {
     total_bytes_ = loader_->instance_size();
     streaming_ = !assume_fully_buffered_ &&
         (total_bytes_ == kPositionNotSpecified || !loader_->range_supported());
+
+    media_log_->SetIntegerProperty("total_bytes", total_bytes_);

[scherkus (not reviewing), 2013/08/21 20:28:41]

note that total_bytes_ might be -1 (kPositionNotSpecified)

did you intend to log that?

Also we run into the silliness with sizes larger than 2G here, so may have to
use strings

This information is also duplicated by FFmpegDemuxer (filesize_in_bytes) -- we
should decide which one we want to keep (FYI FFD gets that information from BDS
via BlockingUrlProtocol)

[Ty Overby, 2013/08/21 22:19:52]

That's right; I forgot that we already had it from FFD.  I'll remove it here.

[Ty Overby, 2013/08/21 22:19:52]

Done.

   } else {
     loader_->Stop();
   }
 
+  // HTTP range header
+  media_log_->SetBooleanProperty("range_supported", loader_->range_supported());
+
   // TODO(scherkus): we shouldn't have to lock to signal host(), see
   // http://crbug.com/113712 for details.
   base::AutoLock auto_lock(lock_);
   if (stop_signal_received_)
     return;
 
   if (success)
     UpdateHostState_Locked();

[scherkus (not reviewing), 2013/08/21 20:28:41]

similar to GpuVideoDecoder, I'd do away w/ wrapping the callback and tuck all
the logging inside this success branch

this section of code is the only place where we run init_cb_, so if it's
successful we can go ahead with logging

[Ty Overby, 2013/08/21 22:19:52]

Ok, I'll see if I can avoid the DCHECK and put it here.

[Ty Overby, 2013/08/21 22:19:52]

Done.

 
   base::ResetAndReturn(&init_cb_).Run(success);
 }
 
 void BufferedDataSource::PartialReadStartCallback(
     BufferedResourceLoader::Status status) {
   DCHECK(render_loop_->BelongsToCurrentThread());
   DCHECK(loader_.get());
 
   if (status == BufferedResourceLoader::kOk) {
@@ skipping 26 matching lines @@
     return;
 
   if (status != BufferedResourceLoader::kOk) {
     // Stop the resource load if it failed.
     loader_->Stop();
 
     if (status == BufferedResourceLoader::kCacheMiss &&
         read_op_->retries() < kNumCacheMissRetries) {
       read_op_->IncrementRetries();
 
+      media_log_->SetIntegerProperty("read_retries", read_op_->retries());

[scherkus (not reviewing), 2013/08/21 20:28:41]

I wouldn't bother with this one -- ReadCallback() is every single time we read
(1000s of time for the lifetime of a playback), so this value would be
constantly overwritten with new values

[Ty Overby, 2013/08/21 22:19:52]

It's only called if there is a miss I believe, and you did say in the design doc
that you wanted the number of retries.

I'll leave this one up to you.

+
       // Recreate a loader starting from where we last left off until the
       // end of the resource.
       loader_.reset(CreateResourceLoader(
           read_op_->position(), kPositionNotSpecified));
       loader_->Start(
           base::Bind(&BufferedDataSource::PartialReadStartCallback, weak_this_),
           base::Bind(&BufferedDataSource::LoadingStateChangedCallback,
                      weak_this_),
           base::Bind(&BufferedDataSource::ProgressCallback, weak_this_),
           frame_);
@@ skipping 87 matching lines @@
   if (total_bytes_ == kPositionNotSpecified)
     return;
 
   host()->SetTotalBytes(total_bytes_);
 
   if (assume_fully_buffered_)
     host()->AddBufferedByteRange(0, total_bytes_);
 }
 
 }  // namespace content