Improved extension activity logging for the chrome.webRequest API.

chrome/browser/extensions/api/web_request/web_request_api.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 "chrome/browser/extensions/api/web_request/web_request_api.h"
 
 #include <algorithm>
 
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/json/json_writer.h"
 #include "base/metrics/histogram.h"
 #include "base/string_util.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/time.h"
 #include "base/utf_string_conversions.h"
 #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"
 #include "chrome/browser/extensions/api/web_navigation/web_navigation_api_helpers.h"
 #include "chrome/browser/extensions/api/web_request/upload_data_presenter.h"
 #include "chrome/browser/extensions/api/web_request/web_request_api_constants.h"
 #include "chrome/browser/extensions/api/web_request/web_request_api_helpers.h"
 #include "chrome/browser/extensions/api/web_request/web_request_time_tracker.h"
 #include "chrome/browser/extensions/event_router.h"
 #include "chrome/browser/extensions/extension_info_map.h"
@@ skipping 1383 matching lines @@
       return helpers::CalculateOnAuthRequiredDelta(
           response->extension_id, response->extension_install_time,
           response->cancel, &response->auth_credentials);
     default:
       NOTREACHED();
       break;
   }
   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);
+  }
+  if (!delta.new_url.is_empty()) {
+    details->SetString("new_url", delta.new_url.spec());
+  }
+
+  {

[felt, 2013/04/11 21:13:37]

is this meant to be an if block?

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

No, it was keeping local variables scoped more tightly.  But that probably isn't
necessary (the code is pretty simple now...I think there used to be more to it).
 I'll drop the extra braces.

+    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(
     void* profile,
     const std::string& extension_id,
     const std::string& event_name,
     uint64 request_id,
     EventResponse* response) {
   scoped_ptr<EventResponse> response_scoped(response);
 
   // It's possible that this request was deleted, or cancelled by a previous
   // event handler. If so, ignore this response.
   if (blocked_requests_.find(request_id) == blocked_requests_.end())
     return;
 
   BlockedRequest& blocked_request = blocked_requests_[request_id];
   int num_handlers_blocking = --blocked_request.num_handlers_blocking;
   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));
+
     blocked_request.response_deltas.push_back(
-        linked_ptr<helpers::EventResponseDelta>(
-            CalculateDelta(&blocked_request, response)));
+        linked_ptr<helpers::EventResponseDelta>(delta));
   }
 
   base::TimeDelta block_time =
       base::Time::Now() - blocked_request.blocking_time;
   if (!extension_id.empty()) {
     request_time_tracker_->IncrementExtensionBlockTime(
         extension_id, request_id, block_time);
   } else {
     // |extension_id| is empty for requests blocked on startup waiting for the
     // declarative rules to be read from disk.
@@ skipping 577 matching lines @@
       } else if ((*it)->name().find("AdBlock") != std::string::npos) {
         adblock = true;
       } else {
         other = true;
       }
     }
   }
 
   host->Send(new ExtensionMsg_UsingWebRequestAPI(adblock, adblock_plus, other));
 }