New architecture of the activity logging: Policies for summarization (and compression)

chrome/browser/extensions/activity_log/activity_log.cc

 // 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 <set>
 #include <vector>
 #include "base/command_line.h"
 #include "base/json/json_string_value_serializer.h"
 #include "base/logging.h"
 #include "base/strings/string_util.h"
 #include "base/threading/thread_checker.h"
 #include "chrome/browser/extensions/activity_log/activity_log.h"
 #include "chrome/browser/extensions/activity_log/api_actions.h"
 #include "chrome/browser/extensions/activity_log/blocked_actions.h"
+#include "chrome/browser/extensions/activity_log/stream_noargs_ui_policy.h"
 #include "chrome/browser/extensions/api/activity_log_private/activity_log_private_api.h"
 #include "chrome/browser/extensions/extension_service.h"
 #include "chrome/browser/extensions/extension_system.h"
 #include "chrome/browser/extensions/extension_system_factory.h"
 #include "chrome/browser/extensions/install_tracker_factory.h"
 #include "chrome/browser/prerender/prerender_manager.h"
 #include "chrome/browser/prerender/prerender_manager_factory.h"
 #include "chrome/browser/profiles/incognito_helpers.h"
 #include "chrome/common/chrome_constants.h"
 #include "chrome/common/chrome_switches.h"
@@ skipping 96 matching lines @@
         BrowserContextDependencyManager::GetInstance()) {
   DependsOn(ExtensionSystemFactory::GetInstance());
   DependsOn(InstallTrackerFactory::GetInstance());
 }
 
 ActivityLogFactory::~ActivityLogFactory() {
 }
 
 // ActivityLog
 
+void ActivityLog::SetDefaultPolicy(ActivityLogPolicy::PolicyType policy_type) {
+  if (policy_type != policy_type_ && IsLogEnabled()) {
+    delete policy_;
+
+    // We normally dispatch DB requests to the DB thread, but the thread might
+    // not exist if we are under test conditions. Substitute the UI thread for
+    // this case.
+    content::BrowserThread::ID dispatch_thread;
+    if (BrowserThread::IsMessageLoopValid(BrowserThread::DB)) {
+      dispatch_thread = BrowserThread::DB;
+    } else {
+      LOG(ERROR) << "BrowserThread::DB does not exist, running on UI thread!";
+      dispatch_thread = BrowserThread::UI;
+    }
+
+    switch (policy_type) {
+      case ActivityLogPolicy::POLICY_FULLSTREAM:
+        policy_ = new FullStreamUIPolicy(profile_, dispatch_thread);
+        break;
+      case ActivityLogPolicy::POLICY_NOARGS:
+        policy_ = new StreamWithoutArgsUIPolicy(profile_, dispatch_thread);
+        break;
+      default:
+        if (testing_mode_)
+          LOG(INFO) << "Calling SetDefaultPolicy with invalid policy type?";
+    }
+    policy_type_ = policy_type;
+  }
+}
+
 // Use GetInstance instead of directly creating an ActivityLog.
 ActivityLog::ActivityLog(Profile* profile)
-    : profile_(profile),
+    : policy_type_(ActivityLogPolicy::POLICY_INVALID),
+      profile_(profile),
       first_time_checking_(true),
