diff options
author | skyostil <skyostil@chromium.org> | 2016-03-21 14:53:10 -0700 |
---|---|---|
committer | Commit bot <commit-bot@chromium.org> | 2016-03-21 21:55:15 +0000 |
commit | e69ffec748f93302e2174fd434e198dc295e5bf3 (patch) | |
tree | 647ae641fd9b53b5d315a2b049f20bc2437271a6 | |
parent | 23ce46874e2864219fcc4f8e7218449bd14e64de (diff) | |
download | chromium_src-e69ffec748f93302e2174fd434e198dc295e5bf3.zip chromium_src-e69ffec748f93302e2174fd434e198dc295e5bf3.tar.gz chromium_src-e69ffec748f93302e2174fd434e198dc295e5bf3.tar.bz2 |
base: Add blame context
This patch introduces the concept of a blame context, which is
a logical entity to which we can attribute various types of costs
(e.g., CPU usage, network bandwidth, memory allocations, etc.). A
follow-up patch will add a specific blame context for web frames.
Design doc:
https://docs.google.com/document/d/15BB-suCb9j-nFt55yCFJBJCGzLg2qUm3WaSOPb8APtI
BUG=546021
Review URL: https://codereview.chromium.org/1776673002
Cr-Commit-Position: refs/heads/master@{#382401}
-rw-r--r-- | base/BUILD.gn | 3 | ||||
-rw-r--r-- | base/test/trace_event_analyzer.cc | 52 | ||||
-rw-r--r-- | base/test/trace_event_analyzer.h | 17 | ||||
-rw-r--r-- | base/test/trace_event_analyzer_unittest.cc | 94 | ||||
-rw-r--r-- | base/trace_event/blame_context.cc | 105 | ||||
-rw-r--r-- | base/trace_event/blame_context.h | 129 | ||||
-rw-r--r-- | base/trace_event/blame_context_unittest.cc | 216 | ||||
-rw-r--r-- | base/trace_event/trace_event.gypi | 3 |
8 files changed, 579 insertions, 40 deletions
diff --git a/base/BUILD.gn b/base/BUILD.gn index 226024c..b5552a6 100644 --- a/base/BUILD.gn +++ b/base/BUILD.gn @@ -857,6 +857,8 @@ component("base") { "timer/mock_timer.h", "timer/timer.cc", "timer/timer.h", + "trace_event/blame_context.cc", + "trace_event/blame_context.h", "trace_event/common/trace_event_common.h", "trace_event/heap_profiler_allocation_context.cc", "trace_event/heap_profiler_allocation_context.h", @@ -1852,6 +1854,7 @@ test("base_unittests") { "timer/mock_timer_unittest.cc", "timer/timer_unittest.cc", "tools_sanity_unittest.cc", + "trace_event/blame_context_unittest.cc", "trace_event/heap_profiler_allocation_context_tracker_unittest.cc", "trace_event/heap_profiler_allocation_register_unittest.cc", "trace_event/heap_profiler_heap_dump_writer_unittest.cc", diff --git a/base/test/trace_event_analyzer.cc b/base/test/trace_event_analyzer.cc index fc775f2..18bfe38 100644 --- a/base/test/trace_event_analyzer.cc +++ b/base/test/trace_event_analyzer.cc @@ -26,11 +26,13 @@ TraceEvent::TraceEvent() other_event(NULL) { } -TraceEvent::TraceEvent(const TraceEvent& other) = default; +TraceEvent::TraceEvent(TraceEvent&& other) = default; TraceEvent::~TraceEvent() { } +TraceEvent& TraceEvent::operator=(TraceEvent&& rhs) = default; + bool TraceEvent::SetFromJSON(const base::Value* event_value) { if (event_value->GetType() != base::Value::TYPE_DICTIONARY) { LOG(ERROR) << "Value must be TYPE_DICTIONARY"; @@ -54,6 +56,12 @@ bool TraceEvent::SetFromJSON(const base::Value* event_value) { bool require_id = (phase == TRACE_EVENT_PHASE_ASYNC_BEGIN || phase == TRACE_EVENT_PHASE_ASYNC_STEP_INTO || phase == TRACE_EVENT_PHASE_ASYNC_STEP_PAST || + phase == TRACE_EVENT_PHASE_MEMORY_DUMP || + phase == TRACE_EVENT_PHASE_ENTER_CONTEXT || + phase == TRACE_EVENT_PHASE_LEAVE_CONTEXT || + phase == TRACE_EVENT_PHASE_CREATE_OBJECT || + phase == TRACE_EVENT_PHASE_DELETE_OBJECT || + phase == TRACE_EVENT_PHASE_SNAPSHOT_OBJECT || phase == TRACE_EVENT_PHASE_ASYNC_END); if (require_origin && !dictionary->GetInteger("pid", &thread.process_id)) { @@ -103,11 +111,9 @@ bool TraceEvent::SetFromJSON(const base::Value* event_value) { arg_numbers[it.key()] = static_cast<double>(boolean ? 1 : 0); } else if (it.value().GetAsDouble(&double_num)) { arg_numbers[it.key()] = double_num; - } else { - LOG(WARNING) << "Value type of argument is not supported: " << - static_cast<int>(it.value().GetType()); - continue; // Skip non-supported arguments. } + // Record all arguments as values. + arg_values[it.key()] = it.value().CreateDeepCopy(); } return true; @@ -119,9 +125,9 @@ double TraceEvent::GetAbsTimeToOtherEvent() const { bool TraceEvent::GetArgAsString(const std::string& name, std::string* arg) const { - std::map<std::string, std::string>::const_iterator i = arg_strings.find(name); - if (i != arg_strings.end()) { - *arg = i->second; + const auto it = arg_strings.find(name); + if (it != arg_strings.end()) { + *arg = it->second; return true; } return false; @@ -129,9 +135,19 @@ bool TraceEvent::GetArgAsString(const std::string& name, bool TraceEvent::GetArgAsNumber(const std::string& name, double* arg) const { - std::map<std::string, double>::const_iterator i = arg_numbers.find(name); - if (i != arg_numbers.end()) { - *arg = i->second; + const auto it = arg_numbers.find(name); + if (it != arg_numbers.end()) { + *arg = it->second; + return true; + } + return false; +} + +bool TraceEvent::GetArgAsValue(const std::string& name, + scoped_ptr<base::Value>* arg) const { + const auto it = arg_values.find(name); + if (it != arg_values.end()) { + *arg = it->second->CreateDeepCopy(); return true; } return false; @@ -145,6 +161,10 @@ bool TraceEvent::HasNumberArg(const std::string& name) const { return (arg_numbers.find(name) != arg_numbers.end()); } +bool TraceEvent::HasArg(const std::string& name) const { + return (arg_values.find(name) != arg_values.end()); +} + std::string TraceEvent::GetKnownArgAsString(const std::string& name) const { std::string arg_string; bool result = GetArgAsString(name, &arg_string); @@ -173,6 +193,14 @@ bool TraceEvent::GetKnownArgAsBool(const std::string& name) const { return (arg_double != 0.0); } +scoped_ptr<base::Value> TraceEvent::GetKnownArgAsValue( + const std::string& name) const { + scoped_ptr<base::Value> arg_value; + bool result = GetArgAsValue(name, &arg_value); + DCHECK(result); + return arg_value; +} + // QueryNode QueryNode::QueryNode(const Query& query) : query_(query) { @@ -662,7 +690,7 @@ bool ParseEventsFromJson(const std::string& json, if (root_list->Get(i, &item)) { TraceEvent event; if (event.SetFromJSON(item)) - output->push_back(event); + output->push_back(std::move(event)); else return false; } diff --git a/base/test/trace_event_analyzer.h b/base/test/trace_event_analyzer.h index 253dbb4..8087ec5 100644 --- a/base/test/trace_event_analyzer.h +++ b/base/test/trace_event_analyzer.h @@ -111,7 +111,7 @@ struct TraceEvent { }; TraceEvent(); - TraceEvent(const TraceEvent& other); + TraceEvent(TraceEvent&& other); ~TraceEvent(); bool SetFromJSON(const base::Value* event_value) WARN_UNUSED_RESULT; @@ -120,6 +120,8 @@ struct TraceEvent { return timestamp < rhs.timestamp; } + TraceEvent& operator=(TraceEvent&& rhs); + bool has_other_event() const { return other_event; } // Returns absolute duration in microseconds between this event and other @@ -131,11 +133,16 @@ struct TraceEvent { bool GetArgAsString(const std::string& name, std::string* arg) const; // Return the argument value if it exists and it is a number. bool GetArgAsNumber(const std::string& name, double* arg) const; + // Return the argument value if it exists. + bool GetArgAsValue(const std::string& name, + scoped_ptr<base::Value>* arg) const; // Check if argument exists and is string. bool HasStringArg(const std::string& name) const; // Check if argument exists and is number (double, int or bool). bool HasNumberArg(const std::string& name) const; + // Check if argument exists. + bool HasArg(const std::string& name) const; // Get known existing arguments as specific types. // Useful when you have already queried the argument with @@ -144,6 +151,7 @@ struct TraceEvent { double GetKnownArgAsDouble(const std::string& name) const; int GetKnownArgAsInt(const std::string& name) const; bool GetKnownArgAsBool(const std::string& name) const; + scoped_ptr<base::Value> GetKnownArgAsValue(const std::string& name) const; // Process ID and Thread ID. ProcessThreadID thread; @@ -151,22 +159,17 @@ struct TraceEvent { // Time since epoch in microseconds. // Stored as double to match its JSON representation. double timestamp; - double duration; - char phase; - std::string category; - std::string name; - std::string id; // All numbers and bool values from TraceEvent args are cast to double. // bool becomes 1.0 (true) or 0.0 (false). std::map<std::string, double> arg_numbers; - std::map<std::string, std::string> arg_strings; + std::map<std::string, scoped_ptr<base::Value>> arg_values; // The other event associated with this event (or NULL). const TraceEvent* other_event; diff --git a/base/test/trace_event_analyzer_unittest.cc b/base/test/trace_event_analyzer_unittest.cc index af1a3e0..b133cae 100644 --- a/base/test/trace_event_analyzer_unittest.cc +++ b/base/test/trace_event_analyzer_unittest.cc @@ -11,6 +11,7 @@ #include "base/test/trace_event_analyzer.h" #include "base/threading/platform_thread.h" #include "base/trace_event/trace_buffer.h" +#include "base/trace_event/trace_event_argument.h" #include "testing/gmock/include/gmock/gmock.h" #include "testing/gtest/include/gtest/gtest.h" @@ -98,6 +99,7 @@ TEST_F(TraceEventAnalyzerTest, TraceEvent) { event.arg_numbers["int"] = static_cast<double>(int_num); event.arg_numbers["double"] = double_num; event.arg_strings["string"] = str; + event.arg_values["dict"] = make_scoped_ptr(new base::DictionaryValue()); ASSERT_TRUE(event.HasNumberArg("false")); ASSERT_TRUE(event.HasNumberArg("true")); @@ -106,12 +108,18 @@ TEST_F(TraceEventAnalyzerTest, TraceEvent) { ASSERT_TRUE(event.HasStringArg("string")); ASSERT_FALSE(event.HasNumberArg("notfound")); ASSERT_FALSE(event.HasStringArg("notfound")); + ASSERT_TRUE(event.HasArg("dict")); + ASSERT_FALSE(event.HasArg("notfound")); EXPECT_FALSE(event.GetKnownArgAsBool("false")); EXPECT_TRUE(event.GetKnownArgAsBool("true")); EXPECT_EQ(int_num, event.GetKnownArgAsInt("int")); EXPECT_EQ(double_num, event.GetKnownArgAsDouble("double")); EXPECT_STREQ(str, event.GetKnownArgAsString("string").c_str()); + + scoped_ptr<base::Value> arg; + EXPECT_TRUE(event.GetArgAsValue("dict", &arg)); + EXPECT_EQ(base::Value::TYPE_DICTIONARY, arg->GetType()); } TEST_F(TraceEventAnalyzerTest, QueryEventMember) { @@ -712,8 +720,7 @@ TEST_F(TraceEventAnalyzerTest, RateStats) { std::vector<TraceEvent> events; events.reserve(100); TraceEventVector event_ptrs; - TraceEvent event; - event.timestamp = 0.0; + double timestamp = 0.0; double little_delta = 1.0; double big_delta = 10.0; double tiny_delta = 0.1; @@ -722,8 +729,10 @@ TEST_F(TraceEventAnalyzerTest, RateStats) { // Insert 10 events, each apart by little_delta. for (int i = 0; i < 10; ++i) { - event.timestamp += little_delta; - events.push_back(event); + timestamp += little_delta; + TraceEvent event; + event.timestamp = timestamp; + events.push_back(std::move(event)); event_ptrs.push_back(&events.back()); } @@ -734,9 +743,13 @@ TEST_F(TraceEventAnalyzerTest, RateStats) { EXPECT_EQ(0.0, stats.standard_deviation_us); // Add an event apart by big_delta. - event.timestamp += big_delta; - events.push_back(event); - event_ptrs.push_back(&events.back()); + { + timestamp += big_delta; + TraceEvent event; + event.timestamp = timestamp; + events.push_back(std::move(event)); + event_ptrs.push_back(&events.back()); + } ASSERT_TRUE(GetRateStats(event_ptrs, &stats, NULL)); EXPECT_LT(little_delta, stats.mean_us); @@ -754,9 +767,13 @@ TEST_F(TraceEventAnalyzerTest, RateStats) { EXPECT_EQ(0.0, stats.standard_deviation_us); // Add an event apart by tiny_delta. - event.timestamp += tiny_delta; - events.push_back(event); - event_ptrs.push_back(&events.back()); + { + timestamp += tiny_delta; + TraceEvent event; + event.timestamp = timestamp; + events.push_back(std::move(event)); + event_ptrs.push_back(&events.back()); + } // Trim off both the biggest and tiniest delta and verify stats. options.trim_min = 1; @@ -768,17 +785,20 @@ TEST_F(TraceEventAnalyzerTest, RateStats) { EXPECT_EQ(0.0, stats.standard_deviation_us); // Verify smallest allowed number of events. - TraceEventVector few_event_ptrs; - few_event_ptrs.push_back(&event); - few_event_ptrs.push_back(&event); - ASSERT_FALSE(GetRateStats(few_event_ptrs, &stats, NULL)); - few_event_ptrs.push_back(&event); - ASSERT_TRUE(GetRateStats(few_event_ptrs, &stats, NULL)); - - // Trim off more than allowed and verify failure. - options.trim_min = 0; - options.trim_max = 1; - ASSERT_FALSE(GetRateStats(few_event_ptrs, &stats, &options)); + { + TraceEvent event; + TraceEventVector few_event_ptrs; + few_event_ptrs.push_back(&event); + few_event_ptrs.push_back(&event); + ASSERT_FALSE(GetRateStats(few_event_ptrs, &stats, NULL)); + few_event_ptrs.push_back(&event); + ASSERT_TRUE(GetRateStats(few_event_ptrs, &stats, NULL)); + + // Trim off more than allowed and verify failure. + options.trim_min = 0; + options.trim_max = 1; + ASSERT_FALSE(GetRateStats(few_event_ptrs, &stats, &options)); + } } // Test FindFirstOf and FindLastOf. @@ -895,5 +915,37 @@ TEST_F(TraceEventAnalyzerTest, CountMatches) { EXPECT_EQ(num_named, CountMatches(event_ptrs, query_named)); } +TEST_F(TraceEventAnalyzerTest, ComplexArgument) { + ManualSetUp(); + + BeginTracing(); + { + scoped_ptr<base::trace_event::TracedValue> value( + new base::trace_event::TracedValue); + value->SetString("property", "value"); + TRACE_EVENT1("cat", "name", "arg", std::move(value)); + } + EndTracing(); + + scoped_ptr<TraceAnalyzer> analyzer( + TraceAnalyzer::Create(output_.json_output)); + ASSERT_TRUE(analyzer.get()); + + TraceEventVector events; + analyzer->FindEvents(Query::EventName() == Query::String("name"), &events); + + EXPECT_EQ(1u, events.size()); + EXPECT_EQ("cat", events[0]->category); + EXPECT_EQ("name", events[0]->name); + EXPECT_TRUE(events[0]->HasArg("arg")); + + scoped_ptr<base::Value> arg; + events[0]->GetArgAsValue("arg", &arg); + base::DictionaryValue* arg_dict; + EXPECT_TRUE(arg->GetAsDictionary(&arg_dict)); + std::string property; + EXPECT_TRUE(arg_dict->GetString("property", &property)); + EXPECT_EQ("value", property); +} } // namespace trace_analyzer diff --git a/base/trace_event/blame_context.cc b/base/trace_event/blame_context.cc new file mode 100644 index 0000000..0bf7896 --- /dev/null +++ b/base/trace_event/blame_context.cc @@ -0,0 +1,105 @@ +// Copyright 2016 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. + +#include "base/trace_event/blame_context.h" + +#include "base/strings/stringprintf.h" +#include "base/trace_event/trace_event.h" +#include "base/trace_event/trace_event_argument.h" + +namespace base { +namespace trace_event { + +BlameContext::BlameContext(const char* category, + const char* name, + const char* type, + const char* scope, + int64_t id, + const BlameContext* parent_context) + : category_(category), + name_(name), + type_(type), + scope_(scope), + id_(id), + parent_scope_(parent_context ? parent_context->scope() : nullptr), + parent_id_(parent_context ? parent_context->id() : 0), + category_group_enabled_(nullptr) { + DCHECK(!parent_context || !std::strcmp(name_, parent_context->name())) + << "Parent blame context must have the same name"; +} + +BlameContext::~BlameContext() { + DCHECK(WasInitialized()); + TRACE_EVENT_API_ADD_TRACE_EVENT( + TRACE_EVENT_PHASE_DELETE_OBJECT, category_group_enabled_, type_, scope_, + id_, 0, nullptr, nullptr, nullptr, nullptr, TRACE_EVENT_FLAG_HAS_ID); + trace_event::TraceLog::GetInstance()->RemoveEnabledStateObserver(this); +} + +void BlameContext::Enter() { + DCHECK(WasInitialized()); + TRACE_EVENT_API_ADD_TRACE_EVENT(TRACE_EVENT_PHASE_ENTER_CONTEXT, + category_group_enabled_, name_, scope_, id_, + 0 /* num_args */, nullptr, nullptr, nullptr, + nullptr, TRACE_EVENT_FLAG_HAS_ID); +} + +void BlameContext::Leave() { + DCHECK(WasInitialized()); + TRACE_EVENT_API_ADD_TRACE_EVENT(TRACE_EVENT_PHASE_LEAVE_CONTEXT, + category_group_enabled_, name_, scope_, id_, + 0 /* num_args */, nullptr, nullptr, nullptr, + nullptr, TRACE_EVENT_FLAG_HAS_ID); +} + +void BlameContext::TakeSnapshot() { + DCHECK(WasInitialized()); + if (!*category_group_enabled_) + return; + scoped_ptr<trace_event::TracedValue> snapshot(new trace_event::TracedValue); + AsValueInto(snapshot.get()); + static const char* kArgName = "snapshot"; + const int kNumArgs = 1; + unsigned char arg_types[1] = {TRACE_VALUE_TYPE_CONVERTABLE}; + scoped_ptr<trace_event::ConvertableToTraceFormat> arg_values[1] = { + std::move(snapshot)}; + TRACE_EVENT_API_ADD_TRACE_EVENT(TRACE_EVENT_PHASE_SNAPSHOT_OBJECT, + category_group_enabled_, type_, scope_, id_, + kNumArgs, &kArgName, arg_types, nullptr, + arg_values, TRACE_EVENT_FLAG_HAS_ID); +} + +void BlameContext::OnTraceLogEnabled() { + DCHECK(WasInitialized()); + TakeSnapshot(); +} + +void BlameContext::OnTraceLogDisabled() {} + +void BlameContext::AsValueInto(trace_event::TracedValue* state) { + DCHECK(WasInitialized()); + if (!parent_id_) + return; + state->BeginDictionary("parent"); + state->SetString("id_ref", StringPrintf("0x%" PRIx64, parent_id_)); + state->SetString("scope", parent_scope_); + state->EndDictionary(); +} + +void BlameContext::Initialize() { + category_group_enabled_ = + TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(category_); + TRACE_EVENT_API_ADD_TRACE_EVENT( + TRACE_EVENT_PHASE_CREATE_OBJECT, category_group_enabled_, type_, scope_, + id_, 0, nullptr, nullptr, nullptr, nullptr, TRACE_EVENT_FLAG_HAS_ID); + trace_event::TraceLog::GetInstance()->AddEnabledStateObserver(this); + TakeSnapshot(); +} + +bool BlameContext::WasInitialized() const { + return category_group_enabled_ != nullptr; +} + +} // namespace trace_event +} // namespace base diff --git a/base/trace_event/blame_context.h b/base/trace_event/blame_context.h new file mode 100644 index 0000000..81c35af --- /dev/null +++ b/base/trace_event/blame_context.h @@ -0,0 +1,129 @@ +// Copyright 2016 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. + +#ifndef BASE_TRACE_EVENT_BLAME_CONTEXT_H_ +#define BASE_TRACE_EVENT_BLAME_CONTEXT_H_ + +#include <inttypes.h> + +#include "base/base_export.h" +#include "base/macros.h" +#include "base/trace_event/trace_log.h" + +namespace base { +namespace trace_event { +class TracedValue; +} + +namespace trace_event { + +// A blame context represents a logical unit to which we want to attribute +// different costs (e.g., CPU, network, or memory usage). An example of a blame +// context is an <iframe> element on a web page. Different subsystems can +// "enter" and "leave" blame contexts to indicate that they are doing work which +// should be accounted against this blame context. +// +// A blame context can optionally have a parent context, forming a blame context +// tree. When work is attributed to a particular blame context, it is considered +// to count against all of that context's children too. This is useful when work +// cannot be exactly attributed into a more specific context. For example, +// Javascript garbage collection generally needs to inspect all objects on a +// page instead looking at each <iframe> individually. In this case the work +// should be attributed to a blame context which is the parent of all <iframe> +// blame contexts. +class BASE_EXPORT BlameContext + : public trace_event::TraceLog::EnabledStateObserver { + public: + // Construct a blame context belonging to the blame context tree |name|, using + // the tracing category |category|, identified by |id| from the |scope| + // namespace. |type| identifies the type of this object snapshot in the blame + // context tree. |parent_context| is the parent of this blame context or + // null. Note that all strings must have application lifetime. + // + // For example, a blame context which represents a specific <iframe> in a + // browser frame tree could be specified with: + // + // category="blink", + // name="FrameTree", + // type="IFrame", + // scope="IFrameIdentifier", + // id=1234. + // + // Each <iframe> blame context could have another <iframe> context as a + // parent, or a top-level context which represents the entire browser: + // + // category="blink", + // name="FrameTree", + // type="Browser", + // scope="BrowserIdentifier", + // id=1. + // + // Note that the |name| property is identical, signifying that both context + // types are part of the same tree. + // + BlameContext(const char* category, + const char* name, + const char* type, + const char* scope, + int64_t id, + const BlameContext* parent_context); + ~BlameContext() override; + + // Initialize the blame context, automatically taking a snapshot if tracing is + // enabled. Must be called before any other methods on this class. + void Initialize(); + + // Indicate that the current thread is now doing work which should count + // against this blame context. + void Enter(); + + // Leave and stop doing work for a previously entered blame context. If + // another blame context belongin to the same tree was entered prior to this + // one, it becomes the active blame context for this thread again. + void Leave(); + + // Record a snapshot of the blame context. This is normally only needed if a + // blame context subclass defines custom properties (see AsValueInto) and one + // or more of those properties have changed. + void TakeSnapshot(); + + const char* category() const { return category_; } + const char* name() const { return name_; } + const char* type() const { return type_; } + const char* scope() const { return scope_; } + int64_t id() const { return id_; } + + // trace_event::TraceLog::EnabledStateObserver implementation: + void OnTraceLogEnabled() override; + void OnTraceLogDisabled() override; + + protected: + // Serialize the properties of this blame context into |state|. Subclasses can + // override this method to record additional properties (e.g, the URL for an + // <iframe> blame context). Note that an overridden implementation must still + // call this base method. + virtual void AsValueInto(trace_event::TracedValue* state); + + private: + bool WasInitialized() const; + + // The following string pointers have application lifetime. + const char* category_; + const char* name_; + const char* type_; + const char* scope_; + const int64_t id_; + + const char* parent_scope_; + const int64_t parent_id_; + + const unsigned char* category_group_enabled_; + + DISALLOW_COPY_AND_ASSIGN(BlameContext); +}; + +} // namespace trace_event +} // namespace base + +#endif // BASE_TRACE_EVENT_BLAME_CONTEXT_H_ diff --git a/base/trace_event/blame_context_unittest.cc b/base/trace_event/blame_context_unittest.cc new file mode 100644 index 0000000..7217d8f --- /dev/null +++ b/base/trace_event/blame_context_unittest.cc @@ -0,0 +1,216 @@ +// Copyright 2016 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. + +#include "base/trace_event/blame_context.h" + +#include "base/json/json_writer.h" +#include "base/memory/ref_counted_memory.h" +#include "base/run_loop.h" +#include "base/test/trace_event_analyzer.h" +#include "base/trace_event/trace_buffer.h" +#include "base/trace_event/trace_event_argument.h" +#include "testing/gtest/include/gtest/gtest.h" + +namespace base { +namespace trace_event { +namespace { + +const char kTestBlameContextCategory[] = "test"; +const char kDisabledTestBlameContextCategory[] = "disabled-by-default-test"; +const char kTestBlameContextName[] = "TestBlameContext"; +const char kTestBlameContextType[] = "TestBlameContextType"; +const char kTestBlameContextScope[] = "TestBlameContextScope"; + +class TestBlameContext : public BlameContext { + public: + explicit TestBlameContext(int id) + : BlameContext(kTestBlameContextCategory, + kTestBlameContextName, + kTestBlameContextType, + kTestBlameContextScope, + id, + nullptr) {} + + TestBlameContext(int id, const TestBlameContext& parent) + : BlameContext(kTestBlameContextCategory, + kTestBlameContextName, + kTestBlameContextType, + kTestBlameContextScope, + id, + &parent) {} + + protected: + void AsValueInto(trace_event::TracedValue* state) override { + BlameContext::AsValueInto(state); + state->SetBoolean("crossStreams", false); + } +}; + +class DisabledTestBlameContext : public BlameContext { + public: + explicit DisabledTestBlameContext(int id) + : BlameContext(kDisabledTestBlameContextCategory, + kTestBlameContextName, + kTestBlameContextType, + kTestBlameContextScope, + id, + nullptr) {} +}; + +void OnTraceDataCollected(Closure quit_closure, + trace_event::TraceResultBuffer* buffer, + const scoped_refptr<RefCountedString>& json, + bool has_more_events) { + buffer->AddFragment(json->data()); + if (!has_more_events) + quit_closure.Run(); +} + +class BlameContextTest : public testing::Test { + public: + void StartTracing(); + void StopTracing(); + scoped_ptr<trace_analyzer::TraceAnalyzer> CreateTraceAnalyzer(); +}; + +void BlameContextTest::StartTracing() { + trace_event::TraceLog::GetInstance()->SetEnabled( + trace_event::TraceConfig("*"), trace_event::TraceLog::RECORDING_MODE); +} + +void BlameContextTest::StopTracing() { + trace_event::TraceLog::GetInstance()->SetDisabled(); +} + +scoped_ptr<trace_analyzer::TraceAnalyzer> +BlameContextTest::CreateTraceAnalyzer() { + trace_event::TraceResultBuffer buffer; + trace_event::TraceResultBuffer::SimpleOutput trace_output; + buffer.SetOutputCallback(trace_output.GetCallback()); + RunLoop run_loop; + buffer.Start(); + trace_event::TraceLog::GetInstance()->Flush( + Bind(&OnTraceDataCollected, run_loop.QuitClosure(), Unretained(&buffer))); + run_loop.Run(); + buffer.Finish(); + + return make_scoped_ptr( + trace_analyzer::TraceAnalyzer::Create(trace_output.json_output)); +} + +TEST_F(BlameContextTest, EnterAndLeave) { + using trace_analyzer::Query; + StartTracing(); + { + TestBlameContext blame_context(0x1234); + blame_context.Initialize(); + blame_context.Enter(); + blame_context.Leave(); + } + StopTracing(); + scoped_ptr<trace_analyzer::TraceAnalyzer> analyzer = CreateTraceAnalyzer(); + + trace_analyzer::TraceEventVector events; + Query q = Query::EventPhaseIs(TRACE_EVENT_PHASE_ENTER_CONTEXT) || + Query::EventPhaseIs(TRACE_EVENT_PHASE_LEAVE_CONTEXT); + analyzer->FindEvents(q, &events); + + EXPECT_EQ(2u, events.size()); + EXPECT_EQ(TRACE_EVENT_PHASE_ENTER_CONTEXT, events[0]->phase); + EXPECT_EQ(kTestBlameContextCategory, events[0]->category); + EXPECT_EQ(kTestBlameContextName, events[0]->name); + EXPECT_EQ("0x1234", events[0]->id); + EXPECT_EQ(TRACE_EVENT_PHASE_LEAVE_CONTEXT, events[1]->phase); + EXPECT_EQ(kTestBlameContextCategory, events[1]->category); + EXPECT_EQ(kTestBlameContextName, events[1]->name); + EXPECT_EQ("0x1234", events[1]->id); +} + +TEST_F(BlameContextTest, DifferentCategories) { + // Ensure there is no cross talk between blame contexts from different + // categories. + using trace_analyzer::Query; + StartTracing(); + { + TestBlameContext blame_context(0x1234); + DisabledTestBlameContext disabled_blame_context(0x5678); + blame_context.Initialize(); + blame_context.Enter(); + blame_context.Leave(); + disabled_blame_context.Initialize(); + disabled_blame_context.Enter(); + disabled_blame_context.Leave(); + } + StopTracing(); + scoped_ptr<trace_analyzer::TraceAnalyzer> analyzer = CreateTraceAnalyzer(); + + trace_analyzer::TraceEventVector events; + Query q = Query::EventPhaseIs(TRACE_EVENT_PHASE_ENTER_CONTEXT) || + Query::EventPhaseIs(TRACE_EVENT_PHASE_LEAVE_CONTEXT); + analyzer->FindEvents(q, &events); + + // None of the events from the disabled-by-default category should show up. + EXPECT_EQ(2u, events.size()); + EXPECT_EQ(TRACE_EVENT_PHASE_ENTER_CONTEXT, events[0]->phase); + EXPECT_EQ(kTestBlameContextCategory, events[0]->category); + EXPECT_EQ(kTestBlameContextName, events[0]->name); + EXPECT_EQ("0x1234", events[0]->id); + EXPECT_EQ(TRACE_EVENT_PHASE_LEAVE_CONTEXT, events[1]->phase); + EXPECT_EQ(kTestBlameContextCategory, events[1]->category); + EXPECT_EQ(kTestBlameContextName, events[1]->name); + EXPECT_EQ("0x1234", events[1]->id); +} + +TEST_F(BlameContextTest, TakeSnapshot) { + using trace_analyzer::Query; + StartTracing(); + { + TestBlameContext parent_blame_context(0x5678); + TestBlameContext blame_context(0x1234, parent_blame_context); + parent_blame_context.Initialize(); + blame_context.Initialize(); + blame_context.TakeSnapshot(); + } + StopTracing(); + scoped_ptr<trace_analyzer::TraceAnalyzer> analyzer = CreateTraceAnalyzer(); + + trace_analyzer::TraceEventVector events; + Query q = Query::EventPhaseIs(TRACE_EVENT_PHASE_SNAPSHOT_OBJECT); + analyzer->FindEvents(q, &events); + + // We should have 3 snapshots: one for both calls to Initialize() and one from + // the explicit call to TakeSnapshot(). + EXPECT_EQ(3u, events.size()); + EXPECT_EQ(kTestBlameContextCategory, events[0]->category); + EXPECT_EQ(kTestBlameContextType, events[0]->name); + EXPECT_EQ("0x5678", events[0]->id); + EXPECT_TRUE(events[0]->HasArg("snapshot")); + + EXPECT_EQ(kTestBlameContextCategory, events[1]->category); + EXPECT_EQ(kTestBlameContextType, events[1]->name); + EXPECT_EQ("0x1234", events[1]->id); + EXPECT_TRUE(events[0]->HasArg("snapshot")); + + EXPECT_EQ(kTestBlameContextCategory, events[2]->category); + EXPECT_EQ(kTestBlameContextType, events[2]->name); + EXPECT_EQ("0x1234", events[2]->id); + EXPECT_TRUE(events[0]->HasArg("snapshot")); + + const char kExpectedSnapshotJson[] = + "{" + "\"crossStreams\":false," + "\"parent\":{" + "\"id_ref\":\"0x5678\"," + "\"scope\":\"TestBlameContextScope\"" + "}" + "}"; + + std::string snapshot_json; + JSONWriter::Write(*events[2]->GetKnownArgAsValue("snapshot"), &snapshot_json); + EXPECT_EQ(kExpectedSnapshotJson, snapshot_json); +} + +} // namepace +} // namespace trace_event +} // namespace base diff --git a/base/trace_event/trace_event.gypi b/base/trace_event/trace_event.gypi index d5583fa..a62d213 100644 --- a/base/trace_event/trace_event.gypi +++ b/base/trace_event/trace_event.gypi @@ -4,6 +4,8 @@ { 'variables': { 'trace_event_sources' : [ + 'trace_event/blame_context.cc', + 'trace_event/blame_context.h', 'trace_event/common/trace_event_common.h', 'trace_event/heap_profiler_allocation_context.cc', 'trace_event/heap_profiler_allocation_context.h', @@ -67,6 +69,7 @@ 'trace_event/winheap_dump_provider_win.h', ], 'trace_event_test_sources' : [ + 'trace_event/blame_context_unittest.cc', 'trace_event/heap_profiler_allocation_context_tracker_unittest.cc', 'trace_event/heap_profiler_allocation_register_unittest.cc', 'trace_event/heap_profiler_heap_dump_writer_unittest.cc', |