First pass at adding http/backend cache to NetLog

net/http/http_cache.cc

Index: net/http/http_cache.cc
===================================================================
--- net/http/http_cache.cc	(revision 68857)
+++ net/http/http_cache.cc	(working copy)
@@ -21,6 +21,7 @@
 #include "base/string_number_conversions.h"
 #include "base/string_util.h"
 #include "base/stringprintf.h"
+#include "base/values.h"
 #include "net/base/io_buffer.h"
 #include "net/base/load_flags.h"
 #include "net/base/net_errors.h"
@@ -38,6 +39,48 @@
 
 namespace net {
 
+namespace {
+
+class ActiveEntryCreationParameters : public NetLog::EventParameters {
+ public:
+  ActiveEntryCreationParameters(std::string key, const NetLog::Source& source)
+      : key_(key), source_(source) {
+  }
+
+  virtual Value* ToValue() const {
+    DictionaryValue* dict = new DictionaryValue();
+    dict->SetString("key", key_);
+    dict->Set("source_dependency", source_.ToValue());
+    return dict;
+  }
+
+ private:
+  const std::string key_;
+  const NetLog::Source source_;
+};
+
+// Used for adding and queuing both read and write transactions.
+class AddTransactionParams : public NetLog::EventParameters {
+ public:
+  AddTransactionParams(const NetLog::Source& source, size_t queue_length)
+      : source_(source), queue_length_(queue_length) {
+  }
+
+  virtual Value* ToValue() const {
+    DictionaryValue* dict = new DictionaryValue();
+    dict->Set("source_dependency", source_.ToValue());
+    if (queue_length_ > 0)
+      dict->SetInteger("queue_length", queue_length_);
+    return dict;
+  }
+
+ private:
+  const NetLog::Source source_;
+  size_t queue_length_;
+};
+
+}  // namespace
+
 HttpCache::DefaultBackend::DefaultBackend(CacheType type,
                                           const FilePath& path,
                                           int max_bytes,
@@ -56,22 +99,27 @@
 }
 
 int HttpCache::DefaultBackend::CreateBackend(disk_cache::Backend** backend,
-                                             CompletionCallback* callback) {
+                                             CompletionCallback* callback,
+                                             NetLog* net_log) {
   DCHECK_GE(max_bytes_, 0);
   return disk_cache::CreateCacheBackend(type_, path_, max_bytes_, true,
-                                        thread_, backend, callback);
+                                        thread_, backend, callback, net_log);
 }
 
 //-----------------------------------------------------------------------------
 
-HttpCache::ActiveEntry::ActiveEntry(disk_cache::Entry* e)
-    : disk_entry(e),
+HttpCache::ActiveEntry::ActiveEntry(disk_cache::Entry* entry, NetLog* log)
+    : disk_entry(entry),
       writer(NULL),
       will_process_pending_queue(false),
