[ChromeDriver] Implementing PerfLoggingPrefs for perf log

BUG=

Review URL: https://codereview.chromium.org/429693003

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

chrome/test/chromedriver/capabilities.cc

@@ -302,6 +302,48 @@ Status ParseLoggingPrefs(const base::Value& option,
   return Status(kOk);
 }
 
+Status ParseInspectorDomainStatus(
+    PerfLoggingPrefs::InspectorDomainStatus* to_set,
+    const base::Value& option,
+    Capabilities* capabilities) {
+  bool desired_value;
+  if (!option.GetAsBoolean(&desired_value))
+    return Status(kUnknownError, "must be a boolean");
+  if (desired_value)
+    *to_set = PerfLoggingPrefs::InspectorDomainStatus::kExplicitlyEnabled;
+  else
+    *to_set = PerfLoggingPrefs::InspectorDomainStatus::kExplicitlyDisabled;
+  return Status(kOk);
+}
+
+Status ParsePerfLoggingPrefs(const base::Value& option,
+                             Capabilities* capabilities) {
+  const base::DictionaryValue* perf_logging_prefs = NULL;
+  if (!option.GetAsDictionary(&perf_logging_prefs))
+    return Status(kUnknownError, "must be a dictionary");
+
+  std::map<std::string, Parser> parser_map;
+  parser_map["enableNetwork"] = base::Bind(
+      &ParseInspectorDomainStatus, &capabilities->perf_logging_prefs.network);
+  parser_map["enablePage"] = base::Bind(
+      &ParseInspectorDomainStatus, &capabilities->perf_logging_prefs.page);
+  parser_map["enableTimeline"] = base::Bind(
+      &ParseInspectorDomainStatus, &capabilities->perf_logging_prefs.timeline);
+  parser_map["traceCategories"] = base::Bind(
+      &ParseString, &capabilities->perf_logging_prefs.trace_categories);
+
+  for (base::DictionaryValue::Iterator it(*perf_logging_prefs); !it.IsAtEnd();
+       it.Advance()) {
+     if (parser_map.find(it.key()) == parser_map.end())
+       return Status(kUnknownError, "unrecognized performance logging "
+                     "option: " + it.key());
+     Status status = parser_map[it.key()].Run(it.value(), capabilities);
+     if (status.IsError())
+       return Status(kUnknownError, "cannot parse " + it.key(), status);
+   }
+   return Status(kOk);
+}
+
 Status ParseChromeOptions(
     const base::Value& capability,
     Capabilities* capabilities) {
@@ -318,6 +360,9 @@ Status ParseChromeOptions(
   parser_map["args"] = base::Bind(&IgnoreCapability);
   parser_map["binary"] = base::Bind(&IgnoreCapability);
   parser_map["extensions"] = base::Bind(&IgnoreCapability);
+
+  parser_map["perfLoggingPrefs"] = base::Bind(&ParsePerfLoggingPrefs);
+
   if (is_android) {
     parser_map["androidActivity"] =
         base::Bind(&ParseString, &capabilities->android_activity);
@@ -473,6 +518,14 @@ std::string Switches::ToString() const {
   return str;
 }
 
+PerfLoggingPrefs::PerfLoggingPrefs()
+    : network(InspectorDomainStatus::kDefaultEnabled),
+      page(InspectorDomainStatus::kDefaultEnabled),
+      timeline(InspectorDomainStatus::kDefaultEnabled),
+      trace_categories() {}
+
+PerfLoggingPrefs::~PerfLoggingPrefs() {}
+
 Capabilities::Capabilities()
     : android_use_running_app(false),
       detach(false),
@@ -504,5 +557,16 @@ Status Capabilities::Parse(const base::DictionaryValue& desired_caps) {
       }
     }
   }
+  // Perf log must be enabled if perf log prefs are specified; otherwise, error.
+  LoggingPrefs::const_iterator iter = logging_prefs.find(
+      WebDriverLog::kPerformanceType);
+  if (iter == logging_prefs.end() || iter->second == Log::kOff) {
+    const base::DictionaryValue* chrome_options = NULL;
+    if (desired_caps.GetDictionary("chromeOptions", &chrome_options) &&
+        chrome_options->HasKey("perfLoggingPrefs")) {
+      return Status(kUnknownError, "perfLoggingPrefs specified, "
+                    "but performance logging was not enabled");
+    }
+  }
   return Status(kOk);
 }

