[Storage] Added tracing for blob creation

storage/browser/blob/blob_url_request_job.cc

Index: storage/browser/blob/blob_url_request_job.cc
diff --git a/storage/browser/blob/blob_url_request_job.cc b/storage/browser/blob/blob_url_request_job.cc
index 8e48563601efc4d52f5d44cabde07b95e4f6684f..a35612d2d8e27b1ca33bc8b804329d3a38569dc3 100644
--- a/storage/browser/blob/blob_url_request_job.cc
+++ b/storage/browser/blob/blob_url_request_job.cc
@@ -21,6 +21,7 @@
 #include "base/stl_util.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/stringprintf.h"
+#include "base/trace_event/trace_event.h"
 #include "net/base/io_buffer.h"
 #include "net/base/net_errors.h"
 #include "net/http/http_request_headers.h"
@@ -70,6 +71,8 @@ BlobURLRequestJob::BlobURLRequestJob(
       error_(false),
       byte_range_set_(false),
       weak_factory_(this) {
+  TRACE_EVENT_ASYNC_BEGIN1("Blob", "BlobRequest", this, "uuid",
+                           blob_data_->uuid());
   DCHECK(file_thread_proxy_.get());
 }
 
@@ -163,9 +166,11 @@ void BlobURLRequestJob::SetExtraRequestHeaders(
 
 BlobURLRequestJob::~BlobURLRequestJob() {
   STLDeleteValues(&index_to_reader_);
+  TRACE_EVENT_ASYNC_END1("Blob", "Request", this, "uuid", blob_data_->uuid());
 }
 
 void BlobURLRequestJob::DidStart() {
+  current_file_chunk_number_ = 0;
   error_ = false;
 
   // We only support GET request per the spec.
@@ -185,6 +190,8 @@ void BlobURLRequestJob::DidStart() {
 
 bool BlobURLRequestJob::AddItemLength(size_t index, int64 item_length) {
   if (item_length > kint64max - total_size_) {
+    TRACE_EVENT_ASYNC_END1("Blob", "BlobRequest::CountSize", this->request_,

[michaeln, 2015/03/11 23:45:08]

Why use 'this->request_' here and only 'this' elsewhere? Oh, to create a unique
trace id for each callsite?

[dmurph, 2015/03/12 18:16:21]

I thought it would solve something, but I forgot to remove it.  Using 'this' is
just fine.

+                           "uuid", blob_data_->uuid());
     NotifyFailure(net::ERR_FAILED);
     return false;
   }
@@ -197,6 +204,8 @@ bool BlobURLRequestJob::AddItemLength(size_t index, int64 item_length) {
 }
 
 void BlobURLRequestJob::CountSize() {
+  TRACE_EVENT_ASYNC_BEGIN1("Blob", "BlobRequest::CountSize", this->request_,
+                           "uuid", blob_data_->uuid());
   pending_get_file_info_count_ = 0;
   total_size_ = 0;
   const auto& items = blob_data_->items();
@@ -222,6 +231,8 @@ void BlobURLRequestJob::CountSize() {
 
 void BlobURLRequestJob::DidCountSize(int error) {
   DCHECK(!error_);
+  TRACE_EVENT_ASYNC_END1("Blob", "BlobRequest::CountSize", this->request_,
+                         "uuid", blob_data_->uuid());
 
   // If an error occured, bail out.
   if (error != net::OK) {
@@ -377,6 +388,8 @@ void BlobURLRequestJob::AdvanceBytesRead(int result) {
 
 bool BlobURLRequestJob::ReadBytesItem(const BlobDataItem& item,
                                       int bytes_to_read) {
+  TRACE_EVENT1("Blob", "BlobRequest::ReadBytesItem", "uuid",
+               blob_data_->uuid());
   DCHECK_GE(read_buf_->BytesRemaining(), bytes_to_read);
 
   memcpy(read_buf_->data(),
@@ -391,14 +404,17 @@ bool BlobURLRequestJob::ReadFileItem(FileStreamReader* reader,
                                      int bytes_to_read) {
   DCHECK_GE(read_buf_->BytesRemaining(), bytes_to_read);
   DCHECK(reader);
-  const int result = reader->Read(
-      read_buf_.get(),
-      bytes_to_read,
-      base::Bind(&BlobURLRequestJob::DidReadFile, base::Unretained(this)));
+  int chunk_number = current_file_chunk_number_++;

[michaeln, 2015/03/11 23:45:08]

Do we need the chunk_number? I think there can only be one reader->Read() call
inflight at a given time.

For the 0th chunk, i think the id here collides with the larger "BlobRequest"
event scoped to the life of 'this'.

Maybe have an inline helper to form traceid(this, 1) and traceid(this, 2).

[dmurph, 2015/03/12 18:16:21]

It's a unique id combining the id and the category+name.  So they won't overlap.
 See here:
http://www.chromium.org/developers/how-tos/trace-event-profiling-tool/tracing...

[michaeln, 2015/03/12 20:17:32]

But if no two "BlobRequest::ReadFileItem" events for 'this' can be happening
concurrently, do we need chunkid to disambiguate current events from previously
completed events? That seems unlikely?

Just checking because we should avoid the extra data member unless its really
needed.

+  TRACE_EVENT_ASYNC_BEGIN1("Blob", "BlobRequest::ReadFileItem",
+                           this + chunk_number, "uuid", blob_data_->uuid());
+  const int result =
+      reader->Read(read_buf_.get(), bytes_to_read,
+                   base::Bind(&BlobURLRequestJob::DidReadFile,
+                              base::Unretained(this), chunk_number));
   if (result >= 0) {
     // Data is immediately available.
     if (GetStatus().is_io_pending())
-      DidReadFile(result);
+      DidReadFile(chunk_number, result);
     else
       AdvanceBytesRead(result);
     return true;
@@ -410,7 +426,9 @@ bool BlobURLRequestJob::ReadFileItem(FileStreamReader* reader,
   return false;
 }
 
-void BlobURLRequestJob::DidReadFile(int result) {
+void BlobURLRequestJob::DidReadFile(int chunk_number, int result) {
+  TRACE_EVENT_ASYNC_END1("Blob", "BlobRequest::ReadFileItem",
+                         this + chunk_number, "uuid", blob_data_->uuid());
   if (result <= 0) {
     NotifyFailure(net::ERR_FAILED);
     return;