SSLClientSessionCache: Log number of times Lookup is called per Session.

net/ssl/ssl_client_session_cache.cc

 // Copyright 2015 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/ssl/ssl_client_session_cache.h"
 
 #include <utility>
 
 #include "base/memory/memory_coordinator_client_registry.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/strings/stringprintf.h"
 #include "base/time/clock.h"
 #include "base/time/default_clock.h"
 #include "base/trace_event/process_memory_dump.h"
 #include "net/cert/x509_util_openssl.h"
 #include "third_party/boringssl/src/include/openssl/ssl.h"
 #include "third_party/boringssl/src/include/openssl/x509.h"
 
 namespace net {
 
+SSLClientSessionCache::Entry::Entry()
+    : active_lookups(0), max_lookups(0), should_log(false) {}
+SSLClientSessionCache::Entry::Entry(Entry&&) = default;
+SSLClientSessionCache::Entry::~Entry() = default;
+
 SSLClientSessionCache::SSLClientSessionCache(const Config& config)
     : clock_(new base::DefaultClock),
       config_(config),
       cache_(config.max_entries),
       lookups_since_flush_(0) {
   memory_pressure_listener_.reset(new base::MemoryPressureListener(base::Bind(
       &SSLClientSessionCache::OnMemoryPressure, base::Unretained(this))));
   base::MemoryCoordinatorClientRegistry::GetInstance()->Register(this);
 }
 
@@ skipping 14 matching lines @@
   lookups_since_flush_++;
   if (lookups_since_flush_ >= config_.expiration_check_count) {
     lookups_since_flush_ = 0;
     FlushExpiredSessions();
   }
 
   auto iter = cache_.Get(cache_key);
   if (iter == cache_.end())
     return nullptr;
 
-  SSL_SESSION* session = iter->second.get();
+  SSL_SESSION* session = iter->second.session.get();
   if (IsExpired(session, clock_->Now().ToTimeT())) {
     cache_.Erase(iter);
     return nullptr;
   }
 
+  iter->second.active_lookups++;
+  if (iter->second.active_lookups > iter->second.max_lookups)
+    iter->second.max_lookups = iter->second.active_lookups;
+
   SSL_SESSION_up_ref(session);
   return bssl::UniquePtr<SSL_SESSION>(session);
 }
 
+void SSLClientSessionCache::DecrementLookupCount(const std::string& cache_key,
+                                                 bool should_log) {
+  base::AutoLock lock(lock_);
+
+  // It's possible that the cached session for this key was deleted after the
+  // Lookup, and also possible that it has been replaced by a new Entry. If
+  // that's the case, don't do anything.
+  auto iter = cache_.Get(cache_key);
+  if (iter == cache_.end() || iter->second.active_lookups == 0)
+    return;
+
+  iter->second.active_lookups--;
+  if (should_log)
+    iter->second.should_log = true;
+
+  if (iter->second.active_lookups == 0) {
+    if (iter->second.should_log) {
+      UMA_HISTOGRAM_EXACT_LINEAR("Net.SSLSessionConcurrentLookupCount",
+                                 iter->second.max_lookups, 20);
+    }
+    iter->second.max_lookups = 0;
+    iter->second.should_log = false;
+  }
+}
+
 void SSLClientSessionCache::Insert(const std::string& cache_key,
                                    SSL_SESSION* session) {
   base::AutoLock lock(lock_);
 
   SSL_SESSION_up_ref(session);
-  cache_.Put(cache_key, bssl::UniquePtr<SSL_SESSION>(session));
+  Entry entry;
+  entry.session = bssl::UniquePtr<SSL_SESSION>(session);
+  cache_.Put(cache_key, std::move(entry));
 }
 
 void SSLClientSessionCache::Flush() {
   base::AutoLock lock(lock_);
 
   cache_.Clear();
 }
 
 void SSLClientSessionCache::SetClockForTesting(
     std::unique_ptr<base::Clock> clock) {
@@ skipping 14 matching lines @@
   // This method can be reached from different URLRequestContexts. Since this is
   // a singleton, only log memory stats once.
   // TODO(xunjieli): Change this once crbug.com/458365 is fixed.
   if (cache_dump)
     return;
   cache_dump = pmd->CreateAllocatorDump(absolute_name);
   base::AutoLock lock(lock_);
   int total_serialized_cert_size = 0;
   int total_cert_count = 0;
   for (const auto& pair : cache_) {
-    auto entry = pair.second.get();
+    auto entry = pair.second.session.get();
     auto cert_chain = entry->x509_chain;
     size_t cert_count = sk_X509_num(cert_chain);
     total_cert_count += cert_count;
     for (size_t i = 0; i < cert_count; ++i) {
       X509* cert = sk_X509_value(cert_chain, i);
       total_serialized_cert_size += i2d_X509(cert, nullptr);
     }
   }
   // This measures the lower bound of the serialized certificate. It doesn't
   // measure the actual memory used, which is 4x this amount (see
   // crbug.com/671420 for more details).
   cache_dump->AddScalar("serialized_cert_size",
                         base::trace_event::MemoryAllocatorDump::kUnitsBytes,
                         total_serialized_cert_size);
   cache_dump->AddScalar("cert_count",
                         base::trace_event::MemoryAllocatorDump::kUnitsObjects,
                         total_cert_count);
   cache_dump->AddScalar(base::trace_event::MemoryAllocatorDump::kNameSize,
                         base::trace_event::MemoryAllocatorDump::kUnitsBytes,
                         total_serialized_cert_size);
 }
 
 void SSLClientSessionCache::FlushExpiredSessions() {
   time_t now = clock_->Now().ToTimeT();
   auto iter = cache_.begin();
   while (iter != cache_.end()) {
-    if (IsExpired(iter->second.get(), now)) {
+    if (IsExpired(iter->second.session.get(), now)) {
       iter = cache_.Erase(iter);
     } else {
       ++iter;
     }
   }
 }
 
 void SSLClientSessionCache::OnMemoryPressure(
     base::MemoryPressureListener::MemoryPressureLevel memory_pressure_level) {
   switch (memory_pressure_level) {
@@ skipping 20 matching lines @@
       break;
     case base::MemoryState::SUSPENDED:
     // Note: Not supported at present. Fall through.
     case base::MemoryState::UNKNOWN:
       NOTREACHED();
       break;
   }
 }
 
 }  // namespace net