1 // Copyright (c) 2012 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/test/trace_event_analyzer.h"
6
7 #include <math.h>
8
9 #include <algorithm>
10 #include <set>
11
12 #include "base/json/json_reader.h"
13 #include "base/memory/ptr_util.h"
14 #include "base/memory/ref_counted_memory.h"
15 #include "base/run_loop.h"
16 #include "base/strings/pattern.h"
17 #include "base/trace_event/trace_buffer.h"
18 #include "base/trace_event/trace_config.h"
19 #include "base/trace_event/trace_log.h"
20 #include "base/values.h"
21
22 namespace {
OnTraceDataCollected(base::OnceClosure quit_closure,base::trace_event::TraceResultBuffer * buffer,const scoped_refptr<base::RefCountedString> & json,bool has_more_events)23 void OnTraceDataCollected(base::OnceClosure quit_closure,
24 base::trace_event::TraceResultBuffer* buffer,
25 const scoped_refptr<base::RefCountedString>& json,
26 bool has_more_events) {
27 buffer->AddFragment(json->data());
28 if (!has_more_events)
29 std::move(quit_closure).Run();
30 }
31 } // namespace
32
33 namespace trace_analyzer {
34
35 // TraceEvent
36
TraceEvent()37 TraceEvent::TraceEvent()
38 : thread(0, 0),
39 timestamp(0),
40 duration(0),
41 phase(TRACE_EVENT_PHASE_BEGIN),
42 other_event(nullptr) {}
43
44 TraceEvent::TraceEvent(TraceEvent&& other) = default;
45
46 TraceEvent::~TraceEvent() = default;
47
48 TraceEvent& TraceEvent::operator=(TraceEvent&& rhs) = default;
49
SetFromJSON(const base::Value * event_value)50 bool TraceEvent::SetFromJSON(const base::Value* event_value) {
51 if (event_value->type() != base::Value::Type::DICTIONARY) {
52 LOG(ERROR) << "Value must be Type::DICTIONARY";
53 return false;
54 }
55 const base::DictionaryValue* dictionary =
56 static_cast<const base::DictionaryValue*>(event_value);
57
58 std::string phase_str;
59 const base::DictionaryValue* args = nullptr;
60
61 if (!dictionary->GetString("ph", &phase_str)) {
62 LOG(ERROR) << "ph is missing from TraceEvent JSON";
63 return false;
64 }
65
66 phase = *phase_str.data();
67
68 bool may_have_duration = (phase == TRACE_EVENT_PHASE_COMPLETE);
69 bool require_origin = (phase != TRACE_EVENT_PHASE_METADATA);
70 bool require_id = (phase == TRACE_EVENT_PHASE_ASYNC_BEGIN ||
71 phase == TRACE_EVENT_PHASE_ASYNC_STEP_INTO ||
72 phase == TRACE_EVENT_PHASE_ASYNC_STEP_PAST ||
73 phase == TRACE_EVENT_PHASE_MEMORY_DUMP ||
74 phase == TRACE_EVENT_PHASE_ENTER_CONTEXT ||
75 phase == TRACE_EVENT_PHASE_LEAVE_CONTEXT ||
76 phase == TRACE_EVENT_PHASE_CREATE_OBJECT ||
77 phase == TRACE_EVENT_PHASE_DELETE_OBJECT ||
78 phase == TRACE_EVENT_PHASE_SNAPSHOT_OBJECT ||
79 phase == TRACE_EVENT_PHASE_ASYNC_END);
80
81 if (require_origin && !dictionary->GetInteger("pid", &thread.process_id)) {
82 LOG(ERROR) << "pid is missing from TraceEvent JSON";
83 return false;
84 }
85 if (require_origin && !dictionary->GetInteger("tid", &thread.thread_id)) {
86 LOG(ERROR) << "tid is missing from TraceEvent JSON";
87 return false;
88 }
89 if (require_origin && !dictionary->GetDouble("ts", ×tamp)) {
90 LOG(ERROR) << "ts is missing from TraceEvent JSON";
91 return false;
92 }
93 if (may_have_duration) {
94 dictionary->GetDouble("dur", &duration);
95 }
96 if (!dictionary->GetString("cat", &category)) {
97 LOG(ERROR) << "cat is missing from TraceEvent JSON";
98 return false;
99 }
100 if (!dictionary->GetString("name", &name)) {
101 LOG(ERROR) << "name is missing from TraceEvent JSON";
102 return false;
103 }
104 if (!dictionary->GetDictionary("args", &args)) {
105 LOG(ERROR) << "args is missing from TraceEvent JSON";
106 return false;
107 }
108 if (require_id && !dictionary->GetString("id", &id)) {
109 LOG(ERROR) << "id is missing from ASYNC_BEGIN/ASYNC_END TraceEvent JSON";
110 return false;
111 }
112
113 dictionary->GetDouble("tdur", &thread_duration);
114 dictionary->GetDouble("tts", &thread_timestamp);
115 dictionary->GetString("scope", &scope);
116 dictionary->GetString("bind_id", &bind_id);
117 dictionary->GetBoolean("flow_out", &flow_out);
118 dictionary->GetBoolean("flow_in", &flow_in);
119
120 const base::DictionaryValue* id2;
121 if (dictionary->GetDictionary("id2", &id2)) {
122 id2->GetString("global", &global_id2);
123 id2->GetString("local", &local_id2);
124 }
125
126 // For each argument, copy the type and create a trace_analyzer::TraceValue.
127 for (base::DictionaryValue::Iterator it(*args); !it.IsAtEnd();
128 it.Advance()) {
129 std::string str;
130 bool boolean = false;
131 int int_num = 0;
132 double double_num = 0.0;
133 if (it.value().GetAsString(&str)) {
134 arg_strings[it.key()] = str;
135 } else if (it.value().GetAsInteger(&int_num)) {
136 arg_numbers[it.key()] = static_cast<double>(int_num);
137 } else if (it.value().GetAsBoolean(&boolean)) {
138 arg_numbers[it.key()] = static_cast<double>(boolean ? 1 : 0);
139 } else if (it.value().GetAsDouble(&double_num)) {
140 arg_numbers[it.key()] = double_num;
141 }
142 // Record all arguments as values.
143 arg_values[it.key()] = it.value().CreateDeepCopy();
144 }
145
146 return true;
147 }
148
GetAbsTimeToOtherEvent() const149 double TraceEvent::GetAbsTimeToOtherEvent() const {
150 return fabs(other_event->timestamp - timestamp);
151 }
152
GetArgAsString(const std::string & name,std::string * arg) const153 bool TraceEvent::GetArgAsString(const std::string& name,
154 std::string* arg) const {
155 const auto it = arg_strings.find(name);
156 if (it != arg_strings.end()) {
157 *arg = it->second;
158 return true;
159 }
160 return false;
161 }
162
GetArgAsNumber(const std::string & name,double * arg) const163 bool TraceEvent::GetArgAsNumber(const std::string& name,
164 double* arg) const {
165 const auto it = arg_numbers.find(name);
166 if (it != arg_numbers.end()) {
167 *arg = it->second;
168 return true;
169 }
170 return false;
171 }
172
GetArgAsValue(const std::string & name,std::unique_ptr<base::Value> * arg) const173 bool TraceEvent::GetArgAsValue(const std::string& name,
174 std::unique_ptr<base::Value>* arg) const {
175 const auto it = arg_values.find(name);
176 if (it != arg_values.end()) {
177 *arg = it->second->CreateDeepCopy();
178 return true;
179 }
180 return false;
181 }
182
HasStringArg(const std::string & name) const183 bool TraceEvent::HasStringArg(const std::string& name) const {
184 return (arg_strings.find(name) != arg_strings.end());
185 }
186
HasNumberArg(const std::string & name) const187 bool TraceEvent::HasNumberArg(const std::string& name) const {
188 return (arg_numbers.find(name) != arg_numbers.end());
189 }
190
HasArg(const std::string & name) const191 bool TraceEvent::HasArg(const std::string& name) const {
192 return (arg_values.find(name) != arg_values.end());
193 }
194
GetKnownArgAsString(const std::string & name) const195 std::string TraceEvent::GetKnownArgAsString(const std::string& name) const {
196 std::string arg_string;
197 bool result = GetArgAsString(name, &arg_string);
198 DCHECK(result);
199 return arg_string;
200 }
201
GetKnownArgAsDouble(const std::string & name) const202 double TraceEvent::GetKnownArgAsDouble(const std::string& name) const {
203 double arg_double = 0;
204 bool result = GetArgAsNumber(name, &arg_double);
205 DCHECK(result);
206 return arg_double;
207 }
208
GetKnownArgAsInt(const std::string & name) const209 int TraceEvent::GetKnownArgAsInt(const std::string& name) const {
210 double arg_double = 0;
211 bool result = GetArgAsNumber(name, &arg_double);
212 DCHECK(result);
213 return static_cast<int>(arg_double);
214 }
215
GetKnownArgAsBool(const std::string & name) const216 bool TraceEvent::GetKnownArgAsBool(const std::string& name) const {
217 double arg_double = 0;
218 bool result = GetArgAsNumber(name, &arg_double);
219 DCHECK(result);
220 return (arg_double != 0.0);
221 }
222
GetKnownArgAsValue(const std::string & name) const223 std::unique_ptr<base::Value> TraceEvent::GetKnownArgAsValue(
224 const std::string& name) const {
225 std::unique_ptr<base::Value> arg_value;
226 bool result = GetArgAsValue(name, &arg_value);
227 DCHECK(result);
228 return arg_value;
229 }
230
231 // QueryNode
232
QueryNode(const Query & query)233 QueryNode::QueryNode(const Query& query) : query_(query) {
234 }
235
236 QueryNode::~QueryNode() = default;
237
238 // Query
239
Query(TraceEventMember member)240 Query::Query(TraceEventMember member)
241 : type_(QUERY_EVENT_MEMBER),
242 operator_(OP_INVALID),
243 member_(member),
244 number_(0),
245 is_pattern_(false) {
246 }
247
Query(TraceEventMember member,const std::string & arg_name)248 Query::Query(TraceEventMember member, const std::string& arg_name)
249 : type_(QUERY_EVENT_MEMBER),
250 operator_(OP_INVALID),
251 member_(member),
252 number_(0),
253 string_(arg_name),
254 is_pattern_(false) {
255 }
256
257 Query::Query(const Query& query) = default;
258
259 Query::~Query() = default;
260
String(const std::string & str)261 Query Query::String(const std::string& str) {
262 return Query(str);
263 }
264
Double(double num)265 Query Query::Double(double num) {
266 return Query(num);
267 }
268
Int(int32_t num)269 Query Query::Int(int32_t num) {
270 return Query(static_cast<double>(num));
271 }
272
Uint(uint32_t num)273 Query Query::Uint(uint32_t num) {
274 return Query(static_cast<double>(num));
275 }
276
Bool(bool boolean)277 Query Query::Bool(bool boolean) {
278 return Query(boolean ? 1.0 : 0.0);
279 }
280
Phase(char phase)281 Query Query::Phase(char phase) {
282 return Query(static_cast<double>(phase));
283 }
284
Pattern(const std::string & pattern)285 Query Query::Pattern(const std::string& pattern) {
286 Query query(pattern);
287 query.is_pattern_ = true;
288 return query;
289 }
290
Evaluate(const TraceEvent & event) const291 bool Query::Evaluate(const TraceEvent& event) const {
292 // First check for values that can convert to bool.
293
294 // double is true if != 0:
295 double bool_value = 0.0;
296 bool is_bool = GetAsDouble(event, &bool_value);
297 if (is_bool)
298 return (bool_value != 0.0);
299
300 // string is true if it is non-empty:
301 std::string str_value;
302 bool is_str = GetAsString(event, &str_value);
303 if (is_str)
304 return !str_value.empty();
305
306 DCHECK_EQ(QUERY_BOOLEAN_OPERATOR, type_)
307 << "Invalid query: missing boolean expression";
308 DCHECK(left_.get());
309 DCHECK(right_.get() || is_unary_operator());
310
311 if (is_comparison_operator()) {
312 DCHECK(left().is_value() && right().is_value())
313 << "Invalid query: comparison operator used between event member and "
314 "value.";
315 bool compare_result = false;
316 if (CompareAsDouble(event, &compare_result))
317 return compare_result;
318 if (CompareAsString(event, &compare_result))
319 return compare_result;
320 return false;
321 }
322 // It's a logical operator.
323 switch (operator_) {
324 case OP_AND:
325 return left().Evaluate(event) && right().Evaluate(event);
326 case OP_OR:
327 return left().Evaluate(event) || right().Evaluate(event);
328 case OP_NOT:
329 return !left().Evaluate(event);
330 default:
331 NOTREACHED();
332 return false;
333 }
334 }
335
CompareAsDouble(const TraceEvent & event,bool * result) const336 bool Query::CompareAsDouble(const TraceEvent& event, bool* result) const {
337 double lhs, rhs;
338 if (!left().GetAsDouble(event, &lhs) || !right().GetAsDouble(event, &rhs))
339 return false;
340 switch (operator_) {
341 case OP_EQ:
342 *result = (lhs == rhs);
343 return true;
344 case OP_NE:
345 *result = (lhs != rhs);
346 return true;
347 case OP_LT:
348 *result = (lhs < rhs);
349 return true;
350 case OP_LE:
351 *result = (lhs <= rhs);
352 return true;
353 case OP_GT:
354 *result = (lhs > rhs);
355 return true;
356 case OP_GE:
357 *result = (lhs >= rhs);
358 return true;
359 default:
360 NOTREACHED();
361 return false;
362 }
363 }
364
CompareAsString(const TraceEvent & event,bool * result) const365 bool Query::CompareAsString(const TraceEvent& event, bool* result) const {
366 std::string lhs, rhs;
367 if (!left().GetAsString(event, &lhs) || !right().GetAsString(event, &rhs))
368 return false;
369 switch (operator_) {
370 case OP_EQ:
371 if (right().is_pattern_)
372 *result = base::MatchPattern(lhs, rhs);
373 else if (left().is_pattern_)
374 *result = base::MatchPattern(rhs, lhs);
375 else
376 *result = (lhs == rhs);
377 return true;
378 case OP_NE:
379 if (right().is_pattern_)
380 *result = !base::MatchPattern(lhs, rhs);
381 else if (left().is_pattern_)
382 *result = !base::MatchPattern(rhs, lhs);
383 else
384 *result = (lhs != rhs);
385 return true;
386 case OP_LT:
387 *result = (lhs < rhs);
388 return true;
389 case OP_LE:
390 *result = (lhs <= rhs);
391 return true;
392 case OP_GT:
393 *result = (lhs > rhs);
394 return true;
395 case OP_GE:
396 *result = (lhs >= rhs);
397 return true;
398 default:
399 NOTREACHED();
400 return false;
401 }
402 }
403
EvaluateArithmeticOperator(const TraceEvent & event,double * num) const404 bool Query::EvaluateArithmeticOperator(const TraceEvent& event,
405 double* num) const {
406 DCHECK_EQ(QUERY_ARITHMETIC_OPERATOR, type_);
407 DCHECK(left_.get());
408 DCHECK(right_.get() || is_unary_operator());
409
410 double lhs = 0, rhs = 0;
411 if (!left().GetAsDouble(event, &lhs))
412 return false;
413 if (!is_unary_operator() && !right().GetAsDouble(event, &rhs))
414 return false;
415
416 switch (operator_) {
417 case OP_ADD:
418 *num = lhs + rhs;
419 return true;
420 case OP_SUB:
421 *num = lhs - rhs;
422 return true;
423 case OP_MUL:
424 *num = lhs * rhs;
425 return true;
426 case OP_DIV:
427 *num = lhs / rhs;
428 return true;
429 case OP_MOD:
430 *num = static_cast<double>(static_cast<int64_t>(lhs) %
431 static_cast<int64_t>(rhs));
432 return true;
433 case OP_NEGATE:
434 *num = -lhs;
435 return true;
436 default:
437 NOTREACHED();
438 return false;
439 }
440 }
441
GetAsDouble(const TraceEvent & event,double * num) const442 bool Query::GetAsDouble(const TraceEvent& event, double* num) const {
443 switch (type_) {
444 case QUERY_ARITHMETIC_OPERATOR:
445 return EvaluateArithmeticOperator(event, num);
446 case QUERY_EVENT_MEMBER:
447 return GetMemberValueAsDouble(event, num);
448 case QUERY_NUMBER:
449 *num = number_;
450 return true;
451 default:
452 return false;
453 }
454 }
455
GetAsString(const TraceEvent & event,std::string * str) const456 bool Query::GetAsString(const TraceEvent& event, std::string* str) const {
457 switch (type_) {
458 case QUERY_EVENT_MEMBER:
459 return GetMemberValueAsString(event, str);
460 case QUERY_STRING:
461 *str = string_;
462 return true;
463 default:
464 return false;
465 }
466 }
467
SelectTargetEvent(const TraceEvent * event,TraceEventMember member)468 const TraceEvent* Query::SelectTargetEvent(const TraceEvent* event,
469 TraceEventMember member) {
470 if (member >= OTHER_FIRST_MEMBER && member <= OTHER_LAST_MEMBER) {
471 return event->other_event;
472 } else if (member >= PREV_FIRST_MEMBER && member <= PREV_LAST_MEMBER) {
473 return event->prev_event;
474 } else {
475 return event;
476 }
477 }
478
GetMemberValueAsDouble(const TraceEvent & event,double * num) const479 bool Query::GetMemberValueAsDouble(const TraceEvent& event,
480 double* num) const {
481 DCHECK_EQ(QUERY_EVENT_MEMBER, type_);
482
483 // This could be a request for a member of |event| or a member of |event|'s
484 // associated previous or next event. Store the target event in the_event:
485 const TraceEvent* the_event = SelectTargetEvent(&event, member_);
486
487 // Request for member of associated event, but there is no associated event.
488 if (!the_event)
489 return false;
490
491 switch (member_) {
492 case EVENT_PID:
493 case OTHER_PID:
494 case PREV_PID:
495 *num = static_cast<double>(the_event->thread.process_id);
496 return true;
497 case EVENT_TID:
498 case OTHER_TID:
499 case PREV_TID:
500 *num = static_cast<double>(the_event->thread.thread_id);
501 return true;
502 case EVENT_TIME:
503 case OTHER_TIME:
504 case PREV_TIME:
505 *num = the_event->timestamp;
506 return true;
507 case EVENT_DURATION:
508 if (!the_event->has_other_event())
509 return false;
510 *num = the_event->GetAbsTimeToOtherEvent();
511 return true;
512 case EVENT_COMPLETE_DURATION:
513 if (the_event->phase != TRACE_EVENT_PHASE_COMPLETE)
514 return false;
515 *num = the_event->duration;
516 return true;
517 case EVENT_PHASE:
518 case OTHER_PHASE:
519 case PREV_PHASE:
520 *num = static_cast<double>(the_event->phase);
521 return true;
522 case EVENT_HAS_STRING_ARG:
523 case OTHER_HAS_STRING_ARG:
524 case PREV_HAS_STRING_ARG:
525 *num = (the_event->HasStringArg(string_) ? 1.0 : 0.0);
526 return true;
527 case EVENT_HAS_NUMBER_ARG:
528 case OTHER_HAS_NUMBER_ARG:
529 case PREV_HAS_NUMBER_ARG:
530 *num = (the_event->HasNumberArg(string_) ? 1.0 : 0.0);
531 return true;
532 case EVENT_ARG:
533 case OTHER_ARG:
534 case PREV_ARG: {
535 // Search for the argument name and return its value if found.
536 std::map<std::string, double>::const_iterator num_i =
537 the_event->arg_numbers.find(string_);
538 if (num_i == the_event->arg_numbers.end())
539 return false;
540 *num = num_i->second;
541 return true;
542 }
543 case EVENT_HAS_OTHER:
544 // return 1.0 (true) if the other event exists
545 *num = event.other_event ? 1.0 : 0.0;
546 return true;
547 case EVENT_HAS_PREV:
548 *num = event.prev_event ? 1.0 : 0.0;
549 return true;
550 default:
551 return false;
552 }
553 }
554
GetMemberValueAsString(const TraceEvent & event,std::string * str) const555 bool Query::GetMemberValueAsString(const TraceEvent& event,
556 std::string* str) const {
557 DCHECK_EQ(QUERY_EVENT_MEMBER, type_);
558
559 // This could be a request for a member of |event| or a member of |event|'s
560 // associated previous or next event. Store the target event in the_event:
561 const TraceEvent* the_event = SelectTargetEvent(&event, member_);
562
563 // Request for member of associated event, but there is no associated event.
564 if (!the_event)
565 return false;
566
567 switch (member_) {
568 case EVENT_CATEGORY:
569 case OTHER_CATEGORY:
570 case PREV_CATEGORY:
571 *str = the_event->category;
572 return true;
573 case EVENT_NAME:
574 case OTHER_NAME:
575 case PREV_NAME:
576 *str = the_event->name;
577 return true;
578 case EVENT_ID:
579 case OTHER_ID:
580 case PREV_ID:
581 *str = the_event->id;
582 return true;
583 case EVENT_ARG:
584 case OTHER_ARG:
585 case PREV_ARG: {
586 // Search for the argument name and return its value if found.
587 std::map<std::string, std::string>::const_iterator str_i =
588 the_event->arg_strings.find(string_);
589 if (str_i == the_event->arg_strings.end())
590 return false;
591 *str = str_i->second;
592 return true;
593 }
594 default:
595 return false;
596 }
597 }
598
Query(const std::string & str)599 Query::Query(const std::string& str)
600 : type_(QUERY_STRING),
601 operator_(OP_INVALID),
602 member_(EVENT_INVALID),
603 number_(0),
604 string_(str),
605 is_pattern_(false) {
606 }
607
Query(double num)608 Query::Query(double num)
609 : type_(QUERY_NUMBER),
610 operator_(OP_INVALID),
611 member_(EVENT_INVALID),
612 number_(num),
613 is_pattern_(false) {
614 }
left() const615 const Query& Query::left() const {
616 return left_->query();
617 }
618
right() const619 const Query& Query::right() const {
620 return right_->query();
621 }
622
operator ==(const Query & rhs) const623 Query Query::operator==(const Query& rhs) const {
624 return Query(*this, rhs, OP_EQ);
625 }
626
operator !=(const Query & rhs) const627 Query Query::operator!=(const Query& rhs) const {
628 return Query(*this, rhs, OP_NE);
629 }
630
operator <(const Query & rhs) const631 Query Query::operator<(const Query& rhs) const {
632 return Query(*this, rhs, OP_LT);
633 }
634
operator <=(const Query & rhs) const635 Query Query::operator<=(const Query& rhs) const {
636 return Query(*this, rhs, OP_LE);
637 }
638
operator >(const Query & rhs) const639 Query Query::operator>(const Query& rhs) const {
640 return Query(*this, rhs, OP_GT);
641 }
642
operator >=(const Query & rhs) const643 Query Query::operator>=(const Query& rhs) const {
644 return Query(*this, rhs, OP_GE);
645 }
646
operator &&(const Query & rhs) const647 Query Query::operator&&(const Query& rhs) const {
648 return Query(*this, rhs, OP_AND);
649 }
650
operator ||(const Query & rhs) const651 Query Query::operator||(const Query& rhs) const {
652 return Query(*this, rhs, OP_OR);
653 }
654
operator !() const655 Query Query::operator!() const {
656 return Query(*this, OP_NOT);
657 }
658
operator +(const Query & rhs) const659 Query Query::operator+(const Query& rhs) const {
660 return Query(*this, rhs, OP_ADD);
661 }
662
operator -(const Query & rhs) const663 Query Query::operator-(const Query& rhs) const {
664 return Query(*this, rhs, OP_SUB);
665 }
666
operator *(const Query & rhs) const667 Query Query::operator*(const Query& rhs) const {
668 return Query(*this, rhs, OP_MUL);
669 }
670
operator /(const Query & rhs) const671 Query Query::operator/(const Query& rhs) const {
672 return Query(*this, rhs, OP_DIV);
673 }
674
operator %(const Query & rhs) const675 Query Query::operator%(const Query& rhs) const {
676 return Query(*this, rhs, OP_MOD);
677 }
678
operator -() const679 Query Query::operator-() const {
680 return Query(*this, OP_NEGATE);
681 }
682
683
Query(const Query & left,const Query & right,Operator binary_op)684 Query::Query(const Query& left, const Query& right, Operator binary_op)
685 : operator_(binary_op),
686 left_(new QueryNode(left)),
687 right_(new QueryNode(right)),
688 member_(EVENT_INVALID),
689 number_(0) {
690 type_ = (binary_op < OP_ADD ?
691 QUERY_BOOLEAN_OPERATOR : QUERY_ARITHMETIC_OPERATOR);
692 }
693
Query(const Query & left,Operator unary_op)694 Query::Query(const Query& left, Operator unary_op)
695 : operator_(unary_op),
696 left_(new QueryNode(left)),
697 member_(EVENT_INVALID),
698 number_(0) {
699 type_ = (unary_op < OP_ADD ?
700 QUERY_BOOLEAN_OPERATOR : QUERY_ARITHMETIC_OPERATOR);
701 }
702
703 namespace {
704
705 // Search |events| for |query| and add matches to |output|.
FindMatchingEvents(const std::vector<TraceEvent> & events,const Query & query,TraceEventVector * output,bool ignore_metadata_events)706 size_t FindMatchingEvents(const std::vector<TraceEvent>& events,
707 const Query& query,
708 TraceEventVector* output,
709 bool ignore_metadata_events) {
710 for (size_t i = 0; i < events.size(); ++i) {
711 if (ignore_metadata_events && events[i].phase == TRACE_EVENT_PHASE_METADATA)
712 continue;
713 if (query.Evaluate(events[i]))
714 output->push_back(&events[i]);
715 }
716 return output->size();
717 }
718
ParseEventsFromJson(const std::string & json,std::vector<TraceEvent> * output)719 bool ParseEventsFromJson(const std::string& json,
720 std::vector<TraceEvent>* output) {
721 std::unique_ptr<base::Value> root = base::JSONReader::Read(json);
722
723 base::ListValue* root_list = nullptr;
724 if (!root.get() || !root->GetAsList(&root_list))
725 return false;
726
727 for (size_t i = 0; i < root_list->GetSize(); ++i) {
728 base::Value* item = nullptr;
729 if (root_list->Get(i, &item)) {
730 TraceEvent event;
731 if (event.SetFromJSON(item))
732 output->push_back(std::move(event));
733 else
734 return false;
735 }
736 }
737
738 return true;
739 }
740
741 } // namespace
742
743 // TraceAnalyzer
744
TraceAnalyzer()745 TraceAnalyzer::TraceAnalyzer()
746 : ignore_metadata_events_(false), allow_association_changes_(true) {}
747
748 TraceAnalyzer::~TraceAnalyzer() = default;
749
750 // static
Create(const std::string & json_events)751 TraceAnalyzer* TraceAnalyzer::Create(const std::string& json_events) {
752 std::unique_ptr<TraceAnalyzer> analyzer(new TraceAnalyzer());
753 if (analyzer->SetEvents(json_events))
754 return analyzer.release();
755 return nullptr;
756 }
757
SetEvents(const std::string & json_events)758 bool TraceAnalyzer::SetEvents(const std::string& json_events) {
759 raw_events_.clear();
760 if (!ParseEventsFromJson(json_events, &raw_events_))
761 return false;
762 std::stable_sort(raw_events_.begin(), raw_events_.end());
763 ParseMetadata();
764 return true;
765 }
766
AssociateBeginEndEvents()767 void TraceAnalyzer::AssociateBeginEndEvents() {
768 using trace_analyzer::Query;
769
770 Query begin(Query::EventPhaseIs(TRACE_EVENT_PHASE_BEGIN));
771 Query end(Query::EventPhaseIs(TRACE_EVENT_PHASE_END));
772 Query match(Query::EventName() == Query::OtherName() &&
773 Query::EventCategory() == Query::OtherCategory() &&
774 Query::EventTid() == Query::OtherTid() &&
775 Query::EventPid() == Query::OtherPid());
776
777 AssociateEvents(begin, end, match);
778 }
779
AssociateAsyncBeginEndEvents(bool match_pid)780 void TraceAnalyzer::AssociateAsyncBeginEndEvents(bool match_pid) {
781 using trace_analyzer::Query;
782
783 Query begin(
784 Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_BEGIN) ||
785 Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_STEP_INTO) ||
786 Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_STEP_PAST));
787 Query end(Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_END) ||
788 Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_STEP_INTO) ||
789 Query::EventPhaseIs(TRACE_EVENT_PHASE_ASYNC_STEP_PAST));
790 Query match(Query::EventCategory() == Query::OtherCategory() &&
791 Query::EventId() == Query::OtherId());
792
793 if (match_pid) {
794 match = match && Query::EventPid() == Query::OtherPid();
795 }
796
797 AssociateEvents(begin, end, match);
798 }
799
AssociateEvents(const Query & first,const Query & second,const Query & match)800 void TraceAnalyzer::AssociateEvents(const Query& first,
801 const Query& second,
802 const Query& match) {
803 DCHECK(allow_association_changes_)
804 << "AssociateEvents not allowed after FindEvents";
805
806 // Search for matching begin/end event pairs. When a matching end is found,
807 // it is associated with the begin event.
808 std::vector<TraceEvent*> begin_stack;
809 for (size_t event_index = 0; event_index < raw_events_.size();
810 ++event_index) {
811
812 TraceEvent& this_event = raw_events_[event_index];
813
814 if (second.Evaluate(this_event)) {
815 // Search stack for matching begin, starting from end.
816 for (int stack_index = static_cast<int>(begin_stack.size()) - 1;
817 stack_index >= 0; --stack_index) {
818 TraceEvent& begin_event = *begin_stack[stack_index];
819
820 // Temporarily set other to test against the match query.
821 const TraceEvent* other_backup = begin_event.other_event;
822 begin_event.other_event = &this_event;
823 if (match.Evaluate(begin_event)) {
824 // Found a matching begin/end pair.
825 // Set the associated previous event
826 this_event.prev_event = &begin_event;
827 // Erase the matching begin event index from the stack.
828 begin_stack.erase(begin_stack.begin() + stack_index);
829 break;
830 }
831
832 // Not a match, restore original other and continue.
833 begin_event.other_event = other_backup;
834 }
835 }
836 // Even if this_event is a |second| event that has matched an earlier
837 // |first| event, it can still also be a |first| event and be associated
838 // with a later |second| event.
839 if (first.Evaluate(this_event)) {
840 begin_stack.push_back(&this_event);
841 }
842 }
843 }
844
MergeAssociatedEventArgs()845 void TraceAnalyzer::MergeAssociatedEventArgs() {
846 for (size_t i = 0; i < raw_events_.size(); ++i) {
847 // Merge all associated events with the first event.
848 const TraceEvent* other = raw_events_[i].other_event;
849 // Avoid looping by keeping set of encountered TraceEvents.
850 std::set<const TraceEvent*> encounters;
851 encounters.insert(&raw_events_[i]);
852 while (other && encounters.find(other) == encounters.end()) {
853 encounters.insert(other);
854 raw_events_[i].arg_numbers.insert(
855 other->arg_numbers.begin(),
856 other->arg_numbers.end());
857 raw_events_[i].arg_strings.insert(
858 other->arg_strings.begin(),
859 other->arg_strings.end());
860 other = other->other_event;
861 }
862 }
863 }
864
FindEvents(const Query & query,TraceEventVector * output)865 size_t TraceAnalyzer::FindEvents(const Query& query, TraceEventVector* output) {
866 allow_association_changes_ = false;
867 output->clear();
868 return FindMatchingEvents(
869 raw_events_, query, output, ignore_metadata_events_);
870 }
871
FindFirstOf(const Query & query)872 const TraceEvent* TraceAnalyzer::FindFirstOf(const Query& query) {
873 TraceEventVector output;
874 if (FindEvents(query, &output) > 0)
875 return output.front();
876 return nullptr;
877 }
878
FindLastOf(const Query & query)879 const TraceEvent* TraceAnalyzer::FindLastOf(const Query& query) {
880 TraceEventVector output;
881 if (FindEvents(query, &output) > 0)
882 return output.back();
883 return nullptr;
884 }
885
GetThreadName(const TraceEvent::ProcessThreadID & thread)886 const std::string& TraceAnalyzer::GetThreadName(
887 const TraceEvent::ProcessThreadID& thread) {
888 // If thread is not found, just add and return empty string.
889 return thread_names_[thread];
890 }
891
ParseMetadata()892 void TraceAnalyzer::ParseMetadata() {
893 for (size_t i = 0; i < raw_events_.size(); ++i) {
894 TraceEvent& this_event = raw_events_[i];
895 // Check for thread name metadata.
896 if (this_event.phase != TRACE_EVENT_PHASE_METADATA ||
897 this_event.name != "thread_name")
898 continue;
899 std::map<std::string, std::string>::const_iterator string_it =
900 this_event.arg_strings.find("name");
901 if (string_it != this_event.arg_strings.end())
902 thread_names_[this_event.thread] = string_it->second;
903 }
904 }
905
906 // Utility functions for collecting process-local traces and creating a
907 // |TraceAnalyzer| from the result.
908
Start(const std::string & category_filter_string)909 void Start(const std::string& category_filter_string) {
910 DCHECK(!base::trace_event::TraceLog::GetInstance()->IsEnabled());
911 base::trace_event::TraceLog::GetInstance()->SetEnabled(
912 base::trace_event::TraceConfig(category_filter_string, ""),
913 base::trace_event::TraceLog::RECORDING_MODE);
914 }
915
Stop()916 std::unique_ptr<TraceAnalyzer> Stop() {
917 DCHECK(base::trace_event::TraceLog::GetInstance()->IsEnabled());
918 base::trace_event::TraceLog::GetInstance()->SetDisabled();
919
920 base::trace_event::TraceResultBuffer buffer;
921 base::trace_event::TraceResultBuffer::SimpleOutput trace_output;
922 buffer.SetOutputCallback(trace_output.GetCallback());
923 base::RunLoop run_loop;
924 buffer.Start();
925 base::trace_event::TraceLog::GetInstance()->Flush(
926 base::BindRepeating(&OnTraceDataCollected, run_loop.QuitClosure(),
927 base::Unretained(&buffer)));
928 run_loop.Run();
929 buffer.Finish();
930
931 return base::WrapUnique(TraceAnalyzer::Create(trace_output.json_output));
932 }
933
934 // TraceEventVector utility functions.
935
GetRateStats(const TraceEventVector & events,RateStats * stats,const RateStatsOptions * options)936 bool GetRateStats(const TraceEventVector& events,
937 RateStats* stats,
938 const RateStatsOptions* options) {
939 DCHECK(stats);
940 // Need at least 3 events to calculate rate stats.
941 const size_t kMinEvents = 3;
942 if (events.size() < kMinEvents) {
943 LOG(ERROR) << "Not enough events: " << events.size();
944 return false;
945 }
946
947 std::vector<double> deltas;
948 size_t num_deltas = events.size() - 1;
949 for (size_t i = 0; i < num_deltas; ++i) {
950 double delta = events.at(i + 1)->timestamp - events.at(i)->timestamp;
951 if (delta < 0.0) {
952 LOG(ERROR) << "Events are out of order";
953 return false;
954 }
955 deltas.push_back(delta);
956 }
957
958 std::sort(deltas.begin(), deltas.end());
959
960 if (options) {
961 if (options->trim_min + options->trim_max > events.size() - kMinEvents) {
962 LOG(ERROR) << "Attempt to trim too many events";
963 return false;
964 }
965 deltas.erase(deltas.begin(), deltas.begin() + options->trim_min);
966 deltas.erase(deltas.end() - options->trim_max, deltas.end());
967 }
968
969 num_deltas = deltas.size();
970 double delta_sum = 0.0;
971 for (size_t i = 0; i < num_deltas; ++i)
972 delta_sum += deltas[i];
973
974 stats->min_us = *std::min_element(deltas.begin(), deltas.end());
975 stats->max_us = *std::max_element(deltas.begin(), deltas.end());
976 stats->mean_us = delta_sum / static_cast<double>(num_deltas);
977
978 double sum_mean_offsets_squared = 0.0;
979 for (size_t i = 0; i < num_deltas; ++i) {
980 double offset = fabs(deltas[i] - stats->mean_us);
981 sum_mean_offsets_squared += offset * offset;
982 }
983 stats->standard_deviation_us =
984 sqrt(sum_mean_offsets_squared / static_cast<double>(num_deltas - 1));
985
986 return true;
987 }
988
FindFirstOf(const TraceEventVector & events,const Query & query,size_t position,size_t * return_index)989 bool FindFirstOf(const TraceEventVector& events,
990 const Query& query,
991 size_t position,
992 size_t* return_index) {
993 DCHECK(return_index);
994 for (size_t i = position; i < events.size(); ++i) {
995 if (query.Evaluate(*events[i])) {
996 *return_index = i;
997 return true;
998 }
999 }
1000 return false;
1001 }
1002
FindLastOf(const TraceEventVector & events,const Query & query,size_t position,size_t * return_index)1003 bool FindLastOf(const TraceEventVector& events,
1004 const Query& query,
1005 size_t position,
1006 size_t* return_index) {
1007 DCHECK(return_index);
1008 for (size_t i = std::min(position + 1, events.size()); i != 0; --i) {
1009 if (query.Evaluate(*events[i - 1])) {
1010 *return_index = i - 1;
1011 return true;
1012 }
1013 }
1014 return false;
1015 }
1016
FindClosest(const TraceEventVector & events,const Query & query,size_t position,size_t * return_closest,size_t * return_second_closest)1017 bool FindClosest(const TraceEventVector& events,
1018 const Query& query,
1019 size_t position,
1020 size_t* return_closest,
1021 size_t* return_second_closest) {
1022 DCHECK(return_closest);
1023 if (events.empty() || position >= events.size())
1024 return false;
1025 size_t closest = events.size();
1026 size_t second_closest = events.size();
1027 for (size_t i = 0; i < events.size(); ++i) {
1028 if (!query.Evaluate(*events.at(i)))
1029 continue;
1030 if (closest == events.size()) {
1031 closest = i;
1032 continue;
1033 }
1034 if (fabs(events.at(i)->timestamp - events.at(position)->timestamp) <
1035 fabs(events.at(closest)->timestamp - events.at(position)->timestamp)) {
1036 second_closest = closest;
1037 closest = i;
1038 } else if (second_closest == events.size()) {
1039 second_closest = i;
1040 }
1041 }
1042
1043 if (closest < events.size() &&
1044 (!return_second_closest || second_closest < events.size())) {
1045 *return_closest = closest;
1046 if (return_second_closest)
1047 *return_second_closest = second_closest;
1048 return true;
1049 }
1050
1051 return false;
1052 }
1053
CountMatches(const TraceEventVector & events,const Query & query,size_t begin_position,size_t end_position)1054 size_t CountMatches(const TraceEventVector& events,
1055 const Query& query,
1056 size_t begin_position,
1057 size_t end_position) {
1058 if (begin_position >= events.size())
1059 return 0u;
1060 end_position = (end_position < events.size()) ? end_position : events.size();
1061 size_t count = 0u;
1062 for (size_t i = begin_position; i < end_position; ++i) {
1063 if (query.Evaluate(*events.at(i)))
1064 ++count;
1065 }
1066 return count;
1067 }
1068
1069 } // namespace trace_analyzer
1070