chrome/test/chromedriver/capabilities.h

@@ -60,6 +60,27 @@ class Switches {
 
 typedef std::map<std::string, Log::Level> LoggingPrefs;
 
+struct PerfLoggingPrefs {
+  PerfLoggingPrefs();
+  ~PerfLoggingPrefs();
+
+  // We must distinguish between a log domain being set by default and being
+  // explicitly set. Otherwise, |PerformanceLogger| could only handle 3 of 4
+  // possible combinations (tracing enabled/disabled + Timeline on/off).
+  enum InspectorDomainStatus {
+    kDefaultEnabled,
+    kDefaultDisabled,
+    kExplicitlyEnabled,
+    kExplicitlyDisabled
+  };
+
+  InspectorDomainStatus network;
+  InspectorDomainStatus page;
+  InspectorDomainStatus timeline;
+
+  std::string trace_categories;  // Non-empty string enables tracing.
+};
+
 struct Capabilities {
   Capabilities();
   ~Capabilities();
@@ -114,6 +135,8 @@ struct Capabilities {
   // If set, enable minidump for chrome crashes and save to this directory.
   std::string minidump_path;
 
+  PerfLoggingPrefs perf_logging_prefs;
+
   scoped_ptr<base::DictionaryValue> prefs;
 
   Switches switches;

chrome/test/chromedriver/capabilities_unittest.cc

@@ -7,6 +7,7 @@
 #include "base/values.h"
 #include "chrome/test/chromedriver/chrome/log.h"
 #include "chrome/test/chromedriver/chrome/status.h"
+#include "chrome/test/chromedriver/logging.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 TEST(Switches, Empty) {
@@ -336,6 +337,92 @@ TEST(ParseCapabilities, LoggingPrefsNotDict) {
   ASSERT_FALSE(status.IsOk());
 }
 
+TEST(ParseCapabilities, PerfLoggingPrefsInspectorDomainStatus) {
+  Capabilities capabilities;
+  // Perf log must be enabled if performance log preferences are specified.
+  base::DictionaryValue logging_prefs;
+  logging_prefs.SetString(WebDriverLog::kPerformanceType, "INFO");
+  base::DictionaryValue desired_caps;
+  desired_caps.Set("loggingPrefs", logging_prefs.DeepCopy());
+  ASSERT_EQ(PerfLoggingPrefs::InspectorDomainStatus::kDefaultEnabled,
+            capabilities.perf_logging_prefs.network);
+  ASSERT_EQ(PerfLoggingPrefs::InspectorDomainStatus::kDefaultEnabled,
+            capabilities.perf_logging_prefs.page);
+  ASSERT_EQ(PerfLoggingPrefs::InspectorDomainStatus::kDefaultEnabled,
+            capabilities.perf_logging_prefs.timeline);
+  base::DictionaryValue perf_logging_prefs;
+  perf_logging_prefs.SetBoolean("enableNetwork", true);
+  perf_logging_prefs.SetBoolean("enablePage", false);
+  desired_caps.Set("chromeOptions.perfLoggingPrefs",
+                   perf_logging_prefs.DeepCopy());
+  Status status = capabilities.Parse(desired_caps);
+  ASSERT_TRUE(status.IsOk());
+  ASSERT_EQ(PerfLoggingPrefs::InspectorDomainStatus::kExplicitlyEnabled,
+            capabilities.perf_logging_prefs.network);
+  ASSERT_EQ(PerfLoggingPrefs::InspectorDomainStatus::kExplicitlyDisabled,
+            capabilities.perf_logging_prefs.page);
+  ASSERT_EQ(PerfLoggingPrefs::InspectorDomainStatus::kDefaultEnabled,
+            capabilities.perf_logging_prefs.timeline);
+}
+
+TEST(ParseCapabilities, PerfLoggingPrefsTraceCategories) {
+  Capabilities capabilities;
+  // Perf log must be enabled if performance log preferences are specified.
+  base::DictionaryValue logging_prefs;
+  logging_prefs.SetString(WebDriverLog::kPerformanceType, "INFO");
+  base::DictionaryValue desired_caps;
+  desired_caps.Set("loggingPrefs", logging_prefs.DeepCopy());
+  ASSERT_EQ("", capabilities.perf_logging_prefs.trace_categories);
+  base::DictionaryValue perf_logging_prefs;
+  perf_logging_prefs.SetString("traceCategories", "benchmark,webkit.console");
+  desired_caps.Set("chromeOptions.perfLoggingPrefs",
+                   perf_logging_prefs.DeepCopy());
+  Status status = capabilities.Parse(desired_caps);
+  ASSERT_TRUE(status.IsOk());
+  ASSERT_EQ("benchmark,webkit.console",
+            capabilities.perf_logging_prefs.trace_categories);
+}
+
+TEST(ParseCapabilities, PerfLoggingPrefsNotDict) {
+  Capabilities capabilities;
+  // Perf log must be enabled if performance log preferences are specified.
+  base::DictionaryValue logging_prefs;
+  logging_prefs.SetString(WebDriverLog::kPerformanceType, "INFO");
+  base::DictionaryValue desired_caps;
+  desired_caps.Set("loggingPrefs", logging_prefs.DeepCopy());
+  desired_caps.SetString("chromeOptions.perfLoggingPrefs", "traceCategories");
+  Status status = capabilities.Parse(desired_caps);
+  ASSERT_FALSE(status.IsOk());
+}
+
+TEST(ParseCapabilities, PerfLoggingPrefsNoPerfLogLevel) {
+  Capabilities capabilities;
+  base::DictionaryValue desired_caps;
+  base::DictionaryValue perf_logging_prefs;
+  perf_logging_prefs.SetBoolean("enableNetwork", true);
+  desired_caps.Set("chromeOptions.perfLoggingPrefs",
+                   perf_logging_prefs.DeepCopy());
+  // Should fail because perf log must be enabled if perf log prefs specified.
+  Status status = capabilities.Parse(desired_caps);
+  ASSERT_FALSE(status.IsOk());
+}
+
+TEST(ParseCapabilities, PerfLoggingPrefsPerfLogOff) {
+  Capabilities capabilities;
+  base::DictionaryValue logging_prefs;
+  // Disable performance log by setting logging level to OFF.
+  logging_prefs.SetString(WebDriverLog::kPerformanceType, "OFF");
+  base::DictionaryValue desired_caps;
+  desired_caps.Set("loggingPrefs", logging_prefs.DeepCopy());
+  base::DictionaryValue perf_logging_prefs;
+  perf_logging_prefs.SetBoolean("enableNetwork", true);
+  desired_caps.Set("chromeOptions.perfLoggingPrefs",
+                   perf_logging_prefs.DeepCopy());
+  // Should fail because perf log must be enabled if perf log prefs specified.
+  Status status = capabilities.Parse(desired_caps);
+  ASSERT_FALSE(status.IsOk());
+}
+
 TEST(ParseCapabilities, ExcludeSwitches) {
   Capabilities capabilities;
   base::ListValue exclude_switches;

chrome/test/chromedriver/chrome/devtools_client_impl.cc

@@ -474,16 +474,19 @@ bool ParseInspectorMessage(
   } else if (message_dict->GetInteger("id", &id)) {
     base::DictionaryValue* unscoped_error = NULL;
     base::DictionaryValue* unscoped_result = NULL;
-    if (!message_dict->GetDictionary("error", &unscoped_error) &&
-        !message_dict->GetDictionary("result", &unscoped_result))
-      return false;
-
     *type = kCommandResponseMessageType;
     command_response->id = id;
-    if (unscoped_result)
+    // As per Chromium issue 392577, DevTools does not necessarily return a
+    // "result" dictionary for every valid response. In particular,
+    // Tracing.start and Tracing.end command responses do not contain one.
+    // So, if neither "error" nor "result" keys are present, just provide
+    // a blank result dictionary.
+    if (message_dict->GetDictionary("result", &unscoped_result))
       command_response->result.reset(unscoped_result->DeepCopy());
-    else
+    else if (message_dict->GetDictionary("error", &unscoped_error))
       base::JSONWriter::Write(unscoped_error, &command_response->error);
+    else
+      command_response->result.reset(new base::DictionaryValue());
     return true;
   }
   return false;

chrome/test/chromedriver/chrome/devtools_client_impl_unittest.cc

@@ -569,8 +569,12 @@ TEST(ParseInspectorMessage, CommandNoErrorOrResult) {
   internal::InspectorMessageType type;
   internal::InspectorEvent event;
   internal::InspectorCommandResponse response;
-  ASSERT_FALSE(internal::ParseInspectorMessage(
+  // As per Chromium issue 392577, DevTools does not necessarily return a
+  // "result" dictionary for every valid response. If neither "error" nor
+  // "result" keys are present, a blank result dictionary should be inferred.
+  ASSERT_TRUE(internal::ParseInspectorMessage(
       "{\"id\":1}", 0, &type, &event, &response));
+  ASSERT_TRUE(response.result->empty());
 }
 
 TEST(ParseInspectorMessage, CommandError) {

chrome/test/chromedriver/chrome_launcher.cc

@@ -195,6 +195,7 @@ Status WaitForDevToolsAndCheckVersion(
 
 Status CreateBrowserwideDevToolsClientAndConnect(
     const NetAddress& address,
+    const PerfLoggingPrefs& perf_logging_prefs,
     const SyncWebSocketFactory& socket_factory,
     ScopedVector<DevToolsEventListener>& devtools_event_listeners,
     scoped_ptr<DevToolsClient>* browser_client) {
@@ -203,7 +204,7 @@ Status CreateBrowserwideDevToolsClientAndConnect(
                                          address.ToString().c_str()),
       DevToolsClientImpl::kBrowserwideDevToolsClientId));
   for (ScopedVector<DevToolsEventListener>::const_iterator it =
-      devtools_event_listeners.begin();
+          devtools_event_listeners.begin();
       it != devtools_event_listeners.end();
       ++it) {
     // Only add listeners that subscribe to the browser-wide |DevToolsClient|.
@@ -212,11 +213,17 @@ Status CreateBrowserwideDevToolsClientAndConnect(
     if ((*it)->subscribes_to_browser())
       client->AddListener(*it);
   }
-  // TODO(johnmoore): Call client->ConnectIfNecessary if tracing is enabled.
-  // For now, provide the client anyway, so that Chrome always has a valid
-  // |devtools_websocket_client_|. No listeners will be notified, and the client
-  // will just return kDisconnected errors if used.
+  // Provide the client regardless of whether it connects, so that Chrome always
+  // has a valid |devtools_websocket_client_|. If not connected, no listeners
+  // will be notified, and client will just return kDisconnected errors if used.
   *browser_client = client.Pass();
+  // To avoid unnecessary overhead, only connect if tracing is enabled, since
+  // the browser-wide client is currently only used for tracing.
+  if (!perf_logging_prefs.trace_categories.empty()) {
+    Status status = (*browser_client)->ConnectIfNecessary();
+    if (status.IsError())
+      return status;
+  }
   return Status(kOk);
 }
 
@@ -239,8 +246,8 @@ Status LaunchRemoteChromeSession(
 
   scoped_ptr<DevToolsClient> devtools_websocket_client;
   status = CreateBrowserwideDevToolsClientAndConnect(
-      capabilities.debugger_address, socket_factory, devtools_event_listeners,
-      &devtools_websocket_client);
+      capabilities.debugger_address, capabilities.perf_logging_prefs,
+      socket_factory, devtools_event_listeners, &devtools_websocket_client);
   if (status.IsError()) {
     LOG(WARNING) << "Browser-wide DevTools client failed to connect: "
                  << status.message();
@@ -365,8 +372,8 @@ Status LaunchDesktopChrome(
 
   scoped_ptr<DevToolsClient> devtools_websocket_client;
   status = CreateBrowserwideDevToolsClientAndConnect(
-      NetAddress(port), socket_factory, devtools_event_listeners,
-      &devtools_websocket_client);
+      NetAddress(port), capabilities.perf_logging_prefs, socket_factory,
+      devtools_event_listeners, &devtools_websocket_client);
   if (status.IsError()) {
     LOG(WARNING) << "Browser-wide DevTools client failed to connect: "
                  << status.message();
@@ -446,8 +453,8 @@ Status LaunchAndroidChrome(
 
   scoped_ptr<DevToolsClient> devtools_websocket_client;
   status = CreateBrowserwideDevToolsClientAndConnect(
-      NetAddress(port), socket_factory, devtools_event_listeners,
-      &devtools_websocket_client);
+      NetAddress(port), capabilities.perf_logging_prefs, socket_factory,
+      devtools_event_listeners, &devtools_websocket_client);
   if (status.IsError()) {
     LOG(WARNING) << "Browser-wide DevTools client failed to connect: "
                  << status.message();

chrome/test/chromedriver/logging.cc

@@ -257,7 +257,8 @@ Status CreateLogs(const Capabilities& capabilities,
       if (level != Log::kOff) {
         WebDriverLog* log = new WebDriverLog(type, Log::kAll);
         logs.push_back(log);
-        PerformanceLogger* perf_log = new PerformanceLogger(log);
+        PerformanceLogger* perf_log =
+            new PerformanceLogger(log, capabilities.perf_logging_prefs);
         // We use a proxy for |perf_log|'s |CommandListener| interface.
         // Otherwise, |perf_log| would be owned by both session->chrome and
         // |session|, which would lead to memory errors on destruction.

chrome/test/chromedriver/performance_logger.cc

@@ -2,6 +2,9 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
+#include <string>
+#include <vector>
+
 #include "chrome/test/chromedriver/performance_logger.h"
 
 #include "base/json/json_writer.h"
@@ -17,10 +20,6 @@ namespace {
 // DevTools event domain prefixes to intercept.
 const char* const kDomains[] = {"Network.", "Page.", "Timeline."};
 
-const char* const kDomainEnableCommands[] = {
-    "Network.enable", "Page.enable", "Timeline.start"
-};
-
 // Returns whether the event belongs to one of kDomains.
 bool ShouldLogEvent(const std::string& method) {
   for (size_t i_domain = 0; i_domain < arraysize(kDomains); ++i_domain) {
@@ -30,11 +29,28 @@ bool ShouldLogEvent(const std::string& method) {
   return false;
 }
 
+bool IsEnabled(const PerfLoggingPrefs::InspectorDomainStatus& domain_status) {
+  return (domain_status ==
+          PerfLoggingPrefs::InspectorDomainStatus::kDefaultEnabled ||
+          domain_status ==
+          PerfLoggingPrefs::InspectorDomainStatus::kExplicitlyEnabled);
+}
+
 }  // namespace
 
 PerformanceLogger::PerformanceLogger(Log* log)
     : log_(log) {}
 
+PerformanceLogger::PerformanceLogger(Log* log, const PerfLoggingPrefs& prefs)
+    : log_(log),
+      prefs_(prefs) {
+  if (!prefs_.trace_categories.empty()) {
+    LOG(WARNING) << "Ignoring trace categories because tracing support not yet "
+                 << "implemented: " << prefs_.trace_categories;
+    prefs_.trace_categories = "";
+  }
+}
+
 bool PerformanceLogger::subscribes_to_browser() {
   return true;
 }
@@ -44,9 +60,22 @@ Status PerformanceLogger::OnConnected(DevToolsClient* client) {
     // TODO(johnmoore): Implement tracing log.
     return Status(kOk);
   }
-  base::DictionaryValue params;  // All our enable commands have empty params.
-  for (size_t i_cmd = 0; i_cmd < arraysize(kDomainEnableCommands); ++i_cmd) {
-    Status status = client->SendCommand(kDomainEnableCommands[i_cmd], params);
+  std::vector<std::string> enable_commands;
+  if (IsEnabled(prefs_.network))
+    enable_commands.push_back("Network.enable");
+  if (IsEnabled(prefs_.page))
+    enable_commands.push_back("Page.enable");
+  if (IsEnabled(prefs_.timeline)) {
+    // Timeline feed implicitly disabled when trace categories are specified.
+    // So even if kDefaultEnabled, don't enable unless empty |trace_categories|.
+    if (prefs_.trace_categories.empty() || prefs_.timeline ==
+        PerfLoggingPrefs::InspectorDomainStatus::kExplicitlyEnabled)
+      enable_commands.push_back("Timeline.start");
+  }
+  for (std::vector<std::string>::const_iterator it = enable_commands.begin();
+       it != enable_commands.end(); ++it) {
+    base::DictionaryValue params;  // All the enable commands have empty params.
+    Status status = client->SendCommand(*it, params);
     if (status.IsError())
       return status;
   }

chrome/test/chromedriver/performance_logger.h

@@ -5,8 +5,11 @@
 #ifndef CHROME_TEST_CHROMEDRIVER_PERFORMANCE_LOGGER_H_
 #define CHROME_TEST_CHROMEDRIVER_PERFORMANCE_LOGGER_H_
 
+#include <string>
+
 #include "base/basictypes.h"
 #include "base/compiler_specific.h"
+#include "chrome/test/chromedriver/capabilities.h"
 #include "chrome/test/chromedriver/chrome/devtools_event_listener.h"
 #include "chrome/test/chromedriver/command_listener.h"
 
@@ -21,10 +24,13 @@ class Log;
 // }
 class PerformanceLogger : public DevToolsEventListener, public CommandListener {
  public:
-  // Creates a PerformanceLogger that creates entries in the given Log object.
-  // The log is owned elsewhere and must not be null.
+  // Creates a |PerformanceLogger| with default preferences that creates entries
+  // in the given Log object. The log is owned elsewhere and must not be null.
   explicit PerformanceLogger(Log* log);
 
+  // Creates a |PerformanceLogger| with specific preferences.
+  PerformanceLogger(Log* log, const PerfLoggingPrefs& prefs);
+
   // Enables Page,Network,Timeline events for client, which must not be null.
   virtual Status OnConnected(DevToolsClient* client) OVERRIDE;
   // Translates an event into a log entry.
@@ -39,6 +45,7 @@ class PerformanceLogger : public DevToolsEventListener, public CommandListener {
 
  private:
   Log* log_;  // The log where to create entries.
+  PerfLoggingPrefs prefs_;
 
   DISALLOW_COPY_AND_ASSIGN(PerformanceLogger);
 };

chrome/test/chromedriver/performance_logger_unittest.cc

@@ -188,3 +188,22 @@ TEST(PerformanceLogger, TwoWebViews) {
   ValidateLogEntry(log.GetEntries()[0], "webview-1", "Page.gaga1");
   ValidateLogEntry(log.GetEntries()[1], "webview-2", "Timeline.gaga2");
 }
+
+TEST(PerformanceLogger, PerfLoggingPrefs) {
+  FakeDevToolsClient client("webview-1");
+  FakeLog log;
+  PerfLoggingPrefs prefs;
+  ASSERT_EQ(PerfLoggingPrefs::InspectorDomainStatus::kDefaultEnabled,
+            prefs.network);
+  prefs.network = PerfLoggingPrefs::InspectorDomainStatus::kExplicitlyDisabled;
+  // Trace categories should be ignored until tracing support is implemented.
+  prefs.trace_categories = "benchmark,webkit.console";
+  PerformanceLogger logger(&log, prefs);
+
+  client.AddListener(&logger);
+  logger.OnConnected(&client);
+  EXPECT_EQ("Page.enable", client.PopSentCommand());
+  // Trace categories ignored, so Timeline shouldn't be implicitly disabled.
+  EXPECT_EQ("Timeline.start", client.PopSentCommand());
+  EXPECT_TRUE(client.PopSentCommand().empty());
+}