SimpleCache: synchronously reply on reads from idle if data is in memory.

net/disk_cache/disk_cache_perftest.cc

 // Copyright (c) 2011 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 <limits>
 #include <string>
 
+#include "base/barrier_closure.h"
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/files/file_enumerator.h"
 #include "base/files/file_path.h"
 #include "base/hash.h"
 #include "base/process/process_metrics.h"
 #include "base/rand_util.h"
 #include "base/run_loop.h"
+#include "base/strings/string_number_conversions.h"
 #include "base/strings/string_util.h"
 #include "base/test/perf_time_logger.h"
 #include "base/test/test_file_util.h"
 #include "base/threading/thread.h"
 #include "net/base/cache_type.h"
 #include "net/base/io_buffer.h"
 #include "net/base/net_errors.h"
 #include "net/base/test_completion_callback.h"
 #include "net/disk_cache/blockfile/backend_impl.h"
 #include "net/disk_cache/blockfile/block_files.h"
@@ skipping 274 matching lines @@
 
     files.DeleteBlock(address[entry], false);
     EXPECT_TRUE(
         files.CreateBlock(disk_cache::RANKINGS, block_size, &address[entry]));
   }
 
   timer2.Done();
   base::RunLoop().RunUntilIdle();
 }
 
+void VerifyRvAndCallClosure(base::Closure* c, int expect_rv, int rv) {
+  EXPECT_EQ(expect_rv, rv);
+  c->Run();
+}
+
+TEST_F(DiskCachePerfTest, SimpleCacheInitialReadPortion) {
+  // A benchmark that aims to measure how much time we take in I/O thread
+  // for initial bookkeeping before returning to the caller, and how much
+  // after (batched up some). The later portion includes some event loop
+  // overhead.
+  const int kBatchSize = 100;
+
+  SetSimpleCacheMode();
+
+  InitCache();
+  // Write out the entries, and keep their objects around.
+  scoped_refptr<net::IOBuffer> buffer1(new net::IOBuffer(kHeadersSize));
+  scoped_refptr<net::IOBuffer> buffer2(new net::IOBuffer(kBodySize));
+
+  CacheTestFillBuffer(buffer1->data(), kHeadersSize, false);
+  CacheTestFillBuffer(buffer2->data(), kBodySize, false);
+
+  disk_cache::Entry* cache_entry[kBatchSize];
+  for (int i = 0; i < kBatchSize; ++i) {
+    net::TestCompletionCallback cb;
+    int rv = cache_->CreateEntry(base::IntToString(i), &cache_entry[i],
+                                 cb.callback());
+    ASSERT_EQ(net::OK, cb.GetResult(rv));
+
+    rv = cache_entry[i]->WriteData(0, 0, buffer1.get(), kHeadersSize,
+                                   cb.callback(), false);
+    ASSERT_EQ(kHeadersSize, cb.GetResult(rv));
+    rv = cache_entry[i]->WriteData(1, 0, buffer2.get(), kBodySize,
+                                   cb.callback(), false);
+    ASSERT_EQ(kBodySize, cb.GetResult(rv));
+  }
+
+  // Now repeatedly read these, batching up the waiting to try to
+  // account for the two portions separately. Note that we need separate entries
+  // since we are trying to keep interesting work from being on the delayed-done
+  // portion.
+  const int kIterations = 50000;
+
+  double elapsed_early = 0.0;
+  double elapsed_late = 0.0;
+
+  for (int i = 0; i < kIterations; ++i) {
+    int expected = 0;
+
+    base::RunLoop event_loop;
+    base::Closure barrier =
+        base::BarrierClosure(kIterations, event_loop.QuitWhenIdleClosure());
+    net::CompletionCallback cb_batch(base::Bind(
+        VerifyRvAndCallClosure, base::Unretained(&barrier), kHeadersSize));
+
+    base::ElapsedTimer timer_early;
+    for (int e = 0; e < kBatchSize; ++e) {
+      int rv =
+          cache_entry[e]->ReadData(0, 0, buffer1.get(), kHeadersSize, cb_batch);
+      if (rv == net::ERR_IO_PENDING)
+        ++expected;
+      else
+        ASSERT_EQ(kHeadersSize, rv);
+    }
+    elapsed_early += timer_early.Elapsed().InMillisecondsF();
+
+    base::ElapsedTimer timer_late;
+
+    if (expected != 0) {
+      // if expected is x, done will only get called x times, not kIterations
+      // times. This is a bill silly, but just fake the other kIterations - x
+      // calls. This is a bit silly, but unlike MessageLoopHelper, it doesn't do
+      // major sleeps.
+      for (int extra = 0; extra < kIterations - expected; ++extra)
+        barrier.Run();
+
+      event_loop.Run();
+    }
+
+    elapsed_late += timer_late.Elapsed().InMillisecondsF();
+  }
+
+  // Cleanup
+  for (int i = 0; i < kBatchSize; ++i)
+    cache_entry[i]->Close();
+
+  disk_cache::SimpleBackendImpl::FlushWorkerPoolForTesting();
+  base::RunLoop().RunUntilIdle();
+  LOG(ERROR) << "Early portion:" << elapsed_early << " ms";
+  LOG(ERROR) << "\tPer entry:"
+             << 1000 * (elapsed_early / (kIterations * kBatchSize)) << " us";
+  LOG(ERROR) << "Event loop portion: " << elapsed_late << " ms";
+  LOG(ERROR) << "\tPer entry:"
+             << 1000 * (elapsed_late / (kIterations * kBatchSize)) << " us";
+}
+
 // Measures how quickly SimpleIndex can compute which entries to evict.
 TEST(SimpleIndexPerfTest, EvictionPerformance) {
   const int kEntries = 10000;
 
   class NoOpDelegate : public disk_cache::SimpleIndexDelegate {
     void DoomEntries(std::vector<uint64_t>* entry_hashes,
                      const net::CompletionCallback& callback) override {}
   };
 
   NoOpDelegate delegate;
@@ skipping 19 matching lines @@
     index.SetMaxSize(kEntries);
     index.UpdateEntrySize(0, 1u);
     evict_elapsed_ms += timer.Elapsed().InMillisecondsF();
   }
 
   LOG(ERROR) << "Average time to evict:" << (evict_elapsed_ms / iterations)
              << "ms";
 }
 
 }  // namespace