Improved extension activity logging for the chrome.webRequest API.

chrome/browser/extensions/api/web_request/web_request_api.cc

Index: chrome/browser/extensions/api/web_request/web_request_api.cc
diff --git a/chrome/browser/extensions/api/web_request/web_request_api.cc b/chrome/browser/extensions/api/web_request/web_request_api.cc
index 56a840394cb6e4c86cf0ed4d3e1b7bf1817c779c..420b622ec3a759201f82bb078e8db43503e67ce6 100644
--- a/chrome/browser/extensions/api/web_request/web_request_api.cc
+++ b/chrome/browser/extensions/api/web_request/web_request_api.cc
@@ -17,6 +17,7 @@
 #include "base/values.h"
 #include "chrome/browser/browser_process.h"
 #include "chrome/browser/chrome_content_browser_client.h"
+#include "chrome/browser/extensions/activity_log.h"
 #include "chrome/browser/extensions/api/declarative_webrequest/request_stage.h"
 #include "chrome/browser/extensions/api/declarative_webrequest/webrequest_constants.h"
 #include "chrome/browser/extensions/api/declarative_webrequest/webrequest_rules_registry.h"
@@ -1420,6 +1421,147 @@ helpers::EventResponseDelta* CalculateDelta(
   return NULL;
 }
 