-      doomed(false) {
+      doomed(false),
+      net_log(BoundNetLog::Make(log, NetLog::SOURCE_HTTP_CACHE_ACTIVE_ENTRY)) {
+  net_log.BeginEvent(NetLog::TYPE_HTTP_CACHE_ACTIVE_ENTRY,
+                     new NetLogStringParameter("key", entry->GetKey()));
 }
 
 HttpCache::ActiveEntry::~ActiveEntry() {
+  net_log.EndEvent(NetLog::TYPE_HTTP_CACHE_ACTIVE_ENTRY, NULL);
   if (disk_entry) {
     disk_entry->Close();
     disk_entry = NULL;
@@ -287,7 +335,8 @@
                      HttpNetworkDelegate* network_delegate,
                      NetLog* net_log,
                      BackendFactory* backend_factory)
-    : backend_factory_(backend_factory),
+    : net_log_(net_log),
+      backend_factory_(backend_factory),
       building_backend_(false),
       mode_(NORMAL),
       ssl_host_info_factory_(new SSLHostInfoFactoryAdaptor(
@@ -302,7 +351,8 @@
 
 HttpCache::HttpCache(HttpNetworkSession* session,
                      BackendFactory* backend_factory)
-    : backend_factory_(backend_factory),
+    : net_log_(session->net_log()),
+      backend_factory_(backend_factory),
       building_backend_(false),
       mode_(NORMAL),
       network_layer_(HttpNetworkLayer::CreateFactory(session)),
@@ -310,8 +360,10 @@
 }
 
 HttpCache::HttpCache(HttpTransactionFactory* network_layer,
-                     BackendFactory* backend_factory)
-    : backend_factory_(backend_factory),
+                     BackendFactory* backend_factory,
+                     NetLog* net_log)
+    : net_log_(net_log),
+      backend_factory_(backend_factory),
       building_backend_(false),
       mode_(NORMAL),
       network_layer_(network_layer),
@@ -463,7 +515,8 @@
   BackendCallback* my_callback = new BackendCallback(this, pending_op);
   pending_op->callback = my_callback;
 
-  int rv = backend_factory_->CreateBackend(&pending_op->backend, my_callback);
+  int rv = backend_factory_->CreateBackend(&pending_op->backend, my_callback,
+                                           net_log_);
   if (rv != ERR_IO_PENDING) {
     pending_op->writer->ClearCallback();
     my_callback->Run(rv);
@@ -538,6 +591,8 @@
   ActiveEntry* entry = it->second;
   active_entries_.erase(it);
 
+  entry->net_log.AddEvent(NetLog::TYPE_ACTIVE_ENTRY_DOOM, NULL);
+
   // We keep track of doomed entries so that we can ensure that they are
   // cleaned up properly when the cache is destroyed.
   doomed_entries_.insert(entry);
@@ -579,6 +634,9 @@
   DCHECK(entry->readers.empty());
   DCHECK(entry->pending_queue.empty());
 
+  entry->net_log.AddEvent(NetLog::TYPE_ACTIVE_ENTRY_FINALIZE_DOOMED_ENTRY,
+                          NULL);
+
   ActiveEntriesSet::iterator it = doomed_entries_.find(entry);
   DCHECK(it != doomed_entries_.end());
   doomed_entries_.erase(it);
@@ -594,7 +652,7 @@
 HttpCache::ActiveEntry* HttpCache::ActivateEntry(
     disk_cache::Entry* disk_entry) {
   DCHECK(!FindActiveEntry(disk_entry->GetKey()));
-  ActiveEntry* entry = new ActiveEntry(disk_entry);
+  ActiveEntry* entry = new ActiveEntry(disk_entry, net_log_);
   active_entries_[disk_entry->GetKey()] = entry;
   return entry;
 }
@@ -607,6 +665,8 @@
   DCHECK(entry->readers.empty());
   DCHECK(entry->pending_queue.empty());
 
+  entry->net_log.AddEvent(NetLog::TYPE_ACTIVE_ENTRY_DEACTIVATE, NULL);
+
   std::string key = entry->disk_entry->GetKey();
   if (key.empty())
     return SlowDeactivateEntry(entry);
@@ -732,6 +792,18 @@
 }
 
 int HttpCache::AddTransactionToEntry(ActiveEntry* entry, Transaction* trans) {
+  int result = AddTransactionToEntryInternal(entry, trans);
+  if (result == ERR_IO_PENDING) {
+    entry->net_log.AddEvent(
+        NetLog::TYPE_ACTIVE_ENTRY_ADD_TO_QUEUE,
+        new AddTransactionParams(trans->net_log().source(),
+                                 entry->pending_queue.size()));
+  }
+  return result;
+}
+
+int HttpCache::AddTransactionToEntryInternal(ActiveEntry* entry,
+                                             Transaction* trans) {
   DCHECK(entry);
   DCHECK(entry->disk_entry);
 
@@ -752,6 +824,10 @@
     // transaction needs exclusive access to the entry
     if (entry->readers.empty()) {
       entry->writer = trans;
+      entry->net_log.BeginEvent(
+          NetLog::TYPE_ACTIVE_ENTRY_SET_WRITER,
+          new AddTransactionParams(trans->net_log().source(),
+                                   entry->pending_queue.size()));
     } else {
       entry->pending_queue.push_back(trans);
       return ERR_IO_PENDING;
@@ -759,6 +835,10 @@
   } else {
     // transaction needs read access to the entry
     entry->readers.push_back(trans);
+    entry->net_log.AddEvent(
+        NetLog::TYPE_ACTIVE_ENTRY_ADD_READER,
+        new AddTransactionParams(trans->net_log().source(),
+                                 entry->pending_queue.size()));
   }
 
   // We do this before calling EntryAvailable to force any further calls to
@@ -798,6 +878,7 @@
   DCHECK(entry->readers.empty());
 
   entry->writer = NULL;
+  entry->net_log.EndEvent(NetLog::TYPE_ACTIVE_ENTRY_SET_WRITER, NULL);
 
   if (success) {
     ProcessPendingQueue(entry);
@@ -829,6 +910,10 @@
   DCHECK(it != entry->readers.end());
 
   entry->readers.erase(it);
+  entry->net_log.AddEvent(
+      NetLog::TYPE_ACTIVE_ENTRY_REMOVE_READER,
+      new NetLogSourceParameter("source_dependency",
+                                trans->net_log().source()));
 
   ProcessPendingQueue(entry);
 }
@@ -841,7 +926,12 @@
   Transaction* trans = entry->writer;
 
   entry->writer = NULL;
+  entry->net_log.EndEvent(NetLog::TYPE_ACTIVE_ENTRY_SET_WRITER, NULL);
   entry->readers.push_back(trans);
+  entry->net_log.AddEvent(
+      NetLog::TYPE_ACTIVE_ENTRY_ADD_READER,
+      new NetLogSourceParameter("source_dependency",
+                                trans->net_log().source()));
 
   ProcessPendingQueue(entry);
 }
@@ -900,6 +990,10 @@
   if (j == pending_queue.end())
     return false;
 
+  entry->net_log.AddEvent(
+      NetLog::TYPE_ACTIVE_ENTRY_REMOVE_PENDING_TRANSACTION,
+      new NetLogSourceParameter("source_dependency",
+                                trans->net_log().source()));
   pending_queue.erase(j);
   return true;
 }
@@ -956,7 +1050,7 @@
 
   entry->pending_queue.erase(entry->pending_queue.begin());
 
-  int rv = AddTransactionToEntry(entry, next);
+  int rv = AddTransactionToEntryInternal(entry, next);
   if (rv != ERR_IO_PENDING) {
     next->io_callback()->Run(rv);
   }