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
13namespace {
14
15const size_t kMaxLatencyInfoNumber = 100;
16
17const char* GetComponentName(ui::LatencyComponentType type) {
18#define CASE_TYPE(t) case ui::t:  return #t
19  switch (type) {
20    CASE_TYPE(INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT);
21    CASE_TYPE(INPUT_EVENT_LATENCY_BEGIN_PLUGIN_COMPONENT);
22    CASE_TYPE(INPUT_EVENT_LATENCY_SCROLL_UPDATE_RWH_COMPONENT);
23    CASE_TYPE(INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT);
24    CASE_TYPE(INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT);
25    CASE_TYPE(INPUT_EVENT_LATENCY_UI_COMPONENT);
26    CASE_TYPE(INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_COMPONENT);
27    CASE_TYPE(INPUT_EVENT_LATENCY_ACKED_TOUCH_COMPONENT);
28    CASE_TYPE(WINDOW_SNAPSHOT_FRAME_NUMBER_COMPONENT);
29    CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_MOUSE_COMPONENT);
30    CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_TOUCH_COMPONENT);
31    CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_GESTURE_COMPONENT);
32    CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT);
33    CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_COMMIT_FAILED_COMPONENT);
34    CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_SWAP_FAILED_COMPONENT);
35    CASE_TYPE(LATENCY_INFO_LIST_TERMINATED_OVERFLOW_COMPONENT);
36    CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_PLUGIN_COMPONENT);
37    default:
38      DLOG(WARNING) << "Unhandled LatencyComponentType.\n";
39      break;
40  }
41#undef CASE_TYPE
42  return "unknown";
43}
44
45bool IsTerminalComponent(ui::LatencyComponentType type) {
46  switch (type) {
47    case ui::INPUT_EVENT_LATENCY_TERMINATED_MOUSE_COMPONENT:
48    case ui::INPUT_EVENT_LATENCY_TERMINATED_TOUCH_COMPONENT:
49    case ui::INPUT_EVENT_LATENCY_TERMINATED_GESTURE_COMPONENT:
50    case ui::INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT:
51    case ui::INPUT_EVENT_LATENCY_TERMINATED_COMMIT_FAILED_COMPONENT:
52    case ui::INPUT_EVENT_LATENCY_TERMINATED_SWAP_FAILED_COMPONENT:
53    case ui::LATENCY_INFO_LIST_TERMINATED_OVERFLOW_COMPONENT:
54    case ui::INPUT_EVENT_LATENCY_TERMINATED_PLUGIN_COMPONENT:
55      return true;
56    default:
57      return false;
58  }
59}
60
61bool IsBeginComponent(ui::LatencyComponentType type) {
62  return (type == ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT ||
63          type == ui::INPUT_EVENT_LATENCY_BEGIN_PLUGIN_COMPONENT);
64}
65
66// This class is for converting latency info to trace buffer friendly format.
67class LatencyInfoTracedValue : public base::debug::ConvertableToTraceFormat {
68 public:
69  static scoped_refptr<ConvertableToTraceFormat> FromValue(
70      scoped_ptr<base::Value> value);
71
72  virtual void AppendAsTraceFormat(std::string* out) const OVERRIDE;
73
74 private:
75  explicit LatencyInfoTracedValue(base::Value* value);
76  virtual ~LatencyInfoTracedValue();
77
78  scoped_ptr<base::Value> value_;
79
80  DISALLOW_COPY_AND_ASSIGN(LatencyInfoTracedValue);
81};
82
83scoped_refptr<base::debug::ConvertableToTraceFormat>
84LatencyInfoTracedValue::FromValue(scoped_ptr<base::Value> value) {
85  return scoped_refptr<base::debug::ConvertableToTraceFormat>(
86      new LatencyInfoTracedValue(value.release()));
87}
88
89LatencyInfoTracedValue::~LatencyInfoTracedValue() {
90}
91
92void LatencyInfoTracedValue::AppendAsTraceFormat(std::string* out) const {
93  std::string tmp;
94  base::JSONWriter::Write(value_.get(), &tmp);
95  *out += tmp;
96}
97
98LatencyInfoTracedValue::LatencyInfoTracedValue(base::Value* value)
99    : value_(value) {
100}
101
102// Converts latencyinfo into format that can be dumped into trace buffer.
103scoped_refptr<base::debug::ConvertableToTraceFormat> AsTraceableData(
104    const ui::LatencyInfo& latency) {
105  scoped_ptr<base::DictionaryValue> record_data(new base::DictionaryValue());
106  for (ui::LatencyInfo::LatencyMap::const_iterator it =
107           latency.latency_components.begin();
108       it != latency.latency_components.end(); ++it) {
109    base::DictionaryValue* component_info = new base::DictionaryValue();
110    component_info->SetDouble("comp_id", it->first.second);
111    component_info->SetDouble("time", it->second.event_time.ToInternalValue());
112    component_info->SetDouble("count", it->second.event_count);
113    record_data->Set(GetComponentName(it->first.first), component_info);
114  }
115  record_data->SetDouble("trace_id", latency.trace_id);
116  return LatencyInfoTracedValue::FromValue(record_data.PassAs<base::Value>());
117}
118
119}  // namespace
120
121namespace ui {
122
123LatencyInfo::LatencyInfo() : trace_id(-1), terminated(false) {
124}
125
126LatencyInfo::~LatencyInfo() {
127}
128
129bool LatencyInfo::Verify(const std::vector<LatencyInfo>& latency_info,
130                         const char* referring_msg) {
131  if (latency_info.size() > kMaxLatencyInfoNumber) {
132    LOG(ERROR) << referring_msg << ", LatencyInfo vector size "
133               << latency_info.size() << " is too big.";
134    return false;
135  }
136  return true;
137}
138
139void LatencyInfo::CopyLatencyFrom(const LatencyInfo& other,
140                                  LatencyComponentType type) {
141  for (LatencyMap::const_iterator it = other.latency_components.begin();
142       it != other.latency_components.end();
143       ++it) {
144    if (it->first.first == type) {
145      AddLatencyNumberWithTimestamp(it->first.first,
146                                    it->first.second,
147                                    it->second.sequence_number,
148                                    it->second.event_time,
149                                    it->second.event_count);
150    }
151  }
152}
153
154void LatencyInfo::AddNewLatencyFrom(const LatencyInfo& other) {
155    for (LatencyMap::const_iterator it = other.latency_components.begin();
156         it != other.latency_components.end();
157         ++it) {
158      if (!FindLatency(it->first.first, it->first.second, NULL)) {
159        AddLatencyNumberWithTimestamp(it->first.first,
160                                      it->first.second,
161                                      it->second.sequence_number,
162                                      it->second.event_time,
163                                      it->second.event_count);
164      }
165    }
166}
167
168void LatencyInfo::AddLatencyNumber(LatencyComponentType component,
169                                   int64 id,
170                                   int64 component_sequence_number) {
171  AddLatencyNumberWithTimestamp(component, id, component_sequence_number,
172                                base::TimeTicks::HighResNow(), 1);
173}
174
175void LatencyInfo::AddLatencyNumberWithTimestamp(LatencyComponentType component,
176                                                int64 id,
177                                                int64 component_sequence_number,
178                                                base::TimeTicks time,
179                                                uint32 event_count) {
180  if (IsBeginComponent(component)) {
181    // Should only ever add begin component once.
182    CHECK_EQ(-1, trace_id);
183    trace_id = component_sequence_number;
184    TRACE_EVENT_ASYNC_BEGIN0("benchmark",
185                             "InputLatency",
186                             TRACE_ID_DONT_MANGLE(trace_id));
187    TRACE_EVENT_FLOW_BEGIN0(
188        "input", "LatencyInfo.Flow", TRACE_ID_DONT_MANGLE(trace_id));
189  }
190
191  LatencyMap::key_type key = std::make_pair(component, id);
192  LatencyMap::iterator it = latency_components.find(key);
193  if (it == latency_components.end()) {
194    LatencyComponent info = {component_sequence_number, time, event_count};
195    latency_components[key] = info;
196  } else {
197    it->second.sequence_number = std::max(component_sequence_number,
198                                          it->second.sequence_number);
199    uint32 new_count = event_count + it->second.event_count;
200    if (event_count > 0 && new_count != 0) {
201      // Do a weighted average, so that the new event_time is the average of
202      // the times of events currently in this structure with the time passed
203      // into this method.
204      it->second.event_time += (time - it->second.event_time) * event_count /
205          new_count;
206      it->second.event_count = new_count;
207    }
208  }
209
210  if (IsTerminalComponent(component) && trace_id != -1) {
211    // Should only ever add terminal component once.
212    CHECK(!terminated);
213    terminated = true;
214    TRACE_EVENT_ASYNC_END1("benchmark",
215                           "InputLatency",
216                           TRACE_ID_DONT_MANGLE(trace_id),
217                           "data", AsTraceableData(*this));
218    TRACE_EVENT_FLOW_END0(
219        "input", "LatencyInfo.Flow", TRACE_ID_DONT_MANGLE(trace_id));
220  }
221}
222
223bool LatencyInfo::FindLatency(LatencyComponentType type,
224                              int64 id,
225                              LatencyComponent* output) const {
226  LatencyMap::const_iterator it = latency_components.find(
227      std::make_pair(type, id));
228  if (it == latency_components.end())
229    return false;
230  if (output)
231    *output = it->second;
232  return true;
233}
234
235void LatencyInfo::RemoveLatency(LatencyComponentType type) {
236  LatencyMap::iterator it = latency_components.begin();
237  while (it != latency_components.end()) {
238    if (it->first.first == type) {
239      LatencyMap::iterator tmp = it;
240      ++it;
241      latency_components.erase(tmp);
242    } else {
243      it++;
244    }
245  }
246}
247
248void LatencyInfo::Clear() {
249  latency_components.clear();
250}
251
252void LatencyInfo::TraceEventType(const char* event_type) {
253  TRACE_EVENT_ASYNC_STEP_INTO0("benchmark",
254                               "InputLatency",
255                               TRACE_ID_DONT_MANGLE(trace_id),
256                               event_type);
257}
258
259}  // namespace ui
260