Improvements to fatal JavaScript extension errors: (1) include the extension

chrome/renderer/extensions/module_system.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/renderer/extensions/module_system.h"
 
 #include "base/bind.h"
+#include "base/command_line.h"
 #include "base/debug/trace_event.h"
 #include "base/stl_util.h"
 #include "base/strings/string_util.h"
 #include "base/strings/stringprintf.h"
+#include "chrome/common/chrome_switches.h"
 #include "chrome/common/extensions/extension_messages.h"
 #include "chrome/renderer/extensions/chrome_v8_context.h"
 #include "chrome/renderer/extensions/console.h"
 #include "content/public/renderer/render_view.h"
 #include "third_party/WebKit/Source/WebKit/chromium/public/WebFrame.h"
 #include "third_party/WebKit/Source/WebKit/chromium/public/WebScopedMicrotaskSuppression.h"
 
 namespace extensions {
 
 namespace {
 
 const char* kModuleSystem = "module_system";
 const char* kModuleName = "module_name";
 const char* kModuleField = "module_field";
 const char* kModulesField = "modules";
 
+// Prepends |extension_id| if it's non-empty to |message|.
+std::string PrependExtensionID(const std::string& message,
+                               const std::string& extension_id) {
+  if (extension_id.empty())
+    return message;
+  return "(" + extension_id + ") " + message;

[Jeffrey Yasskin, 2013/06/14 21:42:59]

This sort of expression on std::string is slow and generates lots of code (until
we switch to C++11 anyway). This is why google3 has StrCat(), but it looks like
that's not imported to Chrome yet. It's better to use a local string and +=.

[not at google - send to devlin, 2013/06/14 22:00:32]

Done.

+}
+
+void Fatal(const std::string& message, const std::string& extension_id) {

[Jeffrey Yasskin, 2013/06/14 21:42:59]

nit: I would probably put the extension_id first since it appears first in the
message.

Wouldn't it be nice if we had a distinct type for ExtensionId so the compiler
could tell us if we passed these backwards?

[not at google - send to devlin, 2013/06/14 22:00:32]

done.
hells yes. so often.

+  // Only crash extension processes. Ideally we would crash on *any* (i.e. web
+  // too), but given we hardly have code coverage for JS we should be careful
+  // and not break the web.
+  const CommandLine* command_line = CommandLine::ForCurrentProcess();
+  bool is_extension_process =
+      command_line->HasSwitch(switches::kExtensionProcess) ||
+      command_line->HasSwitch(switches::kSingleProcess);

[Jeffrey Yasskin, 2013/06/14 21:42:59]

You need a comment justifying crashing the whole browser on an extension failure
in single-process mode.

[not at google - send to devlin, 2013/06/14 22:00:32]

Done.

+  std::string with_extension_id = PrependExtensionID(message, extension_id);
+  if (is_extension_process)

[Jeffrey Yasskin, 2013/06/14 21:42:59]

Maybe restrict this to the dev or even canary channel for now. I'm not sure we
want this to land in Beta in a month, although it'll probably be a good idea for
M30.

[not at google - send to devlin, 2013/06/14 22:00:32]

As in - you want it to crash in web pages, or you want it to never crash at all?
We already have the former behaviour. It's a bit weird to make it change
depending on channel, I think an extension silently not working is arguably even
worse than its extension process crashing. Arguably, perhaps tenuously :)

[Jeffrey Yasskin, 2013/06/14 22:11:22]

I think I'd want it to never crash at all on stable, even if the javascript
threw an exception. I'm not sure it's correct to say that "We already have the
former behaviour" since you're adding extra checking and upgrading some of the
Errors here to Fatals, so I don't think it's the case that M29 will crash
strictly less than M28; it'll just be a different arrangement of crashes. If
you're not sick of being hounded by the release engineers, I think it's ok to
leave what you have.

[not at google - send to devlin, 2013/06/14 22:27:44]

True on the case of crashing in new situations; I remember deciding at the time
that they should be error not fatal, but I can't remember why. It seems wrong in
hindsight, since it's our error to be requiring modules that don't exist (etc).

After thinking about this more, I think I'll leave it in. It's quite unlikely
that we'll leave a crash in beta that makes it into stable, certainly one
that'll be bad enough to hurt. The bigger reason though is that having special
code for stable channel makes me scared, regardless of how innocuous it looks.
What if somebody adds to it? Or cargo cults it? A problem that only shows up
once something is promoted to stable would be really bad.

+    console::Fatal(v8::Context::GetCalling(), with_extension_id);
+  else
+    console::Error(v8::Context::GetCalling(), with_extension_id);
+}
+
+void Warn(const std::string& message, const std::string& extension_id) {
+  console::Warn(v8::Context::GetCalling(),
+                PrependExtensionID(message, extension_id));
+}
+
 // Default exception handler which logs the exception.
 class DefaultExceptionHandler : public ModuleSystem::ExceptionHandler {
  public:
+  explicit DefaultExceptionHandler(const std::string& extension_id)
+      : extension_id_(extension_id) {}
+
   // Fatally dumps the debug info from |try_catch| to the console.
   // Make sure this is never used for exceptions that originate in external
   // code!
   virtual void HandleUncaughtException(const v8::TryCatch& try_catch) OVERRIDE {
     v8::HandleScope handle_scope;
     std::string stack_trace = "<stack trace unavailable>";
     if (!try_catch.StackTrace().IsEmpty()) {
       v8::String::Utf8Value stack_value(try_catch.StackTrace());
       if (*stack_value)
         stack_trace.assign(*stack_value, stack_value.length());
       else
         stack_trace = "<could not convert stack trace to string>";
     }
-    console::Fatal(v8::Context::GetCalling(),
-                   CreateExceptionString(try_catch) + "{" + stack_trace + "}");
+    Fatal(CreateExceptionString(try_catch) + "{" + stack_trace + "}",
+          extension_id_);
   }
+
+ private:
+  std::string extension_id_;
 };
 
 } // namespace
 
 std::string ModuleSystem::ExceptionHandler::CreateExceptionString(
     const v8::TryCatch& try_catch) {
   v8::Handle<v8::Message> message(try_catch.Message());
   if (message.IsEmpty()) {
     return "try_catch has no message";
   }
@@ skipping 16 matching lines @@
                             message->GetLineNumber(),
                             error_message.c_str());
 }
 
 ModuleSystem::ModuleSystem(ChromeV8Context* context,
                            SourceMap* source_map)
     : ObjectBackedNativeHandler(context),
       context_(context),
       source_map_(source_map),
       natives_enabled_(0),
