Server push cancellation: add NetLogs to track cache lookup transaction

net/http/http_cache_lookup_manager.cc

Index: net/http/http_cache_lookup_manager.cc
diff --git a/net/http/http_cache_lookup_manager.cc b/net/http/http_cache_lookup_manager.cc
index d4d8a2e023e2de5a99a0a548d4a3187959a0c7b7..370f4fdab0c8a9e4aca19d060eb5a0115c6cf380 100644
--- a/net/http/http_cache_lookup_manager.cc
+++ b/net/http/http_cache_lookup_manager.cc
@@ -5,54 +5,82 @@
 #include "net/http/http_cache_lookup_manager.h"
 
 #include "base/memory/ptr_util.h"
+#include "base/values.h"
 #include "net/base/load_flags.h"
 
 namespace net {
 
+// Returns parameters associated with the start of a server push lookup
+// transaction.
+std::unique_ptr<base::Value> NetLogPushLookupTransactionCallback(
+    const NetLogSource& source,
+    std::string push_url,
+    NetLogCaptureMode /* capture_mode */) {
+  std::unique_ptr<base::DictionaryValue> dict(new base::DictionaryValue());
+  if (source.IsValid())
+    source.AddToEventParameters(dict.get());
+  dict->SetString("push_url", push_url);
+  return std::move(dict);
+}
+
 HttpCacheLookupManager::LookupTransaction::LookupTransaction(
-    std::unique_ptr<ServerPushHelper> server_push_helper)
+    std::unique_ptr<ServerPushHelper> server_push_helper,
+    NetLog* net_log)
     : push_helper_(std::move(server_push_helper)),
       request_(new HttpRequestInfo()),
-      transaction_(nullptr) {}
+      transaction_(nullptr),
+      net_log_(
+          NetLogWithSource::Make(net_log,
+                                 NetLogSourceType::PUSH_LOOKUP_TRANSACTION)) {}
 
-HttpCacheLookupManager::LookupTransaction::~LookupTransaction() {}
+HttpCacheLookupManager::LookupTransaction::~LookupTransaction() {
+  net_log_.EndEvent(NetLogEventType::PUSH_LOOKUP_TRANSACTION);
+}
 
 int HttpCacheLookupManager::LookupTransaction::StartLookup(
     HttpCache* cache,
     const CompletionCallback& callback,
-    const NetLogWithSource& net_log) {
+    const NetLogWithSource& source) {
+  net_log_.BeginEvent(
+      NetLogEventType::PUSH_LOOKUP_TRANSACTION,
+      base::Bind(&NetLogPushLookupTransactionCallback, source.source(),
+                 push_helper_->GetURL().spec()));
+
   request_->url = push_helper_->GetURL();
   request_->method = "GET";
   request_->load_flags = LOAD_ONLY_FROM_CACHE | LOAD_SKIP_CACHE_VALIDATION;
   cache->CreateTransaction(DEFAULT_PRIORITY, &transaction_);
-  return transaction_->Start(request_.get(), callback, net_log);
+  return transaction_->Start(request_.get(), callback, net_log_);
 }
 
 void HttpCacheLookupManager::LookupTransaction::CancelPush() {
+  net_log_.AddEvent(NetLogEventType::PUSH_FOUND_IN_CACHE);

[Ryan Hamilton, 2017/02/06 23:34:55]

I realize that CancelPush() is called from OnLookupComplete when the item is in
the cache, but semantically, it would be clearer to move this down there. You
might also consider logging both when the item is found and when it is not found
(perhaps with a bool "found"?).

[Zhongyi Shi, 2017/02/07 00:00:24]

Well, in this CL, each push lookup transaction will have a separate NetLog
"PUSH_LOOKUP_TRANSACTION" while the manager doesn't own a NetLog. That's why the
cancel event is only logged in the transaction.

If we want to also log the event in the manager, we could introduce a new Source
type NetLog, "CACHE_LOOKUP_MANAGER", which notes the start of all the
PUSH_LOOKUP_TRANSACTION, and the finish of PUSH_LOOKUP_TRANSACTION, as well as
the cancel events. How does that sound?

[Ryan Hamilton, 2017/02/07 00:10:49]

Oh, I see. I missed that CancelPush and OnLookupComplete are in different
classes. In that case, I would be inclined to rename
LookupTransaction::CancelPush ot LookupTransaction::OnLookupComplete(bool
found_in_cache) (or some such). Then in the body of this method, I'd log in both
cases. (but only call the helper's cancel method if it actually was found.  What
do you think?

[Zhongyi Shi, 2017/02/07 06:01:08]

That's a good idea! Done. Now we should always log the result of the push lookup
transaction.

   DCHECK(push_helper_.get());
   push_helper_->Cancel();
 }
 
 HttpCacheLookupManager::HttpCacheLookupManager(HttpCache* http_cache,
-                                               const NetLogWithSource& net_log)
+                                               NetLog* net_log)
     : net_log_(net_log), http_cache_(http_cache), weak_factory_(this) {}
 
 HttpCacheLookupManager::~HttpCacheLookupManager() {}
 
 void HttpCacheLookupManager::OnPush(
-    std::unique_ptr<ServerPushHelper> push_helper) {
+    std::unique_ptr<ServerPushHelper> push_helper,
+    const NetLogWithSource& source) {
   GURL pushed_url = push_helper->GetURL();
 
   // There's a pending lookup transaction sent over already.
   if (base::ContainsKey(lookup_transactions_, pushed_url))
     return;
 
-  auto lookup = base::MakeUnique<LookupTransaction>(std::move(push_helper));
+  auto lookup =
+      base::MakeUnique<LookupTransaction>(std::move(push_helper), net_log_);
 
   int rv = lookup->StartLookup(
       http_cache_, base::Bind(&HttpCacheLookupManager::OnLookupComplete,
                               weak_factory_.GetWeakPtr(), pushed_url),
-      net_log_);
+      source);
 
   if (rv == ERR_IO_PENDING)
     lookup_transactions_[pushed_url] = std::move(lookup);