Add a few histograms to the disk cache.

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

4 files changed, 40 insertions, 0 deletions

diff --git a/net/disk_cache/backend_impl.cc b/net/disk_cache/backend_impl.cc
index 0a09148..9ffb97e 100644
--- a/net/disk_cache/backend_impl.cc
+++ b/net/disk_cache/backend_impl.cc
@@ -30,6 +30,7 @@
 #include "net/disk_cache/backend_impl.h"
 
 #include "base/file_util.h"
+#include "base/histogram.h"
 #include "base/message_loop.h"
 #include "base/scoped_handle.h"
 #include "base/string_util.h"
@@ -325,6 +326,7 @@ bool BackendImpl::OpenEntry(const std::string& key, Entry** entry) {
   if (disabled_)
     return false;
 
+  Time start = Time::Now();
   uint32 hash = Hash(key);
 
   EntryImpl* cache_entry = MatchEntry(key, hash, false);
@@ -336,6 +338,7 @@ bool BackendImpl::OpenEntry(const std::string& key, Entry** entry) {
   DCHECK(entry);
   *entry = cache_entry;
 
+  UMA_HISTOGRAM_TIMES(L"DiskCache.OpenTime", Time::Now() - start);
   stats_.OnEvent(Stats::OPEN_HIT);
   return true;
 }
@@ -344,6 +347,7 @@ bool BackendImpl::CreateEntry(const std::string& key, Entry** entry) {
   if (disabled_ || key.empty())
     return false;
 
+  Time start = Time::Now();
   uint32 hash = Hash(key);
 
   scoped_refptr<EntryImpl> parent;
@@ -406,6 +410,7 @@ bool BackendImpl::CreateEntry(const std::string& key, Entry** entry) {
   *entry = NULL;
   cache_entry.swap(reinterpret_cast<EntryImpl**>(entry));
 
+  UMA_HISTOGRAM_TIMES(L"DiskCache.CreateTime", Time::Now() - start);
   stats_.OnEvent(Stats::CREATE_HIT);
   Trace("create entry hit ");
   return true;
@@ -1034,6 +1039,7 @@ void BackendImpl::TrimCache(bool empty) {
   if (disabled_)
     return;
 
+  Time start = Time::Now();
   Rankings::ScopedRankingsBlock node(&rankings_);
   Rankings::ScopedRankingsBlock next(&rankings_, rankings_.GetPrev(node.get()));
   DCHECK(next.get());
@@ -1053,6 +1059,9 @@ void BackendImpl::TrimCache(bool empty) {
       if (node->Data()->pointer) {
         entry = EntryImpl::Update(entry);
       }
+      static Histogram counter(L"DiskCache.TrimAge", 1, 10000, 50);
+      counter.SetFlags(kUmaTargetedHistogramFlag);
+      counter.Add((Time::Now() - entry->GetLastUsed()).InHours());
       entry->Doom();
       entry->Release();
       if (!empty)
@@ -1060,6 +1069,7 @@ void BackendImpl::TrimCache(bool empty) {
     }
   }
 
+  UMA_HISTOGRAM_TIMES(L"DiskCache.TotalTrimTime", Time::Now() - start);
   Trace("*** Trim Cache end ***");
   return;
 }
diff --git a/net/disk_cache/block_files.cc b/net/disk_cache/block_files.cc
index e985765..93578cf 100644
--- a/net/disk_cache/block_files.cc
+++ b/net/disk_cache/block_files.cc
@@ -29,8 +29,10 @@
 
 #include "net/disk_cache/block_files.h"
 
+#include "base/histogram.h"
 #include "base/scoped_handle.h"
 #include "base/string_util.h"
+#include "base/time.h"
 #include "net/disk_cache/file_lock.h"
 
 namespace {
@@ -61,6 +63,7 @@ bool CreateMapBlock(int target, int size, disk_cache::BlockFileHeader* header,
     return false;
   }
 
+  Time start = Time::Now();
   // We are going to process the map on 32-block chunks (32 bits), and on every
   // chunk, iterate through the 8 nibbles where the new block can be located.
   int current = header->hints[target - 1];
@@ -86,6 +89,7 @@ bool CreateMapBlock(int target, int size, disk_cache::BlockFileHeader* header,
       if (target != size) {
         header->empty[target - size - 1]++;
       }
+      HISTOGRAM_TIMES(L"DiskCache.CreateBlock", Time::Now() - start);
       return true;
     }
   }
@@ -104,6 +108,7 @@ void DeleteMapBlock(int index, int size, disk_cache::BlockFileHeader* header) {
     NOTREACHED();
     return;
   }
+  Time start = Time::Now();
   int byte_index = index / 8;
   uint8* byte_map = reinterpret_cast<uint8*>(header->allocation_map);
   uint8 map_block = byte_map[byte_index];
@@ -132,6 +137,7 @@ void DeleteMapBlock(int index, int size, disk_cache::BlockFileHeader* header) {
   }
   header->num_entries--;
   DCHECK(header->num_entries >= 0);
+  HISTOGRAM_TIMES(L"DiskCache.DeleteBlock", Time::Now() - start);
 }
 
 // Restores the "empty counters" and allocation hints.
@@ -313,6 +319,7 @@ MappedFile* BlockFiles::FileForNewBlock(FileType block_type, int block_count) {
   MappedFile* file = block_files_[block_type - 1];
   BlockFileHeader* header = reinterpret_cast<BlockFileHeader*>(file->buffer());
 
+  Time start = Time::Now();
   while (NeedToGrowBlockFile(header, block_count)) {
     if (kMaxBlocks == header->max_entries) {
       file = NextFile(file);
@@ -326,6 +333,7 @@ MappedFile* BlockFiles::FileForNewBlock(FileType block_type, int block_count) {
       return NULL;
     break;
   }
+  HISTOGRAM_TIMES(L"DiskCache.GetFileForNewBlock", Time::Now() - start);
   return file;
 }
 
diff --git a/net/disk_cache/entry_impl.cc b/net/disk_cache/entry_impl.cc
index 58509c1..3d3ada2 100644
--- a/net/disk_cache/entry_impl.cc
+++ b/net/disk_cache/entry_impl.cc
@@ -29,6 +29,7 @@
 
 #include "net/disk_cache/entry_impl.h"
 
+#include "base/histogram.h"
 #include "base/message_loop.h"
 #include "base/string_util.h"
 #include "net/base/net_errors.h"
@@ -122,6 +123,8 @@ EntryImpl::EntryImpl(BackendImpl* backend, Addr address)
 // written before).
 EntryImpl::~EntryImpl() {
   if (doomed_) {
+    UMA_HISTOGRAM_COUNTS(L"DiskCache.DeleteHeader", GetDataSize(0));
+    UMA_HISTOGRAM_COUNTS(L"DiskCache.DeleteData", GetDataSize(1));
     for (int index = 0; index < kKeyFileIndex; index++) {
       Addr address(entry_.Data()->data_addr[index]);
       if (address.is_initialized()) {
@@ -239,6 +242,11 @@ int EntryImpl::ReadData(int index, int offset, char* buf, int buf_len,
   if (buf_len < 0)
     return net::ERR_INVALID_ARGUMENT;
 
+  Time start = Time::Now();
+  static Histogram stats(L"DiskCache.ReadTime", TimeDelta::FromMilliseconds(1),
+                         TimeDelta::FromSeconds(10), 50);
+  stats.SetFlags(kUmaTargetedHistogramFlag);
+
   if (offset + buf_len > entry_size)
     buf_len = entry_size - offset;
 
@@ -250,6 +258,7 @@ int EntryImpl::ReadData(int index, int offset, char* buf, int buf_len,
     // Complete the operation locally.
     DCHECK(kMaxBlockSize >= offset + buf_len);
     memcpy(buf , user_buffers_[index].get() + offset, buf_len);
+    stats.AddTime(Time::Now() - start);
     return buf_len;
   }
 
@@ -281,6 +290,7 @@ int EntryImpl::ReadData(int index, int offset, char* buf, int buf_len,
   if (io_callback && completed)
     io_callback->Discard();
 
+  stats.AddTime(Time::Now() - start);
   return (completed || !completion_callback) ? buf_len : net::ERR_IO_PENDING;
 }
 
@@ -306,6 +316,11 @@ int EntryImpl::WriteData(int index, int offset, const char* buf, int buf_len,
     return net::ERR_FAILED;
   }
 
+  Time start = Time::Now();
+  static Histogram stats(L"DiskCache.WriteTime", TimeDelta::FromMilliseconds(1),
+                         TimeDelta::FromSeconds(10), 50);
+  stats.SetFlags(kUmaTargetedHistogramFlag);
+
   // Read the size at this point (it may change inside prepare).
   int entry_size = entry_.Data()->data_size[index];
   if (!PrepareTarget(index, offset, buf_len, truncate))
@@ -337,6 +352,7 @@ int EntryImpl::WriteData(int index, int offset, const char* buf, int buf_len,
     // Complete the operation locally.
     DCHECK(kMaxBlockSize >= offset + buf_len);
     memcpy(user_buffers_[index].get() + offset, buf, buf_len);
+    stats.AddTime(Time::Now() - start);
     return buf_len;
   }
 
@@ -371,6 +387,7 @@ int EntryImpl::WriteData(int index, int offset, const char* buf, int buf_len,
   if (io_callback && completed)
     io_callback->Discard();
 
+  stats.AddTime(Time::Now() - start);
   return (completed || !completion_callback) ? buf_len : net::ERR_IO_PENDING;
 }
 
diff --git a/net/disk_cache/rankings.cc b/net/disk_cache/rankings.cc
index 81b5767..42667cc 100644
--- a/net/disk_cache/rankings.cc
+++ b/net/disk_cache/rankings.cc
@@ -29,6 +29,7 @@
 
 #include "net/disk_cache/rankings.h"
 
+#include "base/histogram.h"
 #include "net/disk_cache/backend_impl.h"
 #include "net/disk_cache/entry_impl.h"
 #include "net/disk_cache/errors.h"
@@ -203,6 +204,7 @@ void Rankings::Reset() {
 }
 
 bool Rankings::GetRanking(CacheRankingsBlock* rankings) {
+  Time start = Time::Now();
   if (!rankings->address().is_initialized())
     return false;
 
@@ -233,6 +235,7 @@ bool Rankings::GetRanking(CacheRankingsBlock* rankings) {
   EntryImpl* cache_entry =
       reinterpret_cast<EntryImpl*>(rankings->Data()->pointer);
   rankings->SetData(cache_entry->rankings()->Data());
+  UMA_HISTOGRAM_TIMES(L"DiskCache.GetRankings", Time::Now() - start);
   return true;
 }
 
@@ -380,8 +383,10 @@ void Rankings::Remove(CacheRankingsBlock* node) {
 // but the net effect is just an assert on debug when attempting to remove the
 // entry. Otherwise we'll need reentrant transactions, which is an overkill.
 void Rankings::UpdateRank(CacheRankingsBlock* node, bool modified) {
+  Time start = Time::Now();
   Remove(node);
   Insert(node, modified);
+  UMA_HISTOGRAM_TIMES(L"DiskCache.UpdateRank", Time::Now() - start);
 }
 
 void Rankings::CompleteTransaction() {