Extensions: suspend extension's scripts when V8 is paused

extensions/renderer/script_injection_manager.cc

Index: extensions/renderer/script_injection_manager.cc
diff --git a/extensions/renderer/script_injection_manager.cc b/extensions/renderer/script_injection_manager.cc
index 93862dd04bdfe1109bf23c223ccef4cb734ec90e..51cc6a86add7c9f4bc30bfcffe5c23518cce14ca 100644
--- a/extensions/renderer/script_injection_manager.cc
+++ b/extensions/renderer/script_injection_manager.cc
@@ -242,7 +242,6 @@ ScriptInjectionManager::ScriptInjectionManager(
     const ExtensionSet* extensions,
     UserScriptSetManager* user_script_set_manager)
     : extensions_(extensions),
-      injecting_scripts_(false),
       user_script_set_manager_(user_script_set_manager),
       user_script_set_manager_observer_(this) {
   user_script_set_manager_observer_.Add(user_script_set_manager_);
@@ -256,6 +255,22 @@ void ScriptInjectionManager::OnRenderViewCreated(
   rvo_helpers_.push_back(new RVOHelper(render_view, this));
 }
 
+void ScriptInjectionManager::OnInjectionFinished(
+    ScriptInjection* injection,
+    scoped_refptr<ScriptsRunInfo> scripts_run_info) {
+  blink::WebFrame* frame = injection->web_frame();
+  UserScript::RunLocation run_location = injection->run_location();
+
+  ScopedVector<ScriptInjection>::iterator it;
+  for (it = running_injections_.begin(); it != running_injections_.end(); ++it){
+    running_injections_.erase(it);
+    break;
+  }
+
+  if (scripts_run_info && scripts_run_info->HasOneRef() && IsFrameValid(frame))

[Devlin, 2015/02/25 18:02:15]

ref counted lifetimes are already somewhat Evil.  Coupled with the fact that you
have multiple spots of logic where you need to know how many refs are left, this
seems like a very fragile solution to me.  What's more, there are two things
that a ScriptsRunInfo does:
1. Logs that content scripts are running for the activity log.
2. Logs how long injecting content scripts took.
For 1., we really shouldn't delay sending the message until the script finishes
- there's no need.
For 2., we should probably differentiate between synchronous and asynchronous
injection times. If a script injects an alert, then it could be several seconds
(or longer) before it's complete, which is normally a very, very bad metric.

I propose:
- Notify the activity log of injections synchronously directly after they start.
- Record some metrics - scriptcount, csscount, and existing time metrics -
synchronously directly after they start.
- Record a set of new time metrics (with, e.g., _Blocking appened to the metric
name) once they all finish, if any were blocking.

We should also not use a refcounted ScriptsRunInfo. Instead, have
ScriptInjectionManager own the scripts run infos for each frame/location, and
when an injection (asynchronously) finishes, check if there are any other
injections for that frame/location pair. If not, log the info.

[kozy, 2015/02/27 17:32:28]

I've removed ref counted Scripts Run Info and returned back old implementation.
If injection runs synchronously (when blink doesn't show modal dialog and V8
isn't paused at breakpoint) then ScripsRunInfo will log information about run in
old manner.
If injection runs asynchronously then ScriptsRunInfo will log information about
css and js count in old manner and time spent on the transfer of injection to
blink without script execution time.
This corresponds to the first two points of the your proposal.
Is it really necessary to log time of asynchronous injections? It seems like
rarely case and time of execution can be absolutely unpredictable and depends on
user actions.

[Devlin, 2015/02/27 18:25:32]

Fair enough.  More than anything else, I'd want to know how often exactly this
is happening (as you point out, it should be pretty rare).  Could we omit the
timing logs, but insert a metric for scripts that were delayed (akin to num
scripts injected)?

[kozy, 2015/02/28 15:23:21]

I've added _BlockedScriptCount metrics to ScriptsRunInfo and added these metrics
to histograms.xml with you and Kalman as owners.

+    scripts_run_info->LogRun(frame, run_location);
+}
+
 void ScriptInjectionManager::OnUserScriptsUpdated(
     const std::set<std::string>& changed_extensions,
     const std::vector<UserScript*>& scripts) {
@@ -267,13 +282,6 @@ void ScriptInjectionManager::OnUserScriptsUpdated(
     else
       ++iter;
   }
-
-  // If we are currently injecting scripts, we need to make a note that these
-  // extensions were updated.
-  if (injecting_scripts_) {
-    invalidated_while_injecting_.insert(changed_extensions.begin(),
-                                        changed_extensions.end());
-  }
 }
 
 void ScriptInjectionManager::RemoveObserver(RVOHelper* helper) {
@@ -337,30 +345,21 @@ void ScriptInjectionManager::StartInjectScripts(
 
   frame_statuses_[frame] = run_location;
 
-  // If a content script injects blocking code (such as a javascript alert()),
-  // then there is a chance that we are running in a nested message loop, and
-  // shouldn't inject scripts right now (to avoid conflicts).
-  if (!injecting_scripts_) {
+  InjectScripts(frame, run_location);
+  // As above, we might have been blocked, but that means that, in the mean

[Devlin, 2015/02/25 18:02:15]

Isn't the point of this patch that executing scripts can no longer block and run
a nested loop?  How would this still be possible?

[kozy, 2015/02/27 17:32:28]

Done.

+  // time, it's possible the frame advanced. Inject any scripts for run
+  // locations that were registered, but never ran.
+  while ((iter = frame_statuses_.find(frame)) != frame_statuses_.end() &&
+         iter->second > run_location) {
+    run_location = NextRunLocation(run_location);
+    DCHECK_LE(run_location, UserScript::DOCUMENT_IDLE);
     InjectScripts(frame, run_location);
-    // As above, we might have been blocked, but that means that, in the mean
-    // time, it's possible the frame advanced. Inject any scripts for run
-    // locations that were registered, but never ran.
-    while ((iter = frame_statuses_.find(frame)) != frame_statuses_.end() &&
-           iter->second > run_location) {
-      run_location = NextRunLocation(run_location);
-      DCHECK_LE(run_location, UserScript::DOCUMENT_IDLE);
-      InjectScripts(frame, run_location);
-    }
   }
 }
 
 void ScriptInjectionManager::InjectScripts(
     blink::WebFrame* frame,
     UserScript::RunLocation run_location) {
-  DCHECK(!injecting_scripts_);
-  DCHECK(invalidated_while_injecting_.empty());
-  base::AutoReset<bool>(&injecting_scripts_, true);
-
   // Find any injections that want to run on the given frame.
   // We create a separate vector for these because there is a chance that
   // injected scripts can block, which can create a nested message loop. When
@@ -384,7 +383,7 @@ void ScriptInjectionManager::InjectScripts(
   user_script_set_manager_->GetAllInjections(
       &frame_injections, frame, tab_id, run_location);
 
-  ScriptsRunInfo scripts_run_info;
+  scoped_refptr<ScriptsRunInfo> scripts_run_info(new ScriptsRunInfo());
   for (ScopedVector<ScriptInjection>::iterator iter = frame_injections.begin();
        iter != frame_injections.end();) {
     // If a blocking script was injected, there is potentially a possibility
@@ -395,24 +394,30 @@ void ScriptInjectionManager::InjectScripts(
     const std::string& extension_id = (*iter)->host_id().id();
     scoped_ptr<ExtensionInjectionHost> extension_injection_host =
         GetExtensionInjectionHost(extension_id, extensions_);
-    // Try to inject the script if the extension is not "dirty" (invalidated by
-    // an update). If the injection does not finish (i.e., it is waiting for
-    // permission), add it to the list of pending injections.
-    if (invalidated_while_injecting_.count(extension_id) == 0 &&
-        !(*iter)->TryToInject(run_location,
-                              extension_injection_host.get(),
-                              &scripts_run_info)) {
-      pending_injections_.insert(pending_injections_.begin(), *iter);
+    // Try to inject the script. If the injection does not finish
+    // (i.e., it is waiting for permission), add it to the list of pending
+    // injections.  If the injection does not finished, add it to the list of
+    // running injections.
+    ScriptInjection* injection = *iter;
+    injection->SetScriptInjectionManager(this);
+    if (!injection->TryToInject(run_location,
+                                extension_injection_host.get(),
+                                scripts_run_info)) {
+      pending_injections_.insert(pending_injections_.begin(), injection);
+      iter = frame_injections.weak_erase(iter);
+    } else if (!injection->is_complete()) {
+      running_injections_.insert(running_injections_.begin(), injection);
       iter = frame_injections.weak_erase(iter);
     } else {
       ++iter;
     }
   }
 
-  if (IsFrameValid(frame))
-    scripts_run_info.LogRun(frame, run_location);
-
-  invalidated_while_injecting_.clear();
+  frame_injections.clear();
+  // If injection executes synchronously in OnInjectionFinished handler we
+  // will have two refs to scripts run info and we need call here LogRun
+  if (scripts_run_info && scripts_run_info->HasOneRef() && IsFrameValid(frame))
+    scripts_run_info->LogRun(frame, run_location);
 }
 
 void ScriptInjectionManager::HandleExecuteCode(
@@ -441,18 +446,28 @@ void ScriptInjectionManager::HandleExecuteCode(
       static_cast<UserScript::RunLocation>(params.run_at),
       ExtensionHelper::Get(render_view)->tab_id()));
 
-  ScriptsRunInfo scripts_run_info;
+  scoped_refptr<ScriptsRunInfo> scripts_run_info(new ScriptsRunInfo());
   FrameStatusMap::const_iterator iter = frame_statuses_.find(main_frame);
 
+  blink::WebFrame* frame = injection->web_frame();
+  UserScript::RunLocation run_location = injection->run_location();
+
   scoped_ptr<ExtensionInjectionHost> extension_injection_host =
       GetExtensionInjectionHost(injection->host_id().id(), extensions_);
-
+  injection->SetScriptInjectionManager(this);
   if (!injection->TryToInject(
           iter == frame_statuses_.end() ? UserScript::UNDEFINED : iter->second,
           extension_injection_host.get(),
-          &scripts_run_info)) {
+          scripts_run_info)) {
     pending_injections_.push_back(injection.release());
+  } else if (!injection->is_complete()) {
+    running_injections_.push_back(injection.release());
+  } else {
+    injection = NULL;
   }
+
+  if (scripts_run_info && scripts_run_info->HasOneRef() && IsFrameValid(frame))
+    scripts_run_info->LogRun(frame, run_location);
 }
 
 void ScriptInjectionManager::HandleExecuteDeclarativeScript(
@@ -474,12 +489,23 @@ void ScriptInjectionManager::HandleExecuteDeclarativeScript(
           url,
           extension);
   if (injection.get()) {
-    ScriptsRunInfo scripts_run_info;
+    scoped_refptr<ScriptsRunInfo> scripts_run_info(new ScriptsRunInfo());
+    injection->SetScriptInjectionManager(this);
+
+    blink::WebFrame* frame = injection->web_frame();
+    UserScript::RunLocation run_location = injection->run_location();
+
     // TODO(markdittmer): Use return value of TryToInject for error handling.
-    injection->TryToInject(UserScript::BROWSER_DRIVEN,
-                           extension_injection_host.get(),
-                           &scripts_run_info);
-    scripts_run_info.LogRun(web_frame, UserScript::BROWSER_DRIVEN);
+    if (injection->TryToInject(UserScript::BROWSER_DRIVEN,
+                              extension_injection_host.get(),
+                              scripts_run_info)) {
+      if (!injection->is_complete())
+        running_injections_.push_back(injection.release());
+    }
+    injection = NULL;
+    if (scripts_run_info && scripts_run_info->HasOneRef()
+        && IsFrameValid(frame))
+      scripts_run_info->LogRun(frame, run_location);
   }
 }
 
@@ -501,12 +527,13 @@ void ScriptInjectionManager::HandlePermitScriptInjection(int64 request_id) {
   scoped_ptr<ScriptInjection> injection(*iter);
   pending_injections_.weak_erase(iter);
 
-  ScriptsRunInfo scripts_run_info;
+  injection->SetScriptInjectionManager(this);
+
   scoped_ptr<ExtensionInjectionHost> extension_injection_host =
       GetExtensionInjectionHost(injection->host_id().id(), extensions_);
-  if (injection->OnPermissionGranted(extension_injection_host.get(),
-                                     &scripts_run_info)) {
-    scripts_run_info.LogRun(injection->web_frame(), UserScript::RUN_DEFERRED);
+  if (injection->OnPermissionGranted(extension_injection_host.get())) {
+    if (!injection->is_complete())
+      running_injections_.push_back(injection.Pass());
   }
 }