+Value* SerializeResponseHeaders(const helpers::ResponseHeaders& headers) {
+  scoped_ptr<ListValue> serialized_headers(new ListValue());
+  for (helpers::ResponseHeaders::const_iterator i = headers.begin();
+       i != headers.end(); ++i) {
+    serialized_headers->Append(ToHeaderDictionary(i->first, i->second));
+  }
+  return serialized_headers.release();
+}
+
+// Convert a RequestCookieModifications/ResponseCookieModifications object to a
+// ListValue which summarizes the changes made.  This is templated since the
+// two types (request/response) are different but contain essentially the same
+// fields.
+template<typename CookieType>
+ListValue* SummarizeCookieModifications(
+    const std::vector<linked_ptr<CookieType> >& modifications) {
+  scoped_ptr<ListValue> cookie_modifications(new ListValue());
+  for (typename std::vector<linked_ptr<CookieType> >::const_iterator i =
+           modifications.begin();
+       i != modifications.end(); ++i) {
+    scoped_ptr<DictionaryValue> summary(new DictionaryValue());
+    const CookieType& mod = *i->get();
+    switch (mod.type) {
+      case helpers::ADD:
+        summary->SetString("type", "ADD");
+        break;
+      case helpers::EDIT:
+        summary->SetString("type", "EDIT");
+        break;
+      case helpers::REMOVE:
+        summary->SetString("type", "REMOVE");
+        break;
+    }
+    if (mod.filter) {
+      if (mod.filter->name)
+        summary->SetString("filter_name", *mod.modification->name);
+      if (mod.filter->domain)
+        summary->SetString("filter_domain", *mod.modification->name);
+    }
+    if (mod.modification) {
+      if (mod.modification->name)
+        summary->SetString("mod_name", *mod.modification->name);
+      if (mod.modification->domain)
+        summary->SetString("mod_domain", *mod.modification->name);
+    }
+    cookie_modifications->Append(summary.release());
+  }
+  return cookie_modifications.release();
+}
+
+// Converts an EventResponseDelta object to a dictionary value suitable for the
+// activity log.  The caller takes ownership of the returned DictionaryValue
+// object.
+DictionaryValue* SummarizeResponseDelta(
+    const std::string& event_name,
+    const helpers::EventResponseDelta& delta) {
+  scoped_ptr<DictionaryValue> details(new DictionaryValue());
+  if (delta.cancel) {
+    details->SetBoolean("cancel", true);

[mvrable, 2013/04/11 21:41:26]

I'm wondering whether I should define some constants for these strings, rather
than inlining them.  Much of the code in this file refers to constants in
web_request_api_constants.cc, but I don't think that's appropriate here since
these values aren't part of the WebRequest API--they seem more a part of the
activity log.

[felt, 2013/04/11 21:43:28]

You could consider adding a helper method to one of the Action classes, along
with relevant constants?

[mvrable, 2013/04/12 18:50:49]

I ended up creating a new file in the web_request directory for these; it does
keeps from cluttering the top-level extensions directory too much (no existing
file looked appropriate), but keeps the constants separate from the
web_request_api.cc file.

I can easily relocate the constants if somewhere else is better.

+  }
+  if (!delta.new_url.is_empty()) {
+    details->SetString("new_url", delta.new_url.spec());
+  }
+
+  scoped_ptr<ListValue> modified_headers(new ListValue());
+  net::HttpRequestHeaders::Iterator iter(delta.modified_request_headers);
+  while (iter.GetNext()) {
+    modified_headers->Append(ToHeaderDictionary(iter.name(), iter.value()));
+  }
+  if (!modified_headers->empty()) {
+    details->Set("modified_request_headers", modified_headers.release());
+  }
+
+  scoped_ptr<ListValue> deleted_headers(new ListValue());
+  deleted_headers->AppendStrings(delta.deleted_request_headers);
+  if (!deleted_headers->empty()) {
+    details->Set("deleted_request_headers", deleted_headers.release());
+  }
+
+  if (!delta.added_response_headers.empty()) {
+    details->Set("added_response_headers",
+                 SerializeResponseHeaders(delta.added_response_headers));
+  }
+  if (!delta.deleted_response_headers.empty()) {
+    details->Set("deleted_response_headers",
+                 SerializeResponseHeaders(delta.deleted_response_headers));
+  }
+  if (delta.auth_credentials) {
+    details->SetString("auth_credentials",
+                       UTF16ToUTF8(delta.auth_credentials->username()) + ":*");
+  }
+
+  if (!delta.response_cookie_modifications.empty()) {
+    details->Set(
+        "response_cookie_modifications",
+        SummarizeCookieModifications(delta.response_cookie_modifications));
+  }
+
+  return details.release();
+}
+
+void LogExtensionActivity(Profile* profile,
+                          const std::string& extension_id,
+                          const GURL& url,
+                          const std::string& api_call,
+                          DictionaryValue* details) {
+  if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
+    BrowserThread::PostTask(BrowserThread::UI,
+                            FROM_HERE,
+                            base::Bind(&LogExtensionActivity,
+                                       profile,
+                                       extension_id,
+                                       url,
+                                       api_call,
+                                       details));
+  } else {
+    // An ExtensionService might not be running during unit tests, or an
+    // extension might have been unloadd by the time we get to logging it.  In
+    // those cases log a warning.
+    ExtensionService* extension_service =
+        extensions::ExtensionSystem::Get(profile)->extension_service();
+    if (!extension_service) {
+      LOG(WARNING) << "ExtensionService does not seem to be available "
+                   << "(this may be normal for unit tests)";
+    } else {
+      const Extension* extension =
+          extension_service->extensions()->GetByID(extension_id);
+      if (!extension) {
+        LOG(WARNING) << "Extension " << extension_id << " not found!";
+      } else {
+        extensions::ActivityLog::GetInstance(profile)->LogWebRequestAction(
+            extension,
+            url,
+            api_call,
+            scoped_ptr<DictionaryValue>(details),
+            "");
+      }
+    }
+  }
+}
+
 }  // namespace
 
 void ExtensionWebRequestEventRouter::DecrementBlockCount(
@@ -1440,9 +1582,17 @@ void ExtensionWebRequestEventRouter::DecrementBlockCount(
   CHECK_GE(num_handlers_blocking, 0);
 
   if (response) {
+    helpers::EventResponseDelta* delta =
+        CalculateDelta(&blocked_request, response);
+
+    LogExtensionActivity(static_cast<Profile*>(profile),
+                         extension_id,
+                         blocked_request.request->url(),
+                         event_name,
+                         SummarizeResponseDelta(event_name, *delta));

[Matt Perry, 2013/04/12 00:53:43]

This looks somewhat expensive. Ideally we wouldn't do this if logging were
disabled. We're on the IO thread here. Can we check whether logging is enabled
from the IO thread?

[mvrable, 2013/04/12 18:50:49]

Done.

+
     blocked_request.response_deltas.push_back(
-        linked_ptr<helpers::EventResponseDelta>(
-            CalculateDelta(&blocked_request, response)));
+        linked_ptr<helpers::EventResponseDelta>(delta));
   }
 
   base::TimeDelta block_time =