ui/events/latency_info.cc

   1 // Copyright 2013 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "base/debug/trace_event.h"
   6 #include "base/json/json_writer.h"
   7 #include "base/memory/scoped_ptr.h"
   8 #include "base/strings/stringprintf.h"
   9 #include "ui/events/latency_info.h"
  10
  11 #include <algorithm>
  12
  13 namespace {
  14 const char* GetComponentName(ui::LatencyComponentType type) {
  15 #define CASE_TYPE(t) case ui::t:  return #t
  16   switch (type) {
  17     CASE_TYPE(INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT);
  18     CASE_TYPE(INPUT_EVENT_LATENCY_SCROLL_UPDATE_RWH_COMPONENT);
  19     CASE_TYPE(INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT);
  20     CASE_TYPE(INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT);
  21     CASE_TYPE(INPUT_EVENT_LATENCY_UI_COMPONENT);
  22     CASE_TYPE(INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_COMPONENT);
  23     CASE_TYPE(INPUT_EVENT_LATENCY_ACKED_TOUCH_COMPONENT);
  24     CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_MOUSE_COMPONENT);
  25     CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_TOUCH_COMPONENT);
  26     CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_GESTURE_COMPONENT);
  27     CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT);
  28     default:
  29       DLOG(WARNING) << "Unhandled LatencyComponentType.\n";
  30       break;
  31   }
  32 #undef CASE_TYPE
  33   return "unknown";
  34 }
  35
  36 bool IsTerminalComponent(ui::LatencyComponentType type) {
  37   switch (type) {
  38     case ui::INPUT_EVENT_LATENCY_TERMINATED_MOUSE_COMPONENT:
  39     case ui::INPUT_EVENT_LATENCY_TERMINATED_TOUCH_COMPONENT:
  40     case ui::INPUT_EVENT_LATENCY_TERMINATED_GESTURE_COMPONENT:
  41     case ui::INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT:
  42       return true;
  43     default:
  44       return false;
  45   }
  46 }
  47
  48 bool IsBeginComponent(ui::LatencyComponentType type) {
  49   return (type == ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT);
  50 }
  51
  52 // This class is for converting latency info to trace buffer friendly format.
  53 class LatencyInfoTracedValue : public base::debug::ConvertableToTraceFormat {
  54  public:
  55   static scoped_refptr<ConvertableToTraceFormat> FromValue(
  56       scoped_ptr<base::Value> value);
  57
  58   virtual void AppendAsTraceFormat(std::string* out) const OVERRIDE;
  59
  60  private:
  61   explicit LatencyInfoTracedValue(base::Value* value);
  62   virtual ~LatencyInfoTracedValue();
  63
  64   scoped_ptr<base::Value> value_;
  65
  66   DISALLOW_COPY_AND_ASSIGN(LatencyInfoTracedValue);
  67 };
  68
  69 scoped_refptr<base::debug::ConvertableToTraceFormat>
  70 LatencyInfoTracedValue::FromValue(scoped_ptr<base::Value> value) {
  71   return scoped_refptr<base::debug::ConvertableToTraceFormat>(
  72       new LatencyInfoTracedValue(value.release()));
  73 }
  74
  75 LatencyInfoTracedValue::~LatencyInfoTracedValue() {
  76 }
  77
  78 void LatencyInfoTracedValue::AppendAsTraceFormat(std::string* out) const {
  79   std::string tmp;
  80   base::JSONWriter::Write(value_.get(), &tmp);
  81   *out += tmp;
  82 }
  83
  84 LatencyInfoTracedValue::LatencyInfoTracedValue(base::Value* value)
  85     : value_(value) {
  86 }
  87
  88 // Converts latencyinfo into format that can be dumped into trace buffer.
  89 scoped_refptr<base::debug::ConvertableToTraceFormat> AsTraceableData(
  90     const ui::LatencyInfo& latency) {
  91   scoped_ptr<base::DictionaryValue> record_data(new base::DictionaryValue());
  92   for (ui::LatencyInfo::LatencyMap::const_iterator it =
  93            latency.latency_components.begin();
  94        it != latency.latency_components.end(); ++it) {
  95     base::DictionaryValue* component_info = new base::DictionaryValue();
  96     component_info->SetDouble("comp_id", it->first.second);
  97     component_info->SetDouble("time", it->second.event_time.ToInternalValue());
  98     component_info->SetDouble("count", it->second.event_count);
  99     record_data->Set(GetComponentName(it->first.first), component_info);
 100   }
 101   return LatencyInfoTracedValue::FromValue(record_data.PassAs<base::Value>());
 102 }
 103
 104 }  // namespace
 105
 106 namespace ui {
 107
 108 LatencyInfo::LatencyInfo() : trace_id(-1), terminated(false) {
 109 }
 110
 111 LatencyInfo::~LatencyInfo() {
 112 }
 113
 114 void LatencyInfo::MergeWith(const LatencyInfo& other) {
 115   for (LatencyMap::const_iterator it = other.latency_components.begin();
 116        it != other.latency_components.end();
 117        ++it) {
 118     AddLatencyNumberWithTimestamp(it->first.first,
 119                                   it->first.second,
 120                                   it->second.sequence_number,
 121                                   it->second.event_time,
 122                                   it->second.event_count,
 123                                   false);
 124   }
 125 }
 126
 127 void LatencyInfo::AddNewLatencyFrom(const LatencyInfo& other) {
 128     for (LatencyMap::const_iterator it = other.latency_components.begin();
 129          it != other.latency_components.end();
 130          ++it) {
 131       if (!FindLatency(it->first.first, it->first.second, NULL)) {
 132         AddLatencyNumberWithTimestamp(it->first.first,
 133                                       it->first.second,
 134                                       it->second.sequence_number,
 135                                       it->second.event_time,
 136                                       it->second.event_count,
 137                                       false);
 138       }
 139     }
 140 }
 141
 142 void LatencyInfo::AddLatencyNumber(LatencyComponentType component,
 143                                    int64 id,
 144                                    int64 component_sequence_number) {
 145   AddLatencyNumberWithTimestamp(component, id, component_sequence_number,
 146                                 base::TimeTicks::HighResNow(), 1, true);
 147 }
 148
 149 void LatencyInfo::AddLatencyNumberWithTimestamp(LatencyComponentType component,
 150                                                 int64 id,
 151                                                 int64 component_sequence_number,
 152                                                 base::TimeTicks time,
 153                                                 uint32 event_count,
 154                                                 bool dump_to_trace) {
 155   if (dump_to_trace && IsBeginComponent(component)) {
 156     // Should only ever add begin component once.
 157     CHECK_EQ(-1, trace_id);
 158     trace_id = component_sequence_number;
 159     TRACE_EVENT_ASYNC_BEGIN0("benchmark",
 160                              "InputLatency",
 161                              TRACE_ID_DONT_MANGLE(trace_id));
 162   }
 163
 164   LatencyMap::key_type key = std::make_pair(component, id);
 165   LatencyMap::iterator it = latency_components.find(key);
 166   if (it == latency_components.end()) {
 167     LatencyComponent info = {component_sequence_number, time, event_count};
 168     latency_components[key] = info;
 169   } else {
 170     it->second.sequence_number = std::max(component_sequence_number,
 171                                           it->second.sequence_number);
 172     uint32 new_count = event_count + it->second.event_count;
 173     if (event_count > 0 && new_count != 0) {
 174       // Do a weighted average, so that the new event_time is the average of
 175       // the times of events currently in this structure with the time passed
 176       // into this method.
 177       it->second.event_time += (time - it->second.event_time) * event_count /
 178           new_count;
 179       it->second.event_count = new_count;
 180     }
 181   }
 182
 183   if (dump_to_trace && IsTerminalComponent(component) && trace_id != -1) {
 184     // Should only ever add terminal component once.
 185     CHECK(!terminated);
 186     terminated = true;
 187     TRACE_EVENT_ASYNC_END1("benchmark",
 188                            "InputLatency",
 189                            TRACE_ID_DONT_MANGLE(trace_id),
 190                            "data", AsTraceableData(*this));
 191   }
 192 }
 193
 194 bool LatencyInfo::FindLatency(LatencyComponentType type,
 195                               int64 id,
 196                               LatencyComponent* output) const {
 197   LatencyMap::const_iterator it = latency_components.find(
 198       std::make_pair(type, id));
 199   if (it == latency_components.end())
 200     return false;
 201   if (output)
 202     *output = it->second;
 203   return true;
 204 }
 205
 206 void LatencyInfo::Clear() {
 207   latency_components.clear();
 208 }
 209
 210 }  // namespace ui