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

net/socket/ssl_client_socket_impl.cc

Index: net/socket/ssl_client_socket_impl.cc
diff --git a/net/socket/ssl_client_socket_impl.cc b/net/socket/ssl_client_socket_impl.cc
index 4e3f71311c7c2a4974e2337bc0f583724f3b8a46..f39ef6f4a2fec096af1826a50c92091868030395 100644
--- a/net/socket/ssl_client_socket_impl.cc
+++ b/net/socket/ssl_client_socket_impl.cc
@@ -1997,6 +1997,8 @@ int SSLClientSocketImpl::TokenBindingParse(const uint8_t* contents,
 }
 
 void SSLClientSocketImpl::LogConnectEndEvent(int rv) {
+  SSLContext::GetInstance()->session_cache()->DecrementLookupCount(
+      GetSessionCacheKey(), negotiated_protocol_ == kProtoHTTP2);

[davidben, 2017/01/17 20:16:42]

Doing it in LogConnectEndEvent seems wrong. If Init() fails, you never did an
SSL_SESSION lookup. This gets called on failed connects too. I would think we
only need to do anything on successful connects (on failed connect, that would
still count as "using" the session since we've leaked it).

On successful connect, we would expect the TLS 1.3 server to mint us a new
ticket, so we should be able to reset the counter to zero, right?

[nharper, 2017/01/17 20:33:16]

The lookup happens in Init(), and it can return ERR_UNEXPECTED after that lookup
(all of the failures of Init() appear to be ERR_UNEXPECTED), so I need to
decrement the counter after Lookup.

How about adding a member to SSLClientSocketImpl bool log_session_lookup_ which
gets set to true after Lookup and false after DecrementLookupCount. I can also
add to the d'tor a check of that bool and a call to DecrementLookupCount in case
it's possible to start the connection and then destroy the socket before this
function gets called.

Other suggestions for where to put the DecrementLookupCount call to ensure it
gets called exactly once per Lookup are welcome.
We expect the server to mint a single ticket (although it could mint more), so
we decrement by one - the new ticket replaces the one we just used for this
connection.

[davidben, 2017/01/17 21:27:02]

Oh, I see. You're tracking active lookups. But if Init() fails after an active
lookup, we don't actually get a fresh session or anything, so if we're
simulating what would happen with single use tickets, that should simulate a
lookup we never get back.
Don't we mint two tickets? Though there was talk of whether we should just be
minting one. My thought was, just so we're only controlling one parameter at a
time, we'd act as if the server gave us an infinite number of tickets, record at
that point, and otherwise just increment the counter on lookup. Then we don't
need to hook too many things.

That would tell us how many times a session gets used in parallel before it is
used successfully.

   if (rv != OK) {
     net_log_.EndEventWithNetErrorCode(NetLogEventType::SSL_CONNECT, rv);
     return;