Add implementation of ExtensionActivityLog and extension API logging.

This is the backend implementation of https://docs.google.com/a/google.com/document/d/1Lge-nbnU4RSI0fvb4RkngMAfgKV_zQRPp49zgRea1PM/edit?hl=en_US

BUG=
TEST=


Review URL: http://codereview.chromium.org/8598025

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@114711 0039d316-1c4b-4281-b951-d872f2087c98

6 files changed, 211 insertions, 2 deletions

diff --git a/chrome/browser/extensions/extension_activity_log.cc b/chrome/browser/extensions/extension_activity_log.cc
new file mode 100644
index 0000000..85ad4d2
--- /dev/null
+++ b/chrome/browser/extensions/extension_activity_log.cc
@@ -0,0 +1,82 @@
+// Copyright (c) 2011 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/extension_activity_log.h"
+
+#include "base/command_line.h"
+#include "base/logging.h"
+#include "chrome/common/chrome_switches.h"
+#include "chrome/common/extensions/extension.h"
+
+ExtensionActivityLog::ExtensionActivityLog() {
+  log_activity_to_stdout_ = CommandLine::ForCurrentProcess()->
+      HasSwitch(switches::kEnableExtensionActivityLogging);
+}
+
+ExtensionActivityLog::~ExtensionActivityLog() {
+}
+
+// static
+ExtensionActivityLog* ExtensionActivityLog::GetInstance() {
+  return Singleton<ExtensionActivityLog>::get();
+}
+
+void ExtensionActivityLog::AddObserver(
+    const Extension* extension,
+    ExtensionActivityLog::Observer* observer) {
+  base::AutoLock scoped_lock(lock_);
+
+  if (observers_.count(extension) == 0) {
+    observers_[extension] = new ObserverListThreadSafe<Observer>;
+  }
+
+  observers_[extension]->AddObserver(observer);
+}
+
+void ExtensionActivityLog::RemoveObserver(
+    const Extension* extension,
+    ExtensionActivityLog::Observer* observer) {
+  base::AutoLock scoped_lock(lock_);
+
+  if (observers_.count(extension) == 1) {
+    observers_[extension]->RemoveObserver(observer);
+  }
+}
+
+bool ExtensionActivityLog::HasObservers(const Extension* extension) const {
+  base::AutoLock scoped_lock(lock_);
+
+  // We also return true if extension activity logging is enabled since in that
+  // case this class is observing all extensions.
+  return observers_.count(extension) > 0 || log_activity_to_stdout_;
+}
+
+void ExtensionActivityLog::Log(const Extension* extension,
+                               Activity activity,
+                               const std::string& msg) const {
+  base::AutoLock scoped_lock(lock_);
+
+  ObserverMap::const_iterator iter = observers_.find(extension);
+  if (iter != observers_.end()) {
+    iter->second->Notify(&Observer::OnExtensionActivity, extension, activity,
+                         msg);
+  }
+
+  if (log_activity_to_stdout_) {
+    LOG(INFO) << extension->id() + ":" + ActivityToString(activity) + ":" + msg;
+  }
+}
+
+// static
+const char* ExtensionActivityLog::ActivityToString(Activity activity) {
+  switch (activity) {
+    case ExtensionActivityLog::ACTIVITY_EXTENSION_API_CALL:
+      return "api_call";
+    case ExtensionActivityLog::ACTIVITY_EXTENSION_API_BLOCK:
+      return "api_block";
+    default:
+      NOTREACHED();
+      return "";
+  }
+}
diff --git a/chrome/browser/extensions/extension_activity_log.h b/chrome/browser/extensions/extension_activity_log.h
new file mode 100644
index 0000000..9554f0d
--- /dev/null
+++ b/chrome/browser/extensions/extension_activity_log.h
@@ -0,0 +1,69 @@
+// Copyright (c) 2011 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 CHROME_BROWSER_EXTENSIONS_EXTENSION_ACTIVITY_LOG_H_
+#define CHROME_BROWSER_EXTENSIONS_EXTENSION_ACTIVITY_LOG_H_
+
+#include <map>
+#include <string>
+
+#include "base/memory/singleton.h"
+#include "base/observer_list_threadsafe.h"
+#include "base/synchronization/lock.h"
+
+class Extension;
+
+// A utility for tracing interesting activity for each extension.
+class ExtensionActivityLog {
+ public:
+  enum Activity {
+    ACTIVITY_EXTENSION_API_CALL,  // Extension API invocation is called.
+    ACTIVITY_EXTENSION_API_BLOCK  // Extension API invocation is blocked.
+  };
+
+  // Observers can listen for activity events.
+  class Observer {
+   public:
+    virtual void OnExtensionActivity(const Extension* extension,
+                                     Activity activity,
+                                     const std::string& msg);
+  };
+
+  ~ExtensionActivityLog();
+  static ExtensionActivityLog* GetInstance();
+
+  // Add/remove observer.
+  void AddObserver(const Extension* extension, Observer* observer);
+  void RemoveObserver(const Extension* extension, Observer* observer);
+
+  // Check for the existence observer list by extension_id.
+  bool HasObservers(const Extension* extension) const;
+
+  // Log |activity| for |extension|.
+  void Log(const Extension* extension,
+           Activity activity,
+           const std::string& msg) const;
+
+ private:
+  ExtensionActivityLog();
+  friend struct DefaultSingletonTraits<ExtensionActivityLog>;
+
+  static const char* ActivityToString(Activity activity);
+
+  // A lock used to synchronize access to member variables.
+  mutable base::Lock lock_;
+
+  // Whether to log activity to stdout. This is set by checking the
+  // enable-extension-activity-logging switch.
+  bool log_activity_to_stdout_;
+
+  typedef ObserverListThreadSafe<Observer> ObserverList;
+  typedef std::map<const Extension*, scoped_refptr<ObserverList> > ObserverMap;
+  // A map of extensions to activity observers for that extension.
+  ObserverMap observers_;
+
+  DISALLOW_COPY_AND_ASSIGN(ExtensionActivityLog);
+};
+
+#endif  // CHROME_BROWSER_EXTENSIONS_EXTENSION_ACTIVITY_LOG_H_
diff --git a/chrome/browser/extensions/extension_function_dispatcher.cc b/chrome/browser/extensions/extension_function_dispatcher.cc
index bda138f..00905eb 100644
--- a/chrome/browser/extensions/extension_function_dispatcher.cc
+++ b/chrome/browser/extensions/extension_function_dispatcher.cc
@@ -6,6 +6,7 @@
 
 #include <map>
 
