Add net-log entries when HttpStream jobs are forced to wait, and when they're delayed and resumed.

net/http/http_stream_factory_impl_job.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/http/http_stream_factory_impl_job.h"
 
 #include <algorithm>
 #include <string>
 
 #include "base/bind.h"
@@ skipping 116 matching lines @@
   std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
   if (source.IsValid())
     source.AddToEventParameters(dict.get());
   dict->SetString("original_url", original_url->GetOrigin().spec());
   dict->SetString("url", url->GetOrigin().spec());
   dict->SetString("alternative_service", alternative_service->ToString());
   dict->SetString("priority", RequestPriorityToString(priority));
   return std::move(dict);
 }
 
+// Returns parameters associated with the start of a HTTP stream job.
+std::unique_ptr<base::Value> NetLogHttpStreamJobWaitingCallback(

[eroman, 2017/02/14 21:18:36]

Have you considered using NetLog::BoolCallback() ? (can save writing some boiler
plate for simple cases like this).
(https://cs.chromium.org/chromium/src/net/log/net_log.h?q=net_log.h&dr=CSs&l=172)

[Ryan Hamilton, 2017/02/14 21:42:37]

Oh nice! I didn't know that existed. Thanks!

+    bool should_wait,
+    NetLogCaptureMode /* capture_mode */) {
+  std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
+  dict->SetBoolean("should_wait", should_wait);
+  return std::move(dict);
+}
+
 // Returns parameters associated with the Proto (with NPN negotiation) of a HTTP
 // stream.
 std::unique_ptr<base::Value> NetLogHttpStreamProtoCallback(
     NextProto negotiated_protocol,
     NetLogCaptureMode /* capture_mode */) {
   std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
 
   dict->SetString("proto", NextProtoToString(negotiated_protocol));
   return std::move(dict);
 }
@@ skipping 655 matching lines @@
   return session_->IsQuicEnabled() &&
          (base::ContainsKey(session_->params().origins_to_force_quic_on,
                             HostPortPair()) ||
           base::ContainsKey(session_->params().origins_to_force_quic_on,
                             destination_)) &&
          proxy_info_.is_direct() && origin_url_.SchemeIs(url::kHttpsScheme);
 }
 
 int HttpStreamFactoryImpl::Job::DoWait() {
   next_state_ = STATE_WAIT_COMPLETE;
-  if (delegate_->ShouldWait(this))
+  bool should_wait = delegate_->ShouldWait(this);
+  net_log_.BeginEvent(
+      NetLogEventType::HTTP_STREAM_JOB_WAITING,
+      base::Bind(&NetLogHttpStreamJobWaitingCallback, should_wait));
+  if (should_wait)
     return ERR_IO_PENDING;
 
   return OK;
 }
 
 int HttpStreamFactoryImpl::Job::DoWaitComplete(int result) {
+  net_log_.EndEvent(NetLogEventType::HTTP_STREAM_JOB_WAITING);
   DCHECK_EQ(OK, result);
   next_state_ = STATE_INIT_CONNECTION;
   return OK;
 }
 
 int HttpStreamFactoryImpl::Job::DoInitConnection() {
   int result = DoInitConnectionImpl();
   if (result != ERR_SPDY_SESSION_ALREADY_EXISTS)
     delegate_->OnConnectionInitialized(this, result);
 
@@ skipping 705 matching lines @@
 
   ConnectionAttempts socket_attempts = connection_->connection_attempts();
   if (connection_->socket()) {
     connection_->socket()->GetConnectionAttempts(&socket_attempts);
   }
 
   delegate_->AddConnectionAttemptsToRequest(this, socket_attempts);
 }
 
 }  // namespace net