Add histograms for network activity, and total/cumulative

net/http/http_cache_transaction.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 "net/http/http_cache_transaction.h"
 
 #include "build/build_config.h"
 
 #if defined(OS_POSIX)
 #include <unistd.h>
@@ skipping 134 matching lines @@
       bytes_read_from_network_(0),
       transaction_delegate_(transaction_delegate) {
   COMPILE_ASSERT(HttpCache::Transaction::kNumValidationHeaders ==
                  arraysize(kValidationHeaders),
                  Invalid_number_of_validation_headers);
 }
 
 HttpCache::Transaction::~Transaction() {
   // We may have to issue another IO, but we should never invoke the callback_
   // after this point.
   callback_.Reset();

[rvargas (doing something else), 2012/08/15 22:36:50]

We should reset the delegate at this point, and add a unit test that verifies
that. (delete the transaction and verify that the delegate is not called).

[tburkard, 2012/08/15 23:00:47]

Done.  The test is already verifying that the exact (correct) # of callbacks
happens, and no additional ones after the destruction.

 
   if (cache_) {
     if (entry_) {
       bool cancel_request = reading_;
       if (cancel_request) {
         if (partial_.get()) {
           entry_->disk_entry->CancelSparseIO();
         } else {
           cancel_request &= (response_.headers->response_code() == 200);
         }
@@ skipping 572 matching lines @@
   DCHECK(mode_ & WRITE || mode_ == NONE);
   DCHECK(!network_trans_.get());
 
   send_request_since_ = TimeTicks::Now();
 
   // Create a network transaction.
   int rv = cache_->network_layer_->CreateTransaction(&network_trans_, NULL);
   if (rv != OK)
     return rv;
 
+  ReportNetworkActionStart();

[mmenke, 2012/08/15 15:09:53]

I'm a bit concerned about mismatched Report*() calls, especially as the code
gets modified (Not that this is a particularly often modified file).

Have two suggestions for alleviating these concerns:

1)  Have HttpTransactionDelegateImpl DCHECK on unexpected FINISH events.
2)  Or have a HttpCache::Transaction::SetNextState(State) function, which may
calls a Finish() function based on the old value of next_state_, and/or call a
Start() function based on the new value.

[tburkard, 2012/08/15 16:50:46]

I can add that to the HttpTransactionDelegateImpl, however, it will need to keep
some extra state to keep track of it.  Last time, you asked me to remove such
extra state.. So are you ok with that extra state being added to the delegate
this time?  Please advise.

[mmenke, 2012/08/15 18:45:41]

When the state was solely for use elsewhere, I thought it belonged where it was
being used.  When it's being used to ensure correctness, I'm fine with it.  In
case I was being unclear, those were intended to be either-or options.  Doing
both would be overkill.

I'm open to other ideas, or just leaving it as-is, but I do think regressions
here are a real concern, and could easily go unnoticed.

[mmenke, 2012/08/15 19:08:34]

Actually, my real objection is that it was in net/ and assumed the cache
behavior was completely different from what it really was - which seemed to me
like it might be a reasonable assumption in chrome/, but not net/.

[tburkard, 2012/08/15 20:42:24]

Done.

   next_state_ = STATE_SEND_REQUEST_COMPLETE;
   rv = network_trans_->Start(request_, io_callback_, net_log_);
   return rv;
 }
 
 int HttpCache::Transaction::DoSendRequestComplete(int result) {
+  ReportNetworkActionFinish();
+
   if (!cache_)
     return ERR_UNEXPECTED;
 
   if (result == OK) {
     next_state_ = STATE_SUCCESSFUL_SEND_REQUEST;
     return OK;
   }
 
   // Do not record requests that have network errors or restarts.
   UpdateTransactionPattern(PATTERN_NOT_COVERED);
@@ skipping 68 matching lines @@
     }
     UpdateTransactionPattern(PATTERN_ENTRY_UPDATED);
     mode_ = WRITE;
   }
 
   next_state_ = STATE_OVERWRITE_CACHED_RESPONSE;
   return OK;
 }
 
 int HttpCache::Transaction::DoNetworkRead() {
+  ReportNetworkActionStart();
   next_state_ = STATE_NETWORK_READ_COMPLETE;
   return network_trans_->Read(read_buf_, io_buf_len_, io_callback_);
 }
 
 int HttpCache::Transaction::DoNetworkReadComplete(int result) {
   DCHECK(mode_ & WRITE || mode_ == NONE);
 
+  ReportNetworkActionFinish();
+
   if (!cache_)
     return ERR_UNEXPECTED;
 
   if (result > 0)
     bytes_read_from_network_ += result;
 
   // If there is an error or we aren't saving the data, we are done; just wait
   // until the destructor runs to see if we can keep the data.
   if (mode_ == NONE || result < 0)
     return result;
@@ skipping 453 matching lines @@
   if (entry_) {
     if (net_log_.IsLoggingAllEvents())
       net_log_.BeginEvent(NetLog::TYPE_HTTP_CACHE_WRITE_INFO);
     ReportCacheActionStart();
   }
   return WriteResponseInfoToEntry(false);
 }
 
 int HttpCache::Transaction::DoCacheWriteTruncatedResponse() {
   if (entry_) {
-    if (net_log_.IsLoggingAllEvents() && entry_)
+    if (net_log_.IsLoggingAllEvents())
       net_log_.BeginEvent(NetLog::TYPE_HTTP_CACHE_WRITE_INFO);
     ReportCacheActionStart();
   }
   return WriteResponseInfoToEntry(true);
 }
 
 int HttpCache::Transaction::DoCacheWriteResponseComplete(int result) {
   next_state_ = target_state_;
   target_state_ = STATE_NONE;
   if (!entry_)
@@ skipping 433 matching lines @@
 
   next_state_ = STATE_SEND_REQUEST;
   return OK;
 }
 
 int HttpCache::Transaction::RestartNetworkRequest() {
   DCHECK(mode_ & WRITE || mode_ == NONE);
   DCHECK(network_trans_.get());
   DCHECK_EQ(STATE_NONE, next_state_);
 
+  ReportNetworkActionStart();
   next_state_ = STATE_SEND_REQUEST_COMPLETE;
   int rv = network_trans_->RestartIgnoringLastError(io_callback_);
   if (rv != ERR_IO_PENDING)
     return DoLoop(rv);
   return rv;
 }
 
 int HttpCache::Transaction::RestartNetworkRequestWithCertificate(
     X509Certificate* client_cert) {
   DCHECK(mode_ & WRITE || mode_ == NONE);
   DCHECK(network_trans_.get());
   DCHECK_EQ(STATE_NONE, next_state_);
 
+  ReportNetworkActionStart();
   next_state_ = STATE_SEND_REQUEST_COMPLETE;
   int rv = network_trans_->RestartWithCertificate(client_cert, io_callback_);
   if (rv != ERR_IO_PENDING)
     return DoLoop(rv);
   return rv;
 }
 
 int HttpCache::Transaction::RestartNetworkRequestWithAuth(
     const AuthCredentials& credentials) {
   DCHECK(mode_ & WRITE || mode_ == NONE);
   DCHECK(network_trans_.get());
   DCHECK_EQ(STATE_NONE, next_state_);
 
+  ReportNetworkActionStart();
   next_state_ = STATE_SEND_REQUEST_COMPLETE;
   int rv = network_trans_->RestartWithAuth(credentials, io_callback_);
   if (rv != ERR_IO_PENDING)
     return DoLoop(rv);
   return rv;
 }
 
 bool HttpCache::Transaction::RequiresValidation() {
   // TODO(darin): need to do more work here:
   //  - make sure we have a matching request method
@@ skipping 264 matching lines @@
   // HTTPS with a cert error we show an SSL blocking page.  If the user clicks
   // proceed we reload the resource ignoring the errors.  The loaded resource
   // is then cached.  If that resource is subsequently loaded from the cache,
   // no net error is reported (even though the cert status contains the actual
   // errors) and no SSL blocking page is shown.  An alternative would be to
   // reverse-map the cert status to a net error and replay the net error.
   if ((cache_->mode() != RECORD &&
        response_.headers->HasHeaderValue("cache-control", "no-store")) ||
       net::IsCertStatusError(response_.ssl_info.cert_status)) {
     DoneWritingToEntry(false);
+    ReportCacheActionFinish();
+    if (net_log_.IsLoggingAllEvents()) {
+      net_log_.EndEventWithNetErrorCode(NetLog::TYPE_HTTP_CACHE_WRITE_INFO,
+                                        OK);

[mmenke, 2012/08/15 15:09:53]

optional nit:  Can just use EndEvent.  "OK" is ignored, to avoid spamming it all
over the log.

[tburkard, 2012/08/15 16:50:46]

Done.

+    }
     return OK;
   }
 
   // When writing headers, we normally only write the non-transient
   // headers; when in record mode, record everything.
   bool skip_transient_headers = (cache_->mode() != RECORD);
 
   if (truncated) {
     DCHECK_EQ(200, response_.headers->response_code());
   }
@@ skipping 129 matching lines @@
 void HttpCache::Transaction::ReportCacheActionStart() {
   if (transaction_delegate_)
     transaction_delegate_->OnCacheActionStart();
 }
 
 void HttpCache::Transaction::ReportCacheActionFinish() {
   if (transaction_delegate_)
     transaction_delegate_->OnCacheActionFinish();
 }
 
+void HttpCache::Transaction::ReportNetworkActionStart() {
+  if (transaction_delegate_)
+    transaction_delegate_->OnNetworkActionStart();
+}
+
+void HttpCache::Transaction::ReportNetworkActionFinish() {
+  if (transaction_delegate_)
+    transaction_delegate_->OnNetworkActionFinish();
+}
+
 void HttpCache::Transaction::UpdateTransactionPattern(
     TransactionPattern new_transaction_pattern) {
   if (transaction_pattern_ == PATTERN_NOT_COVERED)
     return;
   DCHECK(transaction_pattern_ == PATTERN_UNDEFINED ||
          new_transaction_pattern == PATTERN_NOT_COVERED);
   transaction_pattern_ = new_transaction_pattern;
 }
 
 void HttpCache::Transaction::RecordHistograms() {
@@ skipping 104 matching lines @@
             before_send_percent);
       }
       break;
     }
     default:
       NOTREACHED();
   }
 }
 
 }  // namespace net