+#include "base/json/json_value_serializer.h"
 #include "base/memory/ref_counted.h"
 #include "base/memory/singleton.h"
 #include "base/process_util.h"
@@ -17,6 +18,7 @@
 #include "chrome/browser/download/download_extension_api.h"
 #include "chrome/browser/extensions/api/socket/socket_api.h"
 #include "chrome/browser/extensions/execute_code_in_tab_function.h"
+#include "chrome/browser/extensions/extension_activity_log.h"
 #include "chrome/browser/extensions/extension_app_api.h"
 #include "chrome/browser/extensions/extension_browser_actions_api.h"
 #include "chrome/browser/extensions/extension_chrome_auth_private_api.h"
@@ -525,6 +527,47 @@ ExtensionFunction* FactoryRegistry::NewFunction(const std::string& name) {
   return function;
 }
 
+const char kAccessDenied[] = "access denied";
+const char kQuotaExceeded[] = "quota exceeded";
+
+void LogSuccess(const Extension* extension,
+                const ExtensionHostMsg_Request_Params& params) {
+  ExtensionActivityLog* extension_activity_log =
+      ExtensionActivityLog::GetInstance();
+  if (extension_activity_log->HasObservers(extension)) {
+    std::string call_signature = params.name + "(";
+    ListValue::const_iterator it = params.arguments.begin();
+    for (; it != params.arguments.end(); ++it) {
+      std::string arg;
+      JSONStringValueSerializer serializer(&arg);
+      if (serializer.SerializeAndOmitBinaryValues(**it)) {
+        if (it != params.arguments.begin())
+          call_signature += ", ";
+        call_signature += arg;
+      }
+    }
+    call_signature += ")";
+
+    extension_activity_log->Log(
+        extension,
+        ExtensionActivityLog::ACTIVITY_EXTENSION_API_CALL,
+        call_signature);
+  }
+}
+
+void LogFailure(const Extension* extension,
+                const std::string& func_name,
+                const char* reason) {
+  ExtensionActivityLog* extension_activity_log =
+      ExtensionActivityLog::GetInstance();
+  if (extension_activity_log->HasObservers(extension)) {
+    extension_activity_log->Log(
+        extension,
+        ExtensionActivityLog::ACTIVITY_EXTENSION_API_BLOCK,
+        func_name + ": " + reason);
+  }
+}
+
 };  // namespace
 
 // ExtensionFunctionDispatcher -------------------------------------------------
