Fixed first pass at adding http/backend cache events to the NetLog. ...

net/http/http_cache_unittest.cc

 // Copyright (c) 2010 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.h"
 
 #include "base/hash_tables.h"
 #include "base/message_loop.h"
 #include "base/scoped_vector.h"
 #include "base/string_util.h"
@@ skipping 518 matching lines @@
 
   EntryMap entries_;
   int open_count_;
   int create_count_;
   bool fail_requests_;
   bool soft_failures_;
 };
 
 class MockBackendFactory : public net::HttpCache::BackendFactory {
  public:
-  virtual int CreateBackend(disk_cache::Backend** backend,
+  virtual int CreateBackend(net::NetLog*  /* net_log */,
+                            disk_cache::Backend** backend,
                             net::CompletionCallback* callback) {
     *backend = new MockDiskCache();
     return net::OK;
   }
 };
 
 class MockHttpCache {
  public:
   MockHttpCache()
-      : http_cache_(new MockNetworkLayer(), new MockBackendFactory()) {
+      : http_cache_(new MockNetworkLayer(), NULL, new MockBackendFactory()) {
   }
 
   explicit MockHttpCache(net::HttpCache::BackendFactory* disk_cache_factory)
-      : http_cache_(new MockNetworkLayer(), disk_cache_factory) {
+      : http_cache_(new MockNetworkLayer(), NULL, disk_cache_factory) {
   }
 
   net::HttpCache* http_cache() { return &http_cache_; }
 
   MockNetworkLayer* network_layer() {
     return static_cast<MockNetworkLayer*>(http_cache_.network_layer());
   }
   MockDiskCache* disk_cache() {
     TestCompletionCallback cb;
     disk_cache::Backend* backend;
@@ skipping 39 matching lines @@
   }
 
   // Helper function to synchronously open a backend entry.
   bool OpenBackendEntry(const std::string& key, disk_cache::Entry** entry) {
     TestCompletionCallback cb;
     int rv = disk_cache()->OpenEntry(key, entry, &cb);
     return (cb.GetResult(rv) == net::OK);
   }
 
   // Helper function to synchronously create a backend entry.
-  bool CreateBackendEntry(const std::string& key, disk_cache::Entry** entry) {
+  bool CreateBackendEntry(const std::string& key, disk_cache::Entry** entry,
+                          net::NetLog*  /* net_log */) {
     TestCompletionCallback cb;
     int rv = disk_cache()->CreateEntry(key, entry, &cb);
     return (cb.GetResult(rv) == net::OK);
   }
 
  private:
   net::HttpCache http_cache_;
 };
 
 // This version of the disk cache doesn't invoke CreateEntry callbacks.
 class MockDiskCacheNoCB : public MockDiskCache {
   virtual int CreateEntry(const std::string& key, disk_cache::Entry** entry,
                           net::CompletionCallback* callback) {
     return net::ERR_IO_PENDING;
   }
 };
 
 class MockBackendNoCbFactory : public net::HttpCache::BackendFactory {
  public:
-  virtual int CreateBackend(disk_cache::Backend** backend,
+  virtual int CreateBackend(net::NetLog*  /* net_log */,
+                            disk_cache::Backend** backend,
                             net::CompletionCallback* callback) {
     *backend = new MockDiskCacheNoCB();
     return net::OK;
   }
 };
 
 // This backend factory allows us to control the backend instantiation.
 class MockBlockingBackendFactory : public net::HttpCache::BackendFactory {
  public:
   MockBlockingBackendFactory()
       : backend_(NULL), callback_(NULL), block_(true), fail_(false) {}
 
-  virtual int CreateBackend(disk_cache::Backend** backend,
+  virtual int CreateBackend(net::NetLog*  /* net_log */,
+                            disk_cache::Backend** backend,
                             net::CompletionCallback* callback) {
     if (!block_) {
       if (!fail_)
         *backend = new MockDiskCache();
       return Result();
     }
 
     backend_ =  backend;
     callback_ = callback;
     return net::ERR_IO_PENDING;
@@ skipping 373 matching lines @@
   EXPECT_EQ(0, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
 }
 
 TEST(HttpCache, SimpleGETNoDiskCache) {
   MockHttpCache cache;
 
   cache.disk_cache()->set_fail_requests();
 
   net::CapturingBoundNetLog log(net::CapturingNetLog::kUnbounded);
+  log.SetLogLevel(net::NetLog::LOG_BASIC);
 
   // Read from the network, and don't use the cache.
   RunTransactionTestWithLog(cache.http_cache(), kSimpleGET_Transaction,
                             log.bound());
 
   // Check that the NetLog was filled as expected.
   // (We attempted to both Open and Create entries, but both failed).
   net::CapturingNetLog::EntryList entries;
   log.GetEntries(&entries);
 
   EXPECT_EQ(6u, entries.size());
   EXPECT_TRUE(net::LogContainsBeginEvent(
-      entries, 0, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 0, net::NetLog::TYPE_HTTP_CACHE_GET_BACKEND));
   EXPECT_TRUE(net::LogContainsEndEvent(
-      entries, 1, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 1, net::NetLog::TYPE_HTTP_CACHE_GET_BACKEND));
   EXPECT_TRUE(net::LogContainsBeginEvent(
       entries, 2, net::NetLog::TYPE_HTTP_CACHE_OPEN_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
       entries, 3, net::NetLog::TYPE_HTTP_CACHE_OPEN_ENTRY));
   EXPECT_TRUE(net::LogContainsBeginEvent(
       entries, 4, net::NetLog::TYPE_HTTP_CACHE_CREATE_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
       entries, 5, net::NetLog::TYPE_HTTP_CACHE_CREATE_ENTRY));
 
   EXPECT_EQ(1, cache.network_layer()->transaction_count());
@@ skipping 71 matching lines @@
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(2, cache.disk_cache()->create_count());
 }
 
 TEST(HttpCache, SimpleGET_LoadOnlyFromCache_Hit) {
   MockHttpCache cache;
 
   net::CapturingBoundNetLog log(net::CapturingNetLog::kUnbounded);
 
+  // This prevents a number of write events from being logged.
+  log.SetLogLevel(net::NetLog::LOG_BASIC);
+
   // write to the cache
   RunTransactionTestWithLog(cache.http_cache(), kSimpleGET_Transaction,
                             log.bound());
 
   // Check that the NetLog was filled as expected.
   net::CapturingNetLog::EntryList entries;
   log.GetEntries(&entries);
 
   EXPECT_EQ(8u, entries.size());
   EXPECT_TRUE(net::LogContainsBeginEvent(
-      entries, 0, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 0, net::NetLog::TYPE_HTTP_CACHE_GET_BACKEND));
   EXPECT_TRUE(net::LogContainsEndEvent(
-      entries, 1, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 1, net::NetLog::TYPE_HTTP_CACHE_GET_BACKEND));
   EXPECT_TRUE(net::LogContainsBeginEvent(
       entries, 2, net::NetLog::TYPE_HTTP_CACHE_OPEN_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
       entries, 3, net::NetLog::TYPE_HTTP_CACHE_OPEN_ENTRY));
   EXPECT_TRUE(net::LogContainsBeginEvent(
       entries, 4, net::NetLog::TYPE_HTTP_CACHE_CREATE_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
       entries, 5, net::NetLog::TYPE_HTTP_CACHE_CREATE_ENTRY));
   EXPECT_TRUE(net::LogContainsBeginEvent(
-      entries, 6, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 6, net::NetLog::TYPE_HTTP_CACHE_ADD_TO_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
-      entries, 7, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 7, net::NetLog::TYPE_HTTP_CACHE_ADD_TO_ENTRY));
 
   // force this transaction to read from the cache
   MockTransaction transaction(kSimpleGET_Transaction);
   transaction.load_flags |= net::LOAD_ONLY_FROM_CACHE;
 
   log.Clear();
 
   RunTransactionTestWithLog(cache.http_cache(), transaction, log.bound());
 
   // Check that the NetLog was filled as expected.
   log.GetEntries(&entries);
 
   EXPECT_EQ(8u, entries.size());
   EXPECT_TRUE(net::LogContainsBeginEvent(
-      entries, 0, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 0, net::NetLog::TYPE_HTTP_CACHE_GET_BACKEND));
   EXPECT_TRUE(net::LogContainsEndEvent(
-      entries, 1, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 1, net::NetLog::TYPE_HTTP_CACHE_GET_BACKEND));
   EXPECT_TRUE(net::LogContainsBeginEvent(
       entries, 2, net::NetLog::TYPE_HTTP_CACHE_OPEN_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
       entries, 3, net::NetLog::TYPE_HTTP_CACHE_OPEN_ENTRY));
   EXPECT_TRUE(net::LogContainsBeginEvent(
-      entries, 4, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 4, net::NetLog::TYPE_HTTP_CACHE_ADD_TO_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
-      entries, 5, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 5, net::NetLog::TYPE_HTTP_CACHE_ADD_TO_ENTRY));
   EXPECT_TRUE(net::LogContainsBeginEvent(
       entries, 6, net::NetLog::TYPE_HTTP_CACHE_READ_INFO));
   EXPECT_TRUE(net::LogContainsEndEvent(
       entries, 7, net::NetLog::TYPE_HTTP_CACHE_READ_INFO));
 
   EXPECT_EQ(1, cache.network_layer()->transaction_count());
   EXPECT_EQ(1, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
 }
 
@@ skipping 60 matching lines @@
 
   // Write to the cache.
   RunTransactionTest(cache.http_cache(), kSimpleGET_Transaction);
 
   // Force this transaction to write to the cache again.
   MockTransaction transaction(kSimpleGET_Transaction);
   transaction.load_flags |= net::LOAD_BYPASS_CACHE;
 
   net::CapturingBoundNetLog log(net::CapturingNetLog::kUnbounded);
 
+  // This prevents a number of write events from being logged.
+  log.SetLogLevel(net::NetLog::LOG_BASIC);
+
   RunTransactionTestWithLog(cache.http_cache(), transaction, log.bound());
 
   // Check that the NetLog was filled as expected.
   net::CapturingNetLog::EntryList entries;
   log.GetEntries(&entries);
 
   EXPECT_EQ(8u, entries.size());
   EXPECT_TRUE(net::LogContainsBeginEvent(
-      entries, 0, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 0, net::NetLog::TYPE_HTTP_CACHE_GET_BACKEND));
   EXPECT_TRUE(net::LogContainsEndEvent(
-      entries, 1, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 1, net::NetLog::TYPE_HTTP_CACHE_GET_BACKEND));
   EXPECT_TRUE(net::LogContainsBeginEvent(
       entries, 2, net::NetLog::TYPE_HTTP_CACHE_DOOM_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
       entries, 3, net::NetLog::TYPE_HTTP_CACHE_DOOM_ENTRY));
   EXPECT_TRUE(net::LogContainsBeginEvent(
       entries, 4, net::NetLog::TYPE_HTTP_CACHE_CREATE_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
       entries, 5, net::NetLog::TYPE_HTTP_CACHE_CREATE_ENTRY));
   EXPECT_TRUE(net::LogContainsBeginEvent(
-      entries, 6, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 6, net::NetLog::TYPE_HTTP_CACHE_ADD_TO_ENTRY));
   EXPECT_TRUE(net::LogContainsEndEvent(
-      entries, 7, net::NetLog::TYPE_HTTP_CACHE_WAITING));
+      entries, 7, net::NetLog::TYPE_HTTP_CACHE_ADD_TO_ENTRY));
 
   EXPECT_EQ(2, cache.network_layer()->transaction_count());
   EXPECT_EQ(0, cache.disk_cache()->open_count());
   EXPECT_EQ(2, cache.disk_cache()->create_count());
 }
 
 TEST(HttpCache, SimpleGET_LoadBypassCache_Implicit) {
   MockHttpCache cache;
 
   // write to the cache
@@ skipping 1986 matching lines @@
 
   RemoveMockTransaction(&transaction);
 }
 
 // Tests that we can handle cached 206 responses that are not sparse.
 TEST(HttpCache, GET_Previous206_NotSparse) {
   MockHttpCache cache;
 
   // Create a disk cache entry that stores 206 headers while not being sparse.
   disk_cache::Entry* entry;
-  ASSERT_TRUE(cache.CreateBackendEntry(kSimpleGET_Transaction.url, &entry));
+  ASSERT_TRUE(cache.CreateBackendEntry(kSimpleGET_Transaction.url, &entry,
+                                       NULL));
 
   std::string raw_headers(kRangeGET_TransactionOK.status);
   raw_headers.append("\n");
   raw_headers.append(kRangeGET_TransactionOK.response_headers);
   raw_headers = net::HttpUtil::AssembleRawHeaders(raw_headers.data(),
                                                   raw_headers.size());
 
   net::HttpResponseInfo response;
   response.headers = new net::HttpResponseHeaders(raw_headers);
   EXPECT_TRUE(MockHttpCache::WriteResponseInfo(entry, &response, true, false));
@@ skipping 22 matching lines @@
 }
 
 // Tests that we can handle cached 206 responses that are not sparse. This time
 // we issue a range request and expect to receive a range.
 TEST(HttpCache, RangeGET_Previous206_NotSparse_2) {
   MockHttpCache cache;
   AddMockTransaction(&kRangeGET_TransactionOK);
 
   // Create a disk cache entry that stores 206 headers while not being sparse.
   disk_cache::Entry* entry;
-  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry));
+  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry,
+                                       NULL));
 
   std::string raw_headers(kRangeGET_TransactionOK.status);
   raw_headers.append("\n");
   raw_headers.append(kRangeGET_TransactionOK.response_headers);
   raw_headers = net::HttpUtil::AssembleRawHeaders(raw_headers.data(),
                                                   raw_headers.size());
 
   net::HttpResponseInfo response;
   response.headers = new net::HttpResponseHeaders(raw_headers);
   EXPECT_TRUE(MockHttpCache::WriteResponseInfo(entry, &response, true, false));
@@ skipping 577 matching lines @@
   EXPECT_EQ(1, cache.disk_cache()->create_count());
 
   RemoveMockTransaction(&kRangeGET_TransactionOK);
 }
 #endif
 
 // Tests the handling of the "truncation" flag.
 TEST(HttpCache, WriteResponseInfo_Truncated) {
   MockHttpCache cache;
   disk_cache::Entry* entry;
-  ASSERT_TRUE(cache.CreateBackendEntry("http://www.google.com", &entry));
+  ASSERT_TRUE(cache.CreateBackendEntry("http://www.google.com", &entry,
+                                       NULL));
 
   std::string headers("HTTP/1.1 200 OK");
   headers = net::HttpUtil::AssembleRawHeaders(headers.data(), headers.size());
   net::HttpResponseInfo response;
   response.headers = new net::HttpResponseHeaders(headers);
 
   // Set the last argument for this to be an incomplete request.
   EXPECT_TRUE(MockHttpCache::WriteResponseInfo(entry, &response, true, true));
   bool truncated = false;
   EXPECT_TRUE(MockHttpCache::ReadResponseInfo(entry, &response, &truncated));
@@ skipping 178 matching lines @@
   RemoveMockTransaction(&transaction);
 }
 
 // Tests that we can continue with a request that was interrupted.
 TEST(HttpCache, GET_IncompleteResource) {
   MockHttpCache cache;
   AddMockTransaction(&kRangeGET_TransactionOK);
 
   // Create a disk cache entry that stores an incomplete resource.
   disk_cache::Entry* entry;
-  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry));
+  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry,
+                                       NULL));
 
   std::string raw_headers("HTTP/1.1 200 OK\n"
                           "Last-Modified: Sat, 18 Apr 2009 01:10:43 GMT\n"
                           "ETag: \"foo\"\n"
                           "Accept-Ranges: bytes\n"
                           "Content-Length: 80\n");
   raw_headers = net::HttpUtil::AssembleRawHeaders(raw_headers.data(),
                                                   raw_headers.size());
 
   net::HttpResponseInfo response;
