Add NetLog event logging to cookie_monster.cc

This CL is split off rdsmith@'s CL at
https://chromium-review.googlesource.com/c/chromium/src/+/925181

This CL only adds the logging code for events, but uses a null NetLog.
A followup CL will modify the CookieStore constructor to pass in a non-null
NetLog.

Bug: 801910
Change-Id: Icd40aa206055c82a4e84ddb66c8547b69ec662ff
Reviewed-on: https://chromium-review.googlesource.com/1170594Reviewed-by: Maks Orlovich <morlovich@chromium.org>
Commit-Queue: Helen Li <xunjieli@chromium.org>
Cr-Commit-Position: refs/heads/master@{#582603}

net/BUILD.gn

@@ -625,6 +625,8 @@ component("net") {
       "cookies/cookie_monster.h",
       "cookies/cookie_monster_change_dispatcher.cc",
       "cookies/cookie_monster_change_dispatcher.h",
+      "cookies/cookie_monster_netlog_params.cc",
+      "cookies/cookie_monster_netlog_params.h",
       "cookies/cookie_options.cc",
       "cookies/cookie_options.h",
       "cookies/cookie_store.cc",

net/cookies/cookie_change_dispatcher.cc

@@ -6,6 +6,34 @@
 
 namespace net {
 
+const char* CookieChangeCauseToString(CookieChangeCause cause) {
+  const char* cause_string = "INVALID";
+  switch (cause) {
+    case CookieChangeCause::INSERTED:
+      cause_string = "inserted";
+      break;
+    case CookieChangeCause::EXPLICIT:
+      cause_string = "explicit";
+      break;
+    case CookieChangeCause::UNKNOWN_DELETION:
+      cause_string = "unknown";
+      break;
+    case CookieChangeCause::OVERWRITE:
+      cause_string = "overwrite";
+      break;
+    case CookieChangeCause::EXPIRED:
+      cause_string = "expired";
+      break;
+    case CookieChangeCause::EVICTED:
+      cause_string = "evicted";
+      break;
+    case CookieChangeCause::EXPIRED_OVERWRITE:
+      cause_string = "expired_overwrite";
+      break;
+  }
+  return cause_string;
+}
+
 bool CookieChangeCauseIsDeletion(CookieChangeCause cause) {
   return cause != CookieChangeCause::INSERTED;
 }

net/cookies/cookie_change_dispatcher.h

@@ -38,9 +38,12 @@ enum class CookieChangeCause {
   EXPIRED_OVERWRITE
 };
 
+// Return a string corresponding to the change cause.  For debugging/logging.
+NET_EXPORT const char* CookieChangeCauseToString(CookieChangeCause cause);
+
 // Returns whether |cause| is one that could be a reason for deleting a cookie.
 // This function assumes that ChangeCause::EXPLICIT is a reason for deletion.
-bool NET_EXPORT CookieChangeCauseIsDeletion(CookieChangeCause cause);
+NET_EXPORT bool CookieChangeCauseIsDeletion(CookieChangeCause cause);
 
 // Called when a cookie is changed in a CookieStore.
 //

net/cookies/cookie_constants.cc

@@ -17,6 +17,7 @@ const char kPriorityHigh[] = "high";
 
 const char kSameSiteLax[] = "lax";
 const char kSameSiteStrict[] = "strict";
+const char kSameSiteDefault[] = "default";
 
 }  // namespace
 
@@ -47,6 +48,18 @@ CookiePriority StringToCookiePriority(const std::string& priority) {
   return COOKIE_PRIORITY_DEFAULT;
 }
 
+std::string CookieSameSiteToString(CookieSameSite same_site) {
+  switch (same_site) {
+    case CookieSameSite::LAX_MODE:
+      return kSameSiteLax;
+    case CookieSameSite::STRICT_MODE:
+      return kSameSiteStrict;
+    case CookieSameSite::DEFAULT_MODE:
+      return kSameSiteDefault;
+  }
+  return "INVALID";
+}
+
 CookieSameSite StringToCookieSameSite(const std::string& same_site) {
   if (base::EqualsCaseInsensitiveASCII(same_site, kSameSiteLax))
     return CookieSameSite::LAX_MODE;

net/cookies/cookie_constants.h

@@ -37,6 +37,10 @@ NET_EXPORT std::string CookiePriorityToString(CookiePriority priority);
 // Defaults to COOKIE_PRIORITY_DEFAULT for empty or unrecognized strings.
 NET_EXPORT CookiePriority StringToCookiePriority(const std::string& priority);
 
+// Returns a string corresponding to the value of the |same_site| token.
+// Intended only for debugging/logging.
+NET_EXPORT std::string CookieSameSiteToString(CookieSameSite same_site);
+
 // Converts the Set-Cookie header SameSite token |same_site| to a
 // CookieSameSite. Defaults to CookieSameSite::DEFAULT_MODE for empty or
 // unrecognized strings.

net/cookies/cookie_monster.cc

@@ -67,8 +67,10 @@
 #include "net/base/registry_controlled_domains/registry_controlled_domain.h"
 #include "net/cookies/canonical_cookie.h"
 #include "net/cookies/cookie_monster_change_dispatcher.h"
+#include "net/cookies/cookie_monster_netlog_params.h"
 #include "net/cookies/cookie_util.h"
 #include "net/cookies/parsed_cookie.h"
+#include "net/log/net_log.h"
 #include "net/ssl/channel_id_service.h"
 #include "url/origin.h"
 
@@ -372,6 +374,9 @@ CookieMonster::CookieMonster(scoped_refptr<PersistentCookieStore> store,
       started_fetching_all_cookies_(false),
       finished_fetching_all_cookies_(false),
       seen_global_task_(false),
+      // TODO(https://crbug.com/801910): Hook up Cookies logging by using a
+      // non-null NetLog.
+      net_log_(NetLogWithSource::Make(nullptr, NetLogSourceType::COOKIE_STORE)),
       store_(std::move(store)),
       last_access_threshold_(last_access_threshold),
       channel_id_service_(channel_id_service),
@@ -393,6 +398,10 @@ CookieMonster::CookieMonster(scoped_refptr<PersistentCookieStore> store,
         base::Bind(&ChannelIDStore::Flush,
                    base::Unretained(channel_id_service_->GetChannelIDStore())));
   }
+  net_log_.BeginEvent(
+      NetLogEventType::COOKIE_STORE_ALIVE,
+      base::BindRepeating(&NetLogCookieMonsterConstructorCallback,
+                          store != nullptr, channel_id_service != nullptr));
 }
 
 // Asynchronous CookieMonster API
@@ -551,6 +560,9 @@ void CookieMonster::SetCookieableSchemes(
 void CookieMonster::SetPersistSessionCookies(bool persist_session_cookies) {
   DCHECK(thread_checker_.CalledOnValidThread());
   DCHECK(!initialized_);
+  net_log_.AddEvent(
+      NetLogEventType::COOKIE_STORE_SESSION_PERSISTENCE,
+      NetLog::BoolCallback("persistence", persist_session_cookies));
   persist_session_cookies_ = persist_session_cookies;
 }
 
@@ -615,6 +627,7 @@ CookieMonster::~CookieMonster() {
     InternalDeleteCookie(current_cookie_it, false /* sync_to_store */,
                          DELETE_COOKIE_DONT_RECORD);
   }
+  net_log_.EndEvent(NetLogEventType::COOKIE_STORE_ALIVE);
 }
 
 void CookieMonster::GetAllCookies(GetCookieListCallback callback) {
@@ -1142,6 +1155,10 @@ bool CookieMonster::DeleteAnyEquivalentCookie(
       skipped_secure_cookie = true;
       histogram_cookie_delete_equivalent_->Add(
           COOKIE_DELETE_EQUIVALENT_SKIPPING_SECURE);
+      net_log_.AddEvent(
+          NetLogEventType::COOKIE_STORE_COOKIE_REJECTED_SECURE,
+          base::BindRepeating(&NetLogCookieMonsterCookieRejectedSecure, cc,
+                              &ecc));
       // If the cookie is equivalent to the new cookie and wouldn't have been
       // skipped for being HTTP-only, record that it is a skipped secure cookie
       // that would have been deleted otherwise.
@@ -1162,6 +1179,10 @@ bool CookieMonster::DeleteAnyEquivalentCookie(
           << "Duplicate equivalent cookies found, cookie store is corrupted.";
       if (skip_httponly && cc->IsHttpOnly()) {
         skipped_httponly = true;
+        net_log_.AddEvent(
+            NetLogEventType::COOKIE_STORE_COOKIE_REJECTED_HTTPONLY,
+            base::BindRepeating(&NetLogCookieMonsterCookieRejectedHttponly, cc,
+                                &ecc));
       } else {
         histogram_cookie_delete_equivalent_->Add(
             COOKIE_DELETE_EQUIVALENT_FOUND);
@@ -1187,6 +1208,9 @@ CookieMonster::CookieMap::iterator CookieMonster::InternalInsertCookie(
   DCHECK(thread_checker_.CalledOnValidThread());
   CanonicalCookie* cc_ptr = cc.get();
 
+  net_log_.AddEvent(NetLogEventType::COOKIE_STORE_COOKIE_ADDED,
+                    base::BindRepeating(&NetLogCookieMonsterCookieAdded,
+                                        cc.get(), sync_to_store));
   if ((cc_ptr->IsPersistent() || persist_session_cookies_) && store_.get() &&
       sync_to_store)
     store_->AddCookie(*cc_ptr);
@@ -1362,10 +1386,16 @@ void CookieMonster::InternalDeleteCookie(CookieMap::iterator it,
       << "InternalDeleteCookie()"
       << ", cause:" << deletion_cause << ", cc: " << cc->DebugString();
 
+  ChangeCausePair mapping = kChangeCauseMapping[deletion_cause];
+  if (deletion_cause != DELETE_COOKIE_DONT_RECORD) {
+    net_log_.AddEvent(NetLogEventType::COOKIE_STORE_COOKIE_DELETED,
+                      base::BindRepeating(&NetLogCookieMonsterCookieDeleted, cc,
+                                          mapping.cause, sync_to_store));
+  }
+
   if ((cc->IsPersistent() || persist_session_cookies_) && store_.get() &&
       sync_to_store)
     store_->DeleteCookie(*cc);
-  ChangeCausePair mapping = kChangeCauseMapping[deletion_cause];
   change_dispatcher_.DispatchChange(*cc, mapping.cause, mapping.notify);
   cookies_.erase(it);
 }

net/cookies/cookie_monster.h

@@ -31,6 +31,7 @@
 #include "net/cookies/cookie_constants.h"
 #include "net/cookies/cookie_monster_change_dispatcher.h"
 #include "net/cookies/cookie_store.h"
+#include "net/log/net_log_with_source.h"
 #include "url/gurl.h"
 
 namespace base {
@@ -617,6 +618,8 @@ class NET_EXPORT CookieMonster : public CookieStore {
   // for typical use.
   bool seen_global_task_;
 
+  NetLogWithSource net_log_;
+
   scoped_refptr<PersistentCookieStore> store_;
 
   base::Time last_time_seen_;

net/cookies/cookie_monster_netlog_params.cc

+// Copyright 2018 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/cookies/cookie_monster_netlog_params.h"
+
+#include "net/cookies/cookie_constants.h"
+#include "net/cookies/cookie_store.h"
+
+namespace net {
+
+std::unique_ptr<base::Value> NetLogCookieMonsterConstructorCallback(
+    bool persistent_store,
+    bool channel_id_service,
+    NetLogCaptureMode /* capture_mode */) {
+  std::unique_ptr<base::Value> dict =
+      std::make_unique<base::Value>(base::Value::Type::DICTIONARY);
+  dict->SetKey("persistent_store", base::Value(persistent_store));
+  dict->SetKey("channel_id_service", base::Value(channel_id_service));
+  return dict;
+}
+
+std::unique_ptr<base::Value> NetLogCookieMonsterCookieAdded(
+    const CanonicalCookie* cookie,
+    bool sync_requested,
+    NetLogCaptureMode capture_mode) {
+  if (!capture_mode.include_cookies_and_credentials())
+    return nullptr;
+
+  std::unique_ptr<base::Value> dict =
+      std::make_unique<base::Value>(base::Value::Type::DICTIONARY);
+  dict->SetKey("name", base::Value(cookie->Name()));
+  dict->SetKey("value", base::Value(cookie->Value()));
+  dict->SetKey("domain", base::Value(cookie->Domain()));
+  dict->SetKey("path", base::Value(cookie->Path()));
+  dict->SetKey("httponly", base::Value(cookie->IsHttpOnly()));
+  dict->SetKey("secure", base::Value(cookie->IsSecure()));
+  dict->SetKey("priority",
+               base::Value(CookiePriorityToString(cookie->Priority())));
+  dict->SetKey("same_site",
+               base::Value(CookieSameSiteToString(cookie->SameSite())));
+  dict->SetKey("is_persistent", base::Value(cookie->IsPersistent()));
+  dict->SetKey("sync_requested", base::Value(sync_requested));
+  return dict;
+}
+
+std::unique_ptr<base::Value> NetLogCookieMonsterCookieDeleted(
+    const CanonicalCookie* cookie,
+    CookieChangeCause cause,
+    bool sync_requested,
+    NetLogCaptureMode capture_mode) {
+  if (!capture_mode.include_cookies_and_credentials())
+    return nullptr;
+
+  std::unique_ptr<base::Value> dict =
+      std::make_unique<base::Value>(base::Value::Type::DICTIONARY);
+  dict->SetKey("name", base::Value(cookie->Name()));
+  dict->SetKey("value", base::Value(cookie->Value()));
+  dict->SetKey("domain", base::Value(cookie->Domain()));
+  dict->SetKey("path", base::Value(cookie->Path()));
+  dict->SetKey("is_persistent", base::Value(cookie->IsPersistent()));
+  dict->SetKey("deletion_cause", base::Value(CookieChangeCauseToString(cause)));
+  dict->SetKey("sync_requested", base::Value(sync_requested));
+  return dict;
+}
+
+std::unique_ptr<base::Value> NetLogCookieMonsterCookieRejectedSecure(
+    const CanonicalCookie* old_cookie,
+    const CanonicalCookie* new_cookie,
+    NetLogCaptureMode capture_mode) {
+  if (!capture_mode.include_cookies_and_credentials())
+    return nullptr;
+  std::unique_ptr<base::Value> dict =
+      std::make_unique<base::Value>(base::Value::Type::DICTIONARY);
+  dict->SetKey("name", base::Value(old_cookie->Name()));
+  dict->SetKey("domain", base::Value(old_cookie->Domain()));
+  dict->SetKey("oldpath", base::Value(old_cookie->Path()));
+  dict->SetKey("newpath", base::Value(new_cookie->Path()));
+  dict->SetKey("oldvalue", base::Value(old_cookie->Value()));
+  dict->SetKey("newvalue", base::Value(new_cookie->Value()));
+  return dict;
+}
+
+std::unique_ptr<base::Value> NetLogCookieMonsterCookieRejectedHttponly(
+    const CanonicalCookie* old_cookie,
+    const CanonicalCookie* new_cookie,
+    NetLogCaptureMode capture_mode) {
+  if (!capture_mode.include_cookies_and_credentials())
+    return nullptr;
+  std::unique_ptr<base::Value> dict =
+      std::make_unique<base::Value>(base::Value::Type::DICTIONARY);
+  dict->SetKey("name", base::Value(old_cookie->Name()));
+  dict->SetKey("domain", base::Value(old_cookie->Domain()));
+  dict->SetKey("path", base::Value(old_cookie->Path()));
+  dict->SetKey("oldvalue", base::Value(old_cookie->Value()));
+  dict->SetKey("newvalue", base::Value(new_cookie->Value()));
+  return dict;
+}
+
+}  // namespace net

net/cookies/cookie_monster_netlog_params.h

+// Copyright 2018 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.
+
+#ifndef NET_COOKIES_COOKIE_MONSTER_NETLOG_PARAMS_H_
+#define NET_COOKIES_COOKIE_MONSTER_NETLOG_PARAMS_H_
+
+#include <memory>
+
+#include "base/values.h"
+#include "net/cookies/canonical_cookie.h"
+#include "net/cookies/cookie_change_dispatcher.h"
+#include "net/cookies/cookie_monster.h"
+#include "net/cookies/cookie_store.h"
+#include "net/log/net_log_capture_mode.h"
+
+namespace net {
+
+// Returns a Value containing NetLog parameters for constructing
+// a CookieMonster.
+std::unique_ptr<base::Value> NetLogCookieMonsterConstructorCallback(
+    bool persistent_store,
+    bool channel_id_service,
+    NetLogCaptureMode capture_mode);
+
+// Returns a Value containing NetLog parameters for adding a cookie.
+std::unique_ptr<base::Value> NetLogCookieMonsterCookieAdded(
+    const CanonicalCookie* cookie,
+    bool sync_requested,
+    NetLogCaptureMode capture_mode);
+
+// Returns a Value containing NetLog parameters for deleting a cookie.
+std::unique_ptr<base::Value> NetLogCookieMonsterCookieDeleted(
+    const CanonicalCookie* cookie,
+    CookieChangeCause cause,
+    bool sync_requested,
+    NetLogCaptureMode capture_mode);
+
+// Returns a Value containing NetLog parameters for when a cookie addition
+// is rejected because of a conflict with a secure cookie.
+std::unique_ptr<base::Value> NetLogCookieMonsterCookieRejectedSecure(
+    const CanonicalCookie* old_cookie,
+    const CanonicalCookie* new_cookie,
+    NetLogCaptureMode capture_mode);
+
+// Returns a Value containing NetLog parameters for when a cookie addition
+// is rejected because of a conflict with an httponly cookie.
+std::unique_ptr<base::Value> NetLogCookieMonsterCookieRejectedHttponly(
+    const CanonicalCookie* old_cookie,
+    const CanonicalCookie* new_cookie,
+    NetLogCaptureMode capture_mode);
+
+}  // namespace net
+
+#endif  // NET_COOKIES_COOKIE_MONSTER_NETLOG_PARAMS_H_

net/log/net_log_event_type_list.h

@@ -3067,3 +3067,70 @@ EVENT_TYPE(WPAD_DHCP_WIN_START_WAIT_TIMER)
 // This event is emitted if the wait timer for remaining fetchers fires. It
 // has no parameters.
 EVENT_TYPE(WPAD_DHCP_WIN_ON_WAIT_TIMER)
+
+// -----------------------------------------------------------------------------
+// CookieStore related events
+// -----------------------------------------------------------------------------
+
+// Event emitted on store creation/deletion
+//  {
+//    "persistent_store": <Whether there is an attached persistent store>,
+//    "channel_id_services": <Whether there is an attached channel id service>,
+//  }
+EVENT_TYPE(COOKIE_STORE_ALIVE)
+
+// Event emitted on cookie addition
+//  {
+//    "name": <Name of the cookie added>
+//    "value": <Value of the cookie added>
+//    "domain": <Domain of the cookie added>
+//    "path": <Path of the cookie added>
+//    "is_persistent": <Whether or not the cookie is persistent>
+//    "sync_requested": <Whether sync to the backing store was requested>
+//  }
+EVENT_TYPE(COOKIE_STORE_COOKIE_ADDED)
+
+// Event emitted on cookie deletion
+//  {
+//    "name": <Name of the cookie added>
+//    "value": <Value of the cookie added>
+//    "domain": <Domain of the cookie added>
+//    "path": <Path of the cookie added>
+//    "deletion_cause": <Reason the cookie was deleted>
+//    "httponly": <httponly field of the cookie>
+//    "secure": <If the cookie is a secure cookie>
+//    "priority": <priority of the cookie>
+//    "samesite": <SameSite setting for the cookie>
+//    "is_persistent": <Whether or not the cookie is persistent>
+//    "sync_requested": <Whether sync to the backing store was requested>
+//  }
+EVENT_TYPE(COOKIE_STORE_COOKIE_DELETED)
+
+// Event emitted on rejection of a cookie addition because of a conflict
+// with a secure cookie that would have been deleted.
+//  {
+//    "name": <Name of the cookies>
+//    "domain": <Domain of the cookies>
+//    "oldpath": <Path of the cookie that would have been deleted>
+//    "newpath": <Path of the cookie that would have been added>
+//    "oldvalue": <Value of the cookie that would have been deleted>
+//    "newvalue": <Value of the cookie that would have been added>
+//  }
+EVENT_TYPE(COOKIE_STORE_COOKIE_REJECTED_SECURE)
+
+// Event emitted on rejection of a cookie addition because of a conflict
+// with an httponly cookie.
+//  {
+//    "name": <Name of the cookies>
+//    "domain": <Domain of the cookies>
+//    "path": <Path of the cookies>
+//    "oldvalue": <Value of the cookie that would have been deleted>
+//    "newvalue": <Value of the cookie that would have been added>
+//  }
+EVENT_TYPE(COOKIE_STORE_COOKIE_REJECTED_HTTPONLY)
+
+// Event emitted on setting store session persistence
+//  {
+//    "persistence" : <Session persistence setting for the store>
+//  }
+EVENT_TYPE(COOKIE_STORE_SESSION_PERSISTENCE)

net/log/net_log_source_type_list.h

@@ -41,3 +41,4 @@ SOURCE_TYPE(QUIC_STREAM_FACTORY_JOB)
 SOURCE_TYPE(HTTP_SERVER_PROPERTIES)
 SOURCE_TYPE(HOST_CACHE_PERSISTENCE_MANAGER)
 SOURCE_TYPE(TRIAL_CERT_VERIFIER_JOB)
+SOURCE_TYPE(COOKIE_STORE)