QUIC - histograms to measure the time spent to read QUIC sever

net/quic/quic_crypto_client_stream.cc

Index: net/quic/quic_crypto_client_stream.cc
diff --git a/net/quic/quic_crypto_client_stream.cc b/net/quic/quic_crypto_client_stream.cc
index 237c1d378f07f5deb83a666f895b3f104fbc74a3..764bb30c93a3acc25da35ee673ac92e275ec5c20 100644
--- a/net/quic/quic_crypto_client_stream.cc
+++ b/net/quic/quic_crypto_client_stream.cc
@@ -4,6 +4,8 @@
 
 #include "net/quic/quic_crypto_client_stream.h"
 
+#include "base/metrics/histogram.h"
+#include "base/time/time.h"
 #include "net/base/completion_callback.h"
 #include "net/base/net_errors.h"
 #include "net/quic/crypto/crypto_protocol.h"
@@ -422,6 +424,7 @@ int QuicCryptoClientStream::DoLoadQuicServerInfo(
     return OK;
   }
 
+  quic_server_info->set_read_start_time(base::TimeTicks::Now());

[Ryan Hamilton, 2014/03/07 04:41:04]

I would have expected that this start time would be saved on the crypto stream,
perhaps in a member. Is there a performance or correctness reason for putting
this in the quic_server_info.

[ramant (doing other things), 2014/03/07 06:09:28]

We share the same quic_server_info (server config) for URLs to the same server
but different ports (www.google.com:80 and www.google.com:443) and thus thought
it is better to save the time in quic_server_info. 

I think there are two different quic sessions one for 80 and another for 443 but
they share the same QuicCrytoClientConfig:CachedState (QuicServerInfo). 

If you don't mind, could we go over the QuicStreamFactory's code tomorrow.

thanks much.

[ramant (doing other things), 2014/03/07 16:23:57]

We go to disk only once for each hostname. After the initial access, we always
get data from memory.

We can see with this histogram what is the worst case performace (or the
performance hit for outliers).

Done.

[ramant (doing other things), 2014/03/07 21:57:15]

Changed the code to collect stats when we load server config from disk cache (as
we had discussed this morning).

   generation_counter_ = cached->generation_counter();
   next_state_ = STATE_LOAD_QUIC_SERVER_INFO_COMPLETE;
 
@@ -454,6 +457,9 @@ void QuicCryptoClientStream::LoadQuicServerInfo(
     QuicCryptoClientConfig::CachedState* cached) {
   next_state_ = STATE_SEND_CHLO;
 
+  UMA_HISTOGRAM_TIMES("Net.QuicServerInfo.DiskCacheReadTime",
+      base::TimeTicks::Now() - cached->quic_server_info()->read_start_time());
+
   // If someone else already saved a server config, we don't want to overwrite
   // it. Also, if someone else saved a server config and then cleared it (so
   // cached->IsEmpty() is true), we still want to load from QuicServerInfo.