Add trace events to measure GPU process startup timing and time to first present.

Review URL: https://chromiumcodereview.appspot.com/10386185

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

4 files changed, 73 insertions, 25 deletions

diff --git a/content/gpu/gpu_info_collector_linux.cc b/content/gpu/gpu_info_collector_linux.cc
index 6608bb3..c3a6941 100644
--- a/content/gpu/gpu_info_collector_linux.cc
+++ b/content/gpu/gpu_info_collector_linux.cc
@@ -8,6 +8,7 @@
 #include <vector>
 
 #include "base/command_line.h"
+#include "base/debug/trace_event.h"
 #include "base/file_util.h"
 #include "base/logging.h"
 #include "base/memory/scoped_ptr.h"
@@ -175,6 +176,8 @@ namespace gpu_info_collector {
 bool CollectGraphicsInfo(content::GPUInfo* gpu_info) {
   DCHECK(gpu_info);
 
+  TRACE_EVENT0("gpu", "gpu_info_collector::CollectGraphicsInfo");
+
   if (CommandLine::ForCurrentProcess()->HasSwitch(
           switches::kGpuNoContextLost)) {
     gpu_info->can_lose_context = false;
diff --git a/content/gpu/gpu_info_collector_mac.mm b/content/gpu/gpu_info_collector_mac.mm
index 434dc15..4c31ed0 100644
--- a/content/gpu/gpu_info_collector_mac.mm
+++ b/content/gpu/gpu_info_collector_mac.mm
@@ -6,6 +6,7 @@
 
 #include <vector>
 
+#include "base/debug/trace_event.h"
 #include "base/logging.h"
 #include "base/mac/scoped_cftyperef.h"
 #include "base/memory/scoped_ptr.h"
@@ -157,6 +158,8 @@ namespace gpu_info_collector {
 bool CollectGraphicsInfo(content::GPUInfo* gpu_info) {
   DCHECK(gpu_info);
 
+  TRACE_EVENT0("gpu", "gpu_info_collector::CollectGraphicsInfo");
+
   gpu_info->can_lose_context =
       (gfx::GetGLImplementation() == gfx::kGLImplementationEGLGLES2);
   gpu_info->finalized = true;
diff --git a/content/gpu/gpu_info_collector_win.cc b/content/gpu/gpu_info_collector_win.cc
index e37d0e9..6e28b51 100644
--- a/content/gpu/gpu_info_collector_win.cc
+++ b/content/gpu/gpu_info_collector_win.cc
@@ -9,6 +9,7 @@
 #include <setupapi.h>
 
 #include "base/command_line.h"
+#include "base/debug/trace_event.h"
 #include "base/file_path.h"
 #include "base/file_util.h"
 #include "base/logging.h"
@@ -50,6 +51,8 @@ float ReadXMLFloatValue(XmlReader* reader) {
 }
 
 content::GpuPerformanceStats RetrieveGpuPerformanceStats() {
+  TRACE_EVENT0("gpu", "RetrieveGpuPerformanceStats");
+
   // If the user re-runs the assessment without restarting, the COM API
   // returns WINSAT_ASSESSMENT_STATE_NOT_AVAILABLE. Because of that and
   // http://crbug.com/124325, read the assessment result files directly.
@@ -151,6 +154,8 @@ content::GpuPerformanceStats RetrieveGpuPerformanceStats() {
 namespace gpu_info_collector {
 
 bool CollectGraphicsInfo(content::GPUInfo* gpu_info) {
+  TRACE_EVENT0("gpu", "CollectGraphicsInfo");
+
   DCHECK(gpu_info);
 
   content::GpuPerformanceStats stats = RetrieveGpuPerformanceStats();
@@ -204,6 +209,8 @@ bool CollectGraphicsInfo(content::GPUInfo* gpu_info) {
 }
 
 bool CollectPreliminaryGraphicsInfo(content::GPUInfo* gpu_info) {
+  TRACE_EVENT0("gpu", "CollectPreliminaryGraphicsInfo");
+
   DCHECK(gpu_info);
 
   bool rt = true;
@@ -216,6 +223,8 @@ bool CollectPreliminaryGraphicsInfo(content::GPUInfo* gpu_info) {
 }
 
 bool CollectGraphicsInfoD3D(IDirect3D9* d3d, content::GPUInfo* gpu_info) {
+  TRACE_EVENT0("gpu", "CollectGraphicsInfoD3D");
+
   DCHECK(d3d);
   DCHECK(gpu_info);
 
@@ -246,6 +255,8 @@ bool CollectGraphicsInfoD3D(IDirect3D9* d3d, content::GPUInfo* gpu_info) {
 }
 
 bool CollectVideoCardInfo(content::GPUInfo* gpu_info) {
+  TRACE_EVENT0("gpu", "CollectVideoCardInfo");
+
   DCHECK(gpu_info);
 
   // nvd3d9wrap.dll is loaded into all processes when Optimus is enabled.
@@ -280,6 +291,8 @@ bool CollectVideoCardInfo(content::GPUInfo* gpu_info) {
 
 bool CollectDriverInfoD3D(const std::wstring& device_id,
                           content::GPUInfo* gpu_info) {
+  TRACE_EVENT0("gpu", "CollectDriverInfoD3D");
+
   // create device info for the display device
   HDEVINFO device_info = SetupDiGetClassDevsW(
       NULL, device_id.c_str(), NULL,
@@ -353,6 +366,8 @@ bool CollectDriverInfoD3D(const std::wstring& device_id,
 }
 
 bool CollectDriverInfoGL(content::GPUInfo* gpu_info) {
+  TRACE_EVENT0("gpu", "CollectDriverInfoGL");
+
   DCHECK(gpu_info);
 
   std::string gl_version_string = gpu_info->gl_version_string;
diff --git a/content/gpu/gpu_main.cc b/content/gpu/gpu_main.cc
index f2bf4ad..eee06ac 100644
--- a/content/gpu/gpu_main.cc
+++ b/content/gpu/gpu_main.cc
@@ -8,6 +8,7 @@
 #include <windows.h>
 #endif
 
+#include "base/debug/trace_event.h"
 #include "base/environment.h"
 #include "base/message_loop.h"
 #include "base/rand_util.h"
@@ -42,6 +43,8 @@
 
 // Main function for starting the Gpu process.
 int GpuMain(const content::MainFunctionParams& parameters) {
+  TRACE_EVENT0("gpu", "GpuMain");
+
   base::Time start_time = base::Time::Now();
 
   const CommandLine& command_line = parameters.command_line;
@@ -118,36 +121,57 @@ int GpuMain(const content::MainFunctionParams& parameters) {
     dead_on_arrival = true;
   }
 
-  // Warm up the random subsystem, which needs to be done pre-sandbox on all
-  // platforms.
-  (void) base::RandUint64();
-
-  // Warm up the crypto subsystem, which needs to done pre-sandbox on all
-  // platforms.
-  crypto::HMAC hmac(crypto::HMAC::SHA256);
-  unsigned char key = '\0';
-  bool ret = hmac.Init(&key, sizeof(key));
-  (void) ret;
+  {
+    TRACE_EVENT0("gpu", "Warm up rand");
+    // Warm up the random subsystem, which needs to be done pre-sandbox on all
+    // platforms.
+    (void) base::RandUint64();
+  }
+  {
+    TRACE_EVENT0("gpu", "Warm up HMAC");
+    // Warm up the crypto subsystem, which needs to done pre-sandbox on all
+    // platforms.
+    crypto::HMAC hmac(crypto::HMAC::SHA256);
+    unsigned char key = '\0';
+    bool ret = hmac.Init(&key, sizeof(key));
+    (void) ret;
+  }
 
 #if defined(OS_LINUX) && !defined(OS_CHROMEOS)
-  content::InitializeSandbox();
+  {
+    TRACE_EVENT0("gpu", "Initialize sandbox");
+    content::InitializeSandbox();
+  }
 #endif
 
-  base::win::ScopedCOMInitializer com_initializer;
+  {
+    TRACE_EVENT0("gpu", "Initialize COM");
+    base::win::ScopedCOMInitializer com_initializer;
+  }
 
 #if defined(OS_WIN)
-  // Preload this DLL because the sandbox prevents it from loading.
-  LoadLibrary(L"setupapi.dll");
-
-  sandbox::TargetServices* target_services =
-      parameters.sandbox_info->target_services;
-  // Initialize H/W video decoding stuff which fails in the sandbox.
-  DXVAVideoDecodeAccelerator::PreSandboxInitialization();
-  // For windows, if the target_services interface is not zero, the process
-  // is sandboxed and we must call LowerToken() before rendering untrusted
-  // content.
-  if (target_services)
-    target_services->LowerToken();
+  {
+    TRACE_EVENT0("gpu", "Preload setupapi.dll");
+    // Preload this DLL because the sandbox prevents it from loading.
+    LoadLibrary(L"setupapi.dll");
+  }
+
+  {
+    TRACE_EVENT0("gpu", "Initialize DXVA");
+    // Initialize H/W video decoding stuff which fails in the sandbox.
+    DXVAVideoDecodeAccelerator::PreSandboxInitialization();
+  }
+
+  {
+    TRACE_EVENT0("gpu", "Lower token");
+    // For windows, if the target_services interface is not zero, the process
+    // is sandboxed and we must call LowerToken() before rendering untrusted
+    // content.
+    sandbox::TargetServices* target_services =
+        parameters.sandbox_info->target_services;
+    if (target_services)
+      target_services->LowerToken();
+  }
 #endif
 
   MessageLoop::Type message_loop_type = MessageLoop::TYPE_UI;
@@ -176,7 +200,10 @@ int GpuMain(const content::MainFunctionParams& parameters) {
 
   gpu_process.set_main_thread(child_thread);
 
-  main_message_loop.Run();
+  {
+    TRACE_EVENT0("gpu", "Run Message Loop");
+    main_message_loop.Run();
+  }
 
   child_thread->StopWatchdog();