Instrumenting WindowImpl::WndProc to find jank

ui/gfx/win/window_impl.cc

Index: ui/gfx/win/window_impl.cc
diff --git a/ui/gfx/win/window_impl.cc b/ui/gfx/win/window_impl.cc
index 5820ed64a6e8a555f98a051e1c7734213775bff3..0c2ed4a30f0031ac644c988bbf16d8c76ac8f013 100644
--- a/ui/gfx/win/window_impl.cc
+++ b/ui/gfx/win/window_impl.cc
@@ -9,6 +9,7 @@
 #include "base/bind.h"
 #include "base/debug/alias.h"
 #include "base/memory/singleton.h"
+#include "base/profiler/scoped_tracker.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/synchronization/lock.h"
 #include "base/win/wrapped_window_proc.h"
@@ -281,7 +282,15 @@ LRESULT CALLBACK WindowImpl::WndProc(HWND hwnd,
                                      UINT message,
                                      WPARAM w_param,
                                      LPARAM l_param) {
+  // TODO(vadimt): Remove ScopedTracker below once crbug.com/440919 is fixed.
+  tracked_objects::ScopedTracker tracking_profile1(
+      FROM_HERE_WITH_EXPLICIT_FUNCTION("440919 WindowImpl::WndProc1"));
+

[cpu_(ooo_6.6-7.5), 2014/12/20 00:51:07]

shouldn't be that lines 285-288 moved to 304 ?

[vadimt, 2014/12/20 01:02:14]

Done; this is more efficient.

FYI, semantically, there is no difference in what we could catch with these 2
instrumentations, since if I left it as as, the second tracker's time would be
subtracted from the first one, so the first one would catch only janks in the
SECOND part of the method.

   if (message == WM_NCCREATE) {
+    // TODO(vadimt): Remove ScopedTracker below once crbug.com/440919 is fixed.
+    tracked_objects::ScopedTracker tracking_profile2(
+        FROM_HERE_WITH_EXPLICIT_FUNCTION("440919 WindowImpl::WndProc2"));
+
     CREATESTRUCT* cs = reinterpret_cast<CREATESTRUCT*>(l_param);
     WindowImpl* window = reinterpret_cast<WindowImpl*>(cs->lpCreateParams);
     DCHECK(window);