net: Add some metrics on reuse of idle sockets.

net: Add some metrics on reuse of idle sockets.

We're investigating keeping fewer of them around, and/or timing them out
more aggressively to decrease memory usage.

BUG=621197
Committed: https://crrev.com/a9d6c7d3dc9a4a700ab9bf0aa71581540e014cd3
Cr-Commit-Position: refs/heads/master@{#401370}

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

mmenke@chromium.org changed reviewers:
+ csharrison@chromium.org

[mmenke, 2016-06-21 21:08:33]

Open to other ideas - figured these two are very simple to get, and a good place
to start.

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
File net/socket/client_socket_pool_base.cc (right):

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:979: if (reuse_type ==
ClientSocketHandle::REUSED_IDLE) {
This is the same as before, just switched to be consistent with the next check.

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

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
File net/socket/client_socket_pool_base.cc (left):

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:985: net_log.AddEvent(
Why remove this?

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
File net/socket/client_socket_pool_base.cc (right):

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:985:
UMA_HISTOGRAM_COUNTS_1000("Net.Socket.IdleSocketReuseTime",
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)

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:992:
UMA_HISTOGRAM_COUNTS_100("Net.Socket.NumIdleSockets",
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]

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
File net/socket/client_socket_pool_base.cc (left):

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:985: net_log.AddEvent(
On 2016/06/21 21:23:20, csharrison wrote:
> Why remove this?

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).

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
File net/socket/client_socket_pool_base.cc (right):

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:985:
UMA_HISTOGRAM_COUNTS_1000("Net.Socket.IdleSocketReuseTime",
On 2016/06/21 21:23:20, csharrison wrote:
> 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)

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.

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:992:
UMA_HISTOGRAM_COUNTS_100("Net.Socket.NumIdleSockets",
On 2016/06/21 21:23:20, csharrison wrote:
> 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.

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]

LGTM with nit.

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
File net/socket/client_socket_pool_base.cc (right):

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:985:
UMA_HISTOGRAM_COUNTS_1000("Net.Socket.IdleSocketReuseTime",
On 2016/06/21 21:34:45, mmenke wrote:
> On 2016/06/21 21:23:20, csharrison wrote:
> > 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)
> 
> 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.

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

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:992:
UMA_HISTOGRAM_COUNTS_100("Net.Socket.NumIdleSockets",
On 2016/06/21 21:34:45, mmenke wrote:
> On 2016/06/21 21:23:20, csharrison wrote:
> > 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.
> 
> 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.

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 :)

https://codereview.chromium.org/2086903003/diff/20001/tools/metrics/histogram...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/2086903003/diff/20001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:30075: +    Seconds a socket was idle
before it was reused. Does not the times sockets
nit: Second sentence here got wonky. "Does not record the times..."?

[mmenke, 2016-06-21 21:44:47]

Thanks!

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
File net/socket/client_socket_pool_base.cc (right):

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:992:
UMA_HISTOGRAM_COUNTS_100("Net.Socket.NumIdleSockets",
On 2016/06/21 21:40:20, csharrison wrote:
> On 2016/06/21 21:34:45, mmenke wrote:
> > On 2016/06/21 21:23:20, csharrison wrote:
> > > 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.
> > 
> > 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.
> 
> 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 :)

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.

https://codereview.chromium.org/2086903003/diff/20001/tools/metrics/histogram...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/2086903003/diff/20001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:30075: +    Seconds a socket was idle
before it was reused. Does not the times sockets
On 2016/06/21 21:40:20, csharrison wrote:
> nit: Second sentence here got wonky. "Does not record the times..."?

Done.

[Charlie Harrison, 2016-06-21 21:45:54]

Oh, could you also update the title? s/metrcs/metrics/g

[mmenke, 2016-06-21 21:49:35]

Description was changed from

==========
net: Add some metrcs on reuse of idle sockets.

We're investigating keeping fewer of them around, and/or timing them out
more aggressively to decrease memory usage.

BUG=621197
==========

to

==========
net: Add some metrics on reuse of idle sockets.

We're investigating keeping fewer of them around, and/or timing them out
more aggressively to decrease memory usage.

BUG=621197
==========

[mmenke, 2016-06-21 21:50:00]

On 2016/06/21 21:45:54, csharrison wrote:
> Oh, could you also update the title? s/metrcs/metrics/g

Done.

[mmenke, 2016-06-21 21:50:56]

mmenke@chromium.org changed reviewers:
+ mpearson@chromium.org

[mmenke, 2016-06-21 21:50:57]

[+mpearson]:  Please review histograms.xml.  Thanks!

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

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
File net/socket/client_socket_pool_base.cc (right):

https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
net/socket/client_socket_pool_base.cc:992:
UMA_HISTOGRAM_COUNTS_100("Net.Socket.NumIdleSockets",
On 2016/06/21 21:44:46, mmenke wrote:
> On 2016/06/21 21:40:20, csharrison wrote:
> > On 2016/06/21 21:34:45, mmenke wrote:
> > > On 2016/06/21 21:23:20, csharrison wrote:
> > > > 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.
> > > 
> > > 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.
> > 
> > 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 :)
> 
> 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.

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

[mmenke, 2016-06-21 21:53:34]

On 2016/06/21 21:52:07, csharrison wrote:
>
https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
> File net/socket/client_socket_pool_base.cc (right):
> 
>
https://codereview.chromium.org/2086903003/diff/1/net/socket/client_socket_po...
> net/socket/client_socket_pool_base.cc:992:
> UMA_HISTOGRAM_COUNTS_100("Net.Socket.NumIdleSockets",
> On 2016/06/21 21:44:46, mmenke wrote:
> > On 2016/06/21 21:40:20, csharrison wrote:
> > > On 2016/06/21 21:34:45, mmenke wrote:
> > > > On 2016/06/21 21:23:20, csharrison wrote:
> > > > > 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.
> > > > 
> > > > 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.
> > > 
> > > 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 :)
> > 
> > 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.
> 
> Good point, though we would like to see what the effect of a idle socket limit
> would be (i.e. approximate measure of wins).

This is actually more a measure of what we could set a cap at, rather than an
indication of how much we'd gain by setting a  cap.

[Mark P, 2016-06-21 22:18:36]

lgtm with one minor comment

https://codereview.chromium.org/2086903003/diff/40001/tools/metrics/histogram...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/2086903003/diff/40001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:30075: +    Seconds a socket was idle
before it was reused. Does not record the times
perhaps between these sentences add:
Emitted upon reuse.

[mmenke, 2016-06-22 17:35:22]

Thank you both!

https://codereview.chromium.org/2086903003/diff/40001/tools/metrics/histogram...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/2086903003/diff/40001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:30075: +    Seconds a socket was idle
before it was reused. Does not record the times
On 2016/06/21 22:18:36, Mark P wrote:
> perhaps between these sentences add:
> Emitted upon reuse.

Done.

[mmenke, 2016-06-22 17:35:27]

The CQ bit was checked by mmenke@chromium.org

[mmenke, 2016-06-22 17:35:27]

The patchset sent to the CQ was uploaded after l-g-t-m from
csharrison@chromium.org, mpearson@chromium.org
Link to the patchset: https://codereview.chromium.org/2086903003/#ps60001
(title: "Response to comments")

[commit-bot: I haz the power, 2016-06-22 17:36:20]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/2086903003/60001

[commit-bot: I haz the power, 2016-06-22 18:48:56]

Description was changed from

==========
net: Add some metrics on reuse of idle sockets.

We're investigating keeping fewer of them around, and/or timing them out
more aggressively to decrease memory usage.

BUG=621197
==========

to

==========
net: Add some metrics on reuse of idle sockets.

We're investigating keeping fewer of them around, and/or timing them out
more aggressively to decrease memory usage.

BUG=621197
==========

[commit-bot: I haz the power, 2016-06-22 18:48:57]

Committed patchset #4 (id:60001)

[commit-bot: I haz the power, 2016-06-22 18:54:52]

Description was changed from

==========
net: Add some metrics on reuse of idle sockets.

We're investigating keeping fewer of them around, and/or timing them out
more aggressively to decrease memory usage.

BUG=621197
==========

to

==========
net: Add some metrics on reuse of idle sockets.

We're investigating keeping fewer of them around, and/or timing them out
more aggressively to decrease memory usage.

BUG=621197

Committed: https://crrev.com/a9d6c7d3dc9a4a700ab9bf0aa71581540e014cd3
Cr-Commit-Position: refs/heads/master@{#401370}
==========

[commit-bot: I haz the power, 2016-06-22 18:54:53]

Patchset 4 (id:??) landed as
https://crrev.com/a9d6c7d3dc9a4a700ab9bf0aa71581540e014cd3
Cr-Commit-Position: refs/heads/master@{#401370}