Instrumenting SSL_do_handshake and UpdateServerCert to find jank

Instrumenting SSL_do_handshake and UpdateServerCert to find jank.

Last instrumentations showed that:
SSL_do_handshake call is 17 jph (I mean janks per startup-hour)
This excludes all callbacks that SSL_do_handshake can invoke.

SSLClientSocketOpenSSL::UpdateServerCert is 5.8 jph.

Adding instrumentations to differentiate the cert from no-cert cases.
Also instrumenting SSLClientSocketOpenSSL::UpdateServerCert.

BUG=424386
Committed: https://crrev.com/5a24328a073d1cf48b43c33def640c2f3a5dadad
Cr-Commit-Position: refs/heads/master@{#309590}

[vadimt, 2014-12-23 00:04:45]

vadimt@chromium.org changed reviewers:
+ rsleevi@chromium.org

[vadimt, 2014-12-23 00:04:45]

rsleevi@, please review

[Ryan Sleevi, 2014-12-23 00:12:30]

https://codereview.chromium.org/787913003/diff/1/net/socket/ssl_client_socket...
File net/socket/ssl_client_socket_openssl.cc (right):

https://codereview.chromium.org/787913003/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:928: static bool is_first_handshake =
true;
Not LGTM.

SSLClientSocketOpenSSL can be used from multiple threads, even if a single
socket instance can not. You need to use thread-safe primitives to measure this.

[vadimt, 2014-12-23 00:56:13]

https://codereview.chromium.org/787913003/diff/1/net/socket/ssl_client_socket...
File net/socket/ssl_client_socket_openssl.cc (right):

https://codereview.chromium.org/787913003/diff/1/net/socket/ssl_client_socket...
net/socket/ssl_client_socket_openssl.cc:928: static bool is_first_handshake =
true;
Done.

The logic behind the reworked implementation is:
Suppose several first handshakes start in parallel. I want all of them to be
counted as DoHandshake1_1 (i.e. the first execution) because they all should be
blocked by the initialization.

This is why I moved setting is_first_handshake to "false" after the
SSL_do_handshake call in the first branch.

I also converted to thread-safe types and operations. Don't think we need
barriers here given that the way we differentiate between first and non-first
executions is already non-deterministic, and added the non-determinism added by
not using barriers shouldn't be substantial.

[Ryan Sleevi, 2014-12-23 01:11:25]

https://codereview.chromium.org/787913003/diff/40001/net/socket/ssl_client_so...
File net/socket/ssl_client_socket_openssl.cc (right):

https://codereview.chromium.org/787913003/diff/40001/net/socket/ssl_client_so...
net/socket/ssl_client_socket_openssl.cc:945: }
Still Not LGTM.

The argument you make for coalescing the multiple initializations violates the
principle of least surprise. It's no longer "first" initialization, it's one of
many.

At the least, "is_first_handshake" should be renamed to something more
meaningful. initialization_complete ?

Before going this route, may I suggest you look at
https://code.google.com/p/chromium/codesearch#chromium/src/net/ssl/openssl_pl...

The cost spent in those methods (in particular, RsaMethodSign / EcdsaMethodSign)
will count against the SSL_do_handshake time, and we expect those methods to be
slow. Note that you're already accounting for the FetchClientCertPrivateKey &
initialization, which is currently bucketed under
https://code.google.com/p/chromium/codesearch#chromium/src/net/socket/ssl_cli...

[Ryan Sleevi, 2014-12-23 01:22:19]

On 2014/12/23 01:11:25, Ryan Sleevi wrote:
>
https://codereview.chromium.org/787913003/diff/40001/net/socket/ssl_client_so...
> File net/socket/ssl_client_socket_openssl.cc (right):
> 
>
https://codereview.chromium.org/787913003/diff/40001/net/socket/ssl_client_so...
> net/socket/ssl_client_socket_openssl.cc:945: }
> Still Not LGTM.
> 
> The argument you make for coalescing the multiple initializations violates the
> principle of least surprise. It's no longer "first" initialization, it's one
of
> many.
> 
> At the least, "is_first_handshake" should be renamed to something more
> meaningful. initialization_complete ?
> 
> Before going this route, may I suggest you look at
>
https://code.google.com/p/chromium/codesearch#chromium/src/net/ssl/openssl_pl...
> 
> The cost spent in those methods (in particular, RsaMethodSign /
EcdsaMethodSign)
> will count against the SSL_do_handshake time, and we expect those methods to
be
> slow. Note that you're already accounting for the FetchClientCertPrivateKey &
> initialization, which is currently bucketed under
>
https://code.google.com/p/chromium/codesearch#chromium/src/net/socket/ssl_cli...

Even more explicitly: If you can detect the difference between startup-janks
when one of those methods (RsaMethodSign / EcdsaMethodSign) is used vs
startup-janks where it isn't, that'd be quite helpful.

[vadimt, 2014-12-23 03:12:43]

