Add UMA metrics for measuring number of coalesed events and their latency.

ui/base/x/x11_util.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.
 
 // This file defines utility functions for X11 (Linux only). This code has been
 // ported from XCB since we can't use XCB on Ubuntu while its 32-bit support
 // remains woefully incomplete.
 
 #include "ui/base/x/x11_util.h"
 
@@ skipping 10 matching lines @@
 #include <X11/extensions/Xrandr.h>
 #include <X11/extensions/randr.h>
 #include <X11/extensions/shape.h>
 
 #include "base/bind.h"
 #include "base/command_line.h"
 #include "base/logging.h"
 #include "base/memory/scoped_ptr.h"
 #include "base/memory/singleton.h"
 #include "base/message_loop.h"
+#include "base/metrics/histogram.h"
 #include "base/string_number_conversions.h"
 #include "base/string_util.h"
 #include "base/stringprintf.h"
 #include "base/sys_byteorder.h"
 #include "base/threading/thread.h"
 #include "ui/base/events/event_utils.h"
 #include "ui/base/keycodes/keyboard_code_conversion_x.h"
 #include "ui/base/touch/touch_factory.h"
 #include "ui/base/x/valuators.h"
 #include "ui/base/x/x11_util_internal.h"
@@ skipping 516 matching lines @@
 
 #if defined(USE_XI2_MT)
   float tracking_id = -1;
   if (event_type == XI_TouchUpdate) {
     if (!ui::ValuatorTracker::GetInstance()->ExtractValuator(*xev,
           ui::ValuatorTracker::VAL_TRACKING_ID, &tracking_id))
       tracking_id = -1;
   }
 #endif
 
+  base::TimeDelta first_coalesed_time;
   while (XPending(display)) {
     XEvent next_event;
     XPeekEvent(display, &next_event);
 
     // If we can't get the cookie, abort the check.
     if (!XGetEventData(next_event.xgeneric.display, &next_event.xcookie))
       return num_coalesed;
 
     // If this isn't from a valid device, throw the event away, as
     // that's what the message pump would do. Device events come in pairs
@@ skipping 36 matching lines @@
           xievent->mods.latched == next_xievent->mods.latched &&
           xievent->mods.locked == next_xievent->mods.locked &&
           xievent->mods.effective == next_xievent->mods.effective) {
         XFreeEventData(display, &next_event.xcookie);
         // Free the previous cookie.
         if (num_coalesed > 0)
           XFreeEventData(display, &last_event->xcookie);
         // Get the event and its cookie data.
         XNextEvent(display, last_event);
         XGetEventData(display, &last_event->xcookie);
+
+        if (num_coalesed == 0)
+          first_coalesed_time = ui::EventTimeFromNative(last_event);

[Rick Byers, 2013/04/05 15:30:35]

I think the first coalesced event is really xev, where this event here is the
2nd.  Eg. think of the case where we return 1 from this function - you could end
up recording a time of about 0, which would be wrong.

[varunjain, 2013/04/05 19:22:58]

Done.

         ++num_coalesed;
         continue;
       } else {
         // This isn't an event we want so free its cookie data.
         XFreeEventData(display, &next_event.xcookie);
       }
     }
     break;
   }
+  UMA_HISTOGRAM_CUSTOM_COUNTS("Event.Latency.Browser.CoalesedCount",

[Rick Byers, 2013/04/05 15:30:35]

UMA_HISTOGRAM_COUNTS_10000 should be sufficient (50 buckets instead of 100
here).

[Rick Byers, 2013/04/05 15:30:35]

Event.Latency.Browser has an existing common meaning (and also Coalesced is
misspelled).  I'd find this simpler if we just called it "Event.CoalescedCount"
and "Event.CoalescedLatency" below.

[varunjain, 2013/04/05 19:22:58]

Done.

[varunjain, 2013/04/05 19:22:58]

Done.

+                              num_coalesed, 0, 10000, 100);
+  std::string name_for_event = base::StringPrintf(
+      "Event.Latency.Browser.Coalesed.%s",
+      (ui::IsMouseEvent(const_cast<XEvent*>(xev)) ? "Mouse" : "Touch"));

[Rick Byers, 2013/04/05 15:30:35]

Please add a CHECK that verifies all events here are either mouse or touch
events (or add a third 'other' category).

[Rick Byers, 2013/04/05 15:30:35]

If we're going to separate Mouse and Touch here, then I think we should also
separate it in the CoalescedCount too so we can compare them directly.  

[flackr, 2013/04/05 16:10:56]

Drive-by, wouldn't it be better / more efficient to switch between two const
strings rather than construct a string?

[varunjain, 2013/04/05 19:22:58]

Done.

[varunjain, 2013/04/05 19:22:58]

Done.

[varunjain, 2013/04/05 19:22:58]

Done.

+  base::TimeDelta delta = EventTimeForNow() - first_coalesed_time;

[Rick Byers, 2013/04/05 15:30:35]

The Event.Latency.Browser metrics already track the latency between event
generation timestamps and consumption in the browser.  Perhaps we should exclude
that time here to keep the measurements separate?  I.e. use last_event timestamp
instead of EventTimeForNow.

[varunjain, 2013/04/05 19:22:58]

Done.

+  base::HistogramBase* counter_for_type =
+      base::Histogram::FactoryGet(

[Rick Byers, 2013/04/05 15:30:35]

Isn't this fully dynamic histogram generation overkill here?  Eg. couldn't you
just do:
UMA_HISTOGRAM_COUNTS_10000(isMouse ? "Event.CoalescedLatency.Mouse" :
"Event.CoalescedLatency.Touch", delta)

[DaveMoore, 2013/04/05 16:46:15]

The macros don't support this...they get confused by having different strings
used. But you could have an if...else.. with two different
UMA_HISTOGRAM_COUNTS() calls.
On 2013/04/05 15:30:35, Rick Byers wrote:

[varunjain, 2013/04/05 19:22:58]

Done.

[varunjain, 2013/04/05 19:22:58]

Done.

+          name_for_event,
+          0,
+          1000000,
+          100,
+          base::HistogramBase::kUmaTargetedHistogramFlag);
+  counter_for_type->Add(delta.InMicroseconds());
   return num_coalesed;
 }
 #endif
 
 void HideHostCursor() {
   CR_DEFINE_STATIC_LOCAL(XScopedCursor, invisible_cursor,
                          (CreateInvisibleCursor(), ui::GetXDisplay()));
   XDefineCursor(ui::GetXDisplay(), DefaultRootWindow(ui::GetXDisplay()),
                 invisible_cursor.get());
 }
@@ skipping 1152 matching lines @@
       << "request_code " << static_cast<int>(error_event.request_code) << ", "
       << "minor_code " << static_cast<int>(error_event.minor_code)
       << " (" << request_str << ")";
 }
 
 // ----------------------------------------------------------------------------
 // End of x11_util_internal.h
 
 
 }  // namespace ui