-      tracker_(NULL),
-      has_threads_(true) {
+      has_threads_(true),
+      tracker_(NULL) {
   enabled_ = IsLogEnabledOnAnyProfile();
 
-  // enable-extension-activity-log-testing
-  // This controls whether arguments are collected.
-  // It also controls whether logging statements are printed.
-  testing_mode_ = CommandLine::ForCurrentProcess()->HasSwitch(
-      switches::kEnableExtensionActivityLogTesting);
-  if (!testing_mode_) {
-    for (int i = 0; i < APIAction::kSizeAlwaysLog; i++) {
-      arg_whitelist_api_.insert(std::string(APIAction::kAlwaysLog[i]));
-    }
-  }
-
   // Check that the right threads exist. If not, we shouldn't try to do things
   // that require them.

[felt, 2013/06/13 18:52:02]

This code was being used to control whether we dispatched anything to the
ActivityDatabase. So either add checks in each of the methods in this file and
don't invoke the policy if has_threads_ is false, *or* you need to copy this
into the policies and have each of the policies not write if has_threads_ is
false.

[dbabic, 2013/06/13 23:10:08]

If has_threads_ is false, IsLogEnabled() will return false, and therefore
SetDefaultPolicy will not create any policy.  Does this address your concern?

[felt, 2013/06/13 23:23:37]

Hmm... originally I had meant for IsLogEnabled to be separate from the
has_threads_ issue, so that we could still try sending events over to the log or
printing them to the console. I added a temporary hack that sets it to false in
IsLogEnabled with no comment (my bad!) when firefighting earlier this week. But
now that I'm thinking about it, maybe it does make sense to leave it in -- since
hopefully this would only come up during testing, anyway.

On 2013/06/13 23:10:08, dbabic wrote:

[dbabic, 2013/06/14 00:30:37]

Ok.

   if (!BrowserThread::IsMessageLoopValid(BrowserThread::DB) ||
       !BrowserThread::IsMessageLoopValid(BrowserThread::FILE) ||
       !BrowserThread::IsMessageLoopValid(BrowserThread::IO)) {
     LOG(ERROR) << "Missing threads, disabling Activity Logging!";
     has_threads_ = false;
   }
 
+  // enable-extension-activity-log-testing
+  // This controls whether arguments are collected.
+  // It also controls whether logging statements are printed.
+  testing_mode_ = CommandLine::ForCurrentProcess()->HasSwitch(
+      switches::kEnableExtensionActivityLogTesting);
+  if (!testing_mode_) {
+    SetDefaultPolicy(ActivityLogPolicy::POLICY_NOARGS);
+  } else {
+    SetDefaultPolicy(ActivityLogPolicy::POLICY_FULLSTREAM);
+  }
+
   observers_ = new ObserverListThreadSafe<Observer>;
-
-  // We initialize the database whether or not the AL is enabled, since we might
-  // be enabled later on. If the database cannot be initialized for some
-  // reason, we keep chugging along but nothing will get recorded. If the UI is
-  // available, things will still get sent to the UI even if nothing
-  // is being written to the database.
-  db_ = new ActivityDatabase();
-  if (!has_threads_) return;
-  base::FilePath base_dir = profile->GetPath();
-  base::FilePath database_name = base_dir.Append(
-      chrome::kExtensionActivityLogFilename);
-  ScheduleAndForget(&ActivityDatabase::Init, database_name);
 }
 
 void ActivityLog::Shutdown() {
   if (!first_time_checking_ && tracker_) tracker_->RemoveObserver(this);
 }
 
 ActivityLog::~ActivityLog() {
-  if (has_threads_)
-    ScheduleAndForget(&ActivityDatabase::Close);
-  else
-    db_->Close();
+  delete policy_;
 }
 
 // We can't register for the InstallTrackerFactory events or talk to the
 // extension service in the constructor, so we do that here the first time
 // this is called (as identified by first_time_checking_).
 bool ActivityLog::IsLogEnabled() {
   if (!first_time_checking_) return enabled_;
   if (!has_threads_) return false;
   tracker_ = InstallTrackerFactory::GetForProfile(profile_);
   tracker_->AddObserver(this);
@@ skipping 26 matching lines @@
 // is reenabled.
 void ActivityLog::OnExtensionDisabled(const Extension* extension) {
   if (extension->id() != kActivityLogExtensionId) return;
   if (!CommandLine::ForCurrentProcess()->HasSwitch(
       switches::kEnableExtensionActivityLogging))
     enabled_ = false;
 }
 
 void ActivityLog::SetArgumentLoggingForTesting(bool log_arguments) {
   testing_mode_ = log_arguments;
+  /*
+=====
+  delete policy_;
+>>>>> approved-policy-patch
+// */

[Matt Perry, 2013/06/13 18:23:23]

merge junk

[dbabic, 2013/06/13 23:10:08]

Done.

 }
 
 // static
 ActivityLog* ActivityLog::GetInstance(Profile* profile) {
   return ActivityLogFactory::GetForProfile(profile);
 }
 
 void ActivityLog::AddObserver(ActivityLog::Observer* observer) {
   observers_->AddObserver(observer);
 }
 
 void ActivityLog::RemoveObserver(ActivityLog::Observer* observer) {
   observers_->RemoveObserver(observer);
 }
 
 void ActivityLog::LogAPIActionInternal(const std::string& extension_id,
                                        const std::string& api_call,
                                        ListValue* args,
                                        const std::string& extra,
                                        const APIAction::Type type) {
   std::string verb, manager;
   bool matches = RE2::FullMatch(api_call, "(.*?)\\.(.*)", &manager, &verb);
   if (matches) {
     if (!args->empty() && manager == "tabs") {
       APIAction::LookupTabId(api_call, args, profile_);
     }
+
+    if (policy_) {
+      DCHECK((type == APIAction::CALL || type == APIAction::EVENT_CALLBACK) &&
+          "Unexpected APIAction call type.");
+      policy_->ProcessAction(
+          type == APIAction::CALL ? ActivityLogPolicy::ACTION_API :
+              ActivityLogPolicy::ACTION_EVENT,
+          extension_id,
+          api_call,
+          NULL,
+          args,
+          NULL);

[felt, 2013/06/13 18:52:02]

Note that we've started using the extra fields so they shouldn't just be thrown
away (for example, Petr's recent patch.) Goes for all action types.

[dbabic, 2013/06/13 23:10:08]

Done.

+    }
+
+    // TODO(felt) Logging should be done more efficiently, so that it
+    // doesn't require construction of the action object.
     scoped_refptr<APIAction> action = new APIAction(
         extension_id,
         base::Time::Now(),
         type,
         api_call,
         MakeArgList(args),
         extra);
-    ScheduleAndForget(&ActivityDatabase::RecordAction, action);
+
     observers_->Notify(&Observer::OnExtensionActivity, action);
     if (testing_mode_) LOG(INFO) << action->PrintForDebug();
   } else {
     LOG(ERROR) << "Unknown API call! " << api_call;
   }
 }
 
 // A wrapper around LogAPIActionInternal, but we know it's an API call.
 void ActivityLog::LogAPIAction(const std::string& extension_id,
                                const std::string& api_call,
                                ListValue* args,
                                const std::string& extra) {
   if (!IsLogEnabled() ||
       ActivityLogAPI::IsExtensionWhitelisted(extension_id)) return;
-  if (!testing_mode_ &&
-      arg_whitelist_api_.find(api_call) == arg_whitelist_api_.end())
-    args->Clear();
   LogAPIActionInternal(extension_id,
                        api_call,
                        args,
                        extra,
                        APIAction::CALL);
 }
 
 // A wrapper around LogAPIActionInternal, but we know it's actually an event
 // being fired and triggering extension code. Having the two separate methods
 // (LogAPIAction vs LogEventAction) lets us hide how we actually choose to
 // handle them. Right now they're being handled almost the same.
 void ActivityLog::LogEventAction(const std::string& extension_id,
                                  const std::string& api_call,
                                  ListValue* args,
                                  const std::string& extra) {
   if (!IsLogEnabled() ||
       ActivityLogAPI::IsExtensionWhitelisted(extension_id)) return;
-  if (!testing_mode_ &&
-      arg_whitelist_api_.find(api_call) == arg_whitelist_api_.end())
-    args->Clear();
   LogAPIActionInternal(extension_id,
                        api_call,
                        args,
                        extra,
                        APIAction::EVENT_CALLBACK);
 }
 
 void ActivityLog::LogBlockedAction(const std::string& extension_id,
                                    const std::string& blocked_call,
                                    ListValue* args,
                                    BlockedAction::Reason reason,
                                    const std::string& extra) {
   if (!IsLogEnabled() ||
       ActivityLogAPI::IsExtensionWhitelisted(extension_id)) return;
-  if (!testing_mode_ &&
-      arg_whitelist_api_.find(blocked_call) == arg_whitelist_api_.end())
-    args->Clear();
+
+  if (policy_) {
+    scoped_ptr<base::DictionaryValue> details(new DictionaryValue());
+    std::string key;
+    policy_->GetKey(ActivityLogPolicy::PARAM_KEY_REASON, &key);
+    details->SetInteger(key, static_cast<int>(reason));
+    policy_->ProcessAction(
+        ActivityLogPolicy::ACTION_BLOCKED,
+        extension_id,
+        blocked_call,
+        NULL,
+        args,
+        details.get());
+  }
+
+  // TODO(felt) Logging should be done more efficiently, so that it
+  // doesn't require construction of the action object.

[felt, 2013/06/13 18:52:02]

This isn't going to happen: we need to make action objects in order to use the
various helper classes for writing to the DB, converting to ExtensionActivities,
etc. Please remove TODO. If it's something you feel strongly about, you can file
a bug and we can discuss it in a thread.

[dbabic, 2013/06/13 23:10:08]

Done.

   scoped_refptr<BlockedAction> action = new BlockedAction(extension_id,
                                                           base::Time::Now(),
                                                           blocked_call,
                                                           MakeArgList(args),
                                                           reason,
                                                           extra);
-  ScheduleAndForget(&ActivityDatabase::RecordAction, action);
   observers_->Notify(&Observer::OnExtensionActivity, action);
   if (testing_mode_) LOG(INFO) << action->PrintForDebug();
 }
 
 void ActivityLog::LogDOMAction(const std::string& extension_id,
                                const GURL& url,
                                const string16& url_title,
                                const std::string& api_call,
                                const ListValue* args,
                                DomActionType::Type call_type,
                                const std::string& extra) {
   if (!IsLogEnabled() ||
       ActivityLogAPI::IsExtensionWhitelisted(extension_id)) return;
   if (call_type == DomActionType::METHOD && api_call == "XMLHttpRequest.open")
     call_type = DomActionType::XHR;
+
+  if (policy_) {
+    scoped_ptr<base::DictionaryValue> details(new DictionaryValue());
+    std::string key;
+    policy_->GetKey(ActivityLogPolicy::PARAM_KEY_DOM_ACTION, &key);
+    details->SetInteger(key, static_cast<int>(call_type));
+    policy_->GetKey(ActivityLogPolicy::PARAM_KEY_URL_TITLE, &key);
+    details->SetString(key, url_title);
+    policy_->ProcessAction(
+        ActivityLogPolicy::ACTION_DOM,
+        extension_id,
+        api_call,
+        &url,
+        args,
+        details.get());
+  }
+
+
+  // TODO(felt) Logging should be done more efficiently, so that it
+  // doesn't require construction of the action object.
   scoped_refptr<DOMAction> action = new DOMAction(
       extension_id,
       base::Time::Now(),
       call_type,
       url,
       url_title,
       api_call,
       MakeArgList(args),
       extra);
-  ScheduleAndForget(&ActivityDatabase::RecordAction, action);
   observers_->Notify(&Observer::OnExtensionActivity, action);
   if (testing_mode_) LOG(INFO) << action->PrintForDebug();
 }
 
 void ActivityLog::LogWebRequestAction(const std::string& extension_id,
                                       const GURL& url,
                                       const std::string& api_call,
                                       scoped_ptr<DictionaryValue> details,
                                       const std::string& extra) {
   string16 null_title;
   if (!IsLogEnabled() ||
       ActivityLogAPI::IsExtensionWhitelisted(extension_id)) return;
 
-  // Strip details of the web request modifications (for privacy reasons),
-  // unless testing is enabled.
-  if (!testing_mode_) {
-    DictionaryValue::Iterator details_iterator(*details);
-    while (!details_iterator.IsAtEnd()) {
-      details->SetBoolean(details_iterator.key(), true);
-      details_iterator.Advance();
-    }
+  std::string details_string;
+  if (policy_) {
+    scoped_ptr<base::DictionaryValue> details(new DictionaryValue());
+    std::string key;
+    policy_->GetKey(ActivityLogPolicy::PARAM_KEY_DETAILS_STRING, &key);
+    details->SetString(key, details_string);
+    policy_->ProcessAction(
+        ActivityLogPolicy::ACTION_WEB_REQUEST,
+        extension_id,
+        api_call,
+        &url,
+        NULL,
+        details.get());
   }
-  std::string details_string;
+
   JSONStringValueSerializer serializer(&details_string);
   serializer.SerializeAndOmitBinaryValues(*details);
 
+  // TODO(felt) Logging should be done more efficiently, so that it
+  // doesn't require construction of the action object.
   scoped_refptr<DOMAction> action = new DOMAction(
       extension_id,
       base::Time::Now(),
       DomActionType::WEBREQUEST,
       url,
       null_title,
       api_call,
       details_string,
       extra);
-  ScheduleAndForget(&ActivityDatabase::RecordAction, action);
   observers_->Notify(&Observer::OnExtensionActivity, action);
   if (testing_mode_) LOG(INFO) << action->PrintForDebug();
 }
 
 void ActivityLog::GetActions(
     const std::string& extension_id,
     const int day,
     const base::Callback
         <void(scoped_ptr<std::vector<scoped_refptr<Action> > >)>& callback) {
-  if (!has_threads_) return;
-  BrowserThread::PostTaskAndReplyWithResult(
-      BrowserThread::DB,
-      FROM_HERE,
-      base::Bind(&ActivityDatabase::GetActions,
-                 base::Unretained(db_),
-                 extension_id,
-                 day),
-      callback);
+  if (policy_) {
+    policy_->ReadData(extension_id, day, callback);
+  }
 }
 
 void ActivityLog::OnScriptsExecuted(
     const content::WebContents* web_contents,
     const ExecutingScriptsMap& extension_ids,
     int32 on_page_id,
     const GURL& on_url) {
   if (!IsLogEnabled()) return;
   Profile* profile =
       Profile::FromBrowserContext(web_contents->GetBrowserContext());
@@ skipping 33 matching lines @@
                    web_contents->GetTitle(),
                    std::string(),  // no api call here
                    script_names.get(),
                    DomActionType::INSERTED,
                    extra);
     }
   }
 }
 
 }  // namespace extensions