Do we want to differentiate 2 cases:
1. (RsaMethodSign / EcdsaMethodSign) is used
2. (RsaMethodSign / EcdsaMethodSign) not used

or 3 cases:
1. First time && (RsaMethodSign / EcdsaMethodSign) is used
2. First time && (RsaMethodSign / EcdsaMethodSign) not used
3. Not first time
?

[Ryan Sleevi, 2014-12-23 03:25:37]

On 2014/12/23 03:12:43, vadimt wrote:
> Do we want to differentiate 2 cases:
> 1. (RsaMethodSign / EcdsaMethodSign) is used
> 2. (RsaMethodSign / EcdsaMethodSign) not used
> 
> or 3 cases:
> 1. First time && (RsaMethodSign / EcdsaMethodSign) is used
> 2. First time && (RsaMethodSign / EcdsaMethodSign) not used
> 3. Not first time
> ?

I guess four.

initializing vs not-initializing <-- this measures whatever OpenSSL
initialization overhead may exist
*MethodSign is used vs not

However, if that's too complex, then the theory I'm putting forth is your first
option - that is, measure janks for when we are using a client cert vs janks
when we aren't.

You can measure that two ways - you could simply look within the
SSLCLientSocketOpenSSL to see if a client cert is provided (in the SSLConfig)
versus when it isn't - or you could look at the *MethodSign and measure their
precise jankiness (though there is some initialization overhead, it shouldn't
show up in any jank measures because by the time a client cert is selected, the
libs MUST have been loaded)

[Ryan Sleevi, 2014-12-23 03:28:14]

The below will help you distinguish w/ and w/o client certs. We could then dive
into the per-signing overhead (or you could instrument that separately), but
that may help us bucket better.

https://codereview.chromium.org/787913003/diff/40001/net/socket/ssl_client_so...
File net/socket/ssl_client_socket_openssl.cc (right):

https://codereview.chromium.org/787913003/diff/40001/net/socket/ssl_client_so...
net/socket/ssl_client_socket_openssl.cc:945: }
Something like
if (ssl_config_.send_client_cert && ssl_config_.client_cert.get()) {
  tracked_objects::... ("DoHandshake_WithCert");
  rv = SSL_do_handshake(ssl_);
} else {
  tracked_objects::...("DoHandshake_WithoutCert");
  rv = SSL_do_handshake(ssl_);
}

[Ryan Sleevi, 2014-12-23 03:29:12]

On 2014/12/23 03:25:37, Ryan Sleevi wrote:
> On 2014/12/23 03:12:43, vadimt wrote:
> > Do we want to differentiate 2 cases:
> > 1. (RsaMethodSign / EcdsaMethodSign) is used
> > 2. (RsaMethodSign / EcdsaMethodSign) not used
> > 
> > or 3 cases:
> > 1. First time && (RsaMethodSign / EcdsaMethodSign) is used
> > 2. First time && (RsaMethodSign / EcdsaMethodSign) not used
> > 3. Not first time
> > ?
> 
> I guess four.
> 
> initializing vs not-initializing <-- this measures whatever OpenSSL
> initialization overhead may exist
> *MethodSign is used vs not
> 
> However, if that's too complex, then the theory I'm putting forth is your
first
> option - that is, measure janks for when we are using a client cert vs janks
> when we aren't.
> 
> You can measure that two ways - you could simply look within the
> SSLCLientSocketOpenSSL to see if a client cert is provided (in the SSLConfig)
> versus when it isn't - or you could look at the *MethodSign and measure their
> precise jankiness (though there is some initialization overhead, it shouldn't
> show up in any jank measures because by the time a client cert is selected,
the
> libs MUST have been loaded)

Oh, I should add that annotating UpdateServerCert still SGTM. So let's pivot to
"when a client cert is used" & "when the cert is updated" [which will force
libraries to load if they haven't already been by sending a client cert]

[vadimt, 2014-12-23 15:57:53]

Cool, I dropped the initialization recognition and added cert / no cert
recognition.
I also instrumented *MethodSign, which may be redundant, but won't hurt.

[Ryan Sleevi, 2014-12-23 18:56:37]

Please rewrite the description to match what you are instrumenting, and then
LGTM.

[vadimt, 2014-12-23 19:21:00]

Done

[vadimt, 2014-12-23 19:21:07]

The CQ bit was checked by vadimt@chromium.org

[commit-bot: I haz the power, 2014-12-23 19:21:52]

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

[commit-bot: I haz the power, 2014-12-23 21:15:24]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2014-12-23 21:15:25]

Try jobs failed on following builders:
  win_chromium_x64_rel_ng on tryserver.chromium.win
(http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_x64_...)

[vadimt, 2014-12-23 21:48:41]

The CQ bit was checked by vadimt@chromium.org

[commit-bot: I haz the power, 2014-12-23 21:49:04]

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

[commit-bot: I haz the power, 2014-12-24 00:26:47]

Committed patchset #4 (id:60001)

[commit-bot: I haz the power, 2014-12-24 00:27:42]

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