Histogram for tracking time to HTTP-response data available.

This CL adds a new histogram, Net.HttpStartTime, which tracks the
amount of time from the creation of an UrlRequestHttpJob, until the
first data is available to be passed back.  This is part of issue
70957, and arguably the easier half.

BUG=70957
TEST=none

Review URL: http://codereview.chromium.org/6537025

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@75632 0039d316-1c4b-4281-b951-d872f2087c98

2 files changed, 39 insertions, 0 deletions

diff --git a/net/url_request/url_request_http_job.cc b/net/url_request/url_request_http_job.cc
index 563c85b..56de783 100644
--- a/net/url_request/url_request_http_job.cc
+++ b/net/url_request/url_request_http_job.cc
@@ -10,6 +10,7 @@
 #include "base/file_util.h"
 #include "base/file_version_info.h"
 #include "base/message_loop.h"
+#include "base/metrics/histogram.h"
 #include "base/rand_util.h"
 #include "base/string_util.h"
 #include "net/base/cert_status_flags.h"
@@ -141,7 +142,9 @@ URLRequestHttpJob::URLRequestHttpJob(URLRequest* request)
       sdch_test_activated_(false),
       sdch_test_control_(false),
       is_cached_content_(false),
+      request_creation_time_(),
       ALLOW_THIS_IN_INITIALIZER_LIST(method_factory_(this)) {
+  ResetTimer();
 }
 
 void URLRequestHttpJob::NotifyHeadersComplete() {
@@ -544,6 +547,8 @@ void URLRequestHttpJob::OnCanSetCookieCompleted(int policy) {
 }
 
 void URLRequestHttpJob::OnStartCompleted(int result) {
+  RecordTimer();
+
   // If the request was destroyed, then there is no more work to do.
   if (!request_ || !request_->delegate())
     return;
@@ -615,6 +620,8 @@ void URLRequestHttpJob::RestartTransactionWithAuth(
   response_info_ = NULL;
   response_cookies_.clear();
 
+  ResetTimer();
+
   // Update the cookies, since the cookie store may have been updated from the
   // headers in the 401/407. Since cookies were already appended to
   // extra_headers, we need to strip them out before adding them again.
@@ -841,6 +848,8 @@ void URLRequestHttpJob::CancelAuth() {
   response_info_ = NULL;
   response_cookies_.clear();
 
+  ResetTimer();
+
   // OK, let the consumer read the error page...
   //
   // Because we set the AUTH_STATE_CANCELED flag, NeedsAuth will return false,
@@ -861,6 +870,8 @@ void URLRequestHttpJob::ContinueWithCertificate(
 
   DCHECK(!response_info_) << "should not have a response yet";
 
+  ResetTimer();
+
   // No matter what, we want to report our status as IO pending since we will
   // be notifying our consumer asynchronously via OnStartCompleted.
   SetStatus(URLRequestStatus(URLRequestStatus::IO_PENDING, 0));
@@ -884,6 +895,8 @@ void URLRequestHttpJob::ContinueDespiteLastError() {
 
   DCHECK(!response_info_) << "should not have a response yet";
 
+  ResetTimer();
+
   // No matter what, we want to report our status as IO pending since we will
   // be notifying our consumer asynchronously via OnStartCompleted.
   SetStatus(URLRequestStatus(URLRequestStatus::IO_PENDING, 0));
@@ -959,4 +972,25 @@ URLRequestHttpJob::~URLRequestHttpJob() {
   }
 }
 
+void URLRequestHttpJob::RecordTimer() {
+  if (request_creation_time_.is_null()) {
+    NOTREACHED()
+        << "The same transaction shouldn't start twice without new timing.";
+    return;
+  }
+
+  base::TimeDelta to_start = base::Time::Now() - request_creation_time_;
+  request_creation_time_ = base::Time();
+  UMA_HISTOGRAM_MEDIUM_TIMES("Net.HttpTimeToFirstByte", to_start);
+}
+
+void URLRequestHttpJob::ResetTimer() {
+  if (!request_creation_time_.is_null()) {
+    NOTREACHED()
+        << "The timer was reset before it was recorded.";
+    return;
+  }
+  request_creation_time_ = base::Time::Now();
+}
+
 }  // namespace net
diff --git a/net/url_request/url_request_http_job.h b/net/url_request/url_request_http_job.h
index e1abf3e..27ba59b 100644
--- a/net/url_request/url_request_http_job.h
+++ b/net/url_request/url_request_http_job.h
@@ -12,6 +12,7 @@
 #include "base/scoped_ptr.h"
 #include "base/string16.h"
 #include "base/task.h"
+#include "base/time.h"
 #include "net/base/auth.h"
 #include "net/base/completion_callback.h"
 #include "net/http/http_request_info.h"
@@ -137,6 +138,10 @@ class URLRequestHttpJob : public URLRequestJob {
  private:
   virtual ~URLRequestHttpJob();
 
+  void RecordTimer();
+  void ResetTimer();
+
+  base::Time request_creation_time_;
   ScopedRunnableMethodFactory<URLRequestHttpJob> method_factory_;
 
   DISALLOW_COPY_AND_ASSIGN(URLRequestHttpJob);