Disk cache: Add a histogram to measure the latency of...

net/disk_cache/entry_impl.cc

 // Copyright (c) 2006-2009 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/disk_cache/entry_impl.h"
 
 #include "base/histogram.h"
 #include "base/message_loop.h"
 #include "base/string_util.h"
 #include "net/base/io_buffer.h"
@@ skipping 11 matching lines @@
 
 // Index for the file used to store the key, if any (files_[kKeyFileIndex]).
 const int kKeyFileIndex = 3;
 
 // This class implements FileIOCallback to buffer the callback from a file IO
 // operation from the actual net class.
 class SyncCallback: public disk_cache::FileIOCallback {
  public:
   SyncCallback(disk_cache::EntryImpl* entry, net::IOBuffer* buffer,
                net::CompletionCallback* callback )
-      : entry_(entry), callback_(callback), buf_(buffer) {
+      : entry_(entry), callback_(callback), buf_(buffer), start_(Time::Now()) {
     entry->AddRef();
     entry->IncrementIoCount();
   }
   ~SyncCallback() {}
 
   virtual void OnFileIOComplete(int bytes_copied);
   void Discard();
  private:
   disk_cache::EntryImpl* entry_;
   net::CompletionCallback* callback_;
   scoped_refptr<net::IOBuffer> buf_;
+  Time start_;
 
   DISALLOW_EVIL_CONSTRUCTORS(SyncCallback);
 };
 
 void SyncCallback::OnFileIOComplete(int bytes_copied) {
   entry_->DecrementIoCount();
+  if (callback_) {
+    entry_->ReportIOTime(disk_cache::EntryImpl::kAsyncIO, start_);
+    callback_->Run(bytes_copied);
+  }
   entry_->Release();
-  if (callback_)
-    callback_->Run(bytes_copied);
   delete this;
 }
 
 void SyncCallback::Discard() {
   callback_ = NULL;
   buf_ = NULL;
   OnFileIOComplete(0);
 }
 
 // Clears buffer before offset and after valid_len, knowing that the size of
@@ skipping 810 matching lines @@
       break;
     case kWrite:
       CACHE_UMA(AGE_MS, "WriteTime", group, start);
       break;
     case kSparseRead:
       CACHE_UMA(AGE_MS, "SparseReadTime", 0, start);
       break;
     case kSparseWrite:
       CACHE_UMA(AGE_MS, "SparseWriteTime", 0, start);
       break;
+    case kAsyncIO:
+      CACHE_UMA(AGE_MS, "AsyncIOTime", group, start);
+      break;
     default:
       NOTREACHED();
   }
 }
 
 void EntryImpl::Log(const char* msg) {
   int dirty = 0;
   if (node_.HasData()) {
     dirty = node_.Data()->dirty;
   }
 
   Trace("%s 0x%p 0x%x 0x%x", msg, reinterpret_cast<void*>(this),
         entry_.address().value(), node_.address().value());
 
   Trace("  data: 0x%x 0x%x 0x%x", entry_.Data()->data_addr[0],
         entry_.Data()->data_addr[1], entry_.Data()->long_key);
 
   Trace("  doomed: %d 0x%x", doomed_, dirty);
 }
 
 }  // namespace disk_cache