-      exception_handler_(new DefaultExceptionHandler()) {
+      exception_handler_(
+          new DefaultExceptionHandler(context->GetExtensionID())) {
   RouteFunction("require",
       base::Bind(&ModuleSystem::RequireForJs, base::Unretained(this)));
   RouteFunction("requireNative",
       base::Bind(&ModuleSystem::RequireNative, base::Unretained(this)));
 
   v8::Handle<v8::Object> global(context->v8_context()->Global());
   global->SetHiddenValue(v8::String::New(kModulesField), v8::Object::New());
   global->SetHiddenValue(v8::String::New(kModuleSystem),
                          v8::External::New(this));
 }
@@ skipping 57 matching lines @@
   v8::Context::Scope context_scope(context()->v8_context());
 
   v8::Handle<v8::Object> global(context()->v8_context()->Global());
 
   // The module system might have been deleted. This can happen if a different
   // context keeps a reference to us, but our frame is destroyed (e.g.
   // background page keeps reference to chrome object in a closed popup).
   v8::Handle<v8::Value> modules_value =
       global->GetHiddenValue(v8::String::New(kModulesField));
   if (modules_value.IsEmpty() || modules_value->IsUndefined()) {
-    console::Warn(v8::Context::GetCalling(), "Extension view no longer exists");
+    Warn("Extension view no longer exists", context_->GetExtensionID());
     return v8::Undefined();
   }
 
   v8::Handle<v8::Object> modules(v8::Handle<v8::Object>::Cast(modules_value));
   v8::Handle<v8::Value> exports(modules->Get(module_name));
   if (!exports->IsUndefined())
     return handle_scope.Close(exports);
 
   std::string module_name_str = *v8::String::AsciiValue(module_name);
   v8::Handle<v8::Value> source(GetSource(module_name_str));
   if (source.IsEmpty() || source->IsUndefined()) {
-    console::Error(v8::Context::GetCalling(),
-                   "No source for require(" + module_name_str + ")");
+    Fatal("No source for require(" + module_name_str + ")",
+          context_->GetExtensionID());
     return v8::Undefined();
   }
   v8::Handle<v8::String> wrapped_source(WrapSource(
       v8::Handle<v8::String>::Cast(source)));
   // Modules are wrapped in (function(){...}) so they always return functions.
   v8::Handle<v8::Value> func_as_value = RunString(wrapped_source, module_name);
   if (func_as_value.IsEmpty() || func_as_value->IsUndefined()) {
-    console::Error(v8::Context::GetCalling(),
-                   "Bad source for require(" + module_name_str + ")");
+    Fatal("Bad source for require(" + module_name_str + ")",
+          context_->GetExtensionID());
     return v8::Undefined();
   }
 
   v8::Handle<v8::Function> func = v8::Handle<v8::Function>::Cast(func_as_value);
 
   exports = v8::Object::New();
   v8::Handle<v8::Object> natives(NewInstance());
   v8::Handle<v8::Value> args[] = {
     natives->Get(v8::String::NewSymbol("require")),
     natives->Get(v8::String::NewSymbol("requireNative")),
@@ skipping 41 matching lines @@
   v8::Context::Scope context_scope(context()->v8_context());
 
   v8::Local<v8::Value> module;
   {
     NativesEnabledScope natives_enabled(this);
     module = v8::Local<v8::Value>::New(
         RequireForJsInner(v8::String::New(module_name.c_str())));
   }
 
   if (module.IsEmpty() || !module->IsObject()) {
-    console::Error(
-        v8::Context::GetCalling(),
-        "Failed to get module " + module_name + " to call " + method_name);
+    Fatal("Failed to get module " + module_name + " to call " + method_name,
+          context_->GetExtensionID());
     return handle_scope.Close(v8::Undefined());
   }
 
   v8::Local<v8::Value> value =
       v8::Handle<v8::Object>::Cast(module)->Get(
           v8::String::New(method_name.c_str()));
   if (value.IsEmpty() || !value->IsFunction()) {
-    console::Error(v8::Context::GetCalling(),
-                   module_name + "." + method_name + " is not a function");
+    Fatal(module_name + "." + method_name + " is not a function",
+          context_->GetExtensionID());
     return handle_scope.Close(v8::Undefined());
   }
 
   v8::Handle<v8::Function> func = v8::Handle<v8::Function>::Cast(value);
   v8::Local<v8::Value> result;
   {
     v8::TryCatch try_catch;
     try_catch.SetCaptureMessage(true);
     result = context_->CallFunction(func, argc, argv);
     if (try_catch.HasCaught())
@@ skipping 43 matching lines @@
   v8::HandleScope handle_scope;
   v8::Handle<v8::Object> parameters = v8::Handle<v8::Object>::Cast(info.Data());
   // This context should be the same as context()->v8_context().
   v8::Handle<v8::Context> context = parameters->CreationContext();
   v8::Handle<v8::Object> global(context->Global());
   v8::Handle<v8::Value> module_system_value =
       global->GetHiddenValue(v8::String::New(kModuleSystem));
   if (module_system_value.IsEmpty() || !module_system_value->IsExternal()) {
     // ModuleSystem has been deleted.
     // TODO(kalman): See comment in header file.
-    console::Warn(v8::Context::GetCalling(),
-                  "Module system has been deleted, does extension view exist?");
+    Warn("Module system has been deleted, does extension view exist?", "");
     return;
   }
 
   ModuleSystem* module_system = static_cast<ModuleSystem*>(
       v8::Handle<v8::External>::Cast(module_system_value)->Value());
 
   std::string name = *v8::String::AsciiValue(
       parameters->Get(v8::String::New(kModuleName))->ToString());
 
   // Switch to our v8 context because we need functions created while running
@@ skipping 11 matching lines @@
     // require_function will have already logged this, we don't need to.
     return;
   }
 
   v8::Handle<v8::Object> module = v8::Handle<v8::Object>::Cast(module_value);
   v8::Handle<v8::String> field =
       parameters->Get(v8::String::New(kModuleField))->ToString();
 
   if (!module->Has(field)) {
     std::string field_str = *v8::String::AsciiValue(field);
-    console::Fatal(v8::Context::GetCalling(),
-                   "Lazy require of " + name + "." + field_str + " did not " +
-                   "set the " + field_str + " field");
+    Fatal("Lazy require of " + name + "." + field_str + " did not " +
+              "set the " + field_str + " field",
+          module_system->context_->GetExtensionID());
     return;
   }
 
   v8::Local<v8::Value> new_field = module->Get(field);
   if (try_catch.HasCaught()) {
     module_system->HandleException(try_catch);
     return;
   }
 
   // Ok for it to be undefined, among other things it's how bindings signify
@@ skipping 79 matching lines @@
 }
 
 v8::Handle<v8::Value> ModuleSystem::RequireNativeFromString(
     const std::string& native_name) {
   if (natives_enabled_ == 0) {
     // HACK: if in test throw exception so that we can test the natives-disabled
     // logic; however, under normal circumstances, this is programmer error so
     // we could crash.
     if (exception_handler_)
       return v8::ThrowException(v8::String::New("Natives disabled"));
-    console::Fatal(v8::Context::GetCalling(),
-                   "Natives disabled for requireNative(" + native_name + ")");
+    Fatal("Natives disabled for requireNative(" + native_name + ")",
+          context_->GetExtensionID());
     return v8::Undefined();
   }
 
   if (overridden_native_handlers_.count(native_name) > 0u)
     return RequireForJsInner(v8::String::New(native_name.c_str()));
 
   NativeHandlerMap::iterator i = native_handler_map_.find(native_name);
   if (i == native_handler_map_.end()) {
-    console::Fatal(
-        v8::Context::GetCalling(),
-        "Couldn't find native for requireNative(" + native_name + ")");
+    Fatal("Couldn't find native for requireNative(" + native_name + ")",
+          context_->GetExtensionID());
     return v8::Undefined();
   }
   return i->second->NewInstance();
 }
 
 v8::Handle<v8::String> ModuleSystem::WrapSource(v8::Handle<v8::String> source) {
   v8::HandleScope handle_scope;
   v8::Handle<v8::String> left = v8::String::New(
       "(function(require, requireNative, exports) {'use strict';");
   v8::Handle<v8::String> right = v8::String::New("\n})");
   return handle_scope.Close(
       v8::String::Concat(left, v8::String::Concat(source, right)));
 }
 
 }  // namespace extensions