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

net/quic/quic_crypto_client_stream.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/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"
 #include "net/quic/crypto/crypto_utils.h"
 #include "net/quic/crypto/null_encrypter.h"
 #include "net/quic/crypto/proof_verifier.h"
 #include "net/quic/crypto/proof_verifier_chromium.h"
 #include "net/quic/crypto/quic_server_info.h"
 #include "net/quic/quic_protocol.h"
 #include "net/quic/quic_session.h"
@@ skipping 398 matching lines @@
 }
 
 int QuicCryptoClientStream::DoLoadQuicServerInfo(
     QuicCryptoClientConfig::CachedState* cached) {
   next_state_ = STATE_SEND_CHLO;
   QuicServerInfo* quic_server_info = cached->quic_server_info();
   if (!quic_server_info) {
     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;
 
   // TODO(rtenneti): If multiple tabs load the same URL, all requests except for

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

I think this TODO is not correct.  We will only have a single
QuicStreamFactory::Job for a given origin.  We will not have multiple jobs for
the same origin, and hence, we will not have more than one session at a time. 
Does that sound right to you?

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

I think comment shouldn't have said same URL. I meant to say same server
hostname but different ports (different host_port_pairs for the same host).

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

Done.

   // the first request send InchoateClientHello. Fix the code to handle multiple
   // requests. A possible solution is to wait for the first request to finish
   // and use the data from the disk cache for all requests.
   // We may need to call quic_server_info->Persist later.
   // quic_server_info->Persist requires quic_server_info to be ready, so we
   // always call WaitForDataReady, even though we might have initialized
   // |cached| config from the cached state for a canonical hostname.
   int rv = quic_server_info->WaitForDataReady(
       base::Bind(&QuicCryptoClientStream::OnIOComplete,
                  weak_factory_.GetWeakPtr()));
 
   if (rv != ERR_IO_PENDING) {
     disk_cache_load_result_ = rv;
   }
   return rv;
 }
 
 void QuicCryptoClientStream::DoLoadQuicServerInfoComplete(
     QuicCryptoClientConfig::CachedState* cached) {
   LoadQuicServerInfo(cached);
   QuicServerInfo::State* state = cached->quic_server_info()->mutable_state();
   state->Clear();
 }
 
 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.
   if (!cached->IsEmpty()) {
     return;
   }
 
   if (disk_cache_load_result_ != OK || !cached->LoadQuicServerInfo(
           session()->connection()->clock()->WallNow())) {
     // It is ok to proceed to STATE_SEND_CHLO when we cannot load QuicServerInfo
     // from the disk cache.
     DCHECK(cached->IsEmpty());
     DVLOG(1) << "Empty server_config";
     return;
   }
 
   ProofVerifier* verifier = crypto_config_->proof_verifier();
   if (!verifier) {
     // If no verifier is set then we don't check the certificates.
     cached->SetProofValid();
   } else if (!cached->signature().empty()) {
     next_state_ = STATE_VERIFY_PROOF;
   }
 }
 
 }  // namespace net