@@ skipping 39 matching lines @@
   entry->Close();
 }
 
 // Tests that we delete truncated entries if the server changes its mind midway.
 TEST(HttpCache, GET_IncompleteResource2) {
   MockHttpCache cache;
   AddMockTransaction(&kRangeGET_TransactionOK);
 
   // Create a disk cache entry that stores an incomplete resource.
   disk_cache::Entry* entry;
-  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry));
+  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry,
+                                       NULL));
 
 
   // Content-length will be intentionally bad.
   std::string raw_headers("HTTP/1.1 200 OK\n"
                           "Last-Modified: Sat, 18 Apr 2009 01:10:43 GMT\n"
                           "ETag: \"foo\"\n"
                           "Accept-Ranges: bytes\n"
                           "Content-Length: 50\n");
   raw_headers = net::HttpUtil::AssembleRawHeaders(raw_headers.data(),
                                                   raw_headers.size());
@@ skipping 38 matching lines @@
 }
 
 // Tests that when we cancel a request that was interrupted, we mark it again
 // as truncated.
 TEST(HttpCache, GET_CancelIncompleteResource) {
   MockHttpCache cache;
   AddMockTransaction(&kRangeGET_TransactionOK);
 
   // Create a disk cache entry that stores an incomplete resource.
   disk_cache::Entry* entry;
-  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry));
+  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry,
+                                       NULL));
 
   std::string raw_headers("HTTP/1.1 200 OK\n"
                           "Last-Modified: Sat, 18 Apr 2009 01:10:43 GMT\n"
                           "ETag: \"foo\"\n"
                           "Accept-Ranges: bytes\n"
                           "Content-Length: 80\n");
   raw_headers = net::HttpUtil::AssembleRawHeaders(raw_headers.data(),
                                                   raw_headers.size());
 
   net::HttpResponseInfo response;
