1116680a4aac90f2aa7413d9095a592090648e557Ben Murdoch// Copyright 2014 The Chromium Authors. All rights reserved. 2b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)// Use of this source code is governed by a BSD-style license that can be 3b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)// found in the LICENSE file. 4b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)#include "chrome/test/chromedriver/performance_logger.h" 603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 75f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles)#include <string> 85f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles)#include <vector> 95f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) 1003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)#include "base/bind.h" 11b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)#include "base/json/json_writer.h" 12868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles)#include "base/strings/string_util.h" 13b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)#include "base/values.h" 14ab8f6f0bd665d3c1ff476eb06c58c42630e462d4Ben Murdoch#include "chrome/test/chromedriver/chrome/browser_info.h" 1503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)#include "chrome/test/chromedriver/chrome/chrome.h" 16b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)#include "chrome/test/chromedriver/chrome/devtools_client.h" 175f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles)#include "chrome/test/chromedriver/chrome/devtools_client_impl.h" 18b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)#include "chrome/test/chromedriver/chrome/log.h" 19b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)#include "chrome/test/chromedriver/chrome/status.h" 2003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)#include "chrome/test/chromedriver/session.h" 21b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 22b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)namespace { 23b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 24b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)// DevTools event domain prefixes to intercept. 25868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles)const char* const kDomains[] = {"Network.", "Page.", "Timeline."}; 26b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 2703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)// Whitelist of WebDriver commands on which to request buffered trace events. 2803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)const char* const kRequestTraceCommands[] = {"GetLog" /* required */, 2903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) "Navigate"}; 3003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 3103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)bool IsBrowserwideClient(DevToolsClient* client) { 3203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return (client->GetId() == DevToolsClientImpl::kBrowserwideDevToolsClientId); 3303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 3403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 3503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)bool IsEnabled(const PerfLoggingPrefs::InspectorDomainStatus& domain_status) { 3603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return (domain_status == 3703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) PerfLoggingPrefs::InspectorDomainStatus::kDefaultEnabled || 3803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) domain_status == 3903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) PerfLoggingPrefs::InspectorDomainStatus::kExplicitlyEnabled); 4003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 4103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 4203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)// Returns whether |command| is in kRequestTraceCommands[] (case-insensitive). 4303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)bool ShouldRequestTraceEvents(const std::string& command) { 4403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) for (size_t i_domain = 0; i_domain < arraysize(kRequestTraceCommands); 4503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) ++i_domain) { 4603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (base::strcasecmp(command.c_str(), kRequestTraceCommands[i_domain]) == 0) 4703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return true; 4803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 4903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return false; 5003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 5103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 52b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)// Returns whether the event belongs to one of kDomains. 53b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)bool ShouldLogEvent(const std::string& method) { 54b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) for (size_t i_domain = 0; i_domain < arraysize(kDomains); ++i_domain) { 55868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles) if (StartsWithASCII(method, kDomains[i_domain], true /* case_sensitive */)) 56b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) return true; 57b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) } 58b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) return false; 59b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)} 60b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 61b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)} // namespace 62b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 6303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)PerformanceLogger::PerformanceLogger(Log* log, const Session* session) 6403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) : log_(log), 6503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) session_(session), 6603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) browser_client_(NULL), 6703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) trace_buffering_(false) {} 68b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 6903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)PerformanceLogger::PerformanceLogger(Log* log, 7003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const Session* session, 7103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const PerfLoggingPrefs& prefs) 725f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) : log_(log), 7303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) session_(session), 7403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) prefs_(prefs), 7503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) browser_client_(NULL), 7603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) trace_buffering_(false) {} 775f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) 785f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles)bool PerformanceLogger::subscribes_to_browser() { 795f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) return true; 805f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles)} 815f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) 82b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)Status PerformanceLogger::OnConnected(DevToolsClient* client) { 8303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (IsBrowserwideClient(client)) { 8403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) browser_client_ = client; 8503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (!prefs_.trace_categories.empty()) { 8603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) Status status = StartTrace(); 8703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (status.IsError()) 8803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return status; 8903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 905f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) return Status(kOk); 915f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) } 9203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return EnableInspectorDomains(client); 9303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 9403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 9503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)Status PerformanceLogger::OnEvent( 9603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) DevToolsClient* client, 9703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const std::string& method, 9803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const base::DictionaryValue& params) { 9903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (IsBrowserwideClient(client)) { 10003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return HandleTraceEvents(client, method, params); 10103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } else { 10203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return HandleInspectorEvents(client, method, params); 10303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 10403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 10503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 10603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)Status PerformanceLogger::BeforeCommand(const std::string& command_name) { 10703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // Only dump trace buffer after tracing has been started. 10803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (trace_buffering_ && ShouldRequestTraceEvents(command_name)) { 10903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) Status status = CollectTraceEvents(); 11003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (status.IsError()) 11103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return status; 11203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 11303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kOk); 11403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 11503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 11603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)void PerformanceLogger::AddLogEntry( 11703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) Log::Level level, 11803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const std::string& webview, 11903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const std::string& method, 12003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const base::DictionaryValue& params) { 12103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) base::DictionaryValue log_message_dict; 12203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) log_message_dict.SetString("webview", webview); 12303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) log_message_dict.SetString("message.method", method); 12403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) log_message_dict.Set("message.params", params.DeepCopy()); 12503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) std::string log_message_json; 12603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) base::JSONWriter::Write(&log_message_dict, &log_message_json); 12703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 12803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // TODO(klm): extract timestamp from params? 12903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // Look at where it is for Page, Network, Timeline, and trace events. 13003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) log_->AddEntry(level, log_message_json); 13103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 13203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 13303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)void PerformanceLogger::AddLogEntry( 13403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const std::string& webview, 13503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const std::string& method, 13603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const base::DictionaryValue& params) { 13703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) AddLogEntry(Log::kInfo, webview, method, params); 13803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 13903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 14003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)Status PerformanceLogger::EnableInspectorDomains(DevToolsClient* client) { 1415f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) std::vector<std::string> enable_commands; 1425f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) if (IsEnabled(prefs_.network)) 1435f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) enable_commands.push_back("Network.enable"); 1445f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) if (IsEnabled(prefs_.page)) 1455f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) enable_commands.push_back("Page.enable"); 1465f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) if (IsEnabled(prefs_.timeline)) { 1475f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) // Timeline feed implicitly disabled when trace categories are specified. 1485f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) // So even if kDefaultEnabled, don't enable unless empty |trace_categories|. 1495f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) if (prefs_.trace_categories.empty() || prefs_.timeline == 1505f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) PerfLoggingPrefs::InspectorDomainStatus::kExplicitlyEnabled) 1515f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) enable_commands.push_back("Timeline.start"); 1525f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) } 1535f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) for (std::vector<std::string>::const_iterator it = enable_commands.begin(); 1545f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) it != enable_commands.end(); ++it) { 1555f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) base::DictionaryValue params; // All the enable commands have empty params. 1565f1c94371a64b3196d4be9466099bb892df9b88eTorne (Richard Coles) Status status = client->SendCommand(*it, params); 157b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) if (status.IsError()) 158b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) return status; 159b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) } 160b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) return Status(kOk); 161b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)} 162b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 16303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)Status PerformanceLogger::HandleInspectorEvents( 164b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) DevToolsClient* client, 165b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) const std::string& method, 166b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) const base::DictionaryValue& params) { 167868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles) if (!ShouldLogEvent(method)) 168868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles) return Status(kOk); 169b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 17003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) AddLogEntry(client->GetId(), method, params); 17103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kOk); 17203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 173b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles) 17403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)Status PerformanceLogger::HandleTraceEvents( 17503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) DevToolsClient* client, 17603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const std::string& method, 17703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const base::DictionaryValue& params) { 17803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (method == "Tracing.tracingComplete") { 17903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) trace_buffering_ = false; 18003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } else if (method == "Tracing.dataCollected") { 18103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // The Tracing.dataCollected event contains a list of trace events. 18203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // Add each one as an individual log entry of method Tracing.dataCollected. 18303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const base::ListValue* traces; 18403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (!params.GetList("value", &traces)) { 18503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kUnknownError, 18603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) "received DevTools trace data in unexpected format"); 18703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 18803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) for (base::ListValue::const_iterator it = traces->begin(); 18903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) it != traces->end(); 19003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) ++it) { 19103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) base::DictionaryValue* event_dict; 19203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (!(*it)->GetAsDictionary(&event_dict)) 19303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kUnknownError, "trace event must be a dictionary"); 19403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) AddLogEntry(client->GetId(), "Tracing.dataCollected", *event_dict); 19503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 19603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } else if (method == "Tracing.bufferUsage") { 19703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // 'value' will be between 0-1 and represents how full the DevTools trace 19803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // buffer is. If the buffer is full, warn the user. 19903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) double buffer_usage = 0; 20003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (!params.GetDouble("value", &buffer_usage)) { 20103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // Tracing.bufferUsage event will occur once per second, and it really 20203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // only serves as a warning, so if we can't reliably tell whether the 20303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // buffer is full, just fail silently instead of spamming the logs. 20403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kOk); 20503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 20603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (buffer_usage >= 0.99999) { 20703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) base::DictionaryValue params; 20803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) std::string err("Chrome's trace buffer filled while collecting events, " 20903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) "so some trace events may have been lost"); 21003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) params.SetString("error", err); 21103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // Expose error to client via perf log using same format as other entries. 21203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) AddLogEntry(Log::kWarning, 21303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) DevToolsClientImpl::kBrowserwideDevToolsClientId, 21403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) "Tracing.bufferUsage", params); 21503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) LOG(WARNING) << err; 21603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 21703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 218868fa2fe829687343ffae624259930155e16dbd8Torne (Richard Coles) return Status(kOk); 219b2df76ea8fec9e32f6f3718986dba0d95315b29cTorne (Richard Coles)} 220116680a4aac90f2aa7413d9095a592090648e557Ben Murdoch 22103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)bool PerformanceLogger::ShouldReportTracingError() { 22203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // Chromium builds 1967-2000, which correspond to Blink revisions 172887- 22303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // 174227, contain a regression where Tracing.start and Tracing.end commands 22403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // erroneously return error -32601 "no such method". The commands still work. 22503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (session_->chrome) { 22603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) const BrowserInfo* browser_info = session_->chrome->GetBrowserInfo(); 22703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 22803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) bool should_report_error = true; 22903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (browser_info->browser_name == "chrome") { 23003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) should_report_error = !(browser_info->build_no >= 1967 && 23103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) browser_info->build_no <= 2000); 23203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } else { 23303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) should_report_error = !(browser_info->blink_revision >= 172887 && 23403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) browser_info->blink_revision <= 174227); 23503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 23603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return should_report_error; 23703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 23803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 23903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // We're not yet able to tell the Chrome version, so don't report this error. 24003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return false; 24103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 24203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 24303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)Status PerformanceLogger::StartTrace() { 24403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (!browser_client_) { 24503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kUnknownError, "tried to start tracing, but connection to " 24603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) "browser was not yet established"); 24703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 24803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (trace_buffering_) { 24903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) LOG(WARNING) << "tried to start tracing, but a trace was already started"; 25003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kOk); 25103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 25203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) base::DictionaryValue params; 25303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) params.SetString("categories", prefs_.trace_categories); 25403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // Ask DevTools to report buffer usage. 25503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) params.SetInteger("bufferUsageReportingInterval", 25603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) prefs_.buffer_usage_reporting_interval); 25703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) Status status = browser_client_->SendCommand("Tracing.start", params); 25803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (status.IsError() && ShouldReportTracingError()) { 25903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) LOG(ERROR) << "error when starting trace: " << status.message(); 26003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return status; 26103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 26203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) trace_buffering_ = true; 26303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kOk); 26403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 26503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 26603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)Status PerformanceLogger::CollectTraceEvents() { 26703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (!browser_client_) { 26803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kUnknownError, "tried to collect trace events, but " 26903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) "connection to browser was not yet established"); 27003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 27103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (!trace_buffering_) { 27203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return Status(kUnknownError, "tried to collect trace events, but tracing " 27303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) "was not started"); 27403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 27503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 27603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) Status status = browser_client_->SendCommand("Tracing.end", 27703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) base::DictionaryValue()); 27803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (status.IsError() && ShouldReportTracingError()) { 27903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) LOG(ERROR) << "error when stopping trace: " << status.message(); 28003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return status; 28103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) } 28203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 28303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) // Block up to 30 seconds until Tracing.tracingComplete event is received. 28403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) status = browser_client_->HandleEventsUntil( 28503b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) base::Bind(&PerformanceLogger::IsTraceDone, base::Unretained(this)), 28603b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) base::TimeDelta::FromSeconds(30)); 28703b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) if (status.IsError()) 28803b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return status; 28903b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 29003b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) return StartTrace(); 29103b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)} 29203b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) 29303b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles)Status PerformanceLogger::IsTraceDone(bool* trace_done) const { 29403b57e008b61dfcb1fbad3aea950ae0e001748b0Torne (Richard Coles) *trace_done = !trace_buffering_; 295116680a4aac90f2aa7413d9095a592090648e557Ben Murdoch return Status(kOk); 296116680a4aac90f2aa7413d9095a592090648e557Ben Murdoch} 297