@@ -558,8 +601,10 @@ void ExtensionFunctionDispatcher::DispatchOnIOThread(
       CreateExtensionFunction(params, extension, render_process_id,
                               extension_info_map->process_map(), profile,
                               ipc_sender, routing_id));
-  if (!function)
+  if (!function) {
+    LogFailure(extension, params.name, kAccessDenied);
     return;
+  }
 
   IOThreadExtensionFunction* function_io =
       function->AsIOThreadExtensionFunction();
@@ -576,8 +621,10 @@ void ExtensionFunctionDispatcher::DispatchOnIOThread(
   if (quota->Assess(extension->id(), function, &params.arguments,
                     base::TimeTicks::Now())) {
     function->Run();
+    LogSuccess(extension, params);
   } else {
     function->OnQuotaExceeded();
+    LogFailure(extension, params.name, kQuotaExceeded);
   }
 }
 
@@ -637,8 +684,10 @@ void ExtensionFunctionDispatcher::Dispatch(
                               *(service->process_map()),
                               profile(), render_view_host,
                               render_view_host->routing_id()));
-  if (!function)
+  if (!function) {
+    LogFailure(extension, params.name, kAccessDenied);
     return;
+  }
 
   UIThreadExtensionFunction* function_ui =
       function->AsUIThreadExtensionFunction();
@@ -658,8 +707,10 @@ void ExtensionFunctionDispatcher::Dispatch(
     ExternalProtocolHandler::PermitLaunchUrl();
 
     function->Run();
+    LogSuccess(extension, params);
   } else {
     function->OnQuotaExceeded();
+    LogFailure(extension, params.name, kQuotaExceeded);
   }
 }
 
diff --git a/chrome/chrome_browser.gypi b/chrome/chrome_browser.gypi
index c2a3d54..e847097 100644
--- a/chrome/chrome_browser.gypi
+++ b/chrome/chrome_browser.gypi
@@ -981,6 +981,8 @@
         'browser/extensions/default_apps_trial.h',
         'browser/extensions/execute_code_in_tab_function.cc',
         'browser/extensions/execute_code_in_tab_function.h',
+        'browser/extensions/extension_activity_log.cc',
+        'browser/extensions/extension_activity_log.h',
         'browser/extensions/extension_app_api.cc',
         'browser/extensions/extension_app_api.h',
         'browser/extensions/extension_browser_actions_api.cc',
diff --git a/chrome/common/chrome_switches.cc b/chrome/common/chrome_switches.cc
index 8a15341..4304abe 100644
--- a/chrome/common/chrome_switches.cc
+++ b/chrome/common/chrome_switches.cc
@@ -473,6 +473,10 @@ const char kEnableCrxlessWebApps[]          = "enable-crxless-web-apps";
 const char kEnableExperimentalExtensionApis[] =
     "enable-experimental-extension-apis";
 
+// Enables logging for extension activity.
+const char kEnableExtensionActivityLogging[] =
+    "enable-extension-activity-logging";
+
 // Enables extension alerts, which are currently in development.
 const char kEnableExtensionAlerts[] = "enable-extension-alerts";
 
diff --git a/chrome/common/chrome_switches.h b/chrome/common/chrome_switches.h
index 1d57efa..4ade86f 100644
--- a/chrome/common/chrome_switches.h
+++ b/chrome/common/chrome_switches.h
@@ -137,6 +137,7 @@ extern const char kEnableConnectBackupJobs[];
 extern const char kEnableCRLSets[];
 extern const char kEnableCrxlessWebApps[];
 extern const char kEnableExperimentalExtensionApis[];
+extern const char kEnableExtensionActivityLogging[];
 extern const char kEnableExtensionAlerts[];
 extern const char kEnableExtensionTimelineApi[];
 extern const char kEnableFastback[];