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.
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"
15 const unsigned int kMaxLatencyInfoNumber = 100;
17 const char* GetComponentName(ui::LatencyComponentType type) {
18 #define CASE_TYPE(t) case ui::t: return #t
20 CASE_TYPE(INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT);
21 CASE_TYPE(INPUT_EVENT_LATENCY_SCROLL_UPDATE_RWH_COMPONENT);
22 CASE_TYPE(INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT);
23 CASE_TYPE(INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT);
24 CASE_TYPE(INPUT_EVENT_LATENCY_UI_COMPONENT);
25 CASE_TYPE(INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_COMPONENT);
26 CASE_TYPE(INPUT_EVENT_LATENCY_ACKED_TOUCH_COMPONENT);
27 CASE_TYPE(WINDOW_SNAPSHOT_FRAME_NUMBER_COMPONENT);
28 CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_MOUSE_COMPONENT);
29 CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_TOUCH_COMPONENT);
30 CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_GESTURE_COMPONENT);
31 CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT);
32 CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_COMMIT_FAILED_COMPONENT);
33 CASE_TYPE(INPUT_EVENT_LATENCY_TERMINATED_SWAP_FAILED_COMPONENT);
34 CASE_TYPE(LATENCY_INFO_LIST_TERMINATED_OVERFLOW_COMPONENT);
36 DLOG(WARNING) << "Unhandled LatencyComponentType.\n";
43 bool IsTerminalComponent(ui::LatencyComponentType type) {
45 case ui::INPUT_EVENT_LATENCY_TERMINATED_MOUSE_COMPONENT:
46 case ui::INPUT_EVENT_LATENCY_TERMINATED_TOUCH_COMPONENT:
47 case ui::INPUT_EVENT_LATENCY_TERMINATED_GESTURE_COMPONENT:
48 case ui::INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT:
49 case ui::INPUT_EVENT_LATENCY_TERMINATED_COMMIT_FAILED_COMPONENT:
50 case ui::INPUT_EVENT_LATENCY_TERMINATED_SWAP_FAILED_COMPONENT:
51 case ui::LATENCY_INFO_LIST_TERMINATED_OVERFLOW_COMPONENT:
58 bool IsBeginComponent(ui::LatencyComponentType type) {
59 return (type == ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT);
62 // This class is for converting latency info to trace buffer friendly format.
63 class LatencyInfoTracedValue : public base::debug::ConvertableToTraceFormat {
65 static scoped_refptr<ConvertableToTraceFormat> FromValue(
66 scoped_ptr<base::Value> value);
68 virtual void AppendAsTraceFormat(std::string* out) const OVERRIDE;
71 explicit LatencyInfoTracedValue(base::Value* value);
72 virtual ~LatencyInfoTracedValue();
74 scoped_ptr<base::Value> value_;
76 DISALLOW_COPY_AND_ASSIGN(LatencyInfoTracedValue);
79 scoped_refptr<base::debug::ConvertableToTraceFormat>
80 LatencyInfoTracedValue::FromValue(scoped_ptr<base::Value> value) {
81 return scoped_refptr<base::debug::ConvertableToTraceFormat>(
82 new LatencyInfoTracedValue(value.release()));
85 LatencyInfoTracedValue::~LatencyInfoTracedValue() {
88 void LatencyInfoTracedValue::AppendAsTraceFormat(std::string* out) const {
90 base::JSONWriter::Write(value_.get(), &tmp);
94 LatencyInfoTracedValue::LatencyInfoTracedValue(base::Value* value)
98 // Converts latencyinfo into format that can be dumped into trace buffer.
99 scoped_refptr<base::debug::ConvertableToTraceFormat> AsTraceableData(
100 const ui::LatencyInfo& latency) {
101 scoped_ptr<base::DictionaryValue> record_data(new base::DictionaryValue());
102 for (ui::LatencyInfo::LatencyMap::const_iterator it =
103 latency.latency_components.begin();
104 it != latency.latency_components.end(); ++it) {
105 base::DictionaryValue* component_info = new base::DictionaryValue();
106 component_info->SetDouble("comp_id", it->first.second);
107 component_info->SetDouble("time", it->second.event_time.ToInternalValue());
108 component_info->SetDouble("count", it->second.event_count);
109 record_data->Set(GetComponentName(it->first.first), component_info);
111 record_data->SetDouble("trace_id", latency.trace_id);
112 return LatencyInfoTracedValue::FromValue(record_data.PassAs<base::Value>());
119 LatencyInfo::LatencyInfo() : trace_id(-1), terminated(false) {
122 LatencyInfo::~LatencyInfo() {
125 bool LatencyInfo::Verify(const std::vector<LatencyInfo>& latency_info,
126 const char* referring_msg) {
127 if (latency_info.size() > kMaxLatencyInfoNumber) {
128 LOG(ERROR) << referring_msg << ", LatencyInfo vector size "
129 << latency_info.size() << " is too big.";
135 void LatencyInfo::AddNewLatencyFrom(const LatencyInfo& other) {
136 for (LatencyMap::const_iterator it = other.latency_components.begin();
137 it != other.latency_components.end();
139 if (!FindLatency(it->first.first, it->first.second, NULL)) {
140 AddLatencyNumberWithTimestamp(it->first.first,
142 it->second.sequence_number,
143 it->second.event_time,
144 it->second.event_count);
149 void LatencyInfo::AddLatencyNumber(LatencyComponentType component,
151 int64 component_sequence_number) {
152 AddLatencyNumberWithTimestamp(component, id, component_sequence_number,
153 base::TimeTicks::HighResNow(), 1);
156 void LatencyInfo::AddLatencyNumberWithTimestamp(LatencyComponentType component,
158 int64 component_sequence_number,
159 base::TimeTicks time,
160 uint32 event_count) {
161 if (IsBeginComponent(component)) {
162 // Should only ever add begin component once.
163 CHECK_EQ(-1, trace_id);
164 trace_id = component_sequence_number;
165 TRACE_EVENT_ASYNC_BEGIN0("benchmark",
167 TRACE_ID_DONT_MANGLE(trace_id));
170 LatencyMap::key_type key = std::make_pair(component, id);
171 LatencyMap::iterator it = latency_components.find(key);
172 if (it == latency_components.end()) {
173 LatencyComponent info = {component_sequence_number, time, event_count};
174 latency_components[key] = info;
176 it->second.sequence_number = std::max(component_sequence_number,
177 it->second.sequence_number);
178 uint32 new_count = event_count + it->second.event_count;
179 if (event_count > 0 && new_count != 0) {
180 // Do a weighted average, so that the new event_time is the average of
181 // the times of events currently in this structure with the time passed
183 it->second.event_time += (time - it->second.event_time) * event_count /
185 it->second.event_count = new_count;
189 if (IsTerminalComponent(component) && trace_id != -1) {
190 // Should only ever add terminal component once.
193 TRACE_EVENT_ASYNC_END1("benchmark",
195 TRACE_ID_DONT_MANGLE(trace_id),
196 "data", AsTraceableData(*this));
200 bool LatencyInfo::FindLatency(LatencyComponentType type,
202 LatencyComponent* output) const {
203 LatencyMap::const_iterator it = latency_components.find(
204 std::make_pair(type, id));
205 if (it == latency_components.end())
208 *output = it->second;
212 void LatencyInfo::RemoveLatency(LatencyComponentType type) {
213 LatencyMap::iterator it = latency_components.begin();
214 while (it != latency_components.end()) {
215 if (it->first.first == type) {
216 LatencyMap::iterator tmp = it;
218 latency_components.erase(tmp);
225 void LatencyInfo::Clear() {
226 latency_components.clear();
229 void LatencyInfo::TraceEventType(const char* event_type) {
230 TRACE_EVENT_ASYNC_STEP_INTO0("benchmark",
232 TRACE_ID_DONT_MANGLE(trace_id),