net: Add some metrics on reuse of idle sockets.

net/socket/client_socket_pool_base.cc

 // Copyright (c) 2012 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/socket/client_socket_pool_base.h"
 
 #include <algorithm>
 #include <utility>
 
 #include "base/compiler_specific.h"
 #include "base/format_macros.h"
 #include "base/location.h"
 #include "base/logging.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/single_thread_task_runner.h"
 #include "base/stl_util.h"
 #include "base/strings/string_util.h"
 #include "base/threading/thread_task_runner_handle.h"
 #include "base/time/time.h"
 #include "base/trace_event/trace_event.h"
 #include "base/values.h"
 #include "net/base/net_errors.h"
 #include "net/log/net_log.h"
 
@@ skipping 944 matching lines @@
     base::TimeDelta idle_time,
     Group* group,
     const BoundNetLog& net_log) {
   DCHECK(socket);
   handle->SetSocket(std::move(socket));
   handle->set_reuse_type(reuse_type);
   handle->set_idle_time(idle_time);
   handle->set_pool_id(pool_generation_number_);
   handle->set_connect_timing(connect_timing);
 
-  if (handle->is_reused()) {
+  if (reuse_type == ClientSocketHandle::REUSED_IDLE) {

[mmenke, 2016/06/21 21:08:32]

This is the same as before, just switched to be consistent with the next check.

     net_log.AddEvent(
         NetLog::TYPE_SOCKET_POOL_REUSED_AN_EXISTING_SOCKET,
         NetLog::IntCallback("idle_ms",
                             static_cast<int>(idle_time.InMilliseconds())));
+
+    UMA_HISTOGRAM_COUNTS_1000("Net.Socket.IdleSocketReuseTime",

[Charlie Harrison, 2016/06/21 21:23:20]

Any reason not to do this in milliseconds? Seems like we should take all the
resolution we can get here, especially considering the loading team may be
interested in looking at this metric for preconnect experiments with short
delays (i.e. shaving off 100ms)

[mmenke, 2016/06/21 21:34:45]

Mostly to make it more readable.  "28" is more readable than "28,646".  Given
that the max here is 5 minutes (300,000) milliseconds, and we only have 50
buckets, that doesn't really get us any extra resolution.  If we need more fine
grained numbers for preconnects, we'll need another histogram, I think.  Also,
this metric doesn't include preconnects.  Preconnects are UNUSED_IDLE sockets,
and I'm deliberately excluding them, since they have their own timeout value.

[Charlie Harrison, 2016/06/21 21:40:20]

Gotcha, thanks for the clarification. Keeping in seconds SGTM.

+                              idle_time.InSeconds());
   }
 
-  net_log.AddEvent(

[Charlie Harrison, 2016/06/21 21:23:20]

Why remove this?

[mmenke, 2016/06/21 21:34:45]

Thanks for catching that!  Mistake due to repeatedly re-applying the change (One
for authentication that defaults to using my corp account, one for git branches
being a pain, one for corp windows being a pain).

-      NetLog::TYPE_SOCKET_POOL_BOUND_TO_SOCKET,
-      handle->socket()->NetLog().source().ToEventParametersCallback());
+  if (reuse_type != ClientSocketHandle::UNUSED) {
+    // The socket being handed out is no longer considered idle, but was
+    // considered idle until just before this method was called.
+    UMA_HISTOGRAM_COUNTS_100("Net.Socket.NumIdleSockets",

[Charlie Harrison, 2016/06/21 21:23:20]

suggestion: Consider bumping this from 100 to something closer to our socket
limit if you think 100 idle sockets are reasonably possible. Better to have
slightly lower resolution and see the long tail.

[mmenke, 2016/06/21 21:34:45]

If we really have 100 idle sockets around, I don't think there's a point to
adding an extra limit.  That having been said, it doesn't hurt us, I was just
being lazy.  Increased it to 256.

[Charlie Harrison, 2016/06/21 21:40:20]

Yeah my comment was mostly due to your observation that brief browsing led to 50
idle sockets pretty easily. If that's the case I would guess that we get > 100
rarely but enough that we'd want to see exactly what's happening there :)

[mmenke, 2016/06/21 21:44:46]

I suspect we'll see it, but I suspect if we have to set the idle socket limit
that high, we're effectively giving up on capping idle sockets.

Worth noting this isn't a great way to count idle sockets - this is the idle
count in the current pool, so it's possible we'll have X in the TCP pool, and Y
in the SSL pool on top of it (Which the TCP pool thinks are used).  Maybe have
to rework this metric in the future, but for now, think it's good enough.

[Charlie Harrison, 2016/06/21 21:52:07]

Good point, though we would like to see what the effect of a idle socket limit
would be (i.e. approximate measure of wins).

+                             idle_socket_count() + 1);
+  }
 
   handed_out_socket_count_++;
   group->IncrementActiveSocketCount();
 }
 
 void ClientSocketPoolBaseHelper::AddIdleSocket(
     std::unique_ptr<StreamSocket> socket,
     Group* group) {
   DCHECK(socket);
   IdleSocket idle_socket;
@@ skipping 311 matching lines @@
   // If there are no more requests, kill the backup timer.
   if (pending_requests_.empty())
     backup_job_timer_.Stop();
   request->CrashIfInvalid();
   return request;
 }
 
 }  // namespace internal
 
 }  // namespace net