@@ skipping 44 matching lines @@
   entry->Close();
 }
 
 // Tests that we can handle range requests when we have a truncated entry.
 TEST(HttpCache, RangeGET_IncompleteResource) {
   MockHttpCache cache;
   AddMockTransaction(&kRangeGET_TransactionOK);
 
   // Create a disk cache entry that stores an incomplete resource.
   disk_cache::Entry* entry;
-  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry));
+  ASSERT_TRUE(cache.CreateBackendEntry(kRangeGET_TransactionOK.url, &entry,
+                                       NULL));
 
   // Content-length will be intentionally bogus.
   std::string raw_headers("HTTP/1.1 200 OK\n"
                           "Last-Modified: something\n"
                           "ETag: \"foo\"\n"
                           "Accept-Ranges: bytes\n"
                           "Content-Length: 10\n");
   raw_headers = net::HttpUtil::AssembleRawHeaders(raw_headers.data(),
                                                   raw_headers.size());
 
@@ skipping 482 matching lines @@
   // Now return 200 when validating the entry so the metadata will be lost.
   MockTransaction trans2(kTypicalGET_Transaction);
   trans2.load_flags = net::LOAD_VALIDATE_CACHE;
   RunTransactionTestWithResponseInfo(cache.http_cache(), trans2, &response);
   EXPECT_TRUE(response.metadata.get() == NULL);
 
   EXPECT_EQ(3, cache.network_layer()->transaction_count());
   EXPECT_EQ(4, cache.disk_cache()->open_count());
   EXPECT_EQ(1, cache.disk_cache